Initial version of migration to new event model

- Begin move away from global timer state.
- Made logging format more consistent

1 files changed, 88 insertions, 53 deletions

diff --git a/timers.go b/timers.go
index ba0d0e5..a336b2f 100644
--- a/timers.go
+++ b/timers.go
@@ -10,8 +10,6 @@ import (
 
 /* NOTE:
  * Notion of validity
- *
- *
  */
 
 /* Called when a new authenticated message has been send
@@ -75,8 +73,7 @@ func (peer *Peer) SendKeepAlive() bool {
  * Sent non-empty (authenticated) transport message
  */
 func (peer *Peer) TimerDataSent() {
-	peer.timer.keepalivePassive.Stop()
-	peer.timer.handshakeNew.Start(NewHandshakeTime)
+	peer.event.dataSent.Fire()
 }
 
 /* Event:
@@ -86,16 +83,19 @@ func (peer *Peer) TimerDataSent() {
  * Set a timer to confirm the message using a keep-alive (if not already set)
  */
 func (peer *Peer) TimerDataReceived() {
-	if !peer.timer.keepalivePassive.Start(KeepaliveTimeout) {
-		peer.timer.needAnotherKeepalive.Set(true)
-	}
+	peer.event.dataReceived.Fire()
+	/*
+		if !peer.timer.keepalivePassive.Start(KeepaliveTimeout) {
+			peer.timer.needAnotherKeepalive.Set(true)
+		}
+	*/
 }
 
 /* Event:
  * Any (authenticated) packet received
  */
 func (peer *Peer) TimerAnyAuthenticatedPacketReceived() {
-	peer.timer.handshakeNew.Stop()
+	peer.event.anyAuthenticatedPacketReceived.Fire()
 }
 
 /* Event:
@@ -105,11 +105,7 @@ func (peer *Peer) TimerAnyAuthenticatedPacketReceived() {
  * Push persistent keep-alive into the future
  */
 func (peer *Peer) TimerAnyAuthenticatedPacketTraversal() {
-	interval := peer.persistentKeepaliveInterval
-	if interval > 0 {
-		duration := time.Duration(interval) * time.Second
-		peer.timer.keepalivePersistent.Reset(duration)
-	}
+	peer.event.anyAuthenticatedPacketTraversal.Fire()
 }
 
 /* Called after successfully completing a handshake.
@@ -120,7 +116,7 @@ func (peer *Peer) TimerAnyAuthenticatedPacketTraversal() {
  */
 func (peer *Peer) TimerHandshakeComplete() {
 	peer.signal.handshakeCompleted.Send()
-	peer.device.log.Info.Println(peer.String() + ": New handshake completed")
+	peer.device.log.Info.Println(peer, ": New handshake completed")
 }
 
 /* Event:
@@ -136,7 +132,8 @@ func (peer *Peer) TimerHandshakeComplete() {
  * upon failure to complete a handshake
  */
 func (peer *Peer) TimerEphemeralKeyCreated() {
-	peer.timer.zeroAllKeys.Reset(RejectAfterTime * 3)
+	peer.event.ephemeralKeyCreated.Fire()
+	// peer.timer.zeroAllKeys.Reset(RejectAfterTime * 3)
 }
 
 /* Sends a new handshake initiation message to the peer (endpoint)
@@ -171,16 +168,15 @@ func (peer *Peer) sendNewHandshake() error {
 		peer.signal.handshakeCompleted.Enable()
 	}
 
-	// set timeout
-
-	jitter := time.Millisecond * time.Duration(rand.Uint32()%334)
-
-	peer.timer.keepalivePassive.Stop()
-	peer.timer.handshakeTimeout.Reset(RekeyTimeout + jitter)
-
 	return err
 }
 
+func newTimer() *time.Timer {
+	timer := time.NewTimer(time.Hour)
+	timer.Stop()
+	return timer
+}
+
 func (peer *Peer) RoutineTimerHandler() {
 
 	device := peer.device
@@ -189,24 +185,28 @@ func (peer *Peer) RoutineTimerHandler() {
 	logDebug := device.log.Debug
 
 	defer func() {
-		logDebug.Println(peer.String() + ": Routine: timer handler - stopped")
+		logDebug.Println(peer, ": Routine: timer handler - stopped")
 		peer.routines.stopping.Done()
 	}()
 
-	logDebug.Println(peer.String() + ": Routine: timer handler - started")
+	logDebug.Println(peer, ": Routine: timer handler - started")
 
 	// reset all timers
 
-	peer.timer.keepalivePassive.Stop()
-	peer.timer.handshakeDeadline.Stop()
-	peer.timer.handshakeTimeout.Stop()
-	peer.timer.handshakeNew.Stop()
-	peer.timer.zeroAllKeys.Stop()
+	pendingHandshakeNew := false
+	pendingKeepalivePassive := false
+
+	timerKeepalivePassive := newTimer()
+	timerHandshakeDeadline := newTimer()
+	timerHandshakeTimeout := newTimer()
+	timerHandshakeNew := newTimer()
+	timerZeroAllKeys := newTimer()
+	timerKeepalivePersistent := newTimer()
 
 	interval := peer.persistentKeepaliveInterval
 	if interval > 0 {
 		duration := time.Duration(interval) * time.Second
-		peer.timer.keepalivePersistent.Reset(duration)
+		timerKeepalivePersistent.Reset(duration)
 	}
 
 	// signal synchronised setup complete
@@ -223,34 +223,56 @@ func (peer *Peer) RoutineTimerHandler() {
 		case <-peer.routines.stop.Wait():
 			return
 
+		/* events */
+
+		case <-peer.event.dataSent.C:
+			timerKeepalivePassive.Stop()
+			if !pendingHandshakeNew {
+				timerHandshakeNew.Reset(NewHandshakeTime)
+			}
+
+		case <-peer.event.dataReceived.C:
+			if pendingKeepalivePassive {
+				peer.timer.needAnotherKeepalive.Set(true) // TODO: make local
+			} else {
+				timerKeepalivePassive.Reset(KeepaliveTimeout)
+			}
+
+		case <-peer.event.anyAuthenticatedPacketTraversal.C:
+			interval := peer.persistentKeepaliveInterval
+			if interval > 0 {
+				duration := time.Duration(interval) * time.Second
+				timerKeepalivePersistent.Reset(duration)
+			}
+
 		/* timers */
 
 		// keep-alive
 
-		case <-peer.timer.keepalivePersistent.Wait():
+		case <-timerKeepalivePersistent.C:
 
 			interval := peer.persistentKeepaliveInterval
 			if interval > 0 {
-				logDebug.Println(peer.String() + ": Send keep-alive (persistent)")
-				peer.timer.keepalivePassive.Stop()
+				logDebug.Println(peer, ": Send keep-alive (persistent)")
+				timerKeepalivePassive.Stop()
 				peer.SendKeepAlive()
 			}
 
-		case <-peer.timer.keepalivePassive.Wait():
+		case <-timerKeepalivePassive.C:
 
-			logDebug.Println(peer.String() + ": Send keep-alive (passive)")
+			logDebug.Println(peer, ": Send keep-alive (passive)")
 
 			peer.SendKeepAlive()
 
 			if peer.timer.needAnotherKeepalive.Swap(false) {
-				peer.timer.keepalivePassive.Reset(KeepaliveTimeout)
+				timerKeepalivePassive.Reset(KeepaliveTimeout)
 			}
 
 		// clear key material timer
 
-		case <-peer.timer.zeroAllKeys.Wait():
+		case <-timerZeroAllKeys.C:
 
-			logDebug.Println(peer.String() + ": Clear all key-material (timer event)")
+			logDebug.Println(peer, ": Clear all key-material (timer event)")
 
 			hs := &peer.handshake
 			hs.mutex.Lock()
@@ -282,11 +304,11 @@ func (peer *Peer) RoutineTimerHandler() {
 
 		// handshake timers
 
-		case <-peer.timer.handshakeNew.Wait():
-			logInfo.Println(peer.String() + ": Retrying handshake (timer event)")
+		case <-timerHandshakeNew.C:
+			logInfo.Println(peer, ": Retrying handshake (timer event)")
 			peer.signal.handshakeBegin.Send()
 
-		case <-peer.timer.handshakeTimeout.Wait():
+		case <-timerHandshakeTimeout.C:
 
 			// clear source (in case this is causing problems)
 
@@ -300,20 +322,27 @@ func (peer *Peer) RoutineTimerHandler() {
 
 			err := peer.sendNewHandshake()
 
+			// set timeout
+
+			jitter := time.Millisecond * time.Duration(rand.Uint32()%334)
+			timerKeepalivePassive.Stop()
+			timerHandshakeTimeout.Reset(RekeyTimeout + jitter)
+
 			if err != nil {
-				logInfo.Println(peer.String()+": Failed to send handshake initiation", err)
+				logInfo.Println(peer, ": Failed to send handshake initiation", err)
 			} else {
-				logDebug.Println(peer.String() + ": Send handshake initiation (subsequent)")
+				logDebug.Println(peer, ": Send handshake initiation (subsequent)")
 			}
 
-		case <-peer.timer.handshakeDeadline.Wait():
+		case <-timerHandshakeDeadline.C:
 
 			// clear all queued packets and stop keep-alive
 
-			logInfo.Println(peer.String() + ": Handshake negotiation timed-out")
+			logInfo.Println(peer, ": Handshake negotiation timed-out")
 
-			peer.signal.flushNonceQueue.Send()
-			peer.timer.keepalivePersistent.Stop()
+			peer.flushNonceQueue()
+			signalSend(peer.signal.flushNonceQueue)
+			timerKeepalivePersistent.Stop()
 			peer.signal.handshakeBegin.Enable()
 
 		/* signals */
@@ -324,25 +353,31 @@ func (peer *Peer) RoutineTimerHandler() {
 
 			err := peer.sendNewHandshake()
 
+			// set timeout
+
+			jitter := time.Millisecond * time.Duration(rand.Uint32()%334)
+			timerKeepalivePassive.Stop()
+			timerHandshakeTimeout.Reset(RekeyTimeout + jitter)
+
 			if err != nil {
-				logInfo.Println(peer.String()+": Failed to send handshake initiation", err)
+				logInfo.Println(peer, ": Failed to send handshake initiation", err)
 			} else {
-				logDebug.Println(peer.String() + ": Send handshake initiation (initial)")
+				logDebug.Println(peer, ": Send handshake initiation (initial)")
 			}
 
-			peer.timer.handshakeDeadline.Reset(RekeyAttemptTime)
+			timerHandshakeDeadline.Reset(RekeyAttemptTime)
 
 		case <-peer.signal.handshakeCompleted.Wait():
 
-			logInfo.Println(peer.String() + ": Handshake completed")
+			logInfo.Println(peer, ": Handshake completed")
 
 			atomic.StoreInt64(
 				&peer.stats.lastHandshakeNano,
 				time.Now().UnixNano(),
 			)
 
-			peer.timer.handshakeTimeout.Stop()
-			peer.timer.handshakeDeadline.Stop()
+			timerHandshakeTimeout.Stop()
+			timerHandshakeDeadline.Stop()
 			peer.signal.handshakeBegin.Enable()
 
 			peer.timer.sendLastMinuteHandshake.Set(false)