From f5e7ec525d948dd503387118de776a71a83b0555 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Sat, 2 Dec 2017 20:05:06 -0500 Subject: [PATCH 1/2] synchronize accesses to client.atime --- irc/client.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/irc/client.go b/irc/client.go index 6deb4410..5cfd9bed 100644 --- a/irc/client.go +++ b/irc/client.go @@ -261,6 +261,8 @@ func (client *Client) run() { // Active updates when the client was last 'active' (i.e. the user should be sitting in front of their client). func (client *Client) Active() { + client.stateMutex.Lock() + defer client.stateMutex.Unlock() client.atime = time.Now() } @@ -298,6 +300,8 @@ func (client *Client) Register() { // IdleTime returns how long this client's been idle. func (client *Client) IdleTime() time.Duration { + client.stateMutex.RLock() + defer client.stateMutex.RUnlock() return time.Since(client.atime) } From ad1e00629b57a62abcfad5942e8b4de9c66a7424 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Sat, 2 Dec 2017 20:14:28 -0500 Subject: [PATCH 2/2] fix a race condition in idle timeouts squigz on freenode reported an issue where bots were responding to PING on time, but were occasionally being timed out regardless. This was a race condition: timeout was detected as idleTime >= it.quitTimeout, but if the client responded promptly to its PING message and sent no further messages, but the main loop subsequently slept for longer than expected (i.e., significantly longer than quitTimeout), this condition would be met through no fault of the client's. The fix here is to explicitly track the last time the ping was sent, then test !lastSeen.After(lastPinged) instead (making use of time.Time's monotonicity). It is sufficient that the measurement of lastPinged happens-before the PING is sent. --- irc/idletimer.go | 19 ++++++++----------- 1 file changed, 8 insertions(+), 11 deletions(-) diff --git a/irc/idletimer.go b/irc/idletimer.go index 209f1a96..74e11fda 100644 --- a/irc/idletimer.go +++ b/irc/idletimer.go @@ -38,7 +38,6 @@ type IdleTimer struct { // mutable client *Client - state TimerState lastSeen time.Time } @@ -49,7 +48,6 @@ func NewIdleTimer(client *Client) *IdleTimer { idleTimeout: IdleTimeout, quitTimeout: QuitTimeout, client: client, - state: TimerUnregistered, } return &it } @@ -58,17 +56,18 @@ func NewIdleTimer(client *Client) *IdleTimer { // it will eventually be stopped. func (it *IdleTimer) Start() { it.Lock() - it.state = TimerUnregistered it.lastSeen = time.Now() it.Unlock() go it.mainLoop() } func (it *IdleTimer) mainLoop() { + state := TimerUnregistered + var lastPinged time.Time + for { it.Lock() client := it.client - state := it.state lastSeen := it.lastSeen it.Unlock() @@ -76,7 +75,8 @@ func (it *IdleTimer) mainLoop() { return } - idleTime := time.Now().Sub(lastSeen) + now := time.Now() + idleTime := now.Sub(lastSeen) var nextSleep time.Duration if state == TimerUnregistered { @@ -87,8 +87,8 @@ func (it *IdleTimer) mainLoop() { nextSleep = it.registerTimeout - idleTime } } else if state == TimerIdle { - if idleTime < it.quitTimeout { - // new ping came in after we transitioned to TimerIdle, + if lastSeen.After(lastPinged) { + // new pong came in after we transitioned to TimerIdle, // transition back to active and process deadlines below state = TimerActive } else { @@ -100,6 +100,7 @@ func (it *IdleTimer) mainLoop() { nextSleep = it.idleTimeout - idleTime if nextSleep <= 0 { state = TimerIdle + lastPinged = now client.Ping() // grant the client at least quitTimeout to respond nextSleep = it.quitTimeout @@ -113,10 +114,6 @@ func (it *IdleTimer) mainLoop() { return } - it.Lock() - it.state = state - it.Unlock() - time.Sleep(nextSleep) } }