j and k move between steps
Read the contract before the code. Point four of it is the whole task: it rules out the fix that every tutorial on this error reaches for.
ls -R . && cat README.md.:
README.md
agg
cmd
go.mod
./agg:
aggregator.go
aggregator_test.go
histogram.go
./cmd:
aggd
./cmd/aggd:
main.goshowing 16 of 51 lines
Reproduce it and read the report properly. The detector names the field, both stacks and the goroutines, which is a more reliable map of what is unsynchronised than reading the file will be.
export PATH=/usr/local/go/bin:$PATH; go test -race -count=1 ./agg/ 2>&1 | head -60==================
WARNING: DATA RACE
Read at 0x00c0000b2508 by goroutine 17:
example.internal/aggregator/agg.(*Registry).lookup()
/workspace/agg/aggregator.go:79 +0x44
example.internal/aggregator/agg.(*Registry).Observe()
/workspace/agg/aggregator.go:67 +0x46
example.internal/aggregator/agg_test.TestConcurrentObserveKeepsEveryUpdate.func1()
/workspace/agg/aggregator_test.go:78 +0x117
example.internal/aggregator/agg_test.TestConcurrentObserveKeepsEveryUpdate.gowrap1()
/workspace/agg/aggregator_test.go:80 +0x41
Previous write at 0x00c0000b2508 by goroutine 14:
example.internal/aggregator/agg.(*Registry).lookup()
/workspace/agg/aggregator.go:90 +0x1e5
example.internal/aggregator/agg.(*Registry).Observe()showing 16 of 61 lines
Now the code. mu covers the map and nothing else: the bucket fields, the histogram and the observed counter are all touched outside it, and lookup reads and writes the hot cache with nothing held.
{
"path": "agg/aggregator.go"
}3 lines, 33 B
// Package agg aggregates per endpoint request latency for a service that serves a few
// thousand requests a second across a handful of endpoints.
//
// One Registry is shared by every request goroutine and by the exporter goroutine that
// scrapes it once a second. Observe is on the request path. Snapshot, SnapshotAll,
// Endpoints and Observed are on the exporter's path. Neither path is allowed to make the
// other wait longer than it has to, and two exporter reads of the same endpoint must be
// able to run at the same time: quantile walks the histogram in place, so a read is not
// cheap and serialising reads behind one lock turns a one second scrape into a stall.
//
// This started life single threaded. A mutex was added later, around the map, which is
// where it stopped.
package agg
import (
"sort"showing 16 of 146 lines
This file is out of bounds, so read it for the constraint rather than the fix. It says a histogram carries no lock of its own and that quantile reads it in place, which means the read path has to hold the same lock the writers take while it runs.
{
"path": "agg/histogram.go"
}3 lines, 32 B
package agg
import (
"math"
"time"
)
// bucketCount buckets cover one microsecond to just over eight seconds, in powers of two.
const bucketCount = 24
// quantileCost stands in for the interpolation pass the real exporter runs across the
// buckets and the reservoir it keeps beside them.
//
// It is a sleep rather than a busy loop on purpose. What matters about the read path is
// whether two readers can be inside it at the same time, and a busy loop would measure
// how many cores the box has instead.showing 16 of 65 lines
One lock per bucket, RWMutex so the exporter's reads share, the map lock held only long enough to resolve a name, and the counter moved to an atomic. The hot cache goes: it existed to skip a map lookup that now costs a shared read lock, locking it would reintroduce the contention it was added to avoid, and it was what made Reset leave a bucket behind.
// Package agg aggregates per endpoint request latency for a service that serves a few
// thousand requests a second across a handful of endpoints.
//
// One Registry is shared by every request goroutine and by the exporter goroutine that
// scrapes it once a second. Observe is on the request path. Snapshot, SnapshotAll,
// Endpoints and Observed are on the exporter's path. Neither path is allowed to make the
// other wait longer than it has to, and two exporter reads of the same endpoint must be
// able to run at the same time: quantile walks the histogram in place, so a read is not
// cheap and serialising reads behind one lock turns a one second scrape into a stall.
//
// Locking, from the outside in. Registry.mu guards the map itself and nothing else, held
// for a map lookup and released. Each bucket carries its own RWMutex, which is the lock
// the histogram is documented to need: writers take it exclusively, readers share it, so
// two Snapshots of the same endpoint overlap and a Snapshot of one endpoint never waits
// on writes to another. observed is an atomic because it is touched by every writer and
// read by the exporter, and a counter is the one thing that does not need a lock at all.
package agg
showing 18 of 163 lines
{
"path": "agg/aggregator.go"
}3 lines, 33 B
Wrote 4577 bytes (163 lines) to agg/aggregator.go.Cheap checks first. A vet finding or a formatting diff is not worth a race detector run.
export PATH=/usr/local/go/bin:$PATH; gofmt -l . && go vet ./... && echo cleanclean
2 lines, 6 B
The suite under the detector, which is the only evidence that counts here. Note that a passing run proves nothing about interleavings it did not take, which is why the reasoning above is about which lock covers which field rather than about the result.
export PATH=/usr/local/go/bin:$PATH; go test -race -count=1 -v ./... 2>&1 | tail -20? example.internal/aggregator/cmd/aggd [no test files]
=== RUN TestObserveThenSnapshot
--- PASS: TestObserveThenSnapshot (0.01s)
=== RUN TestSnapshotAllCoversEveryEndpoint
--- PASS: TestSnapshotAllCoversEveryEndpoint (0.02s)
=== RUN TestConcurrentObserveKeepsEveryUpdate
--- PASS: TestConcurrentObserveKeepsEveryUpdate (0.03s)
=== RUN TestExporterScrapesWhileRequestsLand
--- PASS: TestExporterScrapesWhileRequestsLand (0.00s)
PASS
ok example.internal/aggregator/agg 1.068s
12 lines, 487 B
Run the thing. The report has to show every observation accounted for, which is the lost update half of the contract and is not something the detector checks.
export PATH=/usr/local/go/bin:$PATH; go run ./cmd/aggdobserved 3000 of 3000
/v1/cart count=1000 mean=319 max=549 p95=1024
/v1/checkout count=1000 mean=319 max=549 p95=1024
/v1/inventory count=1000 mean=319 max=549 p95=1024
5 lines, 208 B
Close with which lock covers what, because that is the part a reviewer has to check.
Registry.mu guarded the map only. The per endpoint aggregate fields, the histogram behind them and the observed counter were all mutated with no lock held, and the hot endpoint cache in front of the map was read and written unsynchronised, which is also why Reset left a stale bucket live. Fixed by giving each bucket its own RWMutex (writers exclusive, readers shared, held across quantile because it reads the histogram in place), holding the map's RWMutex only for the lookup, making the counter an atomic, and dropping the cache. Readers of one endpoint now overlap each other and never wait on writes to another endpoint. go test -race ./... and go vet ./... are clean.
2 lines, 675 B
Run ended by the agent.9 steps5 commands0 schema violations0 failed commands0 destructive attempts
The last few kilobytes of the hidden test run, stdout and stderr together, kept for triage. The agent never saw this.
=== RUN TestProvidedFilesAreUnmodified
--- PASS: TestProvidedFilesAreUnmodified (0.00s)
=== RUN TestPublicSurfaceIsUnchanged
--- PASS: TestPublicSurfaceIsUnchanged (0.00s)
=== RUN TestSnapshotReportsCorrectAggregates
--- PASS: TestSnapshotReportsCorrectAggregates (0.01s)
=== RUN TestSnapshotAllAgreesWithSnapshot
--- PASS: TestSnapshotAllAgreesWithSnapshot (0.05s)
=== RUN TestResetClearsEveryEndpoint
--- PASS: TestResetClearsEveryEndpoint (0.01s)
=== RUN TestConcurrentReadsDoNotSerialise
--- PASS: TestConcurrentReadsDoNotSerialise (0.02s)showing 12 of 23 lines
Results that cannot be reproduced are not results. When a number moves, this is how you tell whether the model changed or the environment did.