Repository navigation
-race is red on clean dev: a fixture writes Steward.now while the wall clock reads it under the lock (TestADoneEndingNamesTheCheckItCouldNotRun) #957
Description
What happened
internal/session has a data race on clean dev that the ordinary gate cannot see,
because neither make check nor the pull-request job runs -race. Lane FLAKE met it
while proving PR #952 — its 211-test -race run reported two races, and it confirmed both
in a throwaway worktree of untouched origin/dev, same write site. Base at the time of
filing: dev@c742b8bc8.
The two sites are named below and both were verified on dev; the report the lane saw
pairs them (addresses and goroutine numbers elided — this is the shape, not a verbatim
capture):
go test -race -count=1 -run '^TestADoneEndingNamesTheCheckItCouldNotRun$' ./internal/session/
WARNING: DATA RACE
Write by the test goroutine:
session.TestADoneEndingNamesTheCheckItCouldNotRun.func1
internal/session/checkpoint_test.go:759 <- steward.now = func() time.Time { ... }
Previous read by the wall-clock goroutine:
session.(*Steward).Budget
internal/session/principal.go:1008 <- ... , now := ... , s.now (under s.mu)
session.(*Agent).watchTheWall
internal/session/wallclock.go:68 <- steward.Budget().Left()
The fixture reaches into an unexported field of a live *Steward and assigns it with no
lock, while a goroutine the product started reads the same field under s.mu. A lock on
only one side is no happens-before, so the detector is right.
Why this fixture and not the dozen others that poke the same field: stewardCheckpointAgent
builds an unattended session with Budget{Wall: time.Hour}, and New therefore calls
armWallClock, which starts watchTheWall; that goroutine's first act is
steward.Budget().Left(). nearWall then writes steward.now from the test goroutine a
moment later. Both subtests (stopped turn, and the handover twin) call it.
Replication
Deterministic (no model, no key, no box of ours).
git checkout dev && go test -race -count=1 -run '^TestADoneEndingNamesTheCheckItCouldNotRun$' ./internal/session/
What a developer sees today: WARNING: DATA RACE, the write inside nearWall and the read
in (*Steward).Budget beneath (*Agent).watchTheWall, and a non-zero exit. The test's own
assertions pass; it is the detector that fails the package. It is a window between a
goroutine's first line and the fixture's, so run it a few times (-count=5) if the first
run is quiet.
Field (real models). None, and deliberately: no product code writes this field after
construction, so there is nothing a person can run into. See below.
Where
All in internal/session, by searchable string (line numbers are at dev@c742b8bc8):
- The unsynchronised write:
nearWall, the closure inside
TestADoneEndingNamesTheCheckItCouldNotRunincheckpoint_test.go— search
steward.now = func() time.Time(line 759). It also readssteward.startedand
steward.wallin the same closure. - The synchronised read:
(*Steward).Budgetinprincipal.go— search
wall, money, started, spent, now := s.wall, s.money, s.started, s.spent, s.now
(line 1008), taken unders.mu. - The reading goroutine:
(*Agent).watchTheWallinwallclock.go— search
left, _ := steward.Budget().Left()(line 68), started byarmWallClock
(wallclock.go, searchgo a.watchTheWall) fromNewinagent.go(search
THE WALL IS READ AFTER THE SESSION IS OPEN, line 414). - Why this fixture arms it:
stewardCheckpointAgentinunattendeddoor_test.go—
searchconfig.Budget = Budget{Wall: time.Hour}.
Test-only, not a product race
Test-only. Steward.now is written by product code exactly once, where the Steward is
built (principal.go, now: time.Now), and never assigned again anywhere in the tree.
Every product read of it is under s.mu — (*Steward).Budget, (*Steward).since, and
wallIsUp in wallclock.go all take the lock before they copy the func value. So the
unsynchronised half belongs entirely to the fixtures, which reach past the lock into the
field: checkpoint_test.go, checkmemo_test.go (×4), principal_test.go,
turnwall_test.go (which writes steward.started the same way), wallclock_test.go (×3),
and the sibling shapes fixStore.now and graph.governor.now. Nothing a person meets is
wrong, so sev:papercut — but it is a standing red under -race on clean dev, which
means the next real race in this package arrives as the third line of a report somebody
has already learned to ignore.
The fix
The fixture sets time through the clock door the product uses. Give Steward one
setter that takes s.mu — setClock(func() time.Time), and setStarted(time.Time) beside
it for turnwall_test.go — and change every fixture that assigns steward.now /
steward.started to call it. The field then has exactly one lock guarding every access on
both sides, which is the same shape PR #952 used one package over when it gave the lane
stub lanestub.Server.SetClock instead of letting the rig poke the field. The alternative —
teaching watchTheWall to read the field some other way — is the wrong end: the product's
read is already correct.
Acceptance
- e2e: none, and the reason is the finding above: this race has no road a person can
open, so the honest acceptance is the detector, not a door. Stated here rather than
omitted so nobody goes looking for one. - Race:
go test -race -count=5 -run '^TestADoneEndingNamesTheCheckItCouldNotRun$' ./internal/session/exits 0 with noWARNING: DATA RACEin the output, and both
subtests still assert their ending line (checkpointDoneNote + " · unchecked: " + …) and
their"unread":["tox -e py"]journal row. - Race (the family, so the fix is not one line deep): the same run over every test that
moves the steward's clock —-run '^(TestADoneEndingNamesTheCheckItCouldNotRun|TestAMemoOfAnUnreadCheck.*|…)$',
i.e. the tests incheckmemo_test.go,principal_test.go,turnwall_test.goand
wallclock_test.gothat assignnoworstarted— exits 0 with no race report. - Unit (structural, on the laws gate): a
go/asttest asserting that no test file in
internal/sessionassigns.nowor.startedon a*Stewarddirectly; every fixture
goes through the one door. Without it the next fixture reopens this the day it is written. - The change entry's
invalidatesnames the belief that-raceis clean ondev, and
docs/rules/ci.mdsays which gate does and does not run the detector.
Found by lane FLAKE while proving PR #952 (§5, "Found, not fixed"); not caused by it.
Drafted with CodeAF · reviewed and owned by the author
Activity
session: the Steward's clock moves through its lock, never past it — …