diff --git a/src/internal/kopia/upload.go b/src/internal/kopia/upload.go index deced5bd4..d70fb0152 100644 --- a/src/internal/kopia/upload.go +++ b/src/internal/kopia/upload.go @@ -217,7 +217,7 @@ func (cp *corsoProgress) Error(relpath string, err error, isIgnored bool) { // delta query and a fetch. This is our next point of error // handling, where we can identify and skip over the case. if clues.HasLabel(err, graph.LabelsSkippable) { - cp.counter.Inc(count.PersistenceExpectedErrors) + cp.counter.Inc(count.PersistenceExpectedErrs) cp.incExpectedErrs() return diff --git a/src/internal/kopia/wrapper.go b/src/internal/kopia/wrapper.go index a258b0c60..03a4bc888 100644 --- a/src/internal/kopia/wrapper.go +++ b/src/internal/kopia/wrapper.go @@ -81,8 +81,8 @@ func manifestToStats( progress.counter.Add(count.PersistedCachedFiles, int64(man.Stats.CachedFiles)) progress.counter.Add(count.PersistedNonCachedFiles, int64(man.Stats.NonCachedFiles)) progress.counter.Add(count.PersistedDirectories, int64(man.Stats.TotalDirectoryCount)) - progress.counter.Add(count.PersistenceErrors, int64(man.Stats.ErrorCount)) - progress.counter.Add(count.PersistenceIgnoredErrors, int64(man.Stats.IgnoredErrorCount)) + progress.counter.Add(count.PersistenceErrs, int64(man.Stats.ErrorCount)) + progress.counter.Add(count.PersistenceIgnoredErrs, int64(man.Stats.IgnoredErrorCount)) return BackupStats{ SnapshotID: string(man.ID), diff --git a/src/internal/kopia/wrapper_scale_test.go b/src/internal/kopia/wrapper_scale_test.go index f3934ccda..e2606f8c2 100644 --- a/src/internal/kopia/wrapper_scale_test.go +++ b/src/internal/kopia/wrapper_scale_test.go @@ -116,8 +116,8 @@ func BenchmarkHierarchyMerge(b *testing.B) { assert.Zero(t, stats.IgnoredErrorCount) assert.Zero(t, stats.ErrorCount) - assert.Zero(t, counter.Get(count.PersistenceIgnoredErrors)) - assert.Zero(t, counter.Get(count.PersistenceErrors)) + assert.Zero(t, counter.Get(count.PersistenceIgnoredErrs)) + assert.Zero(t, counter.Get(count.PersistenceErrs)) assert.False(t, stats.Incomplete) snap, err := snapshot.LoadSnapshot( diff --git a/src/internal/kopia/wrapper_test.go b/src/internal/kopia/wrapper_test.go index 61e7a90a4..a1a9852e7 100644 --- a/src/internal/kopia/wrapper_test.go +++ b/src/internal/kopia/wrapper_test.go @@ -952,9 +952,9 @@ func (suite *KopiaIntegrationSuite) TestBackupCollections() { assert.Equal(t, 4+len(test.collections), stats.TotalDirectoryCount, "directory count") assert.Equal(t, int64(4+len(test.collections)), counter.Get(count.PersistedDirectories), "directory count") assert.Zero(t, stats.IgnoredErrorCount, "ignored errors") - assert.Zero(t, counter.Get(count.PersistenceIgnoredErrors), "ignored errors") + assert.Zero(t, counter.Get(count.PersistenceIgnoredErrs), "ignored errors") assert.Zero(t, stats.ErrorCount, "errors") - assert.Zero(t, counter.Get(count.PersistenceErrors), "errors") + assert.Zero(t, counter.Get(count.PersistenceErrs), "errors") assert.False(t, stats.Incomplete) test.hashedBytesCheck(t, stats.TotalHashedBytes, "hashed bytes") test.hashedBytesCheck(t, counter.Get(count.PersistedHashedBytes), "hashed bytes") @@ -1272,9 +1272,9 @@ func (suite *KopiaIntegrationSuite) TestBackupCollections_NoDetailsForMeta() { assert.Equal(t, 5, stats.TotalDirectoryCount, "uploaded directories") assert.Equal(t, int64(5), counter.Get(count.PersistedDirectories), "uploaded directories") assert.Zero(t, stats.IgnoredErrorCount, "ignored errors") - assert.Zero(t, counter.Get(count.PersistenceIgnoredErrors), "ignored errors") + assert.Zero(t, counter.Get(count.PersistenceIgnoredErrs), "ignored errors") assert.Zero(t, stats.ErrorCount, "errors") - assert.Zero(t, counter.Get(count.PersistenceErrors), "errors") + assert.Zero(t, counter.Get(count.PersistenceErrs), "errors") assert.False(t, stats.Incomplete) // 47 file and 1 folder entries. @@ -1454,13 +1454,13 @@ func (suite *KopiaIntegrationSuite) TestBackupCollections_ReaderError() { errs) require.Error(t, err, clues.ToCore(err)) assert.Zero(t, stats.ErrorCount, "error count") - assert.Zero(t, counter.Get(count.PersistenceErrors), "error count") + assert.Zero(t, counter.Get(count.PersistenceErrs), "error count") assert.Equal(t, 5, stats.TotalFileCount, "total files") assert.Equal(t, int64(5), counter.Get(count.PersistedFiles), "total files") assert.Equal(t, 6, stats.TotalDirectoryCount, "total directories") assert.Equal(t, int64(6), counter.Get(count.PersistedDirectories), "total directories") assert.Zero(t, stats.IgnoredErrorCount, "ignored errors") - assert.Zero(t, counter.Get(count.PersistenceIgnoredErrors), "ignored errors") + assert.Zero(t, counter.Get(count.PersistenceIgnoredErrs), "ignored errors") assert.Equal(t, 1, len(errs.Errors().Recovered), "recovered errors") assert.False(t, stats.Incomplete, "incomplete") // 5 file and 2 folder entries. @@ -1704,9 +1704,9 @@ func (suite *KopiaSimpleRepoIntegrationSuite) SetupTest() { fault.New(true)) require.NoError(t, err, clues.ToCore(err)) require.Zero(t, stats.ErrorCount) - require.Zero(t, counter.Get(count.PersistenceErrors)) + require.Zero(t, counter.Get(count.PersistenceErrs)) require.Zero(t, stats.IgnoredErrorCount) - require.Zero(t, counter.Get(count.PersistenceIgnoredErrors)) + require.Zero(t, counter.Get(count.PersistenceIgnoredErrs)) require.Equal(t, expectedFiles, stats.TotalFileCount) require.Equal(t, int64(expectedFiles), counter.Get(count.PersistedFiles)) require.Equal(t, expectedDirs, stats.TotalDirectoryCount) diff --git a/src/internal/m365/collection/exchange/collection.go b/src/internal/m365/collection/exchange/collection.go index 306e0b8fa..9550de760 100644 --- a/src/internal/m365/collection/exchange/collection.go +++ b/src/internal/m365/collection/exchange/collection.go @@ -286,7 +286,7 @@ func (col *prefetchCollection) streamItems( atomic.AddInt64(&success, 1) logger.CtxErr(ctx, err).Info("item not found") } else { - col.Counter.Inc(count.StreamItemsErrored) + col.Counter.Inc(count.StreamItemsErred) el.AddRecoverable(ctx, clues.Wrap(err, "fetching item").Label(fault.LabelForceNoBackupCreation)) } @@ -298,7 +298,7 @@ func (col *prefetchCollection) streamItems( id, details.ItemInfo{Exchange: info}) if err != nil { - col.Counter.Inc(count.StreamItemsErrored) + col.Counter.Inc(count.StreamItemsErred) el.AddRecoverable( ctx, clues.StackWC(ctx, err). diff --git a/src/pkg/count/keys.go b/src/pkg/count/keys.go index 6a5f48932..423a603c8 100644 --- a/src/pkg/count/keys.go +++ b/src/pkg/count/keys.go @@ -2,6 +2,16 @@ package count type Key string +// --------------------------------------------------------------------------- +// General Rules: +// 1. Avoid the word "error", prefer "err". That minimizes log result +// contamination when using common filters like "logs with 'error'". +// 2. When some key (ex: Foo) can be counted with both an in-process +// count, and also an end-of-process count, and the two may not be +// equal, use Foo for the end of process count, and TotalFooProcessed +// for the in-process count. +// --------------------------------------------------------------------------- + const ( // count of bucket-tokens consumed by api calls. APICallTokensConsumed Key = "api-call-tokens-consumed" @@ -19,9 +29,9 @@ const ( PersistedNonMetaFiles Key = "persisted-non-meta-files" PersistedNonMetaUploadedBytes Key = "persisted-non-meta-uploaded-bytes" PersistedUploadedBytes Key = "persisted-uploaded-bytes" - PersistenceErrors Key = "persistence-errors" - PersistenceExpectedErrors Key = "persistence-expected-errors" - PersistenceIgnoredErrors Key = "persistence-ignored-errors" + PersistenceErrs Key = "persistence-errs" + PersistenceExpectedErrs Key = "persistence-expected-errs" + PersistenceIgnoredErrs Key = "persistence-ignored-errs" ) // backup amounts reported by data providers @@ -60,7 +70,7 @@ const ( StreamDirsFound Key = "stream-dirs-found" StreamItemsAdded Key = "stream-items-added" StreamItemsDeletedInFlight Key = "stream-items-deleted-in-flight" - StreamItemsErrored Key = "stream-items-errored" + StreamItemsErred Key = "stream-items-erred" StreamItemsFound Key = "stream-items-found" StreamItemsRemoved Key = "stream-items-removed" TotalContainersSkipped Key = "total-containers-skipped" diff --git a/src/pkg/logger/logger.go b/src/pkg/logger/logger.go index 25843c6c9..94648557f 100644 --- a/src/pkg/logger/logger.go +++ b/src/pkg/logger/logger.go @@ -470,14 +470,18 @@ func SetWithSettings( return context.WithValue(ctx, ctxKey, logger) } -// Ctx retrieves the logger embedded in the context. -func Ctx(ctx context.Context) *zap.SugaredLogger { +func ctxNoClues(ctx context.Context) *zap.SugaredLogger { l := ctx.Value(ctxKey) if l == nil { l = singleton(Settings{}.EnsureDefaults()) } - return l.(*zap.SugaredLogger).With(clues.In(ctx).Slice()...) + return l.(*zap.SugaredLogger) +} + +// Ctx retrieves the logger embedded in the context. +func Ctx(ctx context.Context) *zap.SugaredLogger { + return ctxNoClues(ctx).With(clues.In(ctx).Slice()...) } // CtxStack retrieves the logger embedded in the context, and adds the @@ -491,8 +495,9 @@ func CtxStack(ctx context.Context, skip int) *zap.SugaredLogger { // CtxErr retrieves the logger embedded in the context // and packs all of the structured data in the error inside it. func CtxErr(ctx context.Context, err error) *zap.SugaredLogger { - // TODO(keepers): only log the err values, not the ctx. - return Ctx(ctx). + // don't add the ctx clues or else values will duplicate between + // the err clues and ctx clues. + return ctxNoClues(ctx). With( "error", err, "error_labels", clues.Labels(err)). @@ -504,7 +509,7 @@ func CtxErr(ctx context.Context, err error) *zap.SugaredLogger { // If skip is non-zero, it skips the stack calls starting from the // first. Skip always adds +1 to account for this wrapper. func CtxErrStack(ctx context.Context, err error, skip int) *zap.SugaredLogger { - return Ctx(ctx). + return ctxNoClues(ctx). With( "error", err, "error_labels", clues.Labels(err)).