fix(irc): improve IRC handler management (#1269)

* fix some races in IRC handler management

* remove go 1.21 and slices package

* chore: update deps

* fix: use exp/slices pkg and client callbacks

* fix(irc): remove deadlock mutex from authenticate

* restore locking in authenticate()

* fix(irc): data races

* fix(irc): do not allow restart of disabled network

* fix(irc): disable restart btn if net disabled

---------

Co-authored-by: ze0s <43699394+zze0s@users.noreply.github.com>
This commit is contained in:
Shivaram Lingamneni 2023-12-12 11:29:43 -08:00 committed by GitHub
parent 17e97201fd
commit b2c32a421e
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
5 changed files with 230 additions and 194 deletions

View file

@ -23,9 +23,14 @@ import (
"github.com/r3labs/sse/v2"
"github.com/rs/zerolog"
"github.com/sasha-s/go-deadlock"
"golang.org/x/exp/slices"
)
var (
connectionInProgress = errors.New("A connection attempt is already in progress")
clientDisconnected = errors.New("Message cannot be sent because client is disconnected")
clientManuallyDisconnected = retry.Unrecoverable(errors.New("IRC client was manually disconnected"))
)
@ -62,6 +67,14 @@ func (ch *channelHealth) resetMonitoring() {
ch.m.Unlock()
}
type ircState uint
const (
ircStopped ircState = iota // (Handler).client is nil
ircConnecting // still nil
ircLive // (Handler.client) is non-nil and valid
)
type Handler struct {
log zerolog.Logger
sse *sse.Server
@ -71,12 +84,12 @@ type Handler struct {
announceProcessors map[string]announce.Processor
definitions map[string]*domain.IndexerDefinition
client *ircevent.Connection
m deadlock.RWMutex
client *ircevent.Connection
clientState ircState
m deadlock.RWMutex
connectedSince time.Time
haveDisconnected bool
manuallyDisconnected bool
connectedSince time.Time
haveDisconnected bool
validAnnouncers map[string]struct{}
validChannels map[string]struct{}
@ -155,7 +168,7 @@ func (h *Handler) removeIndexer() {
// TODO remove announceProcessor
}
func (h *Handler) Run() error {
func (h *Handler) Run() (err error) {
// TODO validate
// check if network requires nickserv
// check if network or channels requires invite command
@ -168,9 +181,31 @@ func (h *Handler) Run() error {
// this used to be TraceLevel but was changed to DebugLevel during connect to see the info without needing to change loglevel
// we change back to TraceLevel in the handleJoined method.
subLogger := zstdlog.NewStdLoggerWithLevel(h.log.With().Logger(), zerolog.DebugLevel)
subLogger := zstdlog.NewStdLoggerWithLevel(h.log.With().Logger(), zerolog.TraceLevel)
h.client = &ircevent.Connection{
shouldConnect := false
h.m.Lock()
if h.clientState == ircStopped {
shouldConnect = true
h.clientState = ircConnecting
}
h.m.Unlock()
if !shouldConnect {
return connectionInProgress
}
// either we will successfully transition to `ircLive`, or else
// we need to reset the state to `ircStopped`
defer func() {
h.m.Lock()
if h.clientState == ircConnecting {
h.clientState = ircStopped
}
h.m.Unlock()
}()
client := &ircevent.Connection{
Nick: h.network.Nick,
User: h.network.Auth.Account,
RealName: h.network.Auth.Account,
@ -187,36 +222,38 @@ func (h *Handler) Run() error {
if h.network.Auth.Mechanism == domain.IRCAuthMechanismSASLPlain {
if h.network.Auth.Account != "" && h.network.Auth.Password != "" {
h.client.SASLLogin = h.network.Auth.Account
h.client.SASLPassword = h.network.Auth.Password
h.client.SASLOptional = true
h.client.UseSASL = true
client.SASLLogin = h.network.Auth.Account
client.SASLPassword = h.network.Auth.Password
client.SASLOptional = true
client.UseSASL = true
}
}
if h.network.TLS {
h.client.UseTLS = true
h.client.TLSConfig = &tls.Config{InsecureSkipVerify: true}
client.UseTLS = true
client.TLSConfig = &tls.Config{InsecureSkipVerify: true}
}
h.client.AddConnectCallback(h.onConnect)
h.client.AddDisconnectCallback(h.onDisconnect)
client.AddConnectCallback(h.onConnect)
client.AddDisconnectCallback(h.onDisconnect)
h.client.AddCallback("MODE", h.handleMode)
client.AddCallback("MODE", h.handleMode)
if h.network.BotMode {
h.client.AddCallback("501", h.handleModeUnknownFlag)
client.AddCallback("501", h.handleModeUnknownFlag)
}
h.client.AddCallback("INVITE", h.handleInvite)
h.client.AddCallback("366", h.handleJoined)
h.client.AddCallback("PART", h.handlePart)
h.client.AddCallback("PRIVMSG", h.onMessage)
h.client.AddCallback("NOTICE", h.onNotice)
h.client.AddCallback("NICK", h.onNick)
h.client.AddCallback("903", h.handleSASLSuccess)
client.AddCallback("INVITE", h.handleInvite)
client.AddCallback("366", h.handleJoined)
client.AddCallback("PART", h.handlePart)
client.AddCallback("PRIVMSG", h.onMessage)
client.AddCallback("NOTICE", h.onNotice)
client.AddCallback("NICK", h.onNick)
client.AddCallback("903", h.handleSASLSuccess)
//h.setConnectionStatus()
h.saslauthed = false
h.client = client
if err := func() error {
// count connect attempts
connectAttempts := 0
@ -230,14 +267,14 @@ func (h *Handler) Run() error {
// #1239: don't retry if the user manually disconnected with Stop()
h.m.RLock()
manuallyDisconnected := h.manuallyDisconnected
manuallyDisconnected := h.clientState == ircStopped
h.m.RUnlock()
if manuallyDisconnected {
return clientManuallyDisconnected
}
if err := h.client.Connect(); err != nil {
if err := client.Connect(); err != nil {
h.log.Error().Err(err).Msg("client encountered connection error")
connectAttempts++
return err
@ -265,7 +302,29 @@ func (h *Handler) Run() error {
return err
}
h.client.Loop()
shouldDisconnect := false
h.m.Lock()
switch h.clientState {
case ircStopped:
// concurrent Stop(), bail
shouldDisconnect = true
case ircConnecting:
// success!
//h.client = client
h.clientState = ircLive
case ircLive:
// impossible
h.log.Error().Stack().Msgf("two concurrent connection attempts detected")
shouldDisconnect = true
}
h.m.Unlock()
if shouldDisconnect {
client.Quit()
return clientManuallyDisconnected
}
go client.Loop()
return nil
}
@ -277,29 +336,15 @@ func (h *Handler) isOurNick(nick string) bool {
}
func (h *Handler) isOurCurrentNick(nick string) bool {
h.m.RLock()
defer h.m.RUnlock()
return h.client.CurrentNick() == nick
return h.CurrentNick() == nick
}
func (h *Handler) setConnectionStatus() {
h.m.Lock()
if h.client.Connected() {
if h.client != nil && h.client.Connected() {
h.connectedSince = time.Now()
}
h.m.Unlock()
//else {
// h.connectedSince = time.Time{}
// //h.channelHealth = map[string]*channelHealth{}
// h.resetChannelHealth()
//}
}
func (h *Handler) resetConnectionStatus() {
h.m.Lock()
h.connectedSince = time.Time{}
h.resetChannelHealth()
h.m.Unlock()
}
func (h *Handler) GetNetwork() *domain.IrcNetwork {
@ -331,32 +376,38 @@ func (h *Handler) AddChannelHealth(channel string) {
}
func (h *Handler) resetChannelHealth() {
h.m.RLock()
for _, ch := range h.channelHealth {
ch.resetMonitoring()
}
h.m.RUnlock()
}
// Stop the network and quit
func (h *Handler) Stop() {
h.m.Lock()
h.connectedSince = time.Time{}
h.manuallyDisconnected = true
if h.client.Connected() {
h.log.Debug().Msg("Disconnecting...")
}
client := h.client
h.clientState = ircStopped
h.client = nil
h.m.Unlock()
h.resetChannelHealth()
if client != nil {
h.log.Debug().Msg("Disconnecting...")
h.resetChannelHealth()
client.Quit()
}
}
h.client.Quit()
func (h *Handler) Stopped() bool {
h.m.RLock()
defer h.m.RUnlock()
return h.clientState == ircStopped
}
// Restart stops the network and then runs it
func (h *Handler) Restart() error {
h.log.Debug().Msg("Restarting network...")
h.Stop()
return h.Run()
}
@ -372,7 +423,9 @@ func (h *Handler) onConnect(m ircmsg.Message) {
func() {
h.m.Lock()
if h.haveDisconnected {
if h.haveDisconnected && h.clientState == ircLive {
h.log.Info().Msgf("network re-connected after unexpected disconnect: %s", h.network.Name)
h.notificationService.Send(domain.NotificationEventIRCReconnected, domain.NotificationPayload{
Subject: "IRC Reconnected",
Message: fmt.Sprintf("Network: %s", h.network.Name),
@ -383,7 +436,7 @@ func (h *Handler) onConnect(m ircmsg.Message) {
}
h.m.Unlock()
h.log.Debug().Msgf("connected to: %s", h.network.Name)
h.log.Info().Msgf("network connected to: %s", h.network.Name)
}()
time.Sleep(1 * time.Second)
@ -416,17 +469,17 @@ func (h *Handler) onDisconnect(m ircmsg.Message) {
h.haveDisconnected = true
manuallyDisconnected := h.clientState == ircStopped
// check if we are responsible for disconnect
if !h.manuallyDisconnected {
if !manuallyDisconnected {
// only send notification if we did not initiate disconnect/restart/stop
h.notificationService.Send(domain.NotificationEventIRCDisconnected, domain.NotificationPayload{
Subject: "IRC Disconnected unexpectedly",
Message: fmt.Sprintf("Network: %s", h.network.Name),
})
} else {
// reset
h.manuallyDisconnected = false
}
h.m.Unlock()
}
@ -496,9 +549,22 @@ func (h *Handler) handleNickServ(msg ircmsg.Message) {
if contains(msg.Params[1], "invalid parameters", "help identify") {
h.log.Debug().Msgf("NOTICE nickserv invalid: %v", msg.Params)
if err := h.client.Send("PRIVMSG", "NickServ", fmt.Sprintf("IDENTIFY %s %s", h.network.Auth.Account, h.network.Auth.Password)); err != nil {
return
}
h.Send("PRIVMSG", "NickServ", fmt.Sprintf("IDENTIFY %s %s", h.network.Auth.Account, h.network.Auth.Password))
}
}
func (h *Handler) getClient() *ircevent.Connection {
h.m.RLock()
client := h.client
h.m.RUnlock()
return client
}
func (h *Handler) Send(command string, params ...string) error {
if client := h.getClient(); client != nil {
return client.Send(command, params...)
} else {
return clientDisconnected
}
}
@ -517,28 +583,17 @@ func (h *Handler) setBotMode() {
}
// authenticate sends NickServIdentify if not authenticated
func (h *Handler) authenticate() bool {
func (h *Handler) authenticate() {
h.m.RLock()
defer h.m.RUnlock()
shouldSendNickserv := !h.authenticated && !h.saslauthed && h.network.Auth.Password != ""
h.m.RUnlock()
if h.authenticated {
return true
}
if !h.saslauthed && h.network.Auth.Password != "" {
if shouldSendNickserv {
h.log.Trace().Msg("on connect not authenticated and password not empty: send nickserv identify")
if err := h.NickServIdentify(h.network.Auth.Password); err != nil {
h.log.Error().Stack().Err(err).Msg("error nickserv")
return false
}
return false
h.NickServIdentify(h.network.Auth.Password)
} else {
h.setAuthenticated()
}
// return and wait for NOTICE of nickserv auth
return true
}
// handleSASLSuccess we get here early so set saslauthed before we hit onConnect
@ -551,9 +606,18 @@ func (h *Handler) handleSASLSuccess(msg ircmsg.Message) {
// setAuthenticated sets the states for authenticated, connectionErrors, failedNickServAttempts
// and then sends inviteCommand and after that JoinChannels
func (h *Handler) setAuthenticated() {
h.authenticated = true
h.connectionErrors = []string{}
h.failedNickServAttempts = 0
h.m.Lock()
alreadyAuthenticated := h.authenticated
if !alreadyAuthenticated {
h.authenticated = true
h.connectionErrors = []string{}
h.failedNickServAttempts = 0
}
h.m.Unlock()
if alreadyAuthenticated {
return
}
h.inviteCommand()
h.JoinChannels()
@ -594,9 +658,7 @@ func (h *Handler) onNick(msg ircmsg.Message) {
return
}
if !h.authenticated {
h.authenticate()
}
h.authenticate()
}
func (h *Handler) publishSSEMsg(msg domain.IrcMessage) {
@ -679,24 +741,15 @@ func (h *Handler) JoinChannels() {
// JoinChannel sends join command
func (h *Handler) JoinChannel(channel string, password string) error {
m := ircmsg.Message{
Command: "JOIN",
Params: []string{channel},
}
params := []string{channel}
// support channel password
if password != "" {
m.Params = []string{channel, password}
params = append(params, password)
}
h.log.Debug().Msgf("sending JOIN command %s", strings.Join(m.Params, " "))
h.log.Debug().Msgf("sending JOIN command %s", strings.Join(params, " "))
if err := h.client.SendIRCMessage(m); err != nil {
h.log.Error().Stack().Err(err).Msgf("error handling join: %s", channel)
return err
}
return nil
return h.Send("JOIN", params...)
}
// handlePart listens for PART events
@ -723,14 +776,9 @@ func (h *Handler) handlePart(msg ircmsg.Message) {
func (h *Handler) PartChannel(channel string) error {
h.log.Debug().Msgf("Leaving channel %s", channel)
if err := h.client.Part(channel); err != nil {
h.log.Error().Err(err).Msgf("error handling part: %s", channel)
return err
}
return h.Send("PART", channel)
// TODO remove announceProcessor
return nil
}
// handleJoined listens for 366 JOIN events
@ -782,9 +830,6 @@ func (h *Handler) handleJoined(msg ircmsg.Message) {
}
h.log.Info().Msgf("Monitoring channel %s", channel)
// reset log level to Trace now that we are monitoring a channel
h.client.Log = zstdlog.NewStdLoggerWithLevel(h.log.With().Logger(), zerolog.TraceLevel)
}
// sendConnectCommands sends invite commands
@ -800,15 +845,12 @@ func (h *Handler) sendConnectCommands(msg string) error {
continue
}
m := ircmsg.Message{
Command: "PRIVMSG",
Params: strings.Split(cmd, " "),
}
h.log.Debug().Msgf("sending connect command: %s", cmd)
if err := h.client.SendIRCMessage(m); err != nil {
h.log.Error().Err(err).Msgf("error handling connect command: %v", m)
params := strings.SplitN(cmd, " ", 2)
if err := h.Send("PRIVMSG", params...); err != nil {
h.log.Error().Err(err).Msgf("error handling connect command: %s", cmd)
return err
}
@ -836,7 +878,7 @@ func (h *Handler) handleInvite(msg ircmsg.Message) {
h.log.Debug().Msgf("INVITE from %s, joining %s", msg.Nick(), channel)
if err := h.client.Join(msg.Params[1]); err != nil {
if err := h.Send("JOIN", msg.Params[1]); err != nil {
h.log.Error().Stack().Err(err).Msgf("error handling join: %s", msg.Params[1])
return
}
@ -846,15 +888,8 @@ func (h *Handler) handleInvite(msg ircmsg.Message) {
// NickServIdentify sends NickServ Identify commands
func (h *Handler) NickServIdentify(password string) error {
m := ircmsg.Message{
Command: "PRIVMSG",
Params: []string{"NickServ", "IDENTIFY", password},
}
h.log.Debug().Msgf("NickServ: %v", m)
if err := h.client.SendIRCMessage(m); err != nil {
h.log.Error().Stack().Err(err).Msgf("error identifying with nickserv: %v", m)
if err := h.Send("PRIVMSG", "NickServ", fmt.Sprintf("IDENTIFY %s", password)); err != nil {
h.log.Error().Stack().Err(err).Msgf("error identifying with nickserv")
return err
}
@ -865,19 +900,29 @@ func (h *Handler) NickServIdentify(password string) error {
func (h *Handler) NickChange(nick string) error {
h.log.Debug().Msgf("NICK change: %s", nick)
h.client.SetNick(nick)
if client := h.getClient(); client != nil {
client.SetNick(nick)
}
return nil
}
// CurrentNick returns our current nick set by the server
func (h *Handler) CurrentNick() string {
return h.client.CurrentNick()
if client := h.getClient(); client != nil {
return client.CurrentNick()
} else {
return ""
}
}
// PreferredNick returns our preferred nick from settings
func (h *Handler) PreferredNick() string {
return h.client.PreferredNick()
if client := h.getClient(); client != nil {
return client.PreferredNick()
} else {
return ""
}
}
// listens for MODE events
@ -886,9 +931,7 @@ func (h *Handler) handleMode(msg ircmsg.Message) {
// if our nick and user mode +r (Identifies the nick as being Registered (settable by services only)) then return
if h.isOurCurrentNick(msg.Params[0]) && strings.Contains(msg.Params[1], "+r") {
if !h.authenticated {
h.setAuthenticated()
}
h.setAuthenticated()
return
}
@ -907,7 +950,7 @@ func (h *Handler) handleModeUnknownFlag(msg ircmsg.Message) {
func (h *Handler) SendMsg(channel, msg string) error {
h.log.Debug().Msgf("sending msg command: %s", msg)
if err := h.client.Privmsg(channel, msg); err != nil {
if err := h.Send("PRIVMSG", channel, msg); err != nil {
h.log.Error().Stack().Err(err).Msgf("error sending msg: %s", msg)
return err
}
@ -965,46 +1008,43 @@ func (h *Handler) addConnectError(message string) {
h.connectionErrors = append(h.connectionErrors, message)
}
// Healthy if enabled but not monitoring return false,
//
// if any channel is enabled but not monitoring return false,
// else return true
func (h *Handler) Healthy() bool {
isHealthy := h.networkHealth()
if !isHealthy {
h.log.Warn().Msg("network unhealthy")
return isHealthy
func (h *Handler) ReportStatus(netw *domain.IrcNetworkWithHealth) {
h.m.RLock()
defer h.m.RUnlock()
// only set connected and connected since if we have an active handler and connection
if !h.network.Enabled {
return
}
if h.client == nil {
return
}
netw.Connected = h.connectedSince != time.Time{}
netw.ConnectedSince = h.connectedSince
netw.CurrentNick = h.client.CurrentNick()
netw.PreferredNick = h.client.PreferredNick()
if !netw.Connected {
return
}
h.log.Trace().Msg("network healthy")
channelsHealthy := true
for _, channel := range h.network.Channels {
name := strings.ToLower(channel.Name)
return true
}
func (h *Handler) networkHealth() bool {
if h.network.Enabled {
if !h.client.Connected() {
return false
}
if (h.connectedSince == time.Time{}) {
return false
if chanHealth, ok := h.channelHealth[name]; ok {
chanHealth.m.RLock()
channelsHealthy = channelsHealthy && chanHealth.monitoring
chanHealth.m.RUnlock()
}
for _, channel := range h.network.Channels {
name := strings.ToLower(channel.Name)
if chanHealth, ok := h.channelHealth[name]; ok {
chanHealth.m.RLock()
if !chanHealth.monitoring {
chanHealth.m.RUnlock()
return false
}
chanHealth.m.RUnlock()
}
if !channelsHealthy {
break
}
}
return true
netw.Healthy = channelsHealthy
// TODO with Go 1.21 this can moved from golang.org/x/exp/slices to built in slices:
netw.ConnectionErrors = slices.Clone(h.connectionErrors)
}