diff --git a/go.mod b/go.mod index 4a52eaa3..4280285c 100644 --- a/go.mod +++ b/go.mod @@ -7,7 +7,7 @@ toolchain go1.24.2 require ( github.com/0xAX/notificator v0.0.0-20220220101646-ee9b8921e557 github.com/Masterminds/semver/v3 v3.2.0 - github.com/ProtonMail/gluon v0.17.1-0.20250528125353-9b611f58b753 + github.com/ProtonMail/gluon v0.17.1-0.20250603132151-341ea279ce81 github.com/ProtonMail/go-autostart v0.0.0-20210130080809-00ed301c8e9a github.com/ProtonMail/go-proton-api v0.4.1-0.20250417134000-e624a080f7ba github.com/ProtonMail/gopenpgp/v2 v2.8.2-proton diff --git a/go.sum b/go.sum index e11cf41b..882f2da3 100644 --- a/go.sum +++ b/go.sum @@ -38,6 +38,8 @@ github.com/ProtonMail/bcrypt v0.0.0-20211005172633-e235017c1baf h1:yc9daCCYUefEs github.com/ProtonMail/bcrypt v0.0.0-20211005172633-e235017c1baf/go.mod h1:o0ESU9p83twszAU8LBeJKFAAMX14tISa0yk4Oo5TOqo= github.com/ProtonMail/gluon v0.17.1-0.20250528125353-9b611f58b753 h1:Zym7WHKLOu1RAUc9b8vkhwEaEU2Gi6MkaurCm7zpK6E= github.com/ProtonMail/gluon v0.17.1-0.20250528125353-9b611f58b753/go.mod h1:0/c03TzZPNiSgY5UDJK1iRDkjlDPwWugxTT6et2qDu8= +github.com/ProtonMail/gluon v0.17.1-0.20250603132151-341ea279ce81 h1:p3X/izcQ3VtYI7qF0pmejByXPTRisFkkS+xCxXgeCxs= +github.com/ProtonMail/gluon v0.17.1-0.20250603132151-341ea279ce81/go.mod h1:0/c03TzZPNiSgY5UDJK1iRDkjlDPwWugxTT6et2qDu8= github.com/ProtonMail/go-crypto v0.0.0-20230321155629-9a39f2531310/go.mod h1:8TI4H3IbrackdNgv+92dI+rhpCaLqM0IfpgCgenFvRE= github.com/ProtonMail/go-crypto v1.1.4-proton h1:KIo9uNlk3vzlwI7o5VjhiEjI4Ld1TDixOMnoNZyfpFE= github.com/ProtonMail/go-crypto v1.1.4-proton/go.mod h1:zNoyBJW3p/yVWiHNZgfTF9VsjwqYof5YY0M9kt2QaX0= diff --git a/internal/bridge/mocks.go b/internal/bridge/mocks.go index 48c0748f..d5bf3626 100644 --- a/internal/bridge/mocks.go +++ b/internal/bridge/mocks.go @@ -54,6 +54,9 @@ func NewMocks(tb testing.TB, version, minAuto *semver.Version) *Mocks { mocks.Heartbeat.EXPECT().IsTelemetryAvailable(gomock.Any()).AnyTimes() mocks.Heartbeat.EXPECT().GetHeartbeatPeriodicInterval().AnyTimes().Return(500 * time.Millisecond) + // It's called whenever a context is cancelled during sync. We should ought to remove this and make it more granular in the future. + mocks.Reporter.EXPECT().ReportMessageWithContext("Failed to sync, will retry later", gomock.Any()).AnyTimes() + return mocks } diff --git a/internal/sentry/reporter.go b/internal/sentry/reporter.go index fff55a0e..c22e2f1c 100644 --- a/internal/sentry/reporter.go +++ b/internal/sentry/reporter.go @@ -287,3 +287,21 @@ func contextToString(context sentry.Context) sentry.Context { return res } + +type NullSentryReporter struct{} + +func (n NullSentryReporter) ReportException(any) error { + return nil +} + +func (n NullSentryReporter) ReportMessage(string) error { + return nil +} + +func (n NullSentryReporter) ReportMessageWithContext(string, reporter.Context) error { + return nil +} + +func (n NullSentryReporter) ReportExceptionWithContext(any, reporter.Context) error { + return nil +} diff --git a/internal/services/imapservice/conflicts.go b/internal/services/imapservice/conflicts.go index fd82d436..f9ac6851 100644 --- a/internal/services/imapservice/conflicts.go +++ b/internal/services/imapservice/conflicts.go @@ -28,6 +28,7 @@ import ( "github.com/ProtonMail/gluon/reporter" "github.com/ProtonMail/go-proton-api" "github.com/ProtonMail/proton-bridge/v3/internal/unleash" + "github.com/ProtonMail/proton-bridge/v3/pkg/algo" "github.com/sirupsen/logrus" ) @@ -92,6 +93,7 @@ type labelConflictResolverImpl struct { mailboxFetch mailboxFetcherFn client apiClient reporter sentryReporter + log *logrus.Entry } type nullLabelConflictResolverImpl struct { @@ -112,15 +114,25 @@ func (m *LabelConflictManager) NewConflictResolver(connectors []*Connector) Labe mailboxFetch: m.generateMailboxFetcher(connectors), client: m.client, reporter: m.reporter, + log: logrus.WithFields(logrus.Fields{ + "pkg": "imapservice/labelConflictResolver", + "numberOfConnectors": len(connectors), + }), } } func (r *labelConflictResolverImpl) ResolveConflict(ctx context.Context, label proton.Label, visited map[string]bool) (func() []imap.Update, error) { + logger := r.log.WithFields(logrus.Fields{ + "labelID": label.ID, + "labelPath": hashLabelPaths(GetMailboxName(label)), + }) + var updateFns []func() []imap.Update // There's a cycle, such as in a label swap operation, we'll need to temporarily rename the label. // The change will be overwritten by one of the previous recursive calls. if visited[label.ID] { + logrus.Info("Cycle detected, applying temporary rename") fn := func() []imap.Update { return []imap.Update{newMailboxUpdatedOrCreated(imap.MailboxID(label.ID), getMailboxNameWithTempPrefix(label))} } @@ -134,6 +146,7 @@ func (r *labelConflictResolverImpl) ResolveConflict(ctx context.Context, label p if err != nil { // Name is free, create the mailbox. if db.IsErrNotFound(err) { + logger.Info("Label not found in DB, creating mailbox.") fn := func() []imap.Update { return []imap.Update{newMailboxUpdatedOrCreated(imap.MailboxID(label.ID), GetMailboxName(label))} } @@ -145,14 +158,23 @@ func (r *labelConflictResolverImpl) ResolveConflict(ctx context.Context, label p // Verify whether the label name corresponds to the same label ID. If true terminate, we don't need to update. if mailboxData.RemoteID == label.ID { + logger.Info("Mailbox name matches label ID, no conflict.") return combineIMAPUpdateFns(updateFns), nil } + // This means we've found a conflict. So let's log it. + logger = logger.WithFields(logrus.Fields{ + "conflictingLabelID": mailboxData.RemoteID, + "conflictingLabelPath": hashLabelPaths(mailboxData.BridgeName), + }) + logger.Info("Label conflict found") + // If the label name belongs to some other label ID. Fetch it's state from the remote. conflictingLabel, err := r.client.GetLabel(ctx, mailboxData.RemoteID, proton.LabelTypeFolder, proton.LabelTypeLabel) if err != nil { // If it's not present on the remote we should delete it. And create the new label. if errors.Is(err, proton.ErrNoSuchLabel) { + logger.Info("Conflicting label does not exist on remote. Deleting.") fn := func() []imap.Update { return []imap.Update{ imap.NewMailboxDeleted(imap.MailboxID(mailboxData.RemoteID)), @@ -162,6 +184,7 @@ func (r *labelConflictResolverImpl) ResolveConflict(ctx context.Context, label p updateFns = append(updateFns, fn) return combineIMAPUpdateFns(updateFns), nil } + logger.WithError(err).Error("Failed to fetch conflicting label from remote.") return combineIMAPUpdateFns(updateFns), err } @@ -171,7 +194,7 @@ func (r *labelConflictResolverImpl) ResolveConflict(ctx context.Context, label p "labelID": label.ID, "conflictingLabelID": conflictingLabel.ID, }); err != nil { - logrus.WithError(err).Error("Failed to report update error") + logger.WithError(err).Error("Failed to report update error") } err := fmt.Errorf("unexpected label conflict: the name of label ID %s is already used by label ID %s", label.ID, conflictingLabel.ID) @@ -180,6 +203,8 @@ func (r *labelConflictResolverImpl) ResolveConflict(ctx context.Context, label p // The name of the conflicting label has changed on the remote. We need to verify that the new name does not conflict with anything else. // Thus, a recursive check can be performed. + logger.WithField("conflictingLabelNewPath", hashLabelPaths(conflictingLabel.Path)). + Info("Conflicting label name has changed. Recursively resolving conflict.") childUpdateFns, err := r.ResolveConflict(ctx, conflictingLabel, visited) if err != nil { return combineIMAPUpdateFns(updateFns), err @@ -209,3 +234,7 @@ func compareLabelNames(labelName1, labelName2 []string) bool { name2 := strings.Join(labelName2, "") return name1 == name2 } + +func hashLabelPaths(path []string) string { + return algo.HashBase64SHA256(strings.Join(path, "")) +} diff --git a/internal/services/imapservice/service.go b/internal/services/imapservice/service.go index 34e50a54..cb2b4a1f 100644 --- a/internal/services/imapservice/service.go +++ b/internal/services/imapservice/service.go @@ -181,7 +181,14 @@ func (s *Service) Start( s.syncStateProvider = syncStateProvider } - s.syncHandler = syncservice.NewHandler(syncRegulator, s.client, s.identityState.UserID(), s.syncStateProvider, s.log, s.panicHandler) + s.syncHandler = syncservice.NewHandler( + syncRegulator, + s.client, + s.identityState.UserID(), + s.syncStateProvider, + s.log, + s.panicHandler, + s.reporter) // Get user labels apiLabels, err := s.client.GetLabels(ctx, proton.LabelTypeSystem, proton.LabelTypeFolder, proton.LabelTypeLabel) diff --git a/internal/services/syncservice/handler.go b/internal/services/syncservice/handler.go index 7c9e50ea..a4b1a5e9 100644 --- a/internal/services/syncservice/handler.go +++ b/internal/services/syncservice/handler.go @@ -23,6 +23,7 @@ import ( "time" "github.com/ProtonMail/gluon/async" + "github.com/ProtonMail/gluon/reporter" "github.com/ProtonMail/go-proton-api" "github.com/ProtonMail/proton-bridge/v3/internal/network" "github.com/sirupsen/logrus" @@ -45,6 +46,7 @@ type Handler struct { syncFinishedCh chan error panicHandler async.PanicHandler downloadCache *DownloadCache + sentryReporter reporter.Reporter } func NewHandler( @@ -54,6 +56,7 @@ func NewHandler( state StateProvider, log *logrus.Entry, panicHandler async.PanicHandler, + sentryReporter reporter.Reporter, ) *Handler { return &Handler{ client: client, @@ -65,6 +68,7 @@ func NewHandler( regulator: regulator, panicHandler: panicHandler, downloadCache: newDownloadCache(), + sentryReporter: sentryReporter, } } @@ -105,6 +109,14 @@ func (t *Handler) Execute( break } else if err = t.run(ctx, syncReporter, labels, updateApplier, messageBuilder); err != nil { t.log.WithError(err).Error("Failed to sync, will retry later") + + if sentryErr := t.sentryReporter.ReportMessageWithContext("Failed to sync, will retry later", reporter.Context{ + "err": err.Error(), + "user_id": t.userID, + }); sentryErr != nil { + t.log.WithError(sentryErr).Error("Failed to report sentry message") + } + sleepCtx(ctx, coolDown) } else { break diff --git a/internal/services/syncservice/handler_test.go b/internal/services/syncservice/handler_test.go index 80af6269..72def32e 100644 --- a/internal/services/syncservice/handler_test.go +++ b/internal/services/syncservice/handler_test.go @@ -25,6 +25,7 @@ import ( "github.com/ProtonMail/gluon/async" "github.com/ProtonMail/go-proton-api" + "github.com/ProtonMail/proton-bridge/v3/internal/sentry" "github.com/bradenaw/juniper/xmaps" "github.com/golang/mock/gomock" "github.com/sirupsen/logrus" @@ -342,7 +343,7 @@ func newTestHandler(mockCtrl *gomock.Controller, userID string) thandler { // no client := NewMockAPIClient(mockCtrl) messageBuilder := NewMockMessageBuilder(mockCtrl) syncReporter := NewMockReporter(mockCtrl) - task := NewHandler(regulator, client, userID, syncState, logrus.WithField("test", "test"), &async.NoopPanicHandler{}) + task := NewHandler(regulator, client, userID, syncState, logrus.WithField("test", "test"), &async.NoopPanicHandler{}, sentry.NullSentryReporter{}) return thandler{ task: task, diff --git a/internal/user/user_test.go b/internal/user/user_test.go index dbdc7765..9233f45f 100644 --- a/internal/user/user_test.go +++ b/internal/user/user_test.go @@ -28,6 +28,7 @@ import ( "github.com/ProtonMail/go-proton-api/server/backend" "github.com/ProtonMail/proton-bridge/v3/internal/certs" "github.com/ProtonMail/proton-bridge/v3/internal/events" + "github.com/ProtonMail/proton-bridge/v3/internal/sentry" "github.com/ProtonMail/proton-bridge/v3/internal/services/imapservice" "github.com/ProtonMail/proton-bridge/v3/internal/services/notifications" "github.com/ProtonMail/proton-bridge/v3/internal/services/observability" @@ -157,7 +158,7 @@ func withUser(tb testing.TB, ctx context.Context, _ *server.Server, m *proton.Ma ctx, vaultUser, client, - nil, + sentry.NullSentryReporter{}, apiUser, nil, true, diff --git a/tests/ctx_reporter_test.go b/tests/ctx_reporter_test.go index b24c4f21..bf9e58a0 100644 --- a/tests/ctx_reporter_test.go +++ b/tests/ctx_reporter_test.go @@ -89,8 +89,11 @@ func (r *reportRecorder) close() { } func (r *reportRecorder) assertEmpty() { - if !r.skipAssert { - r.assert.Empty(r.reports) + if !r.skipAssert && len(r.reports) > 0 { + for _, report := range r.reports { + // Sentry reports with failed syncs are expected, mostly due to sync context cancellations. + r.assert.Equal(report.message, "Failed to sync, will retry later") + } } }