Work on logging format

diff --git a/device.go b/device.go
index 22e0990f64d58bc48902d01d24960731c4ad4342..e288ebeca4eb78a8aca6d1865042913ac34614bf 100644 (file)
--- a/device.go
+++ b/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)
        }
 

diff --git a/peer.go b/peer.go
index d8bb2bf90ff133f49d62d82edf1b7211d02e946b..1170720dbde091eb4ba309926fd493e9605f58fa 100644 (file)
--- a/peer.go
+++ b/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

diff --git a/receive.go b/receive.go
index 1f44df2221fae5c7f76de86936650688390c5228..fbaf77d5c1211a85db790f94aa7aad46ed2b0066 100644 (file)
--- a/receive.go
+++ b/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:

diff --git a/send.go b/send.go
index 7488d3a280a511380969c91e0f8fadac0245c7f5..5a59f6e4fb81c66bf558e7d96db8c4b3b2253b1f 100644 (file)
--- a/send.go
+++ b/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():

diff --git a/signal.go b/signal.go
index 2cefad460fd34e3ddfb5cfecfc6c6a04f5ea5885..1505593076d672574c673ae138999ec6e01182a4 100644 (file)
--- a/signal.go
+++ b/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

diff --git a/timer.go b/timer.go
index f00ca499ed72be3766eb0bfab3802ca0698e88a2..6cac40d99edebc871f404b044674976d3dba7279 100644 (file)
--- a/timer.go
+++ b/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:

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