From bfb7af3e7f32867311f91b6d20afdaa5449934ce Mon Sep 17 00:00:00 2001 From: Tor Colvin Date: Tue, 5 Sep 2023 13:09:25 -0400 Subject: [PATCH 1/2] CBG-3332 increase log information --- db/import_listener.go | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/db/import_listener.go b/db/import_listener.go index 4ec1b00306..04c3b0000c 100644 --- a/db/import_listener.go +++ b/db/import_listener.go @@ -150,6 +150,7 @@ func (il *importListener) ProcessFeedEvent(event sgbucket.FeedEvent) (shouldPers // If this is a binary document we can ignore, but update checkpoint to avoid reprocessing upon restart if event.DataType == base.MemcachedDataTypeRaw { + base.DebugfCtx(il.loggingCtx, base.KeyImport, "Ignoring binary mutation event for %s.", base.UD(event.Key)) return true } @@ -179,10 +180,12 @@ func (il *importListener) ImportFeedEvent(event sgbucket.FeedEvent) { syncData, rawBody, rawXattr, rawUserXattr, err := UnmarshalDocumentSyncDataFromFeed(event.Value, event.DataType, collectionCtx.userXattrKey(), false) if err != nil { - base.DebugfCtx(il.loggingCtx, base.KeyImport, "Found sync metadata, but unable to unmarshal for feed document %q. Will not be imported. Error: %v", base.UD(event.Key), err) if err == base.ErrEmptyMetadata { base.WarnfCtx(il.loggingCtx, "Unexpected empty metadata when processing feed event. docid: %s opcode: %v datatype:%v", base.UD(event.Key), event.Opcode, event.DataType) + } else { + base.WarnfCtx(il.loggingCtx, "Found sync metadata, but unable to unmarshal for feed document %q. Will not be imported. Error: %v", base.UD(event.Key), err) } + il.importStats.ImportErrorCount.Add(1) return } From 8f8d8a85adc743beaf7cc0d8ca55662171d7c1c6 Mon Sep 17 00:00:00 2001 From: Tor Colvin Date: Thu, 7 Sep 2023 10:17:30 -0400 Subject: [PATCH 2/2] Change logging to info and write a test --- db/import_listener.go | 2 +- db/import_test.go | 24 ++++++++++++++++++++++++ 2 files changed, 25 insertions(+), 1 deletion(-) diff --git a/db/import_listener.go b/db/import_listener.go index 04c3b0000c..e78d25c477 100644 --- a/db/import_listener.go +++ b/db/import_listener.go @@ -150,7 +150,7 @@ func (il *importListener) ProcessFeedEvent(event sgbucket.FeedEvent) (shouldPers // If this is a binary document we can ignore, but update checkpoint to avoid reprocessing upon restart if event.DataType == base.MemcachedDataTypeRaw { - base.DebugfCtx(il.loggingCtx, base.KeyImport, "Ignoring binary mutation event for %s.", base.UD(event.Key)) + base.InfofCtx(il.loggingCtx, base.KeyImport, "Ignoring binary mutation event for %s.", base.UD(event.Key)) return true } diff --git a/db/import_test.go b/db/import_test.go index 30a5572966..ce02d0369c 100644 --- a/db/import_test.go +++ b/db/import_test.go @@ -557,5 +557,29 @@ func TestImportNonZeroStart(t *testing.T) { doc, err := collection.GetDocument(base.TestCtx(t), doc1, DocUnmarshalAll) require.NoError(t, err) require.Equal(t, revID1, doc.SyncData.CurrentRev) +} + +// TestImportInvalidMetadata tests triggering an import error if the metadata is unmarshalable +func TestImportInvalidMetadata(t *testing.T) { + base.SkipImportTestsIfNotEnabled(t) + bucket := base.GetTestBucket(t) + defer bucket.Close() + + db, ctx := setupTestDBWithOptionsAndImport(t, bucket, DatabaseContextOptions{}) + defer db.Close(ctx) + // make sure no documents are imported + require.Equal(t, int64(0), db.DbStats.SharedBucketImport().ImportCount.Value()) + require.Equal(t, int64(0), db.DbStats.SharedBucketImport().ImportErrorCount.Value()) + + // write a document with inline sync metadata that is unmarshalable, triggering an import error + // can't write a document with invalid sync metadata as an xattr, so rely on legacy behavior + _, err := bucket.GetSingleDataStore().Add("doc1", 0, `{"foo" : "bar", "_sync" : 1 }`) + require.NoError(t, err) + + _, ok := base.WaitForStat(func() int64 { + return db.DbStats.SharedBucketImport().ImportErrorCount.Value() + }, 1) + require.True(t, ok) + require.Equal(t, int64(0), db.DbStats.SharedBucketImport().ImportCount.Value()) }