From e4140e6054f5c30d9902a51f03cc5a49a3888152 Mon Sep 17 00:00:00 2001 From: Dirkjan Bussink Date: Thu, 12 Dec 2024 21:30:13 +0100 Subject: [PATCH] Fix flaky mysqlctl blackbox test This can trigger the race detector: ``` ================== WARNING: DATA RACE Read at 0x00c00031f900 by goroutine 64: vitess.io/vitess/go/vt/mysqlctl/blackbox.AssertLogs() /Users/dirkjan/code/vitessio/vitess/go/vt/mysqlctl/blackbox/utils.go:81 +0xb8 vitess.io/vitess/go/vt/mysqlctl/blackbox.TestExecuteBackupFailToWriteFileTwice() /Users/dirkjan/code/vitessio/vitess/go/vt/mysqlctl/blackbox/backup_test.go:713 +0x7e8 testing.tRunner() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:1690 +0x184 testing.(*T).Run.gowrap1() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:1743 +0x40 Previous write at 0x00c00031f900 by goroutine 75: vitess.io/vitess/go/vt/mysqlctl/blackbox.TestExecuteBackupFailToWriteFileTwice.NewMemoryLogger.func2() /Users/dirkjan/code/vitessio/vitess/go/vt/logutil/logger.go:225 +0x130 vitess.io/vitess/go/vt/logutil.(*CallbackLogger).InfoDepth() /Users/dirkjan/code/vitessio/vitess/go/vt/logutil/logger.go:139 +0x1a0 vitess.io/vitess/go/vt/logutil.(*CallbackLogger).Infof() /Users/dirkjan/code/vitessio/vitess/go/vt/logutil/logger.go:174 +0x60 vitess.io/vitess/go/vt/logutil.(*MemoryLogger).Infof() :1 +0x5c vitess.io/vitess/go/vt/mysqlctl.(*backupPipe).ReportProgress() /Users/dirkjan/code/vitessio/vitess/go/vt/mysqlctl/builtinbackupengine.go:820 +0xac4 vitess.io/vitess/go/vt/mysqlctl.(*BuiltinBackupEngine).backupFile.gowrap1() /Users/dirkjan/code/vitessio/vitess/go/vt/mysqlctl/builtinbackupengine.go:869 +0x90 Goroutine 64 (running) created at: testing.(*T).Run() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:1743 +0x5e0 testing.runTests.func1() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:2168 +0x80 testing.tRunner() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:1690 +0x184 testing.runTests() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:2166 +0x6e0 testing.(*M).Run() /opt/homebrew/Cellar/go/1.23.4/libexec/src/testing/testing.go:2034 +0xb74 main.main() _testmain.go:59 +0x110 Goroutine 75 (finished) created at: vitess.io/vitess/go/vt/mysqlctl.(*BuiltinBackupEngine).backupFile() /Users/dirkjan/code/vitessio/vitess/go/vt/mysqlctl/builtinbackupengine.go:869 +0x734 vitess.io/vitess/go/vt/mysqlctl.(*BuiltinBackupEngine).backupFileEntries.func2() /Users/dirkjan/code/vitessio/vitess/go/vt/mysqlctl/builtinbackupengine.go:706 +0x294 golang.org/x/sync/errgroup.(*Group).Go.func1() /Users/dirkjan/go/pkg/mod/golang.org/x/sync@v0.10.0/errgroup/errgroup.go:78 +0x7c ================== ``` Signed-off-by: Dirkjan Bussink --- go/vt/logutil/logger.go | 6 ++++++ go/vt/mysqlctl/blackbox/utils.go | 2 +- 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/go/vt/logutil/logger.go b/go/vt/logutil/logger.go index 47c3f124238..5667acaab9f 100644 --- a/go/vt/logutil/logger.go +++ b/go/vt/logutil/logger.go @@ -246,6 +246,12 @@ func (ml *MemoryLogger) Clear() { ml.mu.Unlock() } +func (ml *MemoryLogger) LogEvents() []*logutilpb.Event { + ml.mu.Lock() + defer ml.mu.Unlock() + return ml.Events +} + // LoggerWriter is an adapter that implements the io.Writer interface. type LoggerWriter struct { logger Logger diff --git a/go/vt/mysqlctl/blackbox/utils.go b/go/vt/mysqlctl/blackbox/utils.go index e4e3f11fb3c..c7d34ae3cf6 100644 --- a/go/vt/mysqlctl/blackbox/utils.go +++ b/go/vt/mysqlctl/blackbox/utils.go @@ -78,7 +78,7 @@ func GetStats(stats *backupstats.FakeStats) StatSummary { func AssertLogs(t *testing.T, expectedLogs []string, logger *logutil.MemoryLogger) { for _, log := range expectedLogs { - require.Truef(t, slices.ContainsFunc(logger.Events, func(event *logutilpb.Event) bool { + require.Truef(t, slices.ContainsFunc(logger.LogEvents(), func(event *logutilpb.Event) bool { return event.GetValue() == log }), "%s is missing from the logs", log) }