WARNING DATA RACE not detected

[tmablunar]

Running tparse -file test_min.json -all on the included test output does not detect the WARNING DATA RACE. It does detect that the test run failed but not why.

tparse version is v0.18.0

test_min.json

📦 Package github.com/example/myapp/internal/accept_test

Tests: ✓ 2 passed | 0 skipped

Click for test summary

Status	Elapsed	Test
🟢 PASS	0.00	TestPing
🟢 PASS	0.00	TestPing/Ping_returns_status_OK

📦 Package github.com/example/myapp/internal/infrastructure/config_fetcher/templates

Tests: ✓ 2 passed | 0 skipped

Click for test summary

Status	Elapsed	Test
🟢 PASS	0.01	TestGeneration
🟢 PASS	0.01	TestGeneration/should_generate_template

Status	Elapsed	Package	Cover	Pass	Fail	Skip
	0.00s		--	0	0	0
🔴 FAIL	1.52s	github.com/example/myapp/internal/accept_test	--	2	0	0
🟢 PASS	1.04s	github.com/example/myapp/internal/infrastructure/config_fetcher/templates	--	2	0	0

[mfridman]

Curious, what version of Go are you running? I wonder if this is related to recent changes in go1.25

[tmablunar]

This is indeed go1.25

[tmablunar]

I tested on 1.24 which also did not work on the same tests.

On the other hand I created a very simple test for which tparse can detect the race condition on both 1.24 and 1.25. In other words, it does not seem related to the version of go.

func TestRaceCondition(t *testing.T) {
	var counter int
	var wg sync.WaitGroup

	// Start multiple goroutines that write to the same memory location
	for i := 0; i < 100; i++ {
		wg.Add(1)
		go func(val int) {
			defer wg.Done()
			// Direct concurrent writes without synchronization
			for j := 0; j < 100; j++ {
				counter = val + j // Race condition: unsynchronized write
			}
		}(i)
	}

	// Concurrent reader
	for i := 0; i < 10; i++ {
		wg.Add(1)
		go func() {
			defer wg.Done()
			for j := 0; j < 100; j++ {
				temp := counter // Race condition: unsynchronized read
				_ = temp
			}
		}()
	}

	wg.Wait()
	t.Logf("Final counter value: %d", counter)
}

[mfridman]

Perfect, thanks for the added context. I'll mark it as a bug and investigate next chance I get (~days).

[mfridman]

Okay, I see the issue. The test output is not associated with any particular test. I'm curious, do you have a background task that's somehow run outside of tests? Maybe a blank import that calls init()? Doh, you provided a repro above, it's a spawned off goroutine in TestRaceCondition, but it's not associated with that test only the package

I can't say I've seen this case, as typically this output is associated with a specific test.

Slightly unrelated, there's an output line that's not associated with any particular package (this looks like a Go test output bug).

...
{"Time":"2025-09-03T08:38:04.586091585Z","Action":"output","Package":"github.com/example/myapp/internal/accept_test","Output":"  github.com/example/myapp/internal/feature/process_tasks.(*SagaStarter).Start()\n"}
{"Time":"2025-09-03T08:38:04.586093502Z","Action":"output","Package":"github.com/example/myapp/internal/accept_test","Output":"      /work/src/internal/feature/process_tasks/saga_starter.go:46 +0x24\n"}
+ {"Time":"2025-09-03T08:38:04.586095502Z","Action":"output","Package":"github.com/example/myapp/internal/feature/process_tasks.(*Feature).Start.gowrap1()\n"}
{"Time":"2025-09-03T08:38:04.58609746Z","Action":"output","Package":"github.com/example/myapp/internal/accept_test","Output":"      /work/src/internal/feature/process_tasks/setup.go:69 +0x34\n"}
{"Time":"2025-09-03T08:38:04.586099252Z","Action":"output","Package":"github.com/example/myapp/internal/accept_test","Output":"\n"}

[mfridman]

Alright, so I believe the main issue is that the output for the data race failure is not printed, this is what you'd expect?

┏━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┓                                                                                              
┃   DATA RACE  package: github.com/example/myapp/internal/accept_test   ┃                                                                                              
┗━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┛                                                                                              
WARNING: DATA RACE

Read at 0x00c0001c0fd8 by goroutine 503:
  github.com/example/myapp/internal/feature/process_tasks/metrics.(*QueueObserver).Close()
      /work/src/internal/feature/process_tasks/metrics/queue_observers.go:59 +0x4c
  github.com/example/myapp/internal/feature/process_tasks/queue.(*Projection).Close()
      /work/src/internal/feature/process_tasks/queue/projection.go:60 +0x6c
  github.com/example/myapp/internal/feature/process_tasks.(*SagaStarter).Close()
      /work/src/internal/feature/process_tasks/saga_starter.go:51 +0x40
  github.com/example/myapp/internal/feature/process_tasks.(*Feature).Close()
      /work/src/internal/feature/process_tasks/setup.go:80 +0x24
  go.example.com/framework.(*Launcher).closeComponent()
      /go/pkg/mod/go.example.com/framework@v1.2.6/launcher.go:287 +0x168
  go.example.com/framework.(*Launcher).closeComponents.func1()
      /go/pkg/mod/go.example.com/framework@v1.2.6/launcher.go:256 +0x78

Previous write at 0x00c0001c0fd8 by goroutine 406:
  github.com/example/myapp/internal/feature/process_tasks/metrics.(*QueueObserver).Start()
      /work/src/internal/feature/process_tasks/metrics/queue_observers.go:34 +0x68
  github.com/example/myapp/internal/feature/process_tasks/queue.(*Projection).Start()
      /work/src/internal/feature/process_tasks/queue/projection.go:56 +0x54
  github.com/example/myapp/internal/feature/process_tasks.(*SagaStarter).Start()
      /work/src/internal/feature/process_tasks/saga_starter.go:46 +0x24
      /work/src/internal/feature/process_tasks/setup.go:69 +0x34

Goroutine 503 (running) created at:
  go.example.com/framework.(*Launcher).closeComponents()
      /go/pkg/mod/go.example.com/framework@v1.2.6/launcher.go:254 +0x128
  go.example.com/framework.(*Launcher).Launch()
      /go/pkg/mod/go.example.com/framework@v1.2.6/launcher.go:128 +0x184
  github.com/example/myapp/internal/setup.Run()
      /work/src/internal/setup/framework.go:39 +0xd1c
  go.example.com/framework.TestMain.func2()
      /go/pkg/mod/go.example.com/framework@v1.2.6/testing.go:118 +0x130

Goroutine 406 (running) created at:
  github.com/example/myapp/internal/feature/process_tasks.(*Feature).Start()
      /work/src/internal/feature/process_tasks/setup.go:69 +0x9c
  go.example.com/framework.(*Launcher).startComponent()
      /go/pkg/mod/go.example.com/framework@v1.2.6/launcher.go:214 +0x168
  go.example.com/framework.(*Launcher).startComponents.gowrap1()
      /go/pkg/mod/go.example.com/framework@v1.2.6/launcher.go:196 +0x48
                                                                                                                                                                       
╭────────┬─────────┬───────────────────────────────────────────────────────────────────────────┬───────┬──────┬──────┬──────╮
│ Status │ Elapsed │                                  Package                                  │ Cover │ Pass │ Fail │ Skip │
├────────┼─────────┼───────────────────────────────────────────────────────────────────────────┼───────┼──────┼──────┼──────┤
│        │  0.00s  │                                                                           │  --   │  0   │  0   │  0   │
│  FAIL  │  1.52s  │ github.com/example/myapp/internal/accept_test                             │  --   │  2   │  0   │  0   │
│  PASS  │  1.04s  │ github.com/example/myapp/internal/infrastructure/config_fetcher/templates │  --   │  2   │  0   │  0   │
╰────────┴─────────┴───────────────────────────────────────────────────────────────────────────┴───────┴──────┴──────┴──────╯
exit status 1

[tmablunar]

Sorry for my missing your response. Yes, that is what I would expect!

To answer your other questions. The repro test I created is very hypothetical as I am not sure how to consistently reproduce a data race warning.
The output I included is from a real test but have tried to obfuscate it so it might look a bit weird.

[mfridman]

No worries, I understand the root cause (appreciate the details). Just need to find some time to fix this.