From a3e5c9e98c1a845d5b924db1c0257d3a8e0da061 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Fri, 7 Aug 2020 17:30:42 -0400 Subject: [PATCH 1/2] fix #1229 --- irc/client.go | 109 ++++++++++++++++++++++++++++-- irc/commands.go | 7 -- irc/idletimer.go | 170 ----------------------------------------------- 3 files changed, 104 insertions(+), 182 deletions(-) diff --git a/irc/client.go b/irc/client.go index 14535df8..3a75d3e6 100644 --- a/irc/client.go +++ b/irc/client.go @@ -40,6 +40,22 @@ const ( lastSeenWriteInterval = time.Hour ) +const ( + // RegisterTimeout is how long clients have to register before we disconnect them + RegisterTimeout = time.Minute + // DefaultIdleTimeout is how long without traffic before we send the client a PING + DefaultIdleTimeout = time.Minute + 30*time.Second + // For Tor clients, we send a PING at least every 30 seconds, as a workaround for this bug + // (single-onion circuits will close unless the client sends data once every 60 seconds): + // https://bugs.torproject.org/29665 + TorIdleTimeout = time.Second * 30 + // This is how long a client gets without sending any message, including the PONG to our + // PING, before we disconnect them: + DefaultTotalTimeout = 2*time.Minute + 30*time.Second + // Resumeable clients (clients who have negotiated caps.Resume) get longer: + ResumeableTotalTimeout = 3*time.Minute + 30*time.Second +) + // ResumeDetails is a place to stash data at various stages of // the resume process: when handling the RESUME command itself, // when completing the registration, and when rejoining channels. @@ -83,6 +99,7 @@ type Client struct { realname string realIP net.IP registered bool + registrationTimer *time.Timer resumeID string server *Server skeleton string @@ -123,7 +140,10 @@ type Session struct { deviceID string ctime time.Time - lastActive time.Time + lastActive time.Time // last non-CTCP PRIVMSG sent; updates publicly visible idle time + lastTouch time.Time // last line sent; updates timer for idle timeouts + idleTimer *time.Timer + pingSent bool // we sent PING to a putatively idle connection and we're waiting for PONG socket *Socket realIP net.IP @@ -131,7 +151,6 @@ type Session struct { rawHostname string isTor bool - idletimer IdleTimer fakelag Fakelag deferredFakelagCount int destroyed uint32 @@ -342,7 +361,6 @@ func (server *Server) RunClient(conn IRCConn) { } client.sessions = []*Session{session} - session.idletimer.Initialize(session) session.resetFakelag() if wConn.Secure { @@ -363,6 +381,7 @@ func (server *Server) RunClient(conn IRCConn) { } } + client.registrationTimer = time.AfterFunc(RegisterTimeout, client.handleRegisterTimeout) server.stats.Add() client.run(session) } @@ -605,7 +624,7 @@ func (client *Client) run(session *Session) { isReattach := client.Registered() if isReattach { - session.idletimer.Touch() + client.Touch(session) if session.resumeDetails != nil { session.playResume() session.resumeDetails = nil @@ -739,6 +758,7 @@ func (client *Client) Touch(session *Session) { client.lastSeenLastWrite = now } } + client.updateIdleTimer(session, now) client.stateMutex.Unlock() if markDirty { client.markDirty(IncludeLastSeen) @@ -763,6 +783,71 @@ func (client *Client) setLastSeen(now time.Time, deviceID string) { } } +func (client *Client) updateIdleTimer(session *Session, now time.Time) { + session.lastTouch = now + session.pingSent = false + + if session.idleTimer == nil { + pingTimeout := DefaultIdleTimeout + if session.isTor { + pingTimeout = TorIdleTimeout + } + session.idleTimer = time.AfterFunc(pingTimeout, session.handleIdleTimeout) + } +} + +func (session *Session) handleIdleTimeout() { + totalTimeout := DefaultTotalTimeout + if session.capabilities.Has(caps.Resume) { + totalTimeout = ResumeableTotalTimeout + } + pingTimeout := DefaultIdleTimeout + if session.isTor { + pingTimeout = TorIdleTimeout + } + + session.client.stateMutex.Lock() + now := time.Now() + timeUntilDestroy := session.lastTouch.Add(totalTimeout).Sub(now) + timeUntilPing := session.lastTouch.Add(pingTimeout).Sub(now) + shouldDestroy := session.pingSent && timeUntilDestroy <= 0 + shouldSendPing := !session.pingSent && timeUntilPing <= 0 + if !shouldDestroy { + if shouldSendPing { + session.pingSent = true + } + // check in again at the minimum of these 3 possible intervals: + // 1. the ping timeout (assuming we PING and they reply immediately with PONG) + // 2. the next time we would send PING (if they don't send any more lines) + // 3. the next time we would destroy (if they don't send any more lines) + nextTimeout := pingTimeout + if 0 < timeUntilPing && timeUntilPing < nextTimeout { + nextTimeout = timeUntilPing + } + if 0 < timeUntilDestroy && timeUntilDestroy < nextTimeout { + nextTimeout = timeUntilDestroy + } + session.idleTimer.Stop() + session.idleTimer.Reset(nextTimeout) + } + session.client.stateMutex.Unlock() + + if shouldDestroy { + session.client.Quit(fmt.Sprintf("Ping timeout: %v", totalTimeout), session) + session.client.destroy(session) + } else if shouldSendPing { + session.Ping() + } +} + +func (session *Session) stopIdleTimer() { + session.client.stateMutex.Lock() + defer session.client.stateMutex.Unlock() + if session.idleTimer != nil { + session.idleTimer.Stop() + } +} + // Ping sends the client a PING message. func (session *Session) Ping() { session.Send(nil, "", "PING", session.client.Nick()) @@ -1119,6 +1204,10 @@ func (client *Client) SetNick(nick, nickCasefolded, skeleton string) (success bo } else if !client.registered { // XXX test this before setting it to avoid annoying the race detector client.registered = true + if client.registrationTimer != nil { + client.registrationTimer.Stop() + client.registrationTimer = nil + } } client.nick = nick client.nickCasefolded = nickCasefolded @@ -1294,6 +1383,11 @@ func (client *Client) destroy(session *Session) { client.awayMessage = awayMessage } + if client.registrationTimer != nil { + // unconditionally stop; if the client is still unregistered it must be destroyed + client.registrationTimer.Stop() + } + client.stateMutex.Unlock() // XXX there is no particular reason to persist this state here rather than @@ -1311,7 +1405,7 @@ func (client *Client) destroy(session *Session) { // session has been attached to a new client; do not destroy it continue } - session.idletimer.Stop() + session.stopIdleTimer() // send quit/error message to client if they haven't been sent already client.Quit("", session) quitMessage = session.quitMessage @@ -1693,6 +1787,11 @@ func (client *Client) historyStatus(config *Config) (status HistoryStatus, targe return } +func (client *Client) handleRegisterTimeout() { + client.Quit(fmt.Sprintf("Registration timeout: %v", RegisterTimeout), nil) + client.destroy(nil) +} + func (client *Client) copyLastSeen() (result map[string]time.Time) { client.stateMutex.RLock() defer client.stateMutex.RUnlock() diff --git a/irc/commands.go b/irc/commands.go index 62a7f90d..761e886d 100644 --- a/irc/commands.go +++ b/irc/commands.go @@ -58,13 +58,6 @@ func (cmd *Command) Run(server *Server, client *Client, session *Session, msg ir exiting = server.tryRegister(client, session) } - // most servers do this only for PING/PONG, but we'll do it for any command: - if client.registered { - // touch even if `exiting`, so we record the time of a QUIT accurately - session.idletimer.Touch() - } - - // TODO: eliminate idletimer entirely in favor of this measurement if client.registered { client.Touch(session) } diff --git a/irc/idletimer.go b/irc/idletimer.go index 739cf4ba..a9f07f91 100644 --- a/irc/idletimer.go +++ b/irc/idletimer.go @@ -4,179 +4,9 @@ package irc import ( - "fmt" - "sync" "time" - - "github.com/oragono/oragono/irc/caps" ) -const ( - // RegisterTimeout is how long clients have to register before we disconnect them - RegisterTimeout = time.Minute - // DefaultIdleTimeout is how long without traffic before we send the client a PING - DefaultIdleTimeout = time.Minute + 30*time.Second - // For Tor clients, we send a PING at least every 30 seconds, as a workaround for this bug - // (single-onion circuits will close unless the client sends data once every 60 seconds): - // https://bugs.torproject.org/29665 - TorIdleTimeout = time.Second * 30 - // This is how long a client gets without sending any message, including the PONG to our - // PING, before we disconnect them: - DefaultTotalTimeout = 2*time.Minute + 30*time.Second - // Resumeable clients (clients who have negotiated caps.Resume) get longer: - ResumeableTotalTimeout = 3*time.Minute + 30*time.Second -) - -// client idleness state machine - -type TimerState uint - -const ( - TimerUnregistered TimerState = iota // client is unregistered - TimerActive // client is actively sending commands - TimerIdle // client is idle, we sent PING and are waiting for PONG - TimerDead // client was terminated -) - -type IdleTimer struct { - sync.Mutex // tier 1 - - // immutable after construction - registerTimeout time.Duration - session *Session - - // mutable - idleTimeout time.Duration - quitTimeout time.Duration - state TimerState - timer *time.Timer -} - -// Initialize sets up an IdleTimer and starts counting idle time; -// if there is no activity from the client, it will eventually be stopped. -func (it *IdleTimer) Initialize(session *Session) { - it.session = session - it.registerTimeout = RegisterTimeout - it.idleTimeout, it.quitTimeout = it.recomputeDurations() - registered := session.client.Registered() - - it.Lock() - defer it.Unlock() - if registered { - it.state = TimerActive - } else { - it.state = TimerUnregistered - } - it.resetTimeout() -} - -// recomputeDurations recomputes the idle and quit durations, given the client's caps. -func (it *IdleTimer) recomputeDurations() (idleTimeout, quitTimeout time.Duration) { - totalTimeout := DefaultTotalTimeout - // if they have the resume cap, wait longer before pinging them out - // to give them a chance to resume their connection - if it.session.capabilities.Has(caps.Resume) { - totalTimeout = ResumeableTotalTimeout - } - - idleTimeout = DefaultIdleTimeout - if it.session.isTor { - idleTimeout = TorIdleTimeout - } - - quitTimeout = totalTimeout - idleTimeout - return -} - -func (it *IdleTimer) Touch() { - idleTimeout, quitTimeout := it.recomputeDurations() - - it.Lock() - defer it.Unlock() - it.idleTimeout, it.quitTimeout = idleTimeout, quitTimeout - // a touch transitions TimerUnregistered or TimerIdle into TimerActive - if it.state != TimerDead { - it.state = TimerActive - it.resetTimeout() - } -} - -func (it *IdleTimer) processTimeout() { - idleTimeout, quitTimeout := it.recomputeDurations() - - var previousState TimerState - func() { - it.Lock() - defer it.Unlock() - it.idleTimeout, it.quitTimeout = idleTimeout, quitTimeout - previousState = it.state - // TimerActive transitions to TimerIdle, all others to TimerDead - if it.state == TimerActive { - // send them a ping, give them time to respond - it.state = TimerIdle - it.resetTimeout() - } else { - it.state = TimerDead - } - }() - - if previousState == TimerActive { - it.session.Ping() - } else { - it.session.client.Quit(it.quitMessage(previousState), it.session) - it.session.client.destroy(it.session) - } -} - -// Stop stops counting idle time. -func (it *IdleTimer) Stop() { - if it == nil { - return - } - - it.Lock() - defer it.Unlock() - it.state = TimerDead - it.resetTimeout() -} - -func (it *IdleTimer) resetTimeout() { - if it.timer != nil { - it.timer.Stop() - } - var nextTimeout time.Duration - switch it.state { - case TimerUnregistered: - nextTimeout = it.registerTimeout - case TimerActive: - nextTimeout = it.idleTimeout - case TimerIdle: - nextTimeout = it.quitTimeout - case TimerDead: - return - } - if it.timer != nil { - it.timer.Reset(nextTimeout) - } else { - it.timer = time.AfterFunc(nextTimeout, it.processTimeout) - } -} - -func (it *IdleTimer) quitMessage(state TimerState) string { - switch state { - case TimerUnregistered: - return fmt.Sprintf("Registration timeout: %v", it.registerTimeout) - case TimerIdle: - // how many seconds before registered clients are timed out (IdleTimeout plus QuitTimeout). - it.Lock() - defer it.Unlock() - return fmt.Sprintf("Ping timeout: %v", (it.idleTimeout + it.quitTimeout)) - default: - // shouldn't happen - return "" - } -} - // BrbTimer is a timer on the client as a whole (not an individual session) for implementing // the BRB command and related functionality (where a client can remain online without // having any connected sessions). From b54d0f8f34bfca33c5e4a36e9ecd6a94e2ea1a7e Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Sat, 8 Aug 2020 22:39:28 -0400 Subject: [PATCH 2/2] add timer coalescing for the common case --- irc/client.go | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-) diff --git a/irc/client.go b/irc/client.go index 3a75d3e6..7c81f91e 100644 --- a/irc/client.go +++ b/irc/client.go @@ -54,6 +54,9 @@ const ( DefaultTotalTimeout = 2*time.Minute + 30*time.Second // Resumeable clients (clients who have negotiated caps.Resume) get longer: ResumeableTotalTimeout = 3*time.Minute + 30*time.Second + + // round off the ping interval by this much, see below: + PingCoalesceThreshold = time.Second ) // ResumeDetails is a place to stash data at various stages of @@ -811,7 +814,11 @@ func (session *Session) handleIdleTimeout() { timeUntilDestroy := session.lastTouch.Add(totalTimeout).Sub(now) timeUntilPing := session.lastTouch.Add(pingTimeout).Sub(now) shouldDestroy := session.pingSent && timeUntilDestroy <= 0 - shouldSendPing := !session.pingSent && timeUntilPing <= 0 + // XXX this should really be time <= 0, but let's do some hacky timer coalescing: + // a typical idling client will do nothing other than respond immediately to our pings, + // so we'll PING at t=0, they'll respond at t=0.05, then we'll wake up at t=90 and find + // that we need to PING again at t=90.05. Rather than wake up again, just send it now: + shouldSendPing := !session.pingSent && timeUntilPing <= PingCoalesceThreshold if !shouldDestroy { if shouldSendPing { session.pingSent = true @@ -821,7 +828,7 @@ func (session *Session) handleIdleTimeout() { // 2. the next time we would send PING (if they don't send any more lines) // 3. the next time we would destroy (if they don't send any more lines) nextTimeout := pingTimeout - if 0 < timeUntilPing && timeUntilPing < nextTimeout { + if PingCoalesceThreshold < timeUntilPing && timeUntilPing < nextTimeout { nextTimeout = timeUntilPing } if 0 < timeUntilDestroy && timeUntilDestroy < nextTimeout {