From 57684fc1e5399e94bb28ef6cf3249275cc51bb9f Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Mon, 27 May 2019 04:18:07 -0400 Subject: [PATCH 1/8] fix #518 --- irc/client.go | 43 ++++++++++++++++++++++++++++++++++++------- irc/idletimer.go | 15 +++++++++++---- 2 files changed, 47 insertions(+), 11 deletions(-) diff --git a/irc/client.go b/irc/client.go index be6366da..85d3b5c4 100644 --- a/irc/client.go +++ b/irc/client.go @@ -103,6 +103,7 @@ type Session struct { idletimer IdleTimer fakelag Fakelag + destroyed uint32 quitMessage string @@ -146,6 +147,20 @@ func (session *Session) MaxlenRest() int { return int(atomic.LoadUint32(&session.maxlenRest)) } +// returns whether the session was actively destroyed (for example, by ping +// timeout or NS GHOST). +// avoids a race condition between asynchronous idle-timing-out of sessions, +// and a condition that allows implicit BRB on connection errors (since +// destroy()'s socket.Close() appears to socket.Read() as a connection error) +func (session *Session) Destroyed() bool { + return atomic.LoadUint32(&session.destroyed) == 1 +} + +// sets the timed-out flag +func (session *Session) SetDestroyed() { + atomic.StoreUint32(&session.destroyed, 1) +} + // WhoWas is the subset of client details needed to answer a WHOWAS query type WhoWas struct { nick string @@ -373,7 +388,7 @@ func (client *Client) run(session *Session) { client.nickTimer.Initialize(client) } - firstLine := true + firstLine := !isReattach for { maxlenRest := session.MaxlenRest() @@ -386,8 +401,10 @@ func (client *Client) run(session *Session) { } client.Quit(quitMessage, session) // since the client did not actually send us a QUIT, - // give them a chance to resume or reattach if applicable: - client.brbTimer.Enable() + // give them a chance to resume if applicable: + if !session.Destroyed() { + client.brbTimer.Enable() + } break } @@ -396,7 +413,7 @@ func (client *Client) run(session *Session) { } // special-cased handling of PROXY protocol, see `handleProxyCommand` for details: - if !isReattach && firstLine { + if firstLine { firstLine = false if strings.HasPrefix(line, "PROXY") { err = handleProxyCommand(client.server, client, session, line) @@ -946,6 +963,7 @@ func (client *Client) destroy(session *Session) { client.stateMutex.Lock() details := client.detailsNoMutex() brbState := client.brbTimer.state + brbAt := client.brbTimer.brbAt wasReattach := session != nil && session.client != client sessionRemoved := false var remainingSessions int @@ -972,6 +990,7 @@ func (client *Client) destroy(session *Session) { // send quit/error message to client if they haven't been sent already client.Quit("", session) quitMessage = session.quitMessage + session.SetDestroyed() session.socket.Close() // remove from connection limits @@ -992,6 +1011,7 @@ func (client *Client) destroy(session *Session) { // do not destroy the client if it has either remaining sessions, or is BRB'ed if remainingSessions != 0 || brbState == BrbEnabled || brbState == BrbSticky { + client.server.logger.Debug("quit", fmt.Sprintf("preserving client %s with %d remaining sessions\n", details.nick, remainingSessions)) return } @@ -1056,10 +1076,19 @@ func (client *Client) destroy(session *Session) { client.server.stats.ChangeOperators(-1) } - for friend := range friends { - if quitMessage == "" { - quitMessage = "Exited" + // this happens under failure to return from BRB + if quitMessage == "" { + if !brbAt.IsZero() { + awayMessage := client.AwayMessage() + if awayMessage != "" { + quitMessage = fmt.Sprintf("%s [%s ago]", awayMessage, time.Since(brbAt).Truncate(time.Second).String()) + } } + } + if quitMessage == "" { + quitMessage = "Exited" + } + for friend := range friends { friend.sendFromClientInternal(false, splitQuitMessage.Time, splitQuitMessage.Msgid, details.nickMask, details.accountName, nil, "QUIT", quitMessage) } diff --git a/irc/idletimer.go b/irc/idletimer.go index c16065c7..dca2712e 100644 --- a/irc/idletimer.go +++ b/irc/idletimer.go @@ -334,6 +334,7 @@ type BrbTimer struct { client *Client state BrbState + brbAt time.Time duration time.Duration timer *time.Timer } @@ -344,9 +345,7 @@ func (bt *BrbTimer) Initialize(client *Client) { // attempts to enable BRB for a client, returns whether it succeeded func (bt *BrbTimer) Enable() (success bool, duration time.Duration) { - // BRB only makes sense if a new connection can attach to the session; - // this can happen either via RESUME or via bouncer reattach - if bt.client.Account() == "" && bt.client.ResumeID() == "" { + if !bt.client.Registered() || bt.client.ResumeID() == "" { return } @@ -361,6 +360,11 @@ func (bt *BrbTimer) Enable() (success bool, duration time.Duration) { bt.state = BrbEnabled bt.duration = duration bt.resetTimeout() + // only track the earliest BRB, if multiple sessions are BRB'ing at once + // TODO(#524) this is inaccurate in case of an auto-BRB + if bt.brbAt.IsZero() { + bt.brbAt = time.Now().UTC() + } success = true case BrbSticky: success = true @@ -373,14 +377,17 @@ func (bt *BrbTimer) Enable() (success bool, duration time.Duration) { // turns off BRB for a client and stops the timer; used on resume and during // client teardown -func (bt *BrbTimer) Disable() { +func (bt *BrbTimer) Disable() (brbAt time.Time) { bt.client.stateMutex.Lock() defer bt.client.stateMutex.Unlock() if bt.state == BrbEnabled { bt.state = BrbDisabled + brbAt = bt.brbAt + bt.brbAt = time.Time{} } bt.resetTimeout() + return } func (bt *BrbTimer) resetTimeout() { From 74732c4aebef6022983b97d758a66ca759179dad Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Mon, 27 May 2019 04:40:24 -0400 Subject: [PATCH 2/8] new proposed format for RESUMED messages --- irc/client.go | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/irc/client.go b/irc/client.go index 85d3b5c4..7d0f0a0e 100644 --- a/irc/client.go +++ b/irc/client.go @@ -578,6 +578,9 @@ func (session *Session) playResume() { } timestamp := session.resumeDetails.Timestamp + if timestamp.IsZero() { + timestamp = session.client.ctime + } gap := lastDiscarded.Sub(timestamp) session.resumeDetails.HistoryIncomplete = gap > 0 gapSeconds := int(gap.Seconds()) + 1 // round up to avoid confusion @@ -595,10 +598,10 @@ func (session *Session) playResume() { } for _, fSession := range friend.Sessions() { if fSession.capabilities.Has(caps.Resume) { - if timestamp.IsZero() { - fSession.Send(nil, oldNickmask, "RESUMED", hostname) - } else { + if session.resumeDetails.HistoryIncomplete { fSession.Send(nil, oldNickmask, "RESUMED", hostname, timestampString) + } else { + fSession.Send(nil, oldNickmask, "RESUMED", hostname) } } else { if session.resumeDetails.HistoryIncomplete { From 1a7169d75d21c6f6a44b6f769a378c6f24b23085 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Mon, 27 May 2019 05:52:40 -0400 Subject: [PATCH 3/8] fix double-destroy bug --- irc/client.go | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/irc/client.go b/irc/client.go index 7d0f0a0e..c31bdd28 100644 --- a/irc/client.go +++ b/irc/client.go @@ -53,6 +53,7 @@ type Client struct { certfp string channels ChannelSet ctime time.Time + destroyed bool exitedSnomaskSent bool flags modes.ModeSet hostname string @@ -962,7 +963,6 @@ func (client *Client) Quit(message string, session *Session) { func (client *Client) destroy(session *Session) { var sessionsToDestroy []*Session - // allow destroy() to execute at most once client.stateMutex.Lock() details := client.detailsNoMutex() brbState := client.brbTimer.state @@ -980,6 +980,13 @@ func (client *Client) destroy(session *Session) { sessionsToDestroy = []*Session{session} } } + + // should we destroy the whole client this time? + shouldDestroy := !client.destroyed && remainingSessions == 0 && (brbState != BrbEnabled && brbState != BrbSticky) + if shouldDestroy { + // if it's our job to destroy it, don't let anyone else try + client.destroyed = true + } client.stateMutex.Unlock() // destroy all applicable sessions: @@ -1013,8 +1020,7 @@ func (client *Client) destroy(session *Session) { } // do not destroy the client if it has either remaining sessions, or is BRB'ed - if remainingSessions != 0 || brbState == BrbEnabled || brbState == BrbSticky { - client.server.logger.Debug("quit", fmt.Sprintf("preserving client %s with %d remaining sessions\n", details.nick, remainingSessions)) + if !shouldDestroy { return } From 5ac7ea5b1c83b87e33b4c35cd26d15e1889a3ffd Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Mon, 27 May 2019 14:33:59 -0400 Subject: [PATCH 4/8] fix data race on exitedSnomaskSent --- irc/client.go | 3 ++- irc/getters.go | 6 ++++++ irc/handlers.go | 6 +++--- 3 files changed, 11 insertions(+), 4 deletions(-) diff --git a/irc/client.go b/irc/client.go index c31bdd28..add5b3d4 100644 --- a/irc/client.go +++ b/irc/client.go @@ -987,6 +987,7 @@ func (client *Client) destroy(session *Session) { // if it's our job to destroy it, don't let anyone else try client.destroyed = true } + exitedSnomaskSent := client.exitedSnomaskSent client.stateMutex.Unlock() // destroy all applicable sessions: @@ -1101,7 +1102,7 @@ func (client *Client) destroy(session *Session) { friend.sendFromClientInternal(false, splitQuitMessage.Time, splitQuitMessage.Msgid, details.nickMask, details.accountName, nil, "QUIT", quitMessage) } - if !client.exitedSnomaskSent && registered { + if !exitedSnomaskSent && registered { client.server.snomasks.Send(sno.LocalQuits, fmt.Sprintf(ircfmt.Unescape("%s$r exited the network"), details.nick)) } } diff --git a/irc/getters.go b/irc/getters.go index 4d3ad7a8..91187cc1 100644 --- a/irc/getters.go +++ b/irc/getters.go @@ -187,6 +187,12 @@ func (client *Client) SetAway(away bool, awayMessage string) (changed bool) { return } +func (client *Client) SetExitedSnomaskSent() { + client.stateMutex.Lock() + client.exitedSnomaskSent = true + client.stateMutex.Unlock() +} + // uniqueIdentifiers returns the strings for which the server enforces per-client // uniqueness/ownership; no two clients can have colliding casefolded nicks or // skeletons. diff --git a/irc/handlers.go b/irc/handlers.go index a80c366a..e6cf61ce 100644 --- a/irc/handlers.go +++ b/irc/handlers.go @@ -1052,7 +1052,7 @@ func dlineHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *Res } for _, mcl := range clientsToKill { - mcl.exitedSnomaskSent = true + mcl.SetExitedSnomaskSent() mcl.Quit(fmt.Sprintf(mcl.t("You have been banned from this server (%s)"), reason), nil) if mcl == client { killClient = true @@ -1362,7 +1362,7 @@ func killHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *Resp quitMsg := fmt.Sprintf("Killed (%s (%s))", client.nick, comment) server.snomasks.Send(sno.LocalKills, fmt.Sprintf(ircfmt.Unescape("%s$r was killed by %s $c[grey][$r%s$c[grey]]"), target.nick, client.nick, comment)) - target.exitedSnomaskSent = true + target.SetExitedSnomaskSent() target.Quit(quitMsg, nil) target.destroy(nil) @@ -1489,7 +1489,7 @@ func klineHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *Res } for _, mcl := range clientsToKill { - mcl.exitedSnomaskSent = true + mcl.SetExitedSnomaskSent() mcl.Quit(fmt.Sprintf(mcl.t("You have been banned from this server (%s)"), reason), nil) if mcl == client { killClient = true From b134a63dc28d62a986ffbe882c15b0f2a89bc040 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Tue, 28 May 2019 04:56:56 -0400 Subject: [PATCH 5/8] simplify "client dead" logic in AddSession now that we have client.destroyed again, we don't need to test the "0 sessions && brb disabled" condition in both AddSession() and destroy() --- irc/getters.go | 8 +------- 1 file changed, 1 insertion(+), 7 deletions(-) diff --git a/irc/getters.go b/irc/getters.go index 91187cc1..c6a0d208 100644 --- a/irc/getters.go +++ b/irc/getters.go @@ -97,14 +97,8 @@ func (client *Client) AddSession(session *Session) (success bool) { defer client.stateMutex.Unlock() // client may be dying and ineligible to receive another session - switch client.brbTimer.state { - case BrbDisabled: - if len(client.sessions) == 0 { - return false - } - case BrbDead: + if client.destroyed { return false - // default: BrbEnabled or BrbSticky, proceed } // success, attach the new session to the client session.client = client From acc9d8c13db8c5d1d0c9353e0ba74482a271c7d8 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Wed, 29 May 2019 05:58:47 -0400 Subject: [PATCH 6/8] update to proposed draft/resume-0.5 behavior --- gencapdefs.py | 2 +- irc/caps/defs.go | 4 ++-- irc/client.go | 3 --- irc/commands.go | 2 +- irc/handlers.go | 23 ++++++++++------------- 5 files changed, 14 insertions(+), 20 deletions(-) diff --git a/gencapdefs.py b/gencapdefs.py index f3825c51..23efda52 100644 --- a/gencapdefs.py +++ b/gencapdefs.py @@ -113,7 +113,7 @@ CAPDEFS = [ ), CapDef( identifier="Resume", - name="draft/resume-0.4", + name="draft/resume-0.5", url="https://github.com/DanielOaks/ircv3-specifications/blob/master+resume/extensions/resume.md", standard="proposed IRCv3", ), diff --git a/irc/caps/defs.go b/irc/caps/defs.go index 0ac48337..6a691bbc 100644 --- a/irc/caps/defs.go +++ b/irc/caps/defs.go @@ -77,7 +77,7 @@ const ( // https://github.com/SaberUK/ircv3-specifications/blob/rename/extensions/rename.md Rename Capability = iota - // Resume is the proposed IRCv3 capability named "draft/resume-0.4": + // Resume is the proposed IRCv3 capability named "draft/resume-0.5": // https://github.com/DanielOaks/ircv3-specifications/blob/master+resume/extensions/resume.md Resume Capability = iota @@ -141,7 +141,7 @@ var ( "message-tags", "multi-prefix", "draft/rename", - "draft/resume-0.4", + "draft/resume-0.5", "sasl", "server-time", "draft/setname", diff --git a/irc/client.go b/irc/client.go index add5b3d4..f28153db 100644 --- a/irc/client.go +++ b/irc/client.go @@ -579,9 +579,6 @@ func (session *Session) playResume() { } timestamp := session.resumeDetails.Timestamp - if timestamp.IsZero() { - timestamp = session.client.ctime - } gap := lastDiscarded.Sub(timestamp) session.resumeDetails.HistoryIncomplete = gap > 0 gapSeconds := int(gap.Seconds()) + 1 // round up to avoid confusion diff --git a/irc/commands.go b/irc/commands.go index f5049948..2b221621 100644 --- a/irc/commands.go +++ b/irc/commands.go @@ -232,7 +232,7 @@ func init() { "RESUME": { handler: resumeHandler, usablePreReg: true, - minParams: 1, + minParams: 2, }, "SAJOIN": { handler: sajoinHandler, diff --git a/irc/handlers.go b/irc/handlers.go index e6cf61ce..98b77c8d 100644 --- a/irc/handlers.go +++ b/irc/handlers.go @@ -2359,27 +2359,24 @@ func renameHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *Re return false } -// RESUME [timestamp] +// RESUME func resumeHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *ResponseBuffer) bool { - details := ResumeDetails{ - PresentedToken: msg.Params[0], - } - if client.registered { rb.Add(nil, server.name, "FAIL", "RESUME", "REGISTRATION_IS_COMPLETED", client.t("Cannot resume connection, connection registration has already been completed")) return false } - if 1 < len(msg.Params) { - ts, err := time.Parse(IRCv3TimestampFormat, msg.Params[1]) - if err == nil { - details.Timestamp = ts - } else { - rb.Add(nil, server.name, "WARN", "RESUME", "HISTORY_LOST", client.t("Timestamp is not in 2006-01-02T15:04:05.999Z format, ignoring it")) - } + ts, err := time.Parse(IRCv3TimestampFormat, msg.Params[1]) + if err != nil { + rb.Add(nil, server.name, "FAIL", "RESUME", "INVALID_TIMESTAMP", client.t("Cannot resume connection, timestamp is not valid")) + return false + } + + rb.session.resumeDetails = &ResumeDetails{ + PresentedToken: msg.Params[0], + Timestamp: ts, } - rb.session.resumeDetails = &details return false } From c0b554e98cbcd1573850dfe7a472219f82eee168 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Wed, 29 May 2019 07:34:23 -0400 Subject: [PATCH 7/8] changes from discussion --- irc/client.go | 20 +++++++++++++------- irc/commands.go | 2 +- irc/handlers.go | 23 +++++++++++++---------- 3 files changed, 27 insertions(+), 18 deletions(-) diff --git a/irc/client.go b/irc/client.go index f28153db..3d920910 100644 --- a/irc/client.go +++ b/irc/client.go @@ -580,14 +580,14 @@ func (session *Session) playResume() { timestamp := session.resumeDetails.Timestamp gap := lastDiscarded.Sub(timestamp) - session.resumeDetails.HistoryIncomplete = gap > 0 + session.resumeDetails.HistoryIncomplete = gap > 0 || timestamp.IsZero() gapSeconds := int(gap.Seconds()) + 1 // round up to avoid confusion details := client.Details() oldNickmask := details.nickMask client.SetRawHostname(session.rawHostname) hostname := client.Hostname() // may be a vhost - timestampString := session.resumeDetails.Timestamp.Format(IRCv3TimestampFormat) + timestampString := timestamp.Format(IRCv3TimestampFormat) // send quit/resume messages to friends for friend := range friends { @@ -596,23 +596,29 @@ func (session *Session) playResume() { } for _, fSession := range friend.Sessions() { if fSession.capabilities.Has(caps.Resume) { - if session.resumeDetails.HistoryIncomplete { + if !session.resumeDetails.HistoryIncomplete { + fSession.Send(nil, oldNickmask, "RESUMED", hostname, "ok") + } else if session.resumeDetails.HistoryIncomplete && !timestamp.IsZero() { fSession.Send(nil, oldNickmask, "RESUMED", hostname, timestampString) } else { fSession.Send(nil, oldNickmask, "RESUMED", hostname) } } else { - if session.resumeDetails.HistoryIncomplete { - fSession.Send(nil, oldNickmask, "QUIT", fmt.Sprintf(friend.t("Client reconnected (up to %d seconds of history lost)"), gapSeconds)) - } else { + if !session.resumeDetails.HistoryIncomplete { fSession.Send(nil, oldNickmask, "QUIT", fmt.Sprintf(friend.t("Client reconnected"))) + } else if session.resumeDetails.HistoryIncomplete && !timestamp.IsZero() { + fSession.Send(nil, oldNickmask, "QUIT", fmt.Sprintf(friend.t("Client reconnected (up to %d seconds of message history lost)"), gapSeconds)) + } else { + fSession.Send(nil, oldNickmask, "QUIT", fmt.Sprintf(friend.t("Client reconnected (message history may have been lost)"))) } } } } - if session.resumeDetails.HistoryIncomplete { + if session.resumeDetails.HistoryIncomplete && !timestamp.IsZero() { session.Send(nil, client.server.name, "WARN", "RESUME", "HISTORY_LOST", fmt.Sprintf(client.t("Resume may have lost up to %d seconds of history"), gapSeconds)) + } else { + session.Send(nil, client.server.name, "WARN", "RESUME", "HISTORY_LOST", client.t("Resume may have lost some message history")) } session.Send(nil, client.server.name, "RESUME", "SUCCESS", details.nick) diff --git a/irc/commands.go b/irc/commands.go index 2b221621..f5049948 100644 --- a/irc/commands.go +++ b/irc/commands.go @@ -232,7 +232,7 @@ func init() { "RESUME": { handler: resumeHandler, usablePreReg: true, - minParams: 2, + minParams: 1, }, "SAJOIN": { handler: sajoinHandler, diff --git a/irc/handlers.go b/irc/handlers.go index 98b77c8d..e6cf61ce 100644 --- a/irc/handlers.go +++ b/irc/handlers.go @@ -2359,24 +2359,27 @@ func renameHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *Re return false } -// RESUME +// RESUME [timestamp] func resumeHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *ResponseBuffer) bool { + details := ResumeDetails{ + PresentedToken: msg.Params[0], + } + if client.registered { rb.Add(nil, server.name, "FAIL", "RESUME", "REGISTRATION_IS_COMPLETED", client.t("Cannot resume connection, connection registration has already been completed")) return false } - ts, err := time.Parse(IRCv3TimestampFormat, msg.Params[1]) - if err != nil { - rb.Add(nil, server.name, "FAIL", "RESUME", "INVALID_TIMESTAMP", client.t("Cannot resume connection, timestamp is not valid")) - return false - } - - rb.session.resumeDetails = &ResumeDetails{ - PresentedToken: msg.Params[0], - Timestamp: ts, + if 1 < len(msg.Params) { + ts, err := time.Parse(IRCv3TimestampFormat, msg.Params[1]) + if err == nil { + details.Timestamp = ts + } else { + rb.Add(nil, server.name, "WARN", "RESUME", "HISTORY_LOST", client.t("Timestamp is not in 2006-01-02T15:04:05.999Z format, ignoring it")) + } } + rb.session.resumeDetails = &details return false } From 4350b92bef792e029652f0f7c4f0983f87ee1fce Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Thu, 30 May 2019 18:48:12 -0400 Subject: [PATCH 8/8] fix KILL etc. for BRB'ed clients --- irc/client.go | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/irc/client.go b/irc/client.go index 3d920910..07a761c3 100644 --- a/irc/client.go +++ b/irc/client.go @@ -985,7 +985,9 @@ func (client *Client) destroy(session *Session) { } // should we destroy the whole client this time? - shouldDestroy := !client.destroyed && remainingSessions == 0 && (brbState != BrbEnabled && brbState != BrbSticky) + // BRB is not respected if this is a destroy of the whole client (i.e., session == nil) + brbEligible := session != nil && (brbState == BrbEnabled || brbState == BrbSticky) + shouldDestroy := !client.destroyed && remainingSessions == 0 && !brbEligible if shouldDestroy { // if it's our job to destroy it, don't let anyone else try client.destroyed = true