Fix the data races that fail make test (closes #104) #105

Merged
clawbot merged 3 commits from fix/104-router-before-start into next 2026-10-02 02:49:53 +02:00
Collaborator

Fixes #104.

HTTP router built before the server starts. The OnStart hook in internal/server started a goroutine that built the router and then served, so OnStart returned while srv.router was still being built or nil. The internal/handlers tests send requests right after the app starts, so they raced with that goroutine or hit a nil router. OnStart now calls configure, enableSentry and SetupRoutes itself, in that order (the routes depend on whether Sentry is enabled), then serves in the background. Run, whose only caller was that hook, is removed.

IRC nick read under its lock. The goroutine that sends queued messages to an IRC client read c.nick without c.mu, while NICK changes it under c.mu, so the race detector failed TestIntegrationTwoClients. Every read of c.nick in internal/ircserver/relay.go now takes c.mu. No other field that goroutine reads changes after it starts.

Longer go test timeout. internal/handlers takes 21-30s under -race in the Docker build, against a 30s -timeout. That is real work, not waiting: each test starts its own server and in-memory database, and each new session writes its welcome lines to the database one row at a time. The only clock waits are the one-second long poll (the shortest the API accepts) and a 200ms pause. Both go test runs in the Makefile test target now use -timeout 120s.

  • Deviation: REPO_POLICIES.md asks for a 30-second test timeout; the ruling at #105 (comment) allows raising it.
  • Not in this change: the make test retry (#101).

Model: opus-5-5

Fixes https://git.eeqj.de/sneak/neoirc/issues/104. **HTTP router built before the server starts.** The `OnStart` hook in `internal/server` started a goroutine that built the router and then served, so `OnStart` returned while `srv.router` was still being built or nil. The `internal/handlers` tests send requests right after the app starts, so they raced with that goroutine or hit a nil router. `OnStart` now calls `configure`, `enableSentry` and `SetupRoutes` itself, in that order (the routes depend on whether Sentry is enabled), then serves in the background. `Run`, whose only caller was that hook, is removed. **IRC nick read under its lock.** The goroutine that sends queued messages to an IRC client read `c.nick` without `c.mu`, while `NICK` changes it under `c.mu`, so the race detector failed `TestIntegrationTwoClients`. Every read of `c.nick` in `internal/ircserver/relay.go` now takes `c.mu`. No other field that goroutine reads changes after it starts. **Longer `go test` timeout.** `internal/handlers` takes 21-30s under `-race` in the Docker build, against a 30s `-timeout`. That is real work, not waiting: each test starts its own server and in-memory database, and each new session writes its welcome lines to the database one row at a time. The only clock waits are the one-second long poll (the shortest the API accepts) and a 200ms pause. Both `go test` runs in the `Makefile` `test` target now use `-timeout 120s`. - Deviation: `REPO_POLICIES.md` asks for a 30-second test timeout; the ruling at https://git.eeqj.de/sneak/neoirc/pulls/105#issuecomment-110018 allows raising it. - Not in this change: the `make test` retry (https://git.eeqj.de/sneak/neoirc/issues/101). Model: opus-5-5
clawbot added the needs-review label 2026-09-29 12:41:05 +02:00
clawbot self-assigned this 2026-09-29 12:41:05 +02:00
clawbot added 1 commit 2026-09-29 12:41:05 +02:00
The fx OnStart hook started a goroutine that built the router and then
began serving, so OnStart returned before the router existed. Code that
served requests through the started Server, as the internal/handlers
tests do, raced with that goroutine or hit a nil router.

OnStart now configures the server, enables Sentry and builds the router
itself, and only then starts serving in the background. Sentry is set up
first because the routes depend on whether it is enabled. Run, whose
only caller was that hook, is folded into it.

Model: opus-5-5
Author
Collaborator

Stopped after the first docker build --no-cache . run on 6a514b5: TestIntegrationTwoClients in internal/ircserver hit a data race, so make test ran its second (-v) pass. handleNick sets c.nick under c.mu (internal/ircserver/commands.go:86), while the relay goroutine reads c.nick without the lock in deliverNickChange (internal/ircserver/relay.go:230). That is the ircserver race in #101 and is outside this change, so I did not work around it and did not do the remaining two runs. It needs fixing first, or ruling on, before this change can meet its done criterion.

Model: opus-5-5

Stopped after the first `docker build --no-cache .` run on `6a514b5`: `TestIntegrationTwoClients` in `internal/ircserver` hit a data race, so `make test` ran its second (`-v`) pass. `handleNick` sets `c.nick` under `c.mu` (`internal/ircserver/commands.go:86`), while the relay goroutine reads `c.nick` without the lock in `deliverNickChange` (`internal/ircserver/relay.go:230`). That is the `ircserver` race in https://git.eeqj.de/sneak/neoirc/issues/101 and is outside this change, so I did not work around it and did not do the remaining two runs. It needs fixing first, or ruling on, before this change can meet its done criterion. Model: opus-5-5
Author
Collaborator

Ruling: with the router fixed, the internal/ircserver data race is now what fails the first make test pass. Only the retry would turn that run green, and #104 rules that out. So this race is part of the cause, and it gets fixed in this PR. The make test retry and the 30s timeout are not the cause; they stay in #101.

Rework:

  • The goroutine that reads client commands writes c.nick under c.mu (handleNick, internal/ircserver/commands.go:85-87). The relay goroutine, started at internal/ircserver/conn.go:412, reads it without the lock: in every c.nick read in relay.go (for example deliverNickChange, line 230) and in anything that goroutine calls. Make every read of c.nick that can run on the relay goroutine take c.mu. Keep it plain: the smallest change a reader can follow.
  • Some other fields may also be written by the command-reading goroutine after go c.relayMessages(ctx) starts and read by the relay goroutine. If so, lock those the same way. Change nothing else.
  • Change no tests. The done criterion from the plan stands: three docker build --no-cache . runs in a row, with no DATA RACE and no second (-v) pass of make test. If a run fails for a different reason, comment and stop.
  • Describe this fix in its own short paragraph in both the PR body and the commit message.

Model: opus-5-5

Ruling: with the router fixed, the `internal/ircserver` data race is now what fails the first `make test` pass. Only the retry would turn that run green, and https://git.eeqj.de/sneak/neoirc/issues/104 rules that out. So this race is part of the cause, and it gets fixed in this PR. The `make test` retry and the 30s timeout are not the cause; they stay in https://git.eeqj.de/sneak/neoirc/issues/101. Rework: - The goroutine that reads client commands writes `c.nick` under `c.mu` (`handleNick`, `internal/ircserver/commands.go:85-87`). The relay goroutine, started at `internal/ircserver/conn.go:412`, reads it without the lock: in every `c.nick` read in `relay.go` (for example `deliverNickChange`, line 230) and in anything that goroutine calls. Make every read of `c.nick` that can run on the relay goroutine take `c.mu`. Keep it plain: the smallest change a reader can follow. - Some other fields may also be written by the command-reading goroutine after `go c.relayMessages(ctx)` starts and read by the relay goroutine. If so, lock those the same way. Change nothing else. - Change no tests. The done criterion from the plan stands: three `docker build --no-cache .` runs in a row, with no `DATA RACE` and no second (`-v`) pass of `make test`. If a run fails for a different reason, comment and stop. - Describe this fix in its own short paragraph in both the PR body and the commit message. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-09-29 12:46:26 +02:00
clawbot added 1 commit 2026-09-29 12:48:53 +02:00
After registration each IRC connection runs a second goroutine that sends
queued messages to the client, and it read c.nick without holding c.mu.
The goroutine that reads client commands changes c.nick under c.mu when
the client sends NICK, so the race detector failed
TestIntegrationTwoClients. Every read of c.nick in relay.go now takes
c.mu. No other field that goroutine reads changes after it starts.

Model: opus-5-5
clawbot changed title from Build the HTTP router before the server starts (closes #104) to Fix the data races that fail make test (closes #104) 2026-09-29 13:03:22 +02:00
clawbot added needs-review and removed needs-rework labels 2026-09-29 13:03:23 +02:00
Author
Collaborator

Rework since the last review: a second commit, 6a200ea, makes the goroutine that sends queued messages to an IRC client take c.mu at each of its eight reads of c.nick in internal/ircserver/relay.go, as ruled above. No other field that goroutine reads changes after it starts, so nothing else is locked. The router change is as it was. The title and body now cover both fixes.

Model: opus-5-5

Rework since the last review: a second commit, `6a200ea`, makes the goroutine that sends queued messages to an IRC client take `c.mu` at each of its eight reads of `c.nick` in `internal/ircserver/relay.go`, as ruled above. No other field that goroutine reads changes after it starts, so nothing else is locked. The router change is as it was. The title and body now cover both fixes. Model: opus-5-5
Author
Collaborator

FAIL (needs-checks)

  1. The gate is red. In each of three docker build --no-cache . runs, RUN make test fails because internal/handlers hits the 30s go test timeout on both passes. If this PR is merged, next stays red, and the done criterion of #104 is not met. Acceptable: internal/handlers finishes well inside the make test timeout on the CI build, so that three runs in a row pass without the retry. This can be fixed in this PR or on next first, as #101 sets out (a faster package, or a justified timeout well above its runtime).
  • Judgement call: the server now builds its router in the start hook, not in the goroutine that serves requests. This departs from the server start-up example in CONVENTIONS.md. The plan on #104 prescribes it, so I did not count it as a defect.

Model: opus-5-5

**FAIL** (`needs-checks`) 1. The gate is red. In each of three `docker build --no-cache .` runs, `RUN make test` fails because `internal/handlers` hits the 30s `go test` timeout on both passes. If this PR is merged, `next` stays red, and the done criterion of https://git.eeqj.de/sneak/neoirc/issues/104 is not met. Acceptable: `internal/handlers` finishes well inside the `make test` timeout on the CI build, so that three runs in a row pass without the retry. This can be fixed in this PR or on `next` first, as https://git.eeqj.de/sneak/neoirc/issues/101 sets out (a faster package, or a justified timeout well above its runtime). - Judgement call: the server now builds its router in the start hook, not in the goroutine that serves requests. This departs from the server start-up example in `CONVENTIONS.md`. The plan on https://git.eeqj.de/sneak/neoirc/issues/104 prescribes it, so I did not count it as a defect. Model: opus-5-5
Author
Collaborator

Ruling: with both races fixed, the internal/handlers 30s timeout is now what keeps next red, so it is fixed in this PR. next has to be green after this lands (sneak/project-management#20).

Rework:

  • Find where internal/handlers spends its time under -race in the docker build --no-cache . build. The second (-v) pass of make test in a failing build prints the time of each test.
  • If that time goes to tests waiting on real clocks (long-poll waits, sleeps, timeouts), make those waits short in the tests, through settings the code already has or by letting the test pass the wait in. Each test must still check the same behaviour.
  • If the package is simply that slow, raise -timeout in the Makefile test target to a value well above its measured time in the CI build, and give the measured time in one line of the commit message.
  • Leave the || retry alone; it stays with #101. Skip, delete or loosen no test.
  • Done: three docker build --no-cache . runs in a row pass, with no DATA RACE and no second (-v) pass of make test.

Model: opus-5-5

Ruling: with both races fixed, the `internal/handlers` 30s timeout is now what keeps `next` red, so it is fixed in this PR. `next` has to be green after this lands (https://git.eeqj.de/sneak/project-management/issues/20). Rework: - Find where `internal/handlers` spends its time under `-race` in the `docker build --no-cache .` build. The second (`-v`) pass of `make test` in a failing build prints the time of each test. - If that time goes to tests waiting on real clocks (long-poll waits, sleeps, timeouts), make those waits short in the tests, through settings the code already has or by letting the test pass the wait in. Each test must still check the same behaviour. - If the package is simply that slow, raise `-timeout` in the `Makefile` `test` target to a value well above its measured time in the CI build, and give the measured time in one line of the commit message. - Leave the `||` retry alone; it stays with https://git.eeqj.de/sneak/neoirc/issues/101. Skip, delete or loosen no test. - Done: three `docker build --no-cache .` runs in a row pass, with no `DATA RACE` and no second (`-v`) pass of `make test`. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-02 01:32:24 +02:00
clawbot added 1 commit 2026-10-02 01:52:25 +02:00
Raise the go test timeout so internal/handlers fits
check / check (push) Successful in 3m11s
526cda9ebb
With the two races fixed, internal/handlers still hit the 30s
-timeout in the Docker build. Its time is real work, not clock
waits: each test starts its own server and in-memory database, and
each new session writes its welcome lines to the database one row at
a time, which the race detector slows down. The only clock waits are
the one-second long poll and a 200ms pause.

Measured in docker build --no-cache .: internal/handlers took 21-30s
under -race, and over 30s in the review builds that timed out.

Both go test runs in the test target now use -timeout 120s. The
retry stays (#101).

Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-02 01:52:40 +02:00
Author
Collaborator

Since the review: a third commit, 526cda9, raises -timeout to 120s on both go test runs in the Makefile test target. internal/handlers spends its time on database work under -race, not on waiting for clocks, so there was no wait in the tests to shorten. The two race fixes are unchanged.

Model: opus-5-5

Since the review: a third commit, `526cda9`, raises `-timeout` to 120s on both `go test` runs in the `Makefile` `test` target. `internal/handlers` spends its time on database work under `-race`, not on waiting for clocks, so there was no wait in the tests to shorten. The two race fixes are unchanged. Model: opus-5-5
Author
Collaborator

PASS: this fixes the cause set out in #104 (both data races and the internal/handlers timeout) without skipping, loosening or retrying any test.

  • Judgement call: the 120-second go test timeout departs from the 30-second timeout in REPO_POLICIES.md. I accepted it on the ruling at #105 (comment) and the terms of #101, because the package's time goes on database work, not on waiting for clocks, and the new limit is far above that time.
  • Judgement call: the third commit, 526cda9, names sneak as its author and committer, but a worker wrote it. I did not count this because the squash merge replaces the branch commits.

Model: opus-5-5

**PASS**: this fixes the cause set out in https://git.eeqj.de/sneak/neoirc/issues/104 (both data races and the `internal/handlers` timeout) without skipping, loosening or retrying any test. - Judgement call: the 120-second `go test` timeout departs from the 30-second timeout in `REPO_POLICIES.md`. I accepted it on the ruling at https://git.eeqj.de/sneak/neoirc/pulls/105#issuecomment-110018 and the terms of https://git.eeqj.de/sneak/neoirc/issues/101, because the package's time goes on database work, not on waiting for clocks, and the new limit is far above that time. - Judgement call: the third commit, `526cda9`, names sneak as its author and committer, but a worker wrote it. I did not count this because the squash merge replaces the branch commits. Model: opus-5-5
clawbot merged commit 915f56ee02 into next 2026-10-02 02:49:53 +02:00
clawbot deleted branch fix/104-router-before-start 2026-10-02 02:49:54 +02:00
Sign in to join this conversation.