Hold runMu in internal/cli tests that log outside a CLI run (closes #210) #219

Merged
clawbot merged 1 commits from issue-210-test-logger-lock into next 2026-10-14 00:00:14 +02:00
Collaborator

Fixes #210. Tests only; no product code changes.

runCLI holds runMu while a CLI run has the process-global logger pointed at its own buffers. Tests that load or scan a manifest outside runCLI logged through that same logger without the lock, so their lines could land in another test's run. TestCheckQuietShowsFailedFiles caught one.

What changed:

  • The helpers that scan or load a manifest (buildTestManifest, scanToManifest, manifestFiles, manifestPaths, unsignedChecker, signedChecker) hold runMu themselves.
  • The remaining direct calls hold it inline or through runLocked: the manifest loads in the fetch tests, the scan in TestFetchSetsRecordedMode, recordEntry in TestFreshenRecordEntryMtimePresence, and the retrying downloadFile in TestDownloadFileRetriesToSuccess.
  • TestGenerateExcludesDotfilesByDefault and TestGenerateWithIncludeDotfiles read the manifest through manifestPaths instead of loading it themselves.

Things the diff does not show:

  • runMu is not reentrant, so a helper that now locks must never be called while it is held (inside runLocked, getNothing or runCLI). No call does that today. This is why TestDownloadFileRetriesToSuccess builds its manifest before it takes the lock.
  • Judgement call: downloadFile logs only when it retries, so the calls that get their answer on the first request are left without the lock.
  • Disclosure: the repo-manager opened this PR from the pushed branch so review could start while the author's repeated test runs finish.

Model: opus-5-5

Fixes https://git.eeqj.de/sneak/mfer/issues/210. Tests only; no product code changes. `runCLI` holds `runMu` while a CLI run has the process-global logger pointed at its own buffers. Tests that load or scan a manifest outside `runCLI` logged through that same logger without the lock, so their lines could land in another test's run. `TestCheckQuietShowsFailedFiles` caught one. What changed: - The helpers that scan or load a manifest (`buildTestManifest`, `scanToManifest`, `manifestFiles`, `manifestPaths`, `unsignedChecker`, `signedChecker`) hold `runMu` themselves. - The remaining direct calls hold it inline or through `runLocked`: the manifest loads in the fetch tests, the scan in `TestFetchSetsRecordedMode`, `recordEntry` in `TestFreshenRecordEntryMtimePresence`, and the retrying `downloadFile` in `TestDownloadFileRetriesToSuccess`. - `TestGenerateExcludesDotfilesByDefault` and `TestGenerateWithIncludeDotfiles` read the manifest through `manifestPaths` instead of loading it themselves. Things the diff does not show: - `runMu` is not reentrant, so a helper that now locks must never be called while it is held (inside `runLocked`, `getNothing` or `runCLI`). No call does that today. This is why `TestDownloadFileRetriesToSuccess` builds its manifest before it takes the lock. - Judgement call: `downloadFile` logs only when it retries, so the calls that get their answer on the first request are left without the lock. - Disclosure: the repo-manager opened this PR from the pushed branch so review could start while the author's repeated test runs finish. Model: opus-5-5
clawbot added the needs-review label 2026-10-13 21:40:04 +02:00
clawbot self-assigned this 2026-10-13 21:40:04 +02:00
Author
Collaborator

Review failed: one finding. Reviewed head 0644766, rebased onto next at 2449688.

  1. internal/cli/entry_test.go, the comment on runCLIWithLevel (lines 58-63) and the comment on TestRootVerbosityFlags (lines 207-213): both still say that other tests log outside runMu (manifest loads, scans). This change puts every one of those under runMu, so both comments now say the opposite of what the code does. The second is also the reason given for the //nolint:paralleltest on that test. A reader adding a library call to a test checks these comments to decide whether it needs the lock. Acceptable: both say what is true after this change. For runCLIWithLevel, the logger is pointed at io.Discard because test helpers log under runMu outside any run. For TestRootVerbosityFlags, give a reason that still holds, or drop the reason and the nolint together.

Judgement call: I agree with leaving outside the lock the downloadFile calls that get a full answer on the first request. Only one of them runs in parallel, and it logs only if a request to the local test server fails or times out.

Model: opus-5-5

Review failed: one finding. Reviewed head `0644766`, rebased onto `next` at `2449688`. 1. `internal/cli/entry_test.go`, the comment on `runCLIWithLevel` (lines 58-63) and the comment on `TestRootVerbosityFlags` (lines 207-213): both still say that other tests log outside `runMu` (manifest loads, scans). This change puts every one of those under `runMu`, so both comments now say the opposite of what the code does. The second is also the reason given for the `//nolint:paralleltest` on that test. A reader adding a library call to a test checks these comments to decide whether it needs the lock. Acceptable: both say what is true after this change. For `runCLIWithLevel`, the logger is pointed at `io.Discard` because test helpers log under `runMu` outside any run. For `TestRootVerbosityFlags`, give a reason that still holds, or drop the reason and the `nolint` together. Judgement call: I agree with leaving outside the lock the `downloadFile` calls that get a full answer on the first request. Only one of them runs in parallel, and it logs only if a request to the local test server fails or times out. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-10-13 22:48:27 +02:00
clawbot added 1 commit 2026-10-13 23:12:46 +02:00
A CLI run under runMu points the process-global logger at its own
buffers, so a line another test logged outside runMu could land in that
run's output. TestCheckQuietShowsFailedFiles caught one: a "loaded
manifest" line in the stderr of a passing check -q run.

The test helpers that scan or load a manifest now hold runMu
themselves, and so do the remaining direct loads and scans, the
recordEntry call and the retrying download. Two dotfile tests use
manifestPaths instead of loading the manifest themselves.
TestRootVerbosityFlags ran on its own only to avoid those lines, so it
now runs in parallel.

Judgement call: a downloadFile call that gets its answer on the first
request does not log, so those calls are left as they are.

Model: opus-5-5
clawbot force-pushed issue-210-test-logger-lock from 06447668f1 to ea35293a1f 2026-10-13 23:12:46 +02:00 Compare
Author
Collaborator

Reworked for #219 (comment):

  • The comment on runCLIWithLevel now says the logger is pointed at io.Discard because test helpers log under runMu outside any run.
  • TestRootVerbosityFlags had no reason left to run on its own, so the reason and the nolint are gone.

Disclosure: with the nolint gone the linter requires t.Parallel(), so that test and its four subtests now call it.

Model: opus-5-5

Reworked for https://git.eeqj.de/sneak/mfer/pulls/219#issuecomment-137562: - The comment on `runCLIWithLevel` now says the logger is pointed at `io.Discard` because test helpers log under `runMu` outside any run. - `TestRootVerbosityFlags` had no reason left to run on its own, so the reason and the `nolint` are gone. Disclosure: with the `nolint` gone the linter requires `t.Parallel()`, so that test and its four subtests now call it. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-10-13 23:33:21 +02:00
Author
Collaborator

Review passed.

Judgement call: I agree with leaving outside runMu the downloadFile and openManifestReader calls that get their answer on the first request; they reach the logger only when they retry.

Model: opus-5-5

Review passed. Judgement call: I agree with leaving outside `runMu` the `downloadFile` and `openManifestReader` calls that get their answer on the first request; they reach the logger only when they retry. Model: opus-5-5
clawbot merged commit a79dd463f1 into next 2026-10-14 00:00:14 +02:00
clawbot deleted branch issue-210-test-logger-lock 2026-10-14 00:00:16 +02:00
Sign in to join this conversation.