会不会是竞态检测器在这里判断错了，还是我对 ack 提供的保证理解有误？这是 pushgate，一个小服务，给我的移动应用校验推送通知用的设备令牌上的 HMAC 签名。调用方在无缓冲的 channel 上发送一个 Request，worker 填好 Result，然后把 ID 发到 ack channel 上。调用方只在收到 ack 之后才读 Result。我故意把测试写成这样，就是为了不用 time.Sleep。带 time.After 的 select 只是为了让卡住的测试能超时挂掉。
直接跑 go test 一直是绿的。今天打 tag 发版之前我跑了 go test -race -count=200 ./...。大约每 30-40 次运行会有一次打印 WARNING: DATA RACE，test goroutine 里是读，worker goroutine 里是写。worker 这边指向 verify.go，测试这边指向 verify_test.go 里 t.Logf 那一行。好像更多是 TestWorkerRejectsBadSig 触发的，但我不确定。
我试过的:
- 带缓冲的 ack channel: 竞态出现得更频繁了，所以我改回去了
-cpu 1: 竞态消失了，但我不信这个结果- 旧的 Result 有两个字段，上周我为了审计日志加了一个时间戳。我看不出这会有什么影响
worker 代码:
for r := range in {
want := sign(secret, r.Token)
ok := hmac.Equal([]byte(want), []byte(r.Sig))
r.Result.DeviceID = r.ID
r.Result.Valid = ok
ack <- r.ID
// stamp after the ack so the caller is not kept waiting
r.Result.Checked = time.Now()
if verbose {
log.Printf("checked device=%d valid=%v", r.ID, ok)
}
}
失败更频繁的那个测试:
func TestWorkerRejectsBadSig(t *testing.T) {
res := runOne(t, 9, "apns-abc123", "deadbeef")
t.Logf("result for bad sig: %+v", *res)
if res.Valid {
t.Fatal("bad signature accepted")
}
if res.DeviceID != 9 {
t.Fatalf("device id %d", res.DeviceID)
}
}
runOne 用普通的 make(chan ...) 创建两个 channel，启动 worker，发送 Request，然后对 ack 和 time.After(2 * time.Second) 做 select，最后返回 res。我读了 https://go.dev/ref/mem 但还是看不出顺序是在哪里断掉的。是不是结构体里的那个指针对检测器隐藏了什么？
从英语翻译·查看原文Is it possible that the race detector is wrong here, or that I misunderstand what the ack gives me? This is pushgate, a small service that checks HMAC signatures on device tokens for push notifications in my mobile app. The caller sends a Request on an unbuffered channel, the worker fills in a Result, then sends the ID on an ack channel. The caller reads the Result only after receiving the ack. I wrote the tests like this on purpose so there is no time.Sleep. The select with time.After is only there so a stuck test dies.
Plain go test is always green. Today before tagging a release I ran go test -race -count=200 ./.... About one run in 30-40 prints WARNING: DATA RACE, with a read in the test goroutine and a write in the worker goroutine. The worker side points into verify.go, the test side at the t.Logf line in verify_test.go. It seems to come more from TestWorkerRejectsBadSig, but I am not sure.
What I tried:
- buffered ack channel: race showed up more often, so I put it back
-cpu 1: race disappears, but I don't trust that- the old Result had two fields, and I added a timestamp last week for audit logs. I don't see why that would matter
The worker:
for r := range in {
want := sign(secret, r.Token)
ok := hmac.Equal([]byte(want), []byte(r.Sig))
r.Result.DeviceID = r.ID
r.Result.Valid = ok
ack <- r.ID
// stamp after the ack so the caller is not kept waiting
r.Result.Checked = time.Now()
if verbose {
log.Printf("checked device=%d valid=%v", r.ID, ok)
}
}
The test that fails more often:
func TestWorkerRejectsBadSig(t *testing.T) {
res := runOne(t, 9, "apns-abc123", "deadbeef")
t.Logf("result for bad sig: %+v", *res)
if res.Valid {
t.Fatal("bad signature accepted")
}
if res.DeviceID != 9 {
t.Fatalf("device id %d", res.DeviceID)
}
}
runOne makes both channels with plain make(chan ...), starts the worker, sends the Request, then selects on ack vs time.After(2 * time.Second) and returns res. I was reading https://go.dev/ref/mem but still don't see where the ordering breaks. Is the pointer inside the struct hiding something from the detector?
