diff --git a/imap/utils.go b/imap/utils.go index c6b1b51c..19d503a7 100644 --- a/imap/utils.go +++ b/imap/utils.go @@ -2,7 +2,7 @@ package imap // ShortID return a string containing a short version of the given ID. Use only for debug display. func ShortID(id string) string { - const l = 12 + const l = 36 if len(id) < l { return id diff --git a/internal/backend/backend.go b/internal/backend/backend.go index 32577096..2e3bf37f 100644 --- a/internal/backend/backend.go +++ b/internal/backend/backend.go @@ -53,6 +53,8 @@ type Backend struct { database db.ClientInterface panicHandler async.PanicHandler + + log *logrus.Entry } func New(dataDir, databaseDir string, @@ -73,6 +75,7 @@ func New(dataDir, databaseDir string, imapLimits: imapLimits, panicHandler: panicHandler, database: database, + log: logrus.WithField("pkg", "gluon/backend"), }, nil } @@ -97,7 +100,7 @@ func (b *Backend) AddUser(ctx context.Context, userID string, conn connector.Con onErrorExit := func() { if err := storeBuilder.Close(); err != nil { - logrus.WithError(err).Error("Failed to close store builder") + b.log.WithError(err).Error("Failed to close store builder") } } @@ -109,7 +112,7 @@ func (b *Backend) AddUser(ctx context.Context, userID string, conn connector.Con if err := database.Init(ctx, uidValidityGenerator); err != nil { if err := database.Close(); err != nil { - logrus.WithError(err).Errorf("Failed to close db after migration failure") + b.log.WithError(err).Errorf("Failed to close db after migration failure") } if !errors.Is(err, db.ErrMigrationFailed) && !errors.Is(err, db.ErrInvalidDatabaseVersion) { @@ -117,15 +120,15 @@ func (b *Backend) AddUser(ctx context.Context, userID string, conn connector.Con return false, err } - logrus.WithError(err).Errorf("First database migration failed") + b.log.WithError(err).Errorf("First database migration failed") reporter.ExceptionWithContext(ctx, "database migration failed", reporter.Context{ "error": err, }) - logrus.Debugf("First migration failed, recreating database") + b.log.Debugf("First migration failed, recreating database") if err := b.database.Delete(b.getDBDir(), userID); err != nil { - logrus.WithError(err).Errorf("Failed to delete old database") + b.log.WithError(err).Errorf("Failed to delete old database") onErrorExit() return false, fmt.Errorf("failed to remove database after migration: %w", err) @@ -133,24 +136,24 @@ func (b *Backend) AddUser(ctx context.Context, userID string, conn connector.Con database, isNew, err = b.database.New(b.getDBDir(), userID) if err != nil { - logrus.WithError(err).Errorf("Failed to create new database") + b.log.WithError(err).Errorf("Failed to create new database") onErrorExit() return false, err } if !isNew { - logrus.Errorf("Expected new database to not exist") + b.log.Errorf("Expected new database to not exist") if err := database.Close(); err != nil { - logrus.WithError(err).Errorf("failed to closed db") + b.log.WithError(err).Errorf("failed to closed db") } return false, fmt.Errorf("expected database to be new after failed migration cleanup") } if err := database.Init(ctx, uidValidityGenerator); err != nil { - logrus.WithError(err).Errorf("Second database migration failed") + b.log.WithError(err).Errorf("Second database migration failed") onErrorExit() return false, err @@ -245,7 +248,7 @@ func (b *Backend) GetState(ctx context.Context, username string, password []byte return nil, err } - logrus. + b.log. WithField("userID", userID). WithField("username", username). WithField("stateID", state.StateID). @@ -285,7 +288,7 @@ func (b *Backend) Close(ctx context.Context) error { delete(b.users, userID) } - logrus.Debug("Backend was closed") + b.log.Debug("Backend was closed") return nil } diff --git a/internal/backend/connector_updates.go b/internal/backend/connector_updates.go index dcd0abed..a6051677 100644 --- a/internal/backend/connector_updates.go +++ b/internal/backend/connector_updates.go @@ -16,13 +16,12 @@ import ( "github.com/ProtonMail/gluon/rfc822" "github.com/bradenaw/juniper/parallel" "github.com/bradenaw/juniper/xslices" - "github.com/sirupsen/logrus" "golang.org/x/exp/slices" ) // apply an incoming update originating from the connector. func (user *user) apply(ctx context.Context, update imap.Update) error { - logrus.WithField("update", update).WithField("user-id", user.userID).Debug("Applying update") + user.log.WithField("update", update).Debug("Applying update") err := func() error { switch update := update.(type) { @@ -208,7 +207,7 @@ func (user *user) applyMessagesCreated(ctx context.Context, update *imap.Message err := userDBWrite(ctx, user, func(ctx context.Context, tx db.Transaction) ([]state.Update, error) { for _, message := range update.Messages { if slices.Contains(message.MailboxIDs, ids.GluonInternalRecoveryMailboxRemoteID) { - logrus.Errorf("attempting to import messages into protected mailbox (recovery), skipping") + user.log.Errorf("attempting to import messages into protected mailbox (recovery), skipping") continue } @@ -251,7 +250,7 @@ func (user *user) applyMessagesCreated(ctx context.Context, update *imap.Message if err != nil { // If a mailbox doesn't exist and we are allowed to skip move to next mailbox. if update.IgnoreUnknownMailboxIDs { - logrus.WithField("MailboxID", mboxID.ShortID()). + user.log.WithField("MailboxID", mboxID.ShortID()). WithField("MessageID", message.Message.ID.ShortID()). Warn("Unknown Mailbox ID, skipping add to mailbox") continue @@ -336,7 +335,7 @@ func (user *user) applyMessagesCreated(ctx context.Context, update *imap.Message for _, message := range messagesToCreate { if err := user.store.DeleteUnchecked(message.InternalID); err != nil { if !os.IsNotExist(err) { - logrus.WithError(err).Errorf("Failed to delete cache message %v after failed transaction", message.InternalID) + user.log.WithError(err).Errorf("Failed to delete cache message %v after failed transaction", message.InternalID) } } } @@ -571,7 +570,7 @@ func (user *user) applyMessageDeleted(ctx context.Context, update *imap.MessageD } func (user *user) applyMessageUpdated(ctx context.Context, update *imap.MessageUpdated) error { - log := logrus.WithField("message updated", update.Message.ID.ShortID()) + log := user.log.WithField("message updated", update.Message.ID.ShortID()) internalMessageID, err := db.ClientReadType(ctx, user.db, func(ctx context.Context, client db.ReadOnly) (imap.InternalMessageID, error) { return client.GetMessageIDFromRemoteID(ctx, update.Message.ID) @@ -598,7 +597,7 @@ func (user *user) applyMessageUpdated(ctx context.Context, update *imap.MessageU // compare and see if the literal has changed. onDiskLiteral, err := user.store.Get(internalMessageID) if err != nil { - logrus.Debugf("failed to retrieve literal from cache: %v", err) + user.log.Debugf("failed to retrieve literal from cache: %v", err) } updateLiteral := update.Literal diff --git a/internal/backend/user.go b/internal/backend/user.go index 2ce212a1..cab57c14 100644 --- a/internal/backend/user.go +++ b/internal/backend/user.go @@ -47,6 +47,8 @@ type user struct { panicHandler async.PanicHandler recoveredMessageHashes *utils.MessageHashesMap + + log *logrus.Entry } func newUser( @@ -62,6 +64,11 @@ func newUser( ) (*user, error) { recoveredMessageHashes := utils.NewMessageHashesMap() + log := logrus.WithFields(logrus.Fields{ + "pkg": "gluon/user", + "userID": userID, + }) + // Create recovery mailbox if it does not exist recoveryMBox, err := db.ClientWriteType(ctx, database, func(ctx context.Context, tx db.Transaction) (*db.Mailbox, error) { uidValidity, err := uidValidityGenerator.Generate() @@ -92,12 +99,12 @@ func newUser( for _, m := range messages { literal, err := st.Get(m.InternalID) if err != nil { - logrus.WithError(err).Errorf("Failed to load %v for store for recovered message hashes map", m.InternalID) + log.WithError(err).Errorf("Failed to load %v for store for recovered message hashes map", m.InternalID) continue } if _, err := recoveredMessageHashes.Insert(m.InternalID, literal); err != nil { - logrus.WithError(err).Errorf("Failed insert literal for %v into recovered message hashes map", m.InternalID) + log.WithError(err).Errorf("Failed insert literal for %v into recovered message hashes map", m.InternalID) } } @@ -129,17 +136,19 @@ func newUser( panicHandler: panicHandler, recoveredMessageHashes: recoveredMessageHashes, + + log: log, } cacheProvider := NewDBIMAPState(database, user) if err := conn.Init(ctx, cacheProvider); err != nil { - logrus.WithError(err).Errorf("Failed to init connector") + log.WithError(err).Errorf("Failed to init connector") return nil, err } if err := user.deleteAllMessagesMarkedDeleted(ctx); err != nil { - logrus.WithError(err).Error("Failed to remove deleted messages") + log.WithError(err).Error("Failed to remove deleted messages") reporter.MessageWithContext(ctx, "Failed to remove deleted messages", reporter.Context{"error": err}, @@ -147,7 +156,7 @@ func newUser( } if err := user.cleanupStaleStoreData(ctx); err != nil { - logrus.WithError(err).Error("Failed to cleanup stale store data") + log.WithError(err).Error("Failed to cleanup stale store data") } user.updateWG.Add(1) @@ -171,7 +180,7 @@ func newUser( reporter.Context{"error": err, "update": update.String()}, ) - logrus.WithError(err).Errorf("Failed to apply update: %v", err) + log.WithError(err).Errorf("Failed to apply update: %v", err) } case <-user.updateQuitCh: @@ -242,7 +251,7 @@ func (user *user) deleteAllMessagesMarkedDeleted(ctx context.Context) error { func (user *user) queueStateUpdate(updates ...state.Update) { if err := user.forState(func(state *state.State) error { if !state.QueueUpdates(updates...) { - logrus.Errorf("Failed to push update to state %v", state.StateID) + user.log.Errorf("Failed to push update to state %v", state.StateID) } return nil @@ -321,7 +330,7 @@ func (user *user) removeState(ctx context.Context, st *state.State) error { // If we fail to delete messages on disk, it shouldn't count as an error at this point. if err := user.store.Delete(messageIDs...); err != nil { - logrus.WithError(err).Error("Failed to delete messages during removeState") + user.log.WithError(err).Error("Failed to delete messages during removeState") } return state.Close(ctx) diff --git a/internal/session/command.go b/internal/session/command.go index fc668251..a639bb97 100644 --- a/internal/session/command.go +++ b/internal/session/command.go @@ -11,7 +11,6 @@ import ( "github.com/ProtonMail/gluon/logging" "github.com/ProtonMail/gluon/reporter" "github.com/ProtonMail/gluon/rfcparser" - "github.com/sirupsen/logrus" ) type commandResult struct { @@ -58,26 +57,26 @@ func (s *Session) startCommandReader(ctx context.Context) <-chan commandResult { // check if we are receiving raw TLS requests, if so skip. for _, tlsHeader := range tlsHeaders { if bytes.HasPrefix(bytesRead, tlsHeader) { - logrus.Errorf("TLS Handshake detected while not running with TLS/SSL") + s.log.Errorf("TLS Handshake detected while not running with TLS/SSL") return } } - logrus.WithError(err).WithField("type", parser.LastParsedCommand()).Error("Failed to parse IMAP command") + s.log.WithError(err).WithField("type", parser.LastParsedCommand()).Error("Failed to parse IMAP command") reporter.MessageWithContext(ctx, "Failed to parse IMAP command", reporter.Context{"error": err, "cmd": parser.LastParsedCommand()}, ) } else { - logrus.Debug(cmd.SanitizedString()) + s.log.Debug(cmd.SanitizedString()) } switch c := cmd.Payload.(type) { case *command.StartTLS: // TLS needs to be handled here to ensure that next command read is over the TLS connection. if err = s.handleStartTLS(cmd.Tag, c); err != nil { - logrus.WithError(err).Error("Cannot upgrade connection") + s.log.WithError(err).Error("Cannot upgrade connection") return } else { continue diff --git a/internal/session/handle.go b/internal/session/handle.go index 5c30e23f..eda886e3 100644 --- a/internal/session/handle.go +++ b/internal/session/handle.go @@ -8,7 +8,6 @@ import ( "github.com/ProtonMail/gluon/internal/response" "github.com/ProtonMail/gluon/internal/state" "github.com/ProtonMail/gluon/logging" - "github.com/sirupsen/logrus" ) func (s *Session) handleOther( @@ -23,7 +22,7 @@ func (s *Session) handleOther( defer close(resCh) if err := s.handleCommand(ctx, tag, cmd, resCh); err != nil { - logrus.WithError(err).WithField("cmd", cmd.SanitizedString()).Error("Command failed") + s.log.WithError(err).WithField("cmd", cmd.SanitizedString()).Error("Command failed") if res, ok := response.FromError(err); ok { resCh <- res } else { diff --git a/internal/session/handle_idle.go b/internal/session/handle_idle.go index e254eaf7..618e05d5 100644 --- a/internal/session/handle_idle.go +++ b/internal/session/handle_idle.go @@ -9,7 +9,6 @@ import ( "github.com/ProtonMail/gluon/internal/response" "github.com/ProtonMail/gluon/logging" "github.com/ProtonMail/gluon/profiling" - "github.com/sirupsen/logrus" ) // GOMSRV-86: What does it mean to do IDLE when you're not selected? @@ -29,7 +28,7 @@ func (s *Session) handleIdle(ctx context.Context, tag string, _ *command.Idle, c } else { for res := range resCh { if err := res.Send(s); err != nil { - logrus.WithError(err).Error("Failed to send IDLE update") + s.log.WithError(err).Error("Failed to send IDLE update") } } } @@ -67,7 +66,7 @@ func (s *Session) handleIdle(ctx context.Context, tag string, _ *command.Idle, c case stateUpdate := <-s.state.GetStateUpdatesCh(): if err := s.state.ApplyUpdate(ctx, stateUpdate); err != nil { - logrus.WithError(err).Error("Failed to apply state update during idle") + s.log.WithError(err).Error("Failed to apply state update during idle") } continue @@ -89,7 +88,7 @@ func (s *Session) handleIdle(ctx context.Context, tag string, _ *command.Idle, c func sendMergedResponses(s *Session, buffer []response.Response) { for _, res := range response.Merge(buffer) { if err := res.Send(s); err != nil { - logrus.WithError(err).Error("Failed to send IDLE update") + s.log.WithError(err).Error("Failed to send IDLE update") } } } @@ -110,7 +109,7 @@ func sendResponsesInBulks(s *Session, resCh chan response.Response, idleBulkTime if res != nil { buffer = append(buffer, res) - logrus.WithField("response", res).Trace("Buffered") + s.log.WithField("response", res).Trace("Buffered") } case <-ticker.C: sendMergedResponses(s, buffer) diff --git a/internal/session/session.go b/internal/session/session.go index 4a4f746a..65f59fc6 100644 --- a/internal/session/session.go +++ b/internal/session/session.go @@ -90,6 +90,8 @@ type Session struct { imapLimits limits.IMAP panicHandler async.PanicHandler + + log *logrus.Entry } func New( @@ -118,6 +120,7 @@ func New( cmdProfilerBuilder: profiler, handleWG: async.MakeWaitGroup(panicHandler), panicHandler: panicHandler, + log: logrus.WithField("pkg", "gluon/session").WithField("session", sessionID), } } @@ -171,7 +174,7 @@ func (s *Session) serve(ctx context.Context) error { select { case update := <-s.state.GetStateUpdatesCh(): if err := s.state.ApplyUpdate(ctx, update); err != nil { - logrus.WithError(err).Error("Failed to apply state update") + s.log.WithError(err).Error("Failed to apply state update") } continue @@ -275,7 +278,7 @@ func (s *Session) done(ctx context.Context) { if s.state != nil { if err := s.state.ReleaseState(ctx); err != nil { - logrus.WithError(err).Error("Failed to close state") + s.log.WithError(err).Error("Failed to close state") } } diff --git a/internal/state/actions.go b/internal/state/actions.go index 031e64fb..c5a40ad7 100644 --- a/internal/state/actions.go +++ b/internal/state/actions.go @@ -13,7 +13,6 @@ import ( "github.com/ProtonMail/gluon/reporter" "github.com/ProtonMail/gluon/rfc822" "github.com/bradenaw/juniper/xslices" - "github.com/sirupsen/logrus" "golang.org/x/exp/slices" ) @@ -126,12 +125,12 @@ func (state *State) actionCreateMessage( "mailbox": mboxID.RemoteID, }) - logrus.Errorf("Append to drafts must not return an existing RemoteID (Remote=%v, Internal=%v)", res.ID, knownInternalID) + state.log.Errorf("Append to drafts must not return an existing RemoteID (Remote=%v, Internal=%v)", res.ID, knownInternalID) return nil, 0, fmt.Errorf("append to drafts returned an existing remote ID") } - logrus.Debugf("Deduped message detected, adding existing %v message to mailbox instead.", knownInternalID.ShortID()) + state.log.Debugf("Deduped message detected, adding existing %v message to mailbox instead.", knownInternalID.ShortID()) addMsgToMBoxUpdates, result, err := state.actionAddMessagesToMailbox(ctx, tx, diff --git a/internal/state/mailbox.go b/internal/state/mailbox.go index ec7ce48d..0b27ef8b 100644 --- a/internal/state/mailbox.go +++ b/internal/state/mailbox.go @@ -30,6 +30,7 @@ type Mailbox struct { selected bool readOnly bool + log *logrus.Entry } type AppendOnlyMailbox interface { @@ -40,8 +41,10 @@ type AppendOnlyMailbox interface { } func newMailbox(mbox *db.Mailbox, state *State, snap *snapshot) *Mailbox { + id := db.NewMailboxIDPair(mbox) + return &Mailbox{ - id: db.NewMailboxIDPair(mbox), + id: id, name: mbox.Name, uidValidity: mbox.UIDValidity, @@ -50,6 +53,9 @@ func newMailbox(mbox *db.Mailbox, state *State, snap *snapshot) *Mailbox { selected: snap != nil, readOnly: state.ro, snap: snap, + log: logrus. + WithField("pkg", "gluon/state/mailbox"). + WithField("mboxID", id.String()), } } @@ -192,9 +198,9 @@ func (m *Mailbox) AppendRegular(ctx context.Context, literal []byte, flags imap. return 0, err } - logrus.WithError(err).Warn("The message has an unknown internal ID") + m.log.WithError(err).Warn("The message has an unknown internal ID") } else if !messageDeleted { - logrus.Debugf("Appending duplicate message with Internal ID:%v", msgID.ShortID()) + m.log.Debugf("Appending duplicate message with Internal ID:%v", msgID.ShortID()) // Only shuffle around messages that haven't been marked for deletion. if res, err := stateDBWriteResult(ctx, m.state, func(ctx context.Context, tx db.Transaction) ([]Update, []db.UIDWithFlags, error) { remoteID, err := tx.GetMessageRemoteID(ctx, msgID) @@ -218,7 +224,7 @@ func (m *Mailbox) AppendRegular(ctx context.Context, literal []byte, flags imap. appendIntoDrafts = true newLiteral, err := rfc822.EraseHeaderValue(literal, ids.InternalIDKey) if err != nil { - logrus.WithError(err).Error("Failed to erase Gluon internal id from draft") + m.log.WithError(err).Error("Failed to erase Gluon internal id from draft") } else { literal = newLiteral } @@ -244,7 +250,7 @@ func (m *Mailbox) Append(ctx context.Context, literal []byte, flags imap.FlagSet return m.state.actionCreateRecoveredMessage(ctx, tx, literal, flags, date) }) if recoverErr != nil && !knownMessage { - logrus.WithError(recoverErr).Error("Failed to insert message into recovery mailbox") + m.log.WithError(recoverErr).Error("Failed to insert message into recovery mailbox") reporter.ExceptionWithContext(ctx, "Failed to insert message into recovery mailbox", reporter.Context{"error": recoverErr}) } diff --git a/internal/state/mailbox_fetch.go b/internal/state/mailbox_fetch.go index 77ca0943..4711ba0b 100644 --- a/internal/state/mailbox_fetch.go +++ b/internal/state/mailbox_fetch.go @@ -33,6 +33,7 @@ func (m *Mailbox) Fetch(ctx context.Context, cmd *command.Fetch, ch chan respons needsLiteral bool wantUID bool setSeen bool + isBodyFetch bool ) for _, attribute := range cmd.Attributes { @@ -53,11 +54,13 @@ func (m *Mailbox) Fetch(ctx context.Context, cmd *command.Fetch, ch chan respons case *command.FetchAttributeRFC822: setSeen = true needsLiteral = true + isBodyFetch = true operations = append(operations, fetchRFC822) case *command.FetchAttributeRFC822Text: setSeen = true needsLiteral = true + isBodyFetch = true operations = append(operations, fetchRFC822Text) case *command.FetchAttributeRFC822Header: @@ -78,6 +81,7 @@ func (m *Mailbox) Fetch(ctx context.Context, cmd *command.Fetch, ch chan respons operations = append(operations, fetchBodyStructure) case *command.FetchAttributeBodySection: needsLiteral = true + isBodyFetch = true if !attribute.Peek { setSeen = true @@ -162,6 +166,10 @@ func (m *Mailbox) Fetch(ctx context.Context, cmd *command.Fetch, ch chan respons snapMessages[i].snapMsg = nil } + if isBodyFetch { + m.log.WithField("UID", msg.UID).WithField("messageID", msg.ID.String()).Debug("Fetch Body") + } + ch <- response.Fetch(msg.Seq).WithItems(items...) return nil diff --git a/internal/state/state.go b/internal/state/state.go index 41b89466..bfd3c123 100644 --- a/internal/state/state.go +++ b/internal/state/state.go @@ -51,6 +51,8 @@ type State struct { imapLimits limits.IMAP panicHandler async.PanicHandler + + log *logrus.Entry } var stateIDGenerator int64 @@ -71,6 +73,7 @@ func NewState(user UserInterface, delimiter string, imapLimits limits.IMAP, pani updatesQueue: async.NewQueuedChannel[Update](32, 128, panicHandler, fmt.Sprintf("gluon-state-%v", stateID)), imapLimits: imapLimits, panicHandler: panicHandler, + log: logrus.WithField("pkg", "gluon/state").WithField("state", stateID), } } @@ -88,7 +91,7 @@ func (state *State) List(ctx context.Context, ref, pattern string, lsub bool, fn recoveryMailboxID := state.user.GetRecoveryMailboxID().InternalID recoveryMBoxMessageCount, err := client.GetMailboxMessageCount(ctx, recoveryMailboxID) if err != nil { - logrus.WithError(err).Error("Failed to get recovery mailbox message count, assuming empty") + state.log.WithError(err).Error("Failed to get recovery mailbox message count, assuming empty") recoveryMBoxMessageCount = 0 } @@ -105,12 +108,12 @@ func (state *State) List(ctx context.Context, ref, pattern string, lsub bool, fn case imap.HiddenIfEmpty: count, err := client.GetMailboxMessageCount(ctx, mailbox.ID) if err != nil { - logrus.WithError(err).Error("Failed to get recovery mailbox message count, assuming not empty") + state.log.WithError(err).Error("Failed to get recovery mailbox message count, assuming not empty") return true } return count > 0 default: - logrus.Errorf("Unknown IMAP Mailbox visibility %v", visibility) + state.log.Errorf("Unknown IMAP Mailbox visibility %v", visibility) return true } }) @@ -612,7 +615,7 @@ func (state *State) QueueUpdates(updates ...Update) bool { } func (state *State) ApplyUpdate(ctx context.Context, update Update) error { - logrus.WithField("Update", update).Debugf("Applying state update on state %v", state.StateID) + state.log.WithField("Update", update).Debugf("Applying state update on state %v", state.StateID) if !update.Filter(state) { return nil @@ -703,15 +706,15 @@ func (state *State) getLiteral(ctx context.Context, messageID db.MessageIDPair) if firstErr != nil { // Do not attempt to recovered messages from the connector. if ids.IsRecoveredRemoteMessageID(messageID.RemoteID) { - logrus.Debugf("Failed load %v from store, but it is a recovered message.", messageID.InternalID) + state.log.Debugf("Failed load %v from store, but it is a recovered message.", messageID.InternalID) return nil, firstErr } - logrus.Debugf("Failed load %v from store, attempting to download from connector", messageID.InternalID.ShortID()) + state.log.Debugf("Failed load %v from store, attempting to download from connector", messageID.InternalID.ShortID()) connectorLiteral, err := state.user.GetRemote().GetMessageLiteral(ctx, messageID.RemoteID) if err != nil { - logrus.Errorf("Failed to download message from connector: %v", err) + state.log.Errorf("Failed to download message from connector: %v", err) return nil, fmt.Errorf("message failed to load from cache (%v), failed to download from connector: %w", firstErr, err) } @@ -721,11 +724,11 @@ func (state *State) getLiteral(ctx context.Context, messageID db.MessageIDPair) } if err := state.user.GetStore().Set(messageID.InternalID, bytes.NewReader(literalWithHeader)); err != nil { - logrus.Errorf("Failed to store download message from connector: %v", err) + state.log.Errorf("Failed to store download message from connector: %v", err) return nil, fmt.Errorf("message failed to load from cache (%v), failed to store new downloaded message: %w", firstErr, err) } - logrus.Debugf("Message %v downloaded and stored ", messageID.InternalID.ShortID()) + state.log.Debugf("Message %v downloaded and stored ", messageID.InternalID.ShortID()) literal = literalWithHeader } else { @@ -748,7 +751,7 @@ func (state *State) flushResponses(ctx context.Context, permitExpunge bool) ([]r var dbUpdates []responderDBUpdate for _, responder := range state.popResponders(permitExpunge) { - logrus.WithField("state", state.StateID).WithField("Origin", "Flush").Debugf("Applying responder: %v", responder.String()) + state.log.WithField("state", state.StateID).WithField("Origin", "Flush").Debugf("Applying responder: %v", responder.String()) res, dbUpdate, err := responder.handle(ctx, state.snap, state.StateID) if err != nil { @@ -783,7 +786,7 @@ func (state *State) PushResponder(ctx context.Context, tx db.Transaction, respon } for _, responder := range responder { - logrus.WithField("state", state.StateID).WithField("Origin", "Push").Debugf("Applying responder: %v", responder.String()) + state.log.WithField("state", state.StateID).WithField("Origin", "Push").Debugf("Applying responder: %v", responder.String()) res, dbUpdate, err := responder.handle(ctx, state.snap, state.StateID) if err != nil {