diff --git a/cmd/ingestor/issue1865_test.go b/cmd/ingestor/issue1865_test.go index c3f745e10..b35fbb51d 100644 --- a/cmd/ingestor/issue1865_test.go +++ b/cmd/ingestor/issue1865_test.go @@ -115,6 +115,11 @@ func openNeighborsStore(t *testing.T) *Store { if err != nil { t.Fatalf("OpenStore: %v", err) } + // Drain RunAsyncMigration's goroutine before returning. It calls + // log.Printf, and TestHandleNeighborsReportInvalidTimestampLogs... + // swaps the log sink for its own bytes.Buffer and then reads it — the + // two race on that buffer if the migration is still running. + store.backfillWg.Wait() t.Cleanup(func() { store.Close() }) return store } diff --git a/cmd/ingestor/main_test.go b/cmd/ingestor/main_test.go index c3a2e0095..4c4d8c3e1 100644 --- a/cmd/ingestor/main_test.go +++ b/cmd/ingestor/main_test.go @@ -125,6 +125,17 @@ func newTestStore(t testing.TB) *Store { if err != nil { t.Fatal(err) } + // OpenStore kicks off RunAsyncMigration in the background so boot is not + // blocked. Draining it here makes every test that uses this helper start + // from a settled database instead of racing a migration it never asked + // for. Individual tests that already knew to wait (see + // tx_last_seen_backfill_test.go and backfill_default_scope_test.go) keep + // their own call; this makes the guarantee the default rather than + // something each new test has to remember. + // + // Same synchronization point Close() uses (db.go:1470). Production is + // unaffected: main.go still never blocks on it. + s.backfillWg.Wait() t.Cleanup(func() { s.Close() }) return s } diff --git a/cmd/ingestor/stats_file.go b/cmd/ingestor/stats_file.go index 677e5245c..da6f6cde0 100644 --- a/cmd/ingestor/stats_file.go +++ b/cmd/ingestor/stats_file.go @@ -6,6 +6,7 @@ import ( "encoding/json" "log" "os" + "sync" "time" "github.com/meshcore-analyzer/perfio" @@ -236,11 +237,22 @@ func procIORate(prev, cur procIOSnapshot, stamp string) *PerfIOSample { // The stats file path is resolved via statsFilePath() once at writer-loop // start; the env var (CORESCOPE_INGESTOR_STATS) is only re-read on process // restart, not per tick. -func StartStatsFileWriter(s *Store, interval time.Duration) { +// +// Returns a stop function that signals the loop and BLOCKS until the +// goroutine has actually returned. Production (main.go) runs the writer for +// the lifetime of the process and ignores it; tests must call it, because a +// writer that outlives its test keeps calling readProcSelfIOFn every tick — +// which races the t.Cleanup that restores the hook, and gets reported against +// whichever unrelated test happens to run next. Stopping asynchronously would +// not fix that: the stop has to be ordered before the restore, so it waits. +func StartStatsFileWriter(s *Store, interval time.Duration) (stop func()) { if interval <= 0 { interval = time.Second } + quit := make(chan struct{}) + done := make(chan struct{}) go func() { + defer close(done) t := time.NewTicker(interval) defer t.Stop() path := statsFilePath() @@ -253,7 +265,12 @@ func StartStatsFileWriter(s *Store, interval time.Duration) { // The buffer grows once and stays. var buf bytes.Buffer enc := json.NewEncoder(&buf) - for range t.C { + for { + select { + case <-quit: + return + case <-t.C: + } // Capture time.Now() ONCE per tick (Carmack must-fix #5). // Both snapshot.SampledAt and procIO.SampledAt MUST share the // same string so the freshness guard isn't validating one @@ -301,4 +318,9 @@ func StartStatsFileWriter(s *Store, interval time.Duration) { } } }() + var once sync.Once + return func() { + once.Do(func() { close(quit) }) + <-done + } } diff --git a/cmd/ingestor/stats_file_test.go b/cmd/ingestor/stats_file_test.go index 29ba4b22c..64ab5a757 100644 --- a/cmd/ingestor/stats_file_test.go +++ b/cmd/ingestor/stats_file_test.go @@ -54,9 +54,15 @@ func TestStatsFileWriter_PublishesProcIO(t *testing.T) { if err != nil { t.Fatalf("OpenStore: %v", err) } - defer store.Close() + // Close via t.Cleanup, not defer: test defers run BEFORE cleanups, so a + // deferred Close would let the writer tick against a closed Store. LIFO + // cleanup ordering puts the writer's stop (registered next) ahead of it. + t.Cleanup(func() { store.Close() }) - StartStatsFileWriter(store, 50*time.Millisecond) + // Stop the writer when the test ends: it writes into t.TempDir() and + // reads the package-level readProcSelfIOFn hook, neither of which may + // outlive the test. + t.Cleanup(StartStatsFileWriter(store, 50*time.Millisecond)) // Wait for at least 2 ticks so the writer has had a chance to populate // procIO rates from a delta. diff --git a/cmd/ingestor/stats_file_timestamp_test.go b/cmd/ingestor/stats_file_timestamp_test.go index 900e65606..8ae4b8c12 100644 --- a/cmd/ingestor/stats_file_timestamp_test.go +++ b/cmd/ingestor/stats_file_timestamp_test.go @@ -42,7 +42,10 @@ func TestStatsFileWriter_SampledAtMatchesProcIOSampledAt(t *testing.T) { if err != nil { t.Fatalf("OpenStore: %v", err) } - defer store.Close() + // Close via t.Cleanup, not defer: test defers run BEFORE cleanups, so a + // deferred Close would let the writer tick against a closed Store. LIFO + // cleanup ordering puts the writer's stop (registered later) ahead of it. + t.Cleanup(func() { store.Close() }) // Inject a deterministic procIO reader. `at` is pinned far in the // past so any code path that formats the inner SampledAt from @@ -69,7 +72,12 @@ func TestStatsFileWriter_SampledAtMatchesProcIOSampledAt(t *testing.T) { } } - StartStatsFileWriter(store, 50*time.Millisecond) + // Registered AFTER the t.Cleanup that restores readProcSelfIOFn, so LIFO + // ordering stops the writer BEFORE the hook is put back. Without that + // ordering the writer's next tick reads the variable while the cleanup + // writes it — and because the goroutine outlived the test, the race was + // reported against whichever unrelated test ran next. + t.Cleanup(StartStatsFileWriter(store, 50*time.Millisecond)) // Wait for the file to land with a populated procIO block. deadline := time.Now().Add(3 * time.Second)