From 6db41d5a269c79bd04b18dbfa171cc241a6cdcc9 Mon Sep 17 00:00:00 2001 From: Mathias Hall-Andersen Date: Sat, 5 May 2018 02:20:52 +0200 Subject: Initial version of migration to new event model - Begin move away from global timer state. - Made logging format more consistent --- timers.go | 141 +++++++++++++++++++++++++++++++++++++++----------------------- 1 file changed, 88 insertions(+), 53 deletions(-) (limited to 'timers.go') 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) -- cgit v1.2.3-59-g8ed1b