Work on logging format

device.go

@@ -339,7 +339,6 @@ func (device *Device) RemoveAllPeers() {
 	defer device.peers.mutex.Unlock()
 
 	for key, peer := range device.peers.keyMap {
-		println("rm", peer.String())
 		unsafeRemovePeer(device, peer, key)
 	}
 

peer.go

@@ -200,7 +200,8 @@ func (peer *Peer) Start() {
 		return
 	}
 
-	peer.device.log.Debug.Println("Starting:", peer.String())
+	device := peer.device
+	device.log.Debug.Println(peer.String(), ": Starting...")
 
 	// sanity check : these should be 0
 
@@ -247,7 +248,7 @@ func (peer *Peer) Stop() {
 	}
 
 	device := peer.device
-	device.log.Debug.Println("Stopping:", peer.String())
+	device.log.Debug.Println(peer.String(), ": Stopping...")
 
 	// stop & wait for ongoing peer routines
 
@@ -270,6 +271,13 @@ func (peer *Peer) Stop() {
 	close(peer.queue.outbound)
 	close(peer.queue.inbound)
 
+	// close signals
+
+	peer.signal.newKeyPair.Close()
+	peer.signal.handshakeBegin.Close()
+	peer.signal.handshakeCompleted.Close()
+	peer.signal.flushNonceQueue.Close()
+
 	// clear key pairs
 
 	kp := &peer.keyPairs

receive.go

@@ -430,7 +430,7 @@ func (device *Device) RoutineHandshake() {
 			peer.TimerEphemeralKeyCreated()
 			peer.NewKeyPair()
 
-			logDebug.Println("Creating response message for", peer.String())
+			logDebug.Println(peer.String(), "Creating handshake response")
 
 			writer := bytes.NewBuffer(temp[:0])
 			binary.Write(writer, binary.LittleEndian, response)
@@ -443,7 +443,7 @@ func (device *Device) RoutineHandshake() {
 			if err == nil {
 				peer.TimerAnyAuthenticatedPacketTraversal()
 			} else {
-				logError.Println("Failed to send response to:", peer.String(), err)
+				logError.Println(peer.String(), "Failed to send handshake response", err)
 			}
 
 		case MessageResponseType:
@@ -495,14 +495,17 @@ func (device *Device) RoutineHandshake() {
 
 func (peer *Peer) RoutineSequentialReceiver() {
 
-	defer peer.routines.stopping.Done()
-
 	device := peer.device
-
 	logInfo := device.log.Info
 	logError := device.log.Error
 	logDebug := device.log.Debug
-	logDebug.Println("Routine, sequential receiver, started for peer", peer.String())
+
+	func() {
+		defer peer.routines.stopping.Done()
+		logDebug.Println(peer.String(), ": Routine, Sequential Receiver, Stopped")
+	}()
+
+	logDebug.Println(peer.String(), ": Routine, Sequential Receiver, Started")
 
 	peer.routines.starting.Done()
 
@@ -511,7 +514,6 @@ func (peer *Peer) RoutineSequentialReceiver() {
 		select {
 
 		case <-peer.routines.stop.Wait():
-			logDebug.Println("Routine, sequential receiver, stopped for peer", peer.String())
 			return
 
 		case elem := <-peer.queue.inbound:

send.go

@@ -187,13 +187,16 @@ func (device *Device) RoutineReadFromTUN() {
 func (peer *Peer) RoutineNonce() {
 	var keyPair *KeyPair
 
-	defer peer.routines.stopping.Done()
-
 	device := peer.device
 	logDebug := device.log.Debug
-	logDebug.Println("Routine, nonce worker, started for peer", peer.String())
+
+	defer func() {
+		peer.routines.stopping.Done()
+		logDebug.Println(peer.String(), ": Routine, Nonce Worker, Stopped")
+	}()
 
 	peer.routines.starting.Done()
+	logDebug.Println(peer.String(), ": Routine, Nonce Worker, Started")
 
 	for {
 	NextPacket:
@@ -215,12 +218,13 @@ func (peer *Peer) RoutineNonce() {
 
 				peer.signal.handshakeBegin.Send()
 
-				logDebug.Println("Awaiting key-pair for", peer.String())
+				logDebug.Println(peer.String(), ": Awaiting key-pair")
 
 				select {
 				case <-peer.signal.newKeyPair.Wait():
+					logDebug.Println(peer.String(), ": Obtained awaited key-pair")
 				case <-peer.signal.flushNonceQueue.Wait():
-					logDebug.Println("Clearing queue for", peer.String())
+					logDebug.Println(peer.String(), ": Flushing nonce queue")
 					peer.FlushNonceQueue()
 					goto NextPacket
 				case <-peer.routines.stop.Wait():

signal.go

@@ -11,6 +11,10 @@ func NewSignal() (s Signal) {
 	return
 }
 
+func (s *Signal) Close() {
+	close(s.C)
+}
+
 func (s *Signal) Disable() {
 	s.enabled.Set(false)
 	s.Clear()
@@ -43,7 +47,9 @@ func (s Signal) Clear() {
 /* Unblocks all listeners (forever)
  */
 func (s Signal) Broadcast() {
-	close(s.C)
+	if s.enabled.Get() {
+		close(s.C)
+	}
 }
 
 /* Wait for the signal

timer.go

@@ -12,8 +12,7 @@ type Timer struct {
 /* Starts the timer if not already pending
  */
 func (t *Timer) Start(dur time.Duration) bool {
-	set := t.pending.Swap(true)
-	if !set {
+	if !t.pending.Swap(true) {
 		t.timer.Reset(dur)
 		return true
 	}
@@ -23,8 +22,7 @@ func (t *Timer) Start(dur time.Duration) bool {
 /* Stops the timer
  */
 func (t *Timer) Stop() {
-	set := t.pending.Swap(true)
-	if set {
+	if t.pending.Swap(true) {
 		t.timer.Stop()
 		select {
 		case <-t.timer.C:

timers.go

@@ -227,14 +227,14 @@ func (peer *Peer) RoutineTimerHandler() {
 
 			interval := atomic.LoadUint64(&peer.persistentKeepaliveInterval)
 			if interval > 0 {
-				logDebug.Println("Sending keep-alive to", peer.String())
+				logDebug.Println(peer.String(), ": Send keep-alive (persistent)")
 				peer.timer.keepalivePassive.Stop()
 				peer.SendKeepAlive()
 			}
 
 		case <-peer.timer.keepalivePassive.Wait():
 
-			logDebug.Println("Sending keep-alive to", peer.String())
+			logDebug.Println(peer.String(), ": Send keep-alive (passive)")
 
 			peer.SendKeepAlive()
 
@@ -247,7 +247,7 @@ func (peer *Peer) RoutineTimerHandler() {
 
 		case <-peer.timer.zeroAllKeys.Wait():
 
-			logDebug.Println("Clearing all key material for", peer.String())
+			logDebug.Println(peer.String(), ": Clear all key-material (timer event)")
 
 			hs := &peer.handshake
 			hs.mutex.Lock()
@@ -280,7 +280,7 @@ func (peer *Peer) RoutineTimerHandler() {
 		// handshake timers
 
 		case <-peer.timer.handshakeNew.Wait():
-			logInfo.Println("Retrying handshake with", peer.String())
+			logInfo.Println(peer.String(), ": Retrying handshake (timer event)")
 			peer.signal.handshakeBegin.Send()
 
 		case <-peer.timer.handshakeTimeout.Wait():
@@ -296,17 +296,18 @@ func (peer *Peer) RoutineTimerHandler() {
 			// send new handshake
 
 			err := peer.sendNewHandshake()
+
 			if err != nil {
-				logInfo.Println(
-					"Failed to send handshake to peer:", peer.String(), "(", err, ")")
+				logInfo.Println(peer.String(), ": Failed to send handshake initiation", err)
+			} else {
+				logDebug.Println(peer.String(), ": Send handshake initiation (subsequent)")
 			}
 
 		case <-peer.timer.handshakeDeadline.Wait():
 
 			// clear all queued packets and stop keep-alive
 
-			logInfo.Println(
-				"Handshake negotiation timed out for:", peer.String())
+			logInfo.Println(peer.String(), ": Handshake negotiation timed-out")
 
 			peer.signal.flushNonceQueue.Send()
 			peer.timer.keepalivePersistent.Stop()
@@ -319,17 +320,18 @@ func (peer *Peer) RoutineTimerHandler() {
 			peer.signal.handshakeBegin.Disable()
 
 			err := peer.sendNewHandshake()
+
 			if err != nil {
-				logInfo.Println(
-					"Failed to send handshake to peer:", peer.String(), "(", err, ")")
+				logInfo.Println(peer.String(), ": Failed to send handshake initiation", err)
+			} else {
+				logDebug.Println(peer.String(), ": Send handshake initiation (initial)")
 			}
 
 			peer.timer.handshakeDeadline.Reset(RekeyAttemptTime)
 
 		case <-peer.signal.handshakeCompleted.Wait():
 
-			logInfo.Println(
-				"Handshake completed for:", peer.String())
+			logInfo.Println(peer.String(), ": Handshake completed")
 
 			atomic.StoreInt64(
 				&peer.stats.lastHandshakeNano,