From ed3f078f3de31931c4a011d8f8856e0bf378dd75 Mon Sep 17 00:00:00 2001 From: Ben Brooks Date: Wed, 11 Oct 2023 15:43:39 +0100 Subject: [PATCH] Fix data race in AssertLogContains and functional race in TestDocChangedLogging (#6517) * Fix race in AssertLogContains by forcing console log buffer flush before checking contents - avoids multiple buffer reads during log writes * Fix TestDocChangedLogging test race --- base/logging.go | 16 ++++------------ rest/changestest/changes_api_test.go | 4 ++++ 2 files changed, 8 insertions(+), 12 deletions(-) diff --git a/base/logging.go b/base/logging.go index df9a689466..3691fd9808 100644 --- a/base/logging.go +++ b/base/logging.go @@ -388,22 +388,14 @@ func LogTraceEnabled(logKey LogKey) bool { // AssertLogContains asserts that the logs produced by function f contain string s. func AssertLogContains(t *testing.T, s string, f func()) { // Temporarily override logger output - b := bytes.Buffer{} - mw := io.MultiWriter(&b, os.Stderr) + b := &bytes.Buffer{} + mw := io.MultiWriter(b, os.Stderr) consoleLogger.logger.SetOutput(mw) defer func() { consoleLogger.logger.SetOutput(os.Stderr) }() // Call the given function f() - // Allow time for logs to be printed - retry := func() (shouldRetry bool, err error, value interface{}) { - if strings.Contains(b.String(), s) { - return false, nil, nil - } - return true, nil, nil - } - err, _ := RetryLoop(TestCtx(t), "wait for logs", retry, CreateSleeperFunc(10, 100)) - - assert.NoError(t, err, "Console logs did not contain %q", s) + consoleLogger.FlushBufferToLog() + assert.True(t, strings.Contains(b.String(), s), "Console logs did not contain %q", s) } diff --git a/rest/changestest/changes_api_test.go b/rest/changestest/changes_api_test.go index c7d5ef73e9..5668acea9e 100644 --- a/rest/changestest/changes_api_test.go +++ b/rest/changestest/changes_api_test.go @@ -4337,6 +4337,10 @@ func TestDocChangedLogging(t *testing.T) { base.AssertLogContains(t, "Ignoring non-metadata mutation for doc", func() { err := rt.GetDatabase().MetadataStore.Set("doc1", 0, nil, db.Body{"foo": "bar"}) require.NoError(t, err) + // write another doc to ensure the previous non-metadata doc has been seen... + // no other way of synchronising this no-op as no stats to wait on + response = rt.SendAdminRequest("PUT", "/{{.keyspace1}}/doc2", `{"foo":"bar"}`) + rest.RequireStatus(t, response, http.StatusCreated) require.NoError(t, rt.WaitForPendingChanges()) }) assert.Equal(t, warnCountBefore, base.SyncGatewayStats.GlobalStats.ResourceUtilizationStats().WarnCount.Value())