From b11bf503e796b0c1b3c0885953e2e107f49f7504 Mon Sep 17 00:00:00 2001 From: Shivaram Lingamneni Date: Mon, 6 May 2019 23:17:57 -0400 Subject: [PATCH] improvements to message replay code --- gencapdefs.py | 6 ++ irc/caps/defs.go | 7 +- irc/channel.go | 160 ++++++++++++++++++++++++------------ irc/client.go | 54 +++++++----- irc/handlers.go | 49 ++++++----- irc/history/history.go | 55 ++++++++++--- irc/history/history_test.go | 42 ++++------ irc/nickname.go | 25 ++++-- irc/responsebuffer.go | 102 ++++++++++++++++++----- irc/utils/text.go | 3 + 10 files changed, 338 insertions(+), 165 deletions(-) diff --git a/gencapdefs.py b/gencapdefs.py index 3dcbdd19..a6baee1b 100644 --- a/gencapdefs.py +++ b/gencapdefs.py @@ -159,6 +159,12 @@ CAPDEFS = [ url="https://wiki.znc.in/Query_buffers", standard="ZNC vendor", ), + CapDef( + identifier="EventPlayback", + name="draft/event-playback", + url="https://github.com/ircv3/ircv3-specifications/pull/362", + standard="Draft IRCv3", + ), ] def validate_defs(): diff --git a/irc/caps/defs.go b/irc/caps/defs.go index 9a3fc94c..9f10f0ae 100644 --- a/irc/caps/defs.go +++ b/irc/caps/defs.go @@ -7,7 +7,7 @@ package caps const ( // number of recognized capabilities: - numCapabs = 24 + numCapabs = 25 // length of the uint64 array that represents the bitset: bitsetLen = 1 ) @@ -108,6 +108,10 @@ const ( // ZNCSelfMessage is the ZNC vendor capability named "znc.in/self-message": // https://wiki.znc.in/Query_buffers ZNCSelfMessage Capability = iota + + // EventPlayback is the Draft IRCv3 capability named "draft/event-playback": + // https://github.com/ircv3/ircv3-specifications/pull/362 + EventPlayback Capability = iota ) // `capabilityNames[capab]` is the string name of the capability `capab` @@ -137,5 +141,6 @@ var ( "userhost-in-names", "oragono.io/bnc", "znc.in/self-message", + "draft/event-playback", } ) diff --git a/irc/channel.go b/irc/channel.go index 6bd15f4b..28315735 100644 --- a/irc/channel.go +++ b/irc/channel.go @@ -536,6 +536,8 @@ func (channel *Channel) Join(client *Client, key string, isSajoin bool, rb *Resp client.server.logger.Debug("join", fmt.Sprintf("%s joined channel %s", details.nick, chname)) + var message utils.SplitMessage + givenMode := func() (givenMode modes.Mode) { channel.joinPartMutex.Lock() defer channel.joinPartMutex.Unlock() @@ -559,14 +561,15 @@ func (channel *Channel) Join(client *Client, key string, isSajoin bool, rb *Resp channel.regenerateMembersCache() - message := utils.SplitMessage{} - message.Msgid = details.realname - channel.history.Add(history.Item{ + message = utils.MakeSplitMessage("", true) + histItem := history.Item{ Type: history.Join, Nick: details.nickMask, AccountName: details.accountName, Message: message, - }) + } + histItem.Params[0] = details.realname + channel.history.Add(histItem) return }() @@ -587,9 +590,10 @@ func (channel *Channel) Join(client *Client, key string, isSajoin bool, rb *Resp continue } if session.capabilities.Has(caps.ExtendedJoin) { - session.Send(nil, details.nickMask, "JOIN", chname, details.accountName, details.realname) + session.sendFromClientInternal(false, message.Time, message.Msgid, details.nickMask, details.accountName, nil, "JOIN", chname, details.accountName, details.realname) } else { session.Send(nil, details.nickMask, "JOIN", chname) + session.sendFromClientInternal(false, message.Time, message.Msgid, details.nickMask, details.accountName, nil, "JOIN", chname) } if givenMode != 0 { session.Send(nil, client.server.name, "MODE", chname, modestr, details.nick) @@ -598,9 +602,9 @@ func (channel *Channel) Join(client *Client, key string, isSajoin bool, rb *Resp } if rb.session.capabilities.Has(caps.ExtendedJoin) { - rb.Add(nil, details.nickMask, "JOIN", chname, details.accountName, details.realname) + rb.AddFromClient(message.Time, message.Msgid, details.nickMask, details.accountName, nil, "JOIN", chname, details.accountName, details.realname) } else { - rb.Add(nil, details.nickMask, "JOIN", chname) + rb.AddFromClient(message.Time, message.Msgid, details.nickMask, details.accountName, nil, "JOIN", chname) } if rb.session.client == client { @@ -613,10 +617,13 @@ func (channel *Channel) Join(client *Client, key string, isSajoin bool, rb *Resp rb.Flush(true) replayLimit := channel.server.Config().History.AutoreplayOnJoin - if replayLimit > 0 { + if 0 < replayLimit { + // TODO don't replay the client's own JOIN line? items := channel.history.Latest(replayLimit) - channel.replayHistoryItems(rb, items) - rb.Flush(true) + if 0 < len(items) { + channel.replayHistoryItems(rb, items, true) + rb.Flush(true) + } } } @@ -647,14 +654,16 @@ func (channel *Channel) Part(client *Client, message string, rb *ResponseBuffer) channel.Quit(client) + splitMessage := utils.MakeSplitMessage(message, true) + details := client.Details() for _, member := range channel.Members() { - member.Send(nil, details.nickMask, "PART", chname, message) + member.sendFromClientInternal(false, splitMessage.Time, splitMessage.Msgid, details.nickMask, details.accountName, nil, "PART", chname, message) } - rb.Add(nil, details.nickMask, "PART", chname, message) + rb.AddFromClient(splitMessage.Time, splitMessage.Msgid, details.nickMask, details.accountName, nil, "PART", chname, message) for _, session := range client.Sessions() { if session != rb.session { - session.Send(nil, details.nickMask, "PART", chname, message) + session.sendFromClientInternal(false, splitMessage.Time, splitMessage.Msgid, details.nickMask, details.accountName, nil, "PART", chname, message) } } @@ -662,7 +671,7 @@ func (channel *Channel) Part(client *Client, message string, rb *ResponseBuffer) Type: history.Part, Nick: details.nickMask, AccountName: details.accountName, - Message: utils.MakeSplitMessage(message, true), + Message: splitMessage, }) client.server.logger.Debug("part", fmt.Sprintf("%s left channel %s", details.nick, chname)) @@ -748,7 +757,7 @@ func (channel *Channel) resumeAndAnnounce(newClient, oldClient *Client) { func (channel *Channel) replayHistoryForResume(newClient *Client, after time.Time, before time.Time) { items, complete := channel.history.Between(after, before, false, 0) rb := NewResponseBuffer(newClient.Sessions()[0]) - channel.replayHistoryItems(rb, items) + channel.replayHistoryItems(rb, items, false) if !complete && !newClient.resumeDetails.HistoryIncomplete { // warn here if we didn't warn already rb.Add(nil, "HistServ", "NOTICE", channel.Name(), newClient.t("Some additional message history may have been lost")) @@ -759,50 +768,93 @@ func (channel *Channel) replayHistoryForResume(newClient *Client, after time.Tim func stripMaskFromNick(nickMask string) (nick string) { index := strings.Index(nickMask, "!") if index == -1 { - return + return nickMask } return nickMask[0:index] } -func (channel *Channel) replayHistoryItems(rb *ResponseBuffer, items []history.Item) { +// munge the msgid corresponding to a replayable event, +// yielding a consistent msgid for the fake PRIVMSG from HistServ +func mungeMsgidForHistserv(token string) (result string) { + return fmt.Sprintf("_%s", token) +} + +func (channel *Channel) replayHistoryItems(rb *ResponseBuffer, items []history.Item, autoreplay bool) { chname := channel.Name() client := rb.target - serverTime := rb.session.capabilities.Has(caps.ServerTime) + eventPlayback := rb.session.capabilities.Has(caps.EventPlayback) + extendedJoin := rb.session.capabilities.Has(caps.ExtendedJoin) + + if len(items) == 0 { + return + } + batchID := rb.StartNestedHistoryBatch(chname) + defer rb.EndNestedBatch(batchID) for _, item := range items { - var tags map[string]string - if serverTime { - tags = map[string]string{"time": item.Time.Format(IRCv3TimestampFormat)} - } - - // TODO(#437) support history.Tagmsg + nick := stripMaskFromNick(item.Nick) switch item.Type { case history.Privmsg: - rb.AddSplitMessageFromClient(item.Nick, item.AccountName, tags, "PRIVMSG", chname, item.Message) + rb.AddSplitMessageFromClient(item.Nick, item.AccountName, item.Tags, "PRIVMSG", chname, item.Message) case history.Notice: - rb.AddSplitMessageFromClient(item.Nick, item.AccountName, tags, "NOTICE", chname, item.Message) - case history.Join: - nick := stripMaskFromNick(item.Nick) - var message string - if item.AccountName == "*" { - message = fmt.Sprintf(client.t("%s joined the channel"), nick) - } else { - message = fmt.Sprintf(client.t("%[1]s [account: %[2]s] joined the channel"), nick, item.AccountName) + rb.AddSplitMessageFromClient(item.Nick, item.AccountName, item.Tags, "NOTICE", chname, item.Message) + case history.Tagmsg: + if rb.session.capabilities.Has(caps.MessageTags) { + rb.AddSplitMessageFromClient(item.Nick, item.AccountName, item.Tags, "TAGMSG", chname, item.Message) + } + case history.Join: + if eventPlayback { + if extendedJoin { + rb.AddFromClient(item.Message.Time, item.Message.Msgid, item.Nick, item.AccountName, nil, "HEVENT", "JOIN", chname, item.AccountName, item.Params[0]) + } else { + rb.AddFromClient(item.Message.Time, item.Message.Msgid, item.Nick, item.AccountName, nil, "HEVENT", "JOIN", chname) + } + } else { + if autoreplay { + continue // #474 + } + var message string + if item.AccountName == "*" { + message = fmt.Sprintf(client.t("%s joined the channel"), nick) + } else { + message = fmt.Sprintf(client.t("%[1]s [account: %[2]s] joined the channel"), nick, item.AccountName) + } + rb.AddFromClient(item.Message.Time, mungeMsgidForHistserv(item.Message.Msgid), "HistServ", "*", nil, "PRIVMSG", chname, message) } - rb.Add(tags, "HistServ", "PRIVMSG", chname, message) case history.Part: - nick := stripMaskFromNick(item.Nick) - message := fmt.Sprintf(client.t("%[1]s left the channel (%[2]s)"), nick, item.Message.Message) - rb.Add(tags, "HistServ", "PRIVMSG", chname, message) - case history.Quit: - nick := stripMaskFromNick(item.Nick) - message := fmt.Sprintf(client.t("%[1]s quit (%[2]s)"), nick, item.Message.Message) - rb.Add(tags, "HistServ", "PRIVMSG", chname, message) + if eventPlayback { + rb.AddFromClient(item.Message.Time, item.Message.Msgid, item.Nick, item.AccountName, nil, "HEVENT", "PART", chname, item.Message.Message) + } else { + if autoreplay { + continue // #474 + } + message := fmt.Sprintf(client.t("%[1]s left the channel (%[2]s)"), nick, item.Message.Message) + rb.AddFromClient(item.Message.Time, mungeMsgidForHistserv(item.Message.Msgid), "HistServ", "*", nil, "PRIVMSG", chname, message) + } case history.Kick: - nick := stripMaskFromNick(item.Nick) - // XXX Msgid is the kick target - message := fmt.Sprintf(client.t("%[1]s kicked %[2]s (%[3]s)"), nick, item.Message.Msgid, item.Message.Message) - rb.Add(tags, "HistServ", "PRIVMSG", chname, message) + if eventPlayback { + rb.AddFromClient(item.Message.Time, item.Message.Msgid, item.Nick, item.AccountName, nil, "HEVENT", "KICK", chname, item.Params[0], item.Message.Message) + } else { + message := fmt.Sprintf(client.t("%[1]s kicked %[2]s (%[3]s)"), nick, item.Params[0], item.Message.Message) + rb.AddFromClient(item.Message.Time, mungeMsgidForHistserv(item.Message.Msgid), "HistServ", "*", nil, "PRIVMSG", chname, message) + } + case history.Quit: + if eventPlayback { + rb.AddFromClient(item.Message.Time, item.Message.Msgid, item.Nick, item.AccountName, nil, "HEVENT", "QUIT", item.Message.Message) + } else { + if autoreplay { + continue // #474 + } + message := fmt.Sprintf(client.t("%[1]s quit (%[2]s)"), nick, item.Message.Message) + rb.AddFromClient(item.Message.Time, mungeMsgidForHistserv(item.Message.Msgid), "HistServ", "*", nil, "PRIVMSG", chname, message) + } + case history.Nick: + if eventPlayback { + rb.AddFromClient(item.Message.Time, item.Message.Msgid, item.Nick, item.AccountName, nil, "HEVENT", "NICK", item.Params[0]) + } else { + message := fmt.Sprintf(client.t("%[1]s changed nick to %[2]s"), nick, item.Params[0]) + rb.AddFromClient(item.Message.Time, mungeMsgidForHistserv(item.Message.Msgid), "HistServ", "*", nil, "PRIVMSG", chname, message) + } } } } @@ -934,7 +986,7 @@ func (channel *Channel) SendSplitMessage(command string, minPrefixMode modes.Mod tagsToUse = clientOnlyTags } if histType == history.Tagmsg && rb.session.capabilities.Has(caps.MessageTags) { - rb.AddFromClient(message.Msgid, nickmask, account, tagsToUse, command, chname) + rb.AddFromClient(message.Time, message.Msgid, nickmask, account, tagsToUse, command, chname) } else { rb.AddSplitMessageFromClient(nickmask, account, tagsToUse, command, chname, message) } @@ -986,7 +1038,7 @@ func (channel *Channel) SendSplitMessage(command string, minPrefixMode modes.Mod Message: message, Nick: nickmask, AccountName: account, - Time: now, + Tags: clientOnlyTags, }) } @@ -1110,27 +1162,29 @@ func (channel *Channel) Kick(client *Client, target *Client, comment string, rb comment = comment[:kicklimit] } + message := utils.MakeSplitMessage(comment, true) clientMask := client.NickMaskString() + clientAccount := client.AccountName() + targetNick := target.Nick() chname := channel.Name() for _, member := range channel.Members() { for _, session := range member.Sessions() { if session != rb.session { - session.Send(nil, clientMask, "KICK", chname, targetNick, comment) + session.sendFromClientInternal(false, message.Time, message.Msgid, clientMask, clientAccount, nil, "KICK", chname, targetNick, comment) } } } rb.Add(nil, clientMask, "KICK", chname, targetNick, comment) - message := utils.SplitMessage{} - message.Message = comment - message.Msgid = targetNick // XXX abuse this field - channel.history.Add(history.Item{ + histItem := history.Item{ Type: history.Kick, Nick: clientMask, AccountName: target.AccountName(), Message: message, - }) + } + histItem.Params[0] = targetNick + channel.history.Add(histItem) channel.Quit(target) } diff --git a/irc/client.go b/irc/client.go index e7cb33a1..73c0bfb6 100644 --- a/irc/client.go +++ b/irc/client.go @@ -487,7 +487,7 @@ func (client *Client) tryResume() (success bool) { } } privmsgMatcher := func(item history.Item) bool { - return item.Type == history.Privmsg || item.Type == history.Notice + return item.Type == history.Privmsg || item.Type == history.Notice || item.Type == history.Tagmsg } privmsgHistory := oldClient.history.Match(privmsgMatcher, false, 0) lastDiscarded := oldClient.history.LastDiscarded() @@ -495,8 +495,7 @@ func (client *Client) tryResume() (success bool) { oldestLostMessage = lastDiscarded } for _, item := range privmsgHistory { - // TODO this is the nickmask, fix that - sender := server.clients.Get(item.Nick) + sender := server.clients.Get(stripMaskFromNick(item.Nick)) if sender != nil { friends.Add(sender) } @@ -561,8 +560,13 @@ func (client *Client) tryResumeChannels() { } func (client *Client) replayPrivmsgHistory(rb *ResponseBuffer, items []history.Item, complete bool) { + var batchID string nick := client.Nick() - serverTime := rb.session.capabilities.Has(caps.ServerTime) + if 0 < len(items) { + batchID = rb.StartNestedHistoryBatch(nick) + } + + allowTags := rb.session.capabilities.Has(caps.MessageTags) for _, item := range items { var command string switch item.Type { @@ -570,15 +574,23 @@ func (client *Client) replayPrivmsgHistory(rb *ResponseBuffer, items []history.I command = "PRIVMSG" case history.Notice: command = "NOTICE" + case history.Tagmsg: + if allowTags { + command = "TAGMSG" + } else { + continue + } default: continue } var tags map[string]string - if serverTime { - tags = map[string]string{"time": item.Time.Format(IRCv3TimestampFormat)} + if allowTags { + tags = item.Tags } rb.AddSplitMessageFromClient(item.Nick, item.AccountName, tags, command, nick, item.Message) } + + rb.EndNestedBatch(batchID) if !complete { rb.Add(nil, "HistServ", "NOTICE", nick, client.t("Some additional message history may have been lost")) } @@ -934,19 +946,21 @@ func (client *Client) destroy(beingResumed bool, session *Session) { return } + details := client.Details() + // see #235: deduplicating the list of PART recipients uses (comparatively speaking) // a lot of RAM, so limit concurrency to avoid thrashing client.server.semaphores.ClientDestroy.Acquire() defer client.server.semaphores.ClientDestroy.Release() if beingResumed { - client.server.logger.Debug("quit", fmt.Sprintf("%s is being resumed", client.nick)) + client.server.logger.Debug("quit", fmt.Sprintf("%s is being resumed", details.nick)) } else { - client.server.logger.Debug("quit", fmt.Sprintf("%s is no longer on the server", client.nick)) + client.server.logger.Debug("quit", fmt.Sprintf("%s is no longer on the server", details.nick)) } if !beingResumed { - client.server.whoWas.Append(client.WhoWas()) + client.server.whoWas.Append(details.WhoWas) } // remove from connection limits @@ -963,6 +977,7 @@ func (client *Client) destroy(beingResumed bool, session *Session) { // clean up monitor state client.server.monitorManager.RemoveAll(client) + splitQuitMessage := utils.MakeSplitMessage(quitMessage, true) // clean up channels friends := make(ClientSet) for _, channel := range client.Channels() { @@ -972,7 +987,7 @@ func (client *Client) destroy(beingResumed bool, session *Session) { Type: history.Quit, Nick: nickMaskString, AccountName: accountName, - Message: utils.MakeSplitMessage(quitMessage, true), + Message: splitQuitMessage, }) } for _, member := range channel.Members() { @@ -1007,14 +1022,14 @@ func (client *Client) destroy(beingResumed bool, session *Session) { if quitMessage == "" { quitMessage = "Exited" } - friend.Send(nil, client.nickMaskString, "QUIT", quitMessage) + friend.sendFromClientInternal(false, splitQuitMessage.Time, splitQuitMessage.Msgid, details.nickMask, details.accountName, nil, "QUIT", quitMessage) } } if !client.exitedSnomaskSent { if beingResumed { client.server.snomasks.Send(sno.LocalQuits, fmt.Sprintf(ircfmt.Unescape("%s$r is resuming their connection, old client has been destroyed"), client.nick)) } else { - client.server.snomasks.Send(sno.LocalQuits, fmt.Sprintf(ircfmt.Unescape("%s$r exited the network"), client.nick)) + client.server.snomasks.Send(sno.LocalQuits, fmt.Sprintf(ircfmt.Unescape("%s$r exited the network"), details.nick)) } } } @@ -1031,15 +1046,7 @@ func (session *Session) sendSplitMsgFromClientInternal(blocking bool, serverTime } } -// SendFromClient sends an IRC line coming from a specific client. -// Adds account-tag to the line as well. -func (client *Client) SendFromClient(msgid string, from *Client, tags map[string]string, command string, params ...string) error { - return client.sendFromClientInternal(false, time.Time{}, msgid, from.NickMaskString(), from.AccountName(), tags, command, params...) -} - -// this is SendFromClient, but directly exposing nickmask and accountName, -// for things like history replay and CHGHOST where they no longer (necessarily) -// correspond to the current state of a client +// Sends a line with `nickmask` as the prefix, adding `time` and `account` tags if supported func (client *Client) sendFromClientInternal(blocking bool, serverTime time.Time, msgid string, nickmask, accountName string, tags map[string]string, command string, params ...string) (err error) { for _, session := range client.Sessions() { err_ := session.sendFromClientInternal(blocking, serverTime, msgid, nickmask, accountName, tags, command, params...) @@ -1062,7 +1069,10 @@ func (session *Session) sendFromClientInternal(blocking bool, serverTime time.Ti } // attach server-time if session.capabilities.Has(caps.ServerTime) { - msg.SetTag("time", time.Now().UTC().Format(IRCv3TimestampFormat)) + if serverTime.IsZero() { + serverTime = time.Now().UTC() + } + msg.SetTag("time", serverTime.Format(IRCv3TimestampFormat)) } return session.SendRawMessage(msg, blocking) diff --git a/irc/handlers.go b/irc/handlers.go index de67ccfd..5194a201 100644 --- a/irc/handlers.go +++ b/irc/handlers.go @@ -585,36 +585,36 @@ func capHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *Respo // e.g., CHATHISTORY #ircv3 BETWEEN timestamp=YYYY-MM-DDThh:mm:ss.sssZ timestamp=YYYY-MM-DDThh:mm:ss.sssZ + 100 func chathistoryHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *ResponseBuffer) (exiting bool) { config := server.Config() - // batch type is chathistory; send an empty batch if necessary - rb.InitializeBatch("chathistory", true) var items []history.Item success := false var hist *history.Buffer var channel *Channel defer func() { - if success { + // successful responses are sent as a chathistory or history batch + if success && 0 < len(items) { + batchType := "chathistory" + if rb.session.capabilities.Has(caps.EventPlayback) { + batchType = "history" + } + rb.ForceBatchStart(batchType, true) if channel == nil { client.replayPrivmsgHistory(rb, items, true) } else { - channel.replayHistoryItems(rb, items) + channel.replayHistoryItems(rb, items, false) } - } - rb.Send(true) // terminate the chathistory batch - if success && len(items) > 0 { return } - newRb := NewResponseBuffer(rb.session) - newRb.Label = rb.Label // same label, new batch + + // errors are sent either without a batch, or in a draft/labeled-response batch as usual // TODO: send `WARN CHATHISTORY MAX_MESSAGES_EXCEEDED` when appropriate if hist == nil { - newRb.Add(nil, server.name, "ERR", "CHATHISTORY", "NO_SUCH_CHANNEL") + rb.Add(nil, server.name, "ERR", "CHATHISTORY", "NO_SUCH_CHANNEL") } else if len(items) == 0 { - newRb.Add(nil, server.name, "ERR", "CHATHISTORY", "NO_TEXT_TO_SEND") + rb.Add(nil, server.name, "ERR", "CHATHISTORY", "NO_TEXT_TO_SEND") } else if !success { - newRb.Add(nil, server.name, "ERR", "CHATHISTORY", "NEED_MORE_PARAMS") + rb.Add(nil, server.name, "ERR", "CHATHISTORY", "NEED_MORE_PARAMS") } - newRb.Send(true) }() target := msg.Params[0] @@ -744,7 +744,7 @@ func chathistoryHandler(server *Server, client *Client, msg ircmsg.IrcMessage, r } } else { matches = func(item history.Item) bool { - return before == item.Time.Before(timestamp) + return before == item.Message.Time.Before(timestamp) } } items = hist.Match(matches, !before, limit) @@ -767,7 +767,7 @@ func chathistoryHandler(server *Server, client *Client, msg ircmsg.IrcMessage, r } } else { matches = func(item history.Item) bool { - return item.Time.After(timestamp) + return item.Message.Time.After(timestamp) } } items = hist.Match(matches, false, limit) @@ -790,16 +790,16 @@ func chathistoryHandler(server *Server, client *Client, msg ircmsg.IrcMessage, r } } else { initialMatcher = func(item history.Item) (result bool) { - return item.Time.Before(timestamp) + return item.Message.Time.Before(timestamp) } } var halfLimit int halfLimit = (limit + 1) / 2 firstPass := hist.Match(initialMatcher, false, halfLimit) if len(firstPass) > 0 { - timeWindowStart := firstPass[0].Time + timeWindowStart := firstPass[0].Message.Time items = hist.Match(func(item history.Item) bool { - return item.Time.Equal(timeWindowStart) || item.Time.After(timeWindowStart) + return item.Message.Time.Equal(timeWindowStart) || item.Message.Time.After(timeWindowStart) }, true, limit) } success = true @@ -1109,7 +1109,7 @@ func historyHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *R items := hist.Latest(limit) if channel != nil { - channel.replayHistoryItems(rb, items) + channel.replayHistoryItems(rb, items, false) } else { client.replayPrivmsgHistory(rb, items, true) } @@ -1960,7 +1960,6 @@ func messageHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *R for i, targetString := range targets { // each target gets distinct msgids splitMsg := utils.MakeSplitMessage(message, !rb.session.capabilities.Has(caps.MaxLine)) - now := time.Now().UTC() // max of four targets per privmsg if i > maxTargets-1 { @@ -2009,17 +2008,17 @@ func messageHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *R if histType == history.Tagmsg { // don't send TAGMSG at all if they don't have the tags cap if session.capabilities.Has(caps.MessageTags) { - session.sendFromClientInternal(false, now, splitMsg.Msgid, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick) + session.sendFromClientInternal(false, splitMsg.Time, splitMsg.Msgid, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick) } } else { - session.sendSplitMsgFromClientInternal(false, now, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick, splitMsg) + session.sendSplitMsgFromClientInternal(false, splitMsg.Time, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick, splitMsg) } } } // an echo-message may need to be included in the response: if rb.session.capabilities.Has(caps.EchoMessage) { if histType == history.Tagmsg && rb.session.capabilities.Has(caps.MessageTags) { - rb.AddFromClient(splitMsg.Msgid, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick) + rb.AddFromClient(splitMsg.Time, splitMsg.Msgid, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick) } else { rb.AddSplitMessageFromClient(nickMaskString, accountName, clientOnlyTags, msg.Command, tnick, splitMsg) } @@ -2030,9 +2029,9 @@ func messageHandler(server *Server, client *Client, msg ircmsg.IrcMessage, rb *R continue } if histType == history.Tagmsg && rb.session.capabilities.Has(caps.MessageTags) { - session.sendFromClientInternal(false, now, splitMsg.Msgid, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick) + session.sendFromClientInternal(false, splitMsg.Time, splitMsg.Msgid, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick) } else { - session.sendSplitMsgFromClientInternal(false, now, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick, splitMsg) + session.sendSplitMsgFromClientInternal(false, splitMsg.Time, nickMaskString, accountName, clientOnlyTags, msg.Command, tnick, splitMsg) } } if histType != history.Notice && user.Away() { diff --git a/irc/history/history.go b/irc/history/history.go index 520ba0bb..3a3655bb 100644 --- a/irc/history/history.go +++ b/irc/history/history.go @@ -22,25 +22,52 @@ const ( Quit Mode Tagmsg + Nick ) +// a Tagmsg that consists entirely of junk tags is not stored +var junkTags = map[string]bool{ + "+draft/typing": true, + "+typing": true, // future-proofing +} + // Item represents an event (e.g., a PRIVMSG or a JOIN) and its associated data type Item struct { Type ItemType - Time time.Time Nick string // this is the uncasefolded account name, if there's no account it should be set to "*" AccountName string - Message utils.SplitMessage // for non-privmsg items, we may stuff some other data in here + Message utils.SplitMessage + Tags map[string]string + Params [1]string } // HasMsgid tests whether a message has the message id `msgid`. func (item *Item) HasMsgid(msgid string) bool { - // XXX we stuff other data in the Msgid field sometimes, - // don't match it by accident - return (item.Type == Privmsg || item.Type == Notice) && item.Message.Msgid == msgid + if item.Message.Msgid == msgid { + return true + } + for _, pair := range item.Message.Wrapped { + if pair.Msgid == msgid { + return true + } + } + return false +} + +func (item *Item) isStorable() bool { + if item.Type == Tagmsg { + for name := range item.Tags { + if !junkTags[name] { + return true + } + } + return false // all tags were blacklisted + } else { + return true + } } type Predicate func(item Item) (matches bool) @@ -94,8 +121,12 @@ func (list *Buffer) Add(item Item) { return } - if item.Time.IsZero() { - item.Time = time.Now().UTC() + if !item.isStorable() { + return + } + + if item.Message.Time.IsZero() { + item.Message.Time = time.Now().UTC() } list.Lock() @@ -114,8 +145,8 @@ func (list *Buffer) Add(item Item) { list.end = (list.end + 1) % len(list.buffer) list.start = list.end // advance start as well, overwriting first entry // record the timestamp of the overwritten item - if list.lastDiscarded.Before(list.buffer[pos].Time) { - list.lastDiscarded = list.buffer[pos].Time + if list.lastDiscarded.Before(list.buffer[pos].Message.Time) { + list.lastDiscarded = list.buffer[pos].Message.Time } } @@ -144,7 +175,7 @@ func (list *Buffer) Between(after, before time.Time, ascending bool, limit int) complete = after.Equal(list.lastDiscarded) || after.After(list.lastDiscarded) satisfies := func(item Item) bool { - return (after.IsZero() || item.Time.After(after)) && (before.IsZero() || item.Time.Before(before)) + return (after.IsZero() || item.Message.Time.After(after)) && (before.IsZero() || item.Message.Time.Before(before)) } return list.matchInternal(satisfies, ascending, limit), complete @@ -264,8 +295,8 @@ func (list *Buffer) Resize(size int) { } // update lastDiscarded for discarded entries for i := list.start; i != start; i = (i + 1) % len(list.buffer) { - if list.lastDiscarded.Before(list.buffer[i].Time) { - list.lastDiscarded = list.buffer[i].Time + if list.lastDiscarded.Before(list.buffer[i].Message.Time) { + list.lastDiscarded = list.buffer[i].Message.Time } } } diff --git a/irc/history/history_test.go b/irc/history/history_test.go index c5ba4594..451f331b 100644 --- a/irc/history/history_test.go +++ b/irc/history/history_test.go @@ -87,6 +87,12 @@ func easyParse(timestamp string) time.Time { return result } +func easyItem(nick string, timestamp string) (result Item) { + result.Message.Time = easyParse(timestamp) + result.Nick = nick + return +} + func assertEqual(supplied, expected interface{}, t *testing.T) { if !reflect.DeepEqual(supplied, expected) { t.Errorf("expected %v but got %v", expected, supplied) @@ -97,30 +103,19 @@ func TestBuffer(t *testing.T) { start := easyParse("2006-01-01 00:00:00Z") buf := NewHistoryBuffer(3) - buf.Add(Item{ - Nick: "testnick0", - Time: easyParse("2006-01-01 15:04:05Z"), - }) + buf.Add(easyItem("testnick0", "2006-01-01 15:04:05Z")) - buf.Add(Item{ - Nick: "testnick1", - Time: easyParse("2006-01-02 15:04:05Z"), - }) + buf.Add(easyItem("testnick1", "2006-01-02 15:04:05Z")) - buf.Add(Item{ - Nick: "testnick2", - Time: easyParse("2006-01-03 15:04:05Z"), - }) + buf.Add(easyItem("testnick2", "2006-01-03 15:04:05Z")) since, complete := buf.Between(start, time.Now(), false, 0) assertEqual(complete, true, t) assertEqual(toNicks(since), []string{"testnick0", "testnick1", "testnick2"}, t) // add another item, evicting the first - buf.Add(Item{ - Nick: "testnick3", - Time: easyParse("2006-01-04 15:04:05Z"), - }) + buf.Add(easyItem("testnick3", "2006-01-04 15:04:05Z")) + since, complete = buf.Between(start, time.Now(), false, 0) assertEqual(complete, false, t) assertEqual(toNicks(since), []string{"testnick1", "testnick2", "testnick3"}, t) @@ -139,18 +134,9 @@ func TestBuffer(t *testing.T) { assertEqual(toNicks(since), []string{"testnick2", "testnick3"}, t) buf.Resize(5) - buf.Add(Item{ - Nick: "testnick4", - Time: easyParse("2006-01-05 15:04:05Z"), - }) - buf.Add(Item{ - Nick: "testnick5", - Time: easyParse("2006-01-06 15:04:05Z"), - }) - buf.Add(Item{ - Nick: "testnick6", - Time: easyParse("2006-01-07 15:04:05Z"), - }) + buf.Add(easyItem("testnick4", "2006-01-05 15:04:05Z")) + buf.Add(easyItem("testnick5", "2006-01-06 15:04:05Z")) + buf.Add(easyItem("testnick6", "2006-01-07 15:04:05Z")) since, complete = buf.Between(easyParse("2006-01-03 00:00:00Z"), time.Now(), false, 0) assertEqual(complete, true, t) assertEqual(toNicks(since), []string{"testnick2", "testnick3", "testnick4", "testnick5", "testnick6"}, t) diff --git a/irc/nickname.go b/irc/nickname.go index 611d88b5..c9098679 100644 --- a/irc/nickname.go +++ b/irc/nickname.go @@ -11,7 +11,9 @@ import ( "strings" "github.com/goshuirc/irc-go/ircfmt" + "github.com/oragono/oragono/irc/history" "github.com/oragono/oragono/irc/sno" + "github.com/oragono/oragono/irc/utils" ) var ( @@ -44,7 +46,7 @@ func performNickChange(server *Server, client *Client, target *Client, session * hadNick := target.HasNick() origNickMask := target.NickMaskString() - whowas := target.WhoWas() + details := target.Details() err = client.server.clients.SetNick(target, session, nickname) if err == errNicknameInUse { rb.Add(nil, server.name, ERR_NICKNAMEINUSE, currentNick, nickname, client.t("Nickname is already in use")) @@ -57,18 +59,31 @@ func performNickChange(server *Server, client *Client, target *Client, session * return false } + message := utils.MakeSplitMessage("", true) + histItem := history.Item{ + Type: history.Nick, + Nick: origNickMask, + AccountName: details.accountName, + Message: message, + } + histItem.Params[0] = nickname + client.server.logger.Debug("nick", fmt.Sprintf("%s changed nickname to %s [%s]", origNickMask, nickname, cfnick)) if hadNick { - target.server.snomasks.Send(sno.LocalNicks, fmt.Sprintf(ircfmt.Unescape("$%s$r changed nickname to %s"), whowas.nick, nickname)) - target.server.whoWas.Append(whowas) - rb.Add(nil, origNickMask, "NICK", nickname) + target.server.snomasks.Send(sno.LocalNicks, fmt.Sprintf(ircfmt.Unescape("$%s$r changed nickname to %s"), details.nick, nickname)) + target.server.whoWas.Append(details.WhoWas) + rb.AddFromClient(message.Time, message.Msgid, origNickMask, details.accountName, nil, "NICK", nickname) for session := range target.Friends() { if session != rb.session { - session.Send(nil, origNickMask, "NICK", nickname) + session.sendFromClientInternal(false, message.Time, message.Msgid, origNickMask, details.accountName, nil, "NICK", nickname) } } } + for _, channel := range client.Channels() { + channel.history.Add(histItem) + } + target.nickTimer.Touch(rb) if target.Registered() { diff --git a/irc/responsebuffer.go b/irc/responsebuffer.go index 16d4613d..3b7b0bcb 100644 --- a/irc/responsebuffer.go +++ b/irc/responsebuffer.go @@ -23,8 +23,19 @@ const ( // buffer will silently create a batch if required and label the outgoing messages as // necessary (or leave it off and simply tag the outgoing message). type ResponseBuffer struct { - Label string - batchID string + Label string // label if this is a labeled response batch + batchID string // ID of the labeled response batch, if one has been initiated + batchType string // type of the labeled response batch (possibly `history` or `chathistory`) + + // stack of batch IDs of nested batches, which are handled separately + // from the underlying labeled-response batch. starting a new nested batch + // unconditionally enqueues its batch start message; subsequent messages + // are tagged with the nested batch ID, until nested batch end. + // (the nested batch start itself may have no batch tag, or the batch tag of the + // underlying labeled-response batch, or the batch tag of the next outermost + // nested batch.) + nestedBatches []string + messages []ircmsg.IrcMessage finalized bool target *Client @@ -40,8 +51,9 @@ func GetLabel(msg ircmsg.IrcMessage) string { // NewResponseBuffer returns a new ResponseBuffer. func NewResponseBuffer(session *Session) *ResponseBuffer { return &ResponseBuffer{ - session: session, - target: session.client, + session: session, + target: session.client, + batchType: defaultBatchType, } } @@ -54,6 +66,9 @@ func (rb *ResponseBuffer) AddMessage(msg ircmsg.IrcMessage) { return } + if 0 < len(rb.nestedBatches) { + msg.SetTag("batch", rb.nestedBatches[len(rb.nestedBatches)-1]) + } rb.messages = append(rb.messages, msg) } @@ -63,9 +78,11 @@ func (rb *ResponseBuffer) Add(tags map[string]string, prefix string, command str } // AddFromClient adds a new message from a specific client to our queue. -func (rb *ResponseBuffer) AddFromClient(msgid string, fromNickMask string, fromAccount string, tags map[string]string, command string, params ...string) { +func (rb *ResponseBuffer) AddFromClient(time time.Time, msgid string, fromNickMask string, fromAccount string, tags map[string]string, command string, params ...string) { msg := ircmsg.MakeMessage(nil, fromNickMask, command, params...) - msg.UpdateTags(tags) + if rb.session.capabilities.Has(caps.MessageTags) { + msg.UpdateTags(tags) + } // attach account-tag if rb.session.capabilities.Has(caps.AccountTag) && fromAccount != "*" { @@ -75,6 +92,10 @@ func (rb *ResponseBuffer) AddFromClient(msgid string, fromNickMask string, fromA if len(msgid) > 0 && rb.session.capabilities.Has(caps.MessageTags) { msg.SetTag("draft/msgid", msgid) } + // attach server-time + if rb.session.capabilities.Has(caps.ServerTime) && !msg.HasTag("time") { + msg.SetTag("time", time.UTC().Format(IRCv3TimestampFormat)) + } rb.AddMessage(msg) } @@ -82,33 +103,31 @@ func (rb *ResponseBuffer) AddFromClient(msgid string, fromNickMask string, fromA // AddSplitMessageFromClient adds a new split message from a specific client to our queue. func (rb *ResponseBuffer) AddSplitMessageFromClient(fromNickMask string, fromAccount string, tags map[string]string, command string, target string, message utils.SplitMessage) { if rb.session.capabilities.Has(caps.MaxLine) || message.Wrapped == nil { - rb.AddFromClient(message.Msgid, fromNickMask, fromAccount, tags, command, target, message.Message) + rb.AddFromClient(message.Time, message.Msgid, fromNickMask, fromAccount, tags, command, target, message.Message) } else { for _, messagePair := range message.Wrapped { - rb.AddFromClient(messagePair.Msgid, fromNickMask, fromAccount, tags, command, target, messagePair.Message) + rb.AddFromClient(message.Time, messagePair.Msgid, fromNickMask, fromAccount, tags, command, target, messagePair.Message) } } } -// InitializeBatch forcibly starts a batch of batch `batchType`. +// ForceBatchStart forcibly starts a batch of batch `batchType`. // Normally, Send/Flush will decide automatically whether to start a batch // of type draft/labeled-response. This allows changing the batch type // and forcing the creation of a possibly empty batch. -func (rb *ResponseBuffer) InitializeBatch(batchType string, blocking bool) { - rb.sendBatchStart(batchType, blocking) +func (rb *ResponseBuffer) ForceBatchStart(batchType string, blocking bool) { + rb.batchType = batchType + rb.sendBatchStart(blocking) } -func (rb *ResponseBuffer) sendBatchStart(batchType string, blocking bool) { +func (rb *ResponseBuffer) sendBatchStart(blocking bool) { if rb.batchID != "" { // batch already initialized return } - // formerly this combined time.Now.UnixNano() in base 36 with an incrementing counter, - // also in base 36. but let's just use a uuidv4-alike (26 base32 characters): rb.batchID = utils.GenerateSecretToken() - - message := ircmsg.MakeMessage(nil, rb.target.server.name, "BATCH", "+"+rb.batchID, batchType) + message := ircmsg.MakeMessage(nil, rb.target.server.name, "BATCH", "+"+rb.batchID, rb.batchType) if rb.Label != "" { message.SetTag(caps.LabelTagName, rb.Label) } @@ -125,6 +144,50 @@ func (rb *ResponseBuffer) sendBatchEnd(blocking bool) { rb.session.SendRawMessage(message, blocking) } +// Starts a nested batch (see the ResponseBuffer struct definition for a description of +// how this works) +func (rb *ResponseBuffer) StartNestedBatch(batchType string, params ...string) (batchID string) { + batchID = utils.GenerateSecretToken() + msgParams := make([]string, len(params)+2) + msgParams[0] = "+" + batchID + msgParams[1] = batchType + copy(msgParams[2:], params) + rb.AddMessage(ircmsg.MakeMessage(nil, rb.target.server.name, "BATCH", msgParams...)) + rb.nestedBatches = append(rb.nestedBatches, batchID) + return +} + +// Ends a nested batch +func (rb *ResponseBuffer) EndNestedBatch(batchID string) { + if batchID == "" { + return + } + + if 0 == len(rb.nestedBatches) || rb.nestedBatches[len(rb.nestedBatches)-1] != batchID { + rb.target.server.logger.Error("internal", "inconsistent batch nesting detected") + debug.PrintStack() + return + } + + rb.nestedBatches = rb.nestedBatches[0 : len(rb.nestedBatches)-1] + rb.AddMessage(ircmsg.MakeMessage(nil, rb.target.server.name, "BATCH", "-"+batchID)) +} + +// Convenience to start a nested batch for history lines, at the highest level +// supported by the client (`history`, `chathistory`, or no batch, in descending order). +func (rb *ResponseBuffer) StartNestedHistoryBatch(params ...string) (batchID string) { + var batchType string + if rb.session.capabilities.Has(caps.EventPlayback) { + batchType = "history" + } else if rb.session.capabilities.Has(caps.Batch) { + batchType = "chathistory" + } + if batchType != "" { + batchID = rb.StartNestedBatch(batchType, params...) + } + return +} + // Send sends all messages in the buffer to the client. // Afterwards, the buffer is in an undefined state and MUST NOT be used further. // If `blocking` is true you MUST be sending to the client from its own goroutine. @@ -158,7 +221,7 @@ func (rb *ResponseBuffer) flushInternal(final bool, blocking bool) error { if useLabel && !useBatch && len(rb.messages) == 1 && rb.batchID == "" { rb.messages[0].SetTag(caps.LabelTagName, rb.Label) } else if useBatch { - rb.sendBatchStart(defaultBatchType, blocking) + rb.sendBatchStart(blocking) } // send each message out @@ -168,8 +231,9 @@ func (rb *ResponseBuffer) flushInternal(final bool, blocking bool) error { message.SetTag("time", time.Now().UTC().Format(IRCv3TimestampFormat)) } - // attach batch ID - if rb.batchID != "" { + // attach batch ID, unless this message was part of a nested batch and is + // already tagged + if rb.batchID != "" && !message.HasTag("batch") { message.SetTag("batch", rb.batchID) } diff --git a/irc/utils/text.go b/irc/utils/text.go index e216d55c..92b9af38 100644 --- a/irc/utils/text.go +++ b/irc/utils/text.go @@ -4,6 +4,7 @@ package utils import "bytes" +import "time" // WordWrap wraps the given text into a series of lines that don't exceed lineWidth characters. func WordWrap(text string, lineWidth int) []string { @@ -59,6 +60,7 @@ type MessagePair struct { type SplitMessage struct { MessagePair Wrapped []MessagePair // if this is nil, `Message` didn't need wrapping and can be sent to anyone + Time time.Time } const defaultLineWidth = 400 @@ -66,6 +68,7 @@ const defaultLineWidth = 400 func MakeSplitMessage(original string, origIs512 bool) (result SplitMessage) { result.Message = original result.Msgid = GenerateSecretToken() + result.Time = time.Now().UTC() if !origIs512 && defaultLineWidth < len(original) { wrapped := WordWrap(original, defaultLineWidth)