Improve logging in reconnection loop

This commit is contained in:
Tulir Asokan 2021-09-24 14:07:32 -04:00
parent 74870ec638
commit cad99ece0a

24
user.go
View file

@ -1015,7 +1015,11 @@ func (user *User) HandleError(err error) {
// Otherwise unknown error, probably mostly harmless // Otherwise unknown error, probably mostly harmless
} }
var reconnectionID int64
func (user *User) tryReconnect(msg string) { func (user *User) tryReconnect(msg string) {
localReconID := atomic.AddInt64(&reconnectionID, 1)
rcLog := user.log.Sub(fmt.Sprintf("Reconnector-%d", localReconID))
user.bridge.Metrics.TrackConnectionState(user.JID, false) user.bridge.Metrics.TrackConnectionState(user.JID, false)
if user.ConnectionErrors > user.bridge.Config.Bridge.MaxConnectionAttempts { if user.ConnectionErrors > user.bridge.Config.Bridge.MaxConnectionAttempts {
user.sendMarkdownBridgeAlert("%s. Use the `reconnect` command to reconnect.", msg) user.sendMarkdownBridgeAlert("%s. Use the `reconnect` command to reconnect.", msg)
@ -1038,30 +1042,32 @@ func (user *User) tryReconnect(msg string) {
ctx, cancel := context.WithCancel(context.Background()) ctx, cancel := context.WithCancel(context.Background())
defer cancel() defer cancel()
user.cancelReconnect = cancel user.cancelReconnect = cancel
for user.ConnectionErrors <= user.bridge.Config.Bridge.MaxConnectionAttempts { for attemptNo := 1; user.ConnectionErrors <= user.bridge.Config.Bridge.MaxConnectionAttempts; attemptNo++ {
select { select {
case <-ctx.Done(): case <-ctx.Done():
user.log.Debugln("tryReconnect context cancelled, aborting reconnection attempts") rcLog.Debugln("tryReconnect context cancelled, aborting reconnection attempts")
return return
default: default:
} }
user.sendBridgeState(BridgeState{StateEvent: StateConnecting, Error: WAConnecting}) user.sendBridgeState(BridgeState{StateEvent: StateConnecting, Error: WAConnecting})
rcLog.Debugfln("Starting reconnection attempt #%d", attemptNo)
err := user.Conn.Restore(true, ctx) err := user.Conn.Restore(true, ctx)
if err == nil { if err == nil {
user.ConnectionErrors = 0 user.ConnectionErrors = 0
if user.bridge.Config.Bridge.ReportConnectionRetry { if user.bridge.Config.Bridge.ReportConnectionRetry {
user.sendBridgeNotice("Reconnected successfully") user.sendBridgeNotice("Reconnected successfully")
} }
rcLog.Debugln("Reconnection successful, running PostLogin and exiting loop")
user.PostLogin() user.PostLogin()
return return
} else if errors.Is(err, whatsapp.ErrBadRequest) { } else if errors.Is(err, whatsapp.ErrBadRequest) {
user.log.Warnln("Got init 400 error when trying to reconnect, resetting connection...") rcLog.Warnln("Got init 400 error when trying to reconnect, resetting connection...")
err = user.Conn.Disconnect() err = user.Conn.Disconnect()
if err != nil { if err != nil {
user.log.Debugln("Error while disconnecting for connection reset:", err) rcLog.Debugln("Error while disconnecting for connection reset:", err)
} }
} else if errors.Is(err, whatsapp.ErrUnpaired) || errors.Is(err, whatsapp.ErrInvalidSession) { } else if errors.Is(err, whatsapp.ErrUnpaired) || errors.Is(err, whatsapp.ErrInvalidSession) {
user.log.Errorfln("Got init %s error when trying to reconnect, not retrying", err) rcLog.Errorfln("Got init %s error when trying to reconnect, not retrying", err)
user.removeFromJIDMap(StateBadCredentials) user.removeFromJIDMap(StateBadCredentials)
//user.JID = "" //user.JID = ""
user.SetSession(nil) user.SetSession(nil)
@ -1074,10 +1080,13 @@ func (user *User) tryReconnect(msg string) {
"To re-pair your phone, log in again.", errMsg) "To re-pair your phone, log in again.", errMsg)
return return
} else if errors.Is(err, whatsapp.ErrAlreadyLoggedIn) { } else if errors.Is(err, whatsapp.ErrAlreadyLoggedIn) {
user.log.Warnln("Reconnection said we're already logged in, not trying anymore") rcLog.Warnln("Reconnection said we're already logged in, not trying anymore")
return
} else if errors.Is(err, whatsapp.ErrLoginInProgress) {
rcLog.Warnln("Reconnection said another reconnection is in progress, hoping there's another thread trying to reconnect and not retrying here")
return return
} else { } else {
user.log.Errorln("Error while trying to reconnect after disconnection:", err) rcLog.Errorln("Error while trying to reconnect after disconnection:", err)
} }
tries++ tries++
user.ConnectionErrors++ user.ConnectionErrors++
@ -1091,6 +1100,7 @@ func (user *User) tryReconnect(msg string) {
time.Sleep(delay * time.Second) time.Sleep(delay * time.Second)
} }
} }
rcLog.Debugln("Giving up trying to reconnect")
user.sendBridgeState(BridgeState{StateEvent: StateBadCredentials, Error: WANotConnected}) user.sendBridgeState(BridgeState{StateEvent: StateBadCredentials, Error: WANotConnected})
if user.bridge.Config.Bridge.ReportConnectionRetry { if user.bridge.Config.Bridge.ReportConnectionRetry {