hid: clean up/finalize logging

hid/main.go

@@ -952,6 +952,12 @@ func ircNotifyRoommates(c *client, message string) {
 
 // --- Clients (continued) -----------------------------------------------------
 
+func (c *client) printDebug(format string, args ...interface{}) {
+	if debugMode {
+		printDebug("(%s) %s", c.address, fmt.Sprintf(format, args...))
+	}
+}
+
 func ircAppendClientModes(m uint, mode []byte) []byte {
 	if 0 != m&ircUserModeInvisible {
 		mode = append(mode, 'i')
@@ -998,6 +1004,8 @@ func (c *client) send(line string) {
 		bytes = bytes[:ircMaxMessageLength]
 	}
 
+	c.printDebug("<- %s", bytes)
+
 	// TODO: Kill the connection above some "SendQ" threshold (careful!)
 	c.sendQ = append(c.sendQ, bytes...)
 	c.sendQ = append(c.sendQ, "\r\n"...)
@@ -1049,13 +1057,12 @@ func (c *client) unregister(reason string) {
 // Close the connection and forget about the client.
 func (c *client) kill(reason string) {
 	if reason == "" {
-		reason = "Client exited"
+		c.unregister("Client exited")
+	} else {
+		c.unregister(reason)
 	}
-	c.unregister(reason)
 
-	// TODO: Log the address; seems like we always have c.address.
+	c.printDebug("client destroyed (%s)", reason)
-	// In fact, do it in most debug logs, could be a method of client.
-	printDebug("client destroyed")
 
 	// Try to send a "close notify" alert if the TLS object is ready,
 	// otherwise just tear down the transport.
@@ -2948,14 +2955,14 @@ func ircProcessMessage(c *client, msg *message, raw string) {
 
 // Handle the results from initializing the client's connection.
 func (c *client) onPrepared(host string, isTLS bool) {
+	c.printDebug("client resolved to %s, TLS %t", host, isTLS)
 	if !isTLS {
 		c.conn = c.transport.(connCloseWriter)
 	} else if tlsConf != nil {
 		c.tls = tls.Server(c.transport, tlsConf)
 		c.conn = c.tls
 	} else {
-		printDebug("could not initialize TLS for %s: TLS support disabled",
+		c.printDebug("could not initialize TLS: disabled")
-			c.address)
 		c.kill("TLS support disabled")
 		return
 	}
@@ -2988,10 +2995,10 @@ func (c *client) onRead(data []byte, readErr error) {
 		// XXX: And since it accepts LF, we miscalculate receivedBytes within.
 		c.recvQ = c.recvQ[advance:]
 		line := string(token)
-		printDebug("-> %s", line)
+		c.printDebug("-> %s", line)
 
 		if msg := ircParseMessage(line); msg == nil {
-			printDebug("error: invalid line")
+			c.printDebug("error: invalid line")
 		} else {
 			ircProcessMessage(c, msg, line)
 		}
@@ -3001,18 +3008,17 @@ func (c *client) onRead(data []byte, readErr error) {
 		c.reading = false
 
 		if readErr != io.EOF {
-			printDebug("%s", readErr)
+			c.printDebug("%s", readErr)
 			c.kill(readErr.Error())
 		} else if c.closing {
 			// Disregarding whether a clean shutdown has happened or not.
-			printDebug("client finished shutdown")
+			c.printDebug("client finished shutdown")
 			c.kill("")
 		} else {
-			printDebug("client EOF")
+			c.printDebug("client EOF")
 			c.closeLink("")
 		}
 	} else if len(c.recvQ) > 8192 {
-		printDebug("client recvQ overrun")
 		c.closeLink("recvQ overrun")
 
 		// tls.Conn doesn't have the CloseRead method (and it needs to be able
@@ -3037,7 +3043,7 @@ func (c *client) onWrite(written int, writeErr error) {
 	c.writing = false
 
 	if writeErr != nil {
-		printDebug("%s", writeErr)
+		c.printDebug("%s", writeErr)
 		c.kill(writeErr.Error())
 	} else if len(c.sendQ) > 0 {
 		c.flushSendQ()
@@ -3076,12 +3082,7 @@ func accept(ln net.Listener) {
 }
 
 func prepare(client *client) {
-	conn := client.transport
+	conn, host := client.transport, client.hostname
-	host, _, err := net.SplitHostPort(conn.RemoteAddr().String())
-	if err != nil {
-		// In effect, we require TCP/UDP, as they have port numbers.
-		exitFatal("%s", err)
-	}
 
 	// The Cgo resolver doesn't pthread_cancel getnameinfo threads, so not
 	// bothering with pointless contexts.
@@ -3163,12 +3164,10 @@ func processOneEvent() {
 			break
 		}
 
-		printDebug("accepted client connection")
-
-		// In effect, we require TCP/UDP, as they have port numbers.
 		address := conn.RemoteAddr().String()
 		host, port, err := net.SplitHostPort(address)
 		if err != nil {
+			// In effect, we require TCP/UDP, as they have port numbers.
 			exitFatal("%s", err)
 		}
 
@@ -3183,26 +3182,25 @@ func processOneEvent() {
 			// TODO: Make this configurable and more fine-grained.
 			antiflood: newFloodDetector(10*time.Second, 20),
 		}
+
 		clients[c] = true
+		c.printDebug("new client")
 		go prepare(c)
 
 		// The TLS autodetection in prepare needs to have a timeout.
 		c.setKillTimer()
 
 	case ev := <-prepared:
-		printDebug("client is ready: %s", ev.host)
 		if _, ok := clients[ev.client]; ok {
 			ev.client.onPrepared(ev.host, ev.isTLS)
 		}
 
 	case ev := <-reads:
-		printDebug("received data from client")
 		if _, ok := clients[ev.client]; ok {
 			ev.client.onRead(ev.data, ev.err)
 		}
 
 	case ev := <-writes:
-		printDebug("sent data to client")
 		if _, ok := clients[ev.client]; ok {
 			ev.client.onWrite(ev.written, ev.err)
 		}
@@ -3392,6 +3390,7 @@ func ircSetupListenFDs() error {
 			return err
 		}
 		listeners = append(listeners, ln)
+		printStatus("listening on %s", address)
 	}
 	if len(listeners) == 0 {
 		return errors.New("network setup failed: no ports to listen on")
@@ -3405,7 +3404,7 @@ func ircSetupListenFDs() error {
 // --- Main --------------------------------------------------------------------
 
 func main() {
-	flag.BoolVar(&debugMode, "debug", false, "run in debug mode")
+	flag.BoolVar(&debugMode, "debug", false, "run in verbose debug mode")
 	version := flag.Bool("version", false, "show version and exit")
 	writeDefaultCfg := flag.Bool("writedefaultcfg", false,
 		"write a default configuration file and exit")