Repository navigation
ci(test): fix silent lint gate, add Windows to test matrix, tooling cleanup - #181
Conversation
|
CI result (first real run on this PR):
This is exactly the kind of thing adding the Windows leg to the matrix was |
|
Windows failure closed. Two distinct sibling defects, both real fixes, no
CI on this push: all green - lint, build x4 (mac/win/linux x2), and |
f47306a to
b341688
Compare
npm run coverage has no precoverage, so pretest never fired for it and ESLint silently never ran in CI - only the local pre-commit hook caught lint errors. A separate job shows up as its own check, independent of which npm script name the test job happens to invoke. Windows was built (build.yml, windows-2022) but never tested; the dev machine already caught a Windows-only real-clock flake CI could not see. Add windows-2022 to the test matrix, and pin the patch coverage gate to ubuntu-latest so it does not run twice on PRs.
eslint.config.js ignored .work-files/** but not .claude/**, so eslint . was scanning nested agent-worktree checkouts under .claude/worktrees/ (each one a full copy of main.js and friends) - 555 extra files, ~49k extra lines, on top of the real 139-file codebase. .gitignore had no entry for .claude/worktrees/ or .worktrees/ (the task test-pr scratch dir), so git status picked up every worktree a sub-agent left behind. .claude/commands/*.md stays tracked - only the worktrees/ subdirectory is ignored.
Neither engines nor .nvmrc existed, so nothing recorded what CI's node-version: [20, 22] matrix meant contributors should run locally. Pin to the range CI covers, with .nvmrc following build.yml's node 20 (the version that actually produces the shipped app).
sidebar.js/grid-view.js compute the TTL re-arm delay as two separate Date.now() reads in the same call stack (map.set at spawn time, then scheduleSubagentTtlTick's own read). The test mocked setTimeout but left Date.now() real, then asserted the resulting delay against a hardcoded constant with a +-50ms window - a window that only covers OS scheduling jitter between those two reads. Reproduced standalone: as little as ~55ms of jitter between the two reads (plausible under memory/CPU contention) flips the assertion. Fully replace Date.now() with an injected, advanceable clock so the delay is deterministic integer arithmetic, and tighten the assertion to the exact expected value (production's own +1ms scheduling grace, not wall-clock slack). Proven red/green: mutating one expected value by 5ms now fails the assertion, where the old +-50ms tolerance would have swallowed the same drift silently.
CI's new windows-2022 leg (this same PR) found 5 real failures in
test/activity-trace.test.js: ENOTEMPTY on rmSync right after t.close()
or setEnabled(false, ...). All five share one cause.
close(), setEnabled(false, done) and rotate() ran their continuation
from old.end(callback), which fires on the stream's 'finish' event -
data flushed, nothing more. autoClose's own fs.close() runs after
that, and only the stream's separate 'close' event means the fd is
actually released. Windows refuses to unlink or remove a directory
holding an open handle; POSIX doesn't care, which is why this was
invisible until Windows joined the test matrix. docs/activity-trace.md
already described the intended behaviour ('the callback only fires
once the OS has actually closed the file') - that description was
wrong about what .end(callback) actually waits for, which is how the
bug got written in the first place.
This is a real handle leak, not a test artifact: anywhere production
code closes the trace and then touches the same file/directory (the
Diagnostics panel's delete-file handler, app shutdown) hits the same
window on Windows. Fixed at the source - listen for 'close' before
running the continuation - rather than adding fs.rmSync's maxRetries
to the test teardown, which would have papered over the leak instead
of closing it.
Proven with a targeted probe against the real module (fs.createWriteStream
spied to capture the live stream): reverted to the old old.end(callback)
code, captured stream.fd at the moment done() fires - non-null (open)
5/5 tries. Same probe against the fix - null (closed) 5/5 tries.
test/activity-trace.test.js: 46/46 passing locally; full suite 910/910
non-skipped passing at both default and constrained concurrency.
Sibling defect to the previous commit, found by grepping the file for
the same pattern (t.close() / t.setEnabled(false)) rather than
stopping at the two tests CI actually flagged this run.
Four call sites called t.close() without awaiting it — a genuine
missing-await, not something the previous commit's event-timing fix
could paper over: no amount of waiting inside close() helps a caller
that never waits for close() to return anything. Each was immediately
followed by fs.rmSync(dir, { recursive: true, force: true }), which on
Windows can hit the same open-handle-on-teardown race independently of
the finish-vs-close fix. Two of the four are exactly the tests still
failing on windows-2022/Node 20 after that fix; the other two hadn't
flaked yet but share the identical unsafe shape.
test/activity-trace.test.js: 46/46 passing locally across 3 runs.
… the last stream Second CI run (Windows/Node 20) still failed one test after the finish-vs-close fix: 'a segment already gone drains the queue instead of jamming it'. Same ENOTEMPTY, different gap. close()/setEnabled(false, done) only waited for the fd of the stream they retire themselves. A run with several rapid rotate() calls can have more than one retired stream mid-close at once (each waiting on its own 'close' event before pruning, per the previous commit); close() returning as soon as its own stream finished left any of those still open, so the directory removal right after can still hit an open handle that has nothing to do with the stream close() knew about. Track every in-flight rotation close (pendingRotationCloses) and make close()/setEnabled(false, ...) wait for that count to reach zero too. Proven with a targeted probe against the real module (fs.createWriteStream spied to capture every stream a 40-write/rotating run opens, not just the last): with the previous, partial fix, close(done) fired while 1-2 of 41 streams still had an open fd, reproducibly (5/5 tries). With this fix, 0/41 5/5 tries. test/activity-trace.test.js: 46/46 passing locally across 5 runs.
…ut fallback Adversarial review of the previous two commits (finish-vs-close, pendingRotationCloses) confirmed the diagnosis but found no exit door: a probe that holds back only an fs.WriteStream's close event (every other event passing through untouched) showed close(cb) never calling back, hang confirmed at 4000ms -- the same pre-PR code recovers in 5ms because it only waits on finish. main.js's Diagnostics toggle awaits this with no timeout; a close that never lands freezes the toggle for the rest of the session, recoverable only by a restart. The trigger (an AV/backup lock holding the handle) is plausible, not reproduced -- the reviewer's own reservation, kept as-is: autoClose emits close close to unconditionally, so forcing its absence needed an artificial probe. What's confirmed is the missing guard, regardless of how rare the trigger turns out to be. guardedDone() fires the callback exactly once, either through the real completion or, after closeTimeoutMs (default 5s, overridable via options.closeTimeoutMs), through a bounded fallback that logs via process.emitWarning with code SWITCHBOARD_TRACE_CLOSE_TIMEOUT. Applied to both close() and setEnabled(false, ...); whichever path settles first wins, the other is a no-op.
…lly wait for a pending close
Adversarial review, MAJEUR 1: reverting each of the two previous
close/rotation commits independently left the suite fully green (46/46
locally x5, 903/903 on the full suite x3). The "5/5 tries" proof in
those commits came from a private probe (fs.createWriteStream spied,
reading .fd) that was never wired into the test file -- it proved the
claim at the moment it ran, not that a regression would be caught.
interceptOnceClose() intercepts the exact .once('close', fn)
registration production code makes, capturing fn instead of letting it
run, so a test can hold it and assert the code under test has not
resolved yet, then release it and assert it now has. This targets the
call, not the underlying stream's real close: an earlier attempt to
suppress emit('close') on the live stream directly did not work --
Node's fs.WriteStream binds its own close emission internally in a way
an outside emit() override does not reliably reach (confirmed by a
throwaway probe: intercepting a real stream's own emit never saw a
single 'close' call, the real close still fired on schedule
underneath it).
Five tests, covering the three reversions named by the review:
- close() / setEnabled(false, ...) wait for their own stream's close,
not just finish -- the direct .end(callback) revert.
- close() / setEnabled(false, ...) wait for a still-pending rotation
close, not just their own stream -- both the rotate() revert (its
own close-wait removed) and the pendingRotationCloses-wrapping
removal, since either one makes the "still pending" assertion fail
the same way.
- close() falls back to done() if the stream's close never comes
(closeTimeoutMs), and records the degraded path exactly once.
Reapplied each of the three reversions from the review in turn and
confirmed red, then restored:
- rotate() reverted to old.end(() => { pruneSegments();
onRotationCloseSettled(); }) -> 2 failures (both "pending rotation
close" tests, close() and setEnabled(false)).
- close()'s own old.once('close', ...) reverted to
old.end(() => { currentPath = null; finish(); }) -> 3 failures
(both close() tests plus the timeout test, since finish now fires
before the held stream ever matters).
- afterRotationCloses(...) wrapping removed from both finish()
definitions -> 2 failures (both "pending rotation close" tests).
51/51 passing with the fix restored.
…close too MAJEUR 2 continued: activityTrace.setEnabled now has its own bounded fallback (see the previous activity-trace.js commit), but the IPC handler awaited it directly with no timeout of its own. Belt and suspenders against a bug in that internal guard, not just against the stream close itself: if setEnabled's own fallback were ever bypassed or broken, this handler would hang for the rest of the session with no recovery short of a restart, same as before this whole PR. Narrow, single-call-site change: main.js is being touched by other in-flight PRs, so this is scoped to exactly the set-activity-trace-enabled handler, nothing else nearby. Verified with node --check (syntax) and by inspection; no dedicated runtime test added, consistent with this file's existing convention (its IPC handlers are not unit-tested elsewhere in this suite either -- see main-wiring-source-check.test.js's own header, which tests that glue is still present as text, not runtime behavior).
…not just the intercepted callback First CI run of the deterministic tests failed on windows-2022/Node 20: ENOTEMPTY on fs.rmSync, in three of the five new tests themselves. interceptOnceClose() correctly controls when activity-trace.js's own callback fires (that is what it is for), but the underlying real fs.WriteStream keeps closing on its own via autoClose regardless -- releasing the intercepted callback does not mean the real fd has been released yet. Each test's cleanup called fs.rmSync right after asserting `done`, without ever waiting for the actual streams it created to finish closing for real. Same bug class this whole PR is about, reproduced inside the new tests' own teardown. Track every stream a test creates and wait for each one's .fd to go null (autoClose's own signal that the fd is released) before rmSync, same pattern already used elsewhere in this file for exactly this reason. Re-verified all three named reversions still go red with this change: rotate() reverted (2 failures), close()'s own stream reverted (3 failures), afterRotationCloses wrapping removed (2 failures) -- same failures as before this fix, confirming it only touched cleanup timing, not what the tests actually assert. 51/51 passing locally across 3 runs.
…nted Windows quirk Second CI run: down to one failure (from three), same shape -- ENOTEMPTY on fs.rmSync, this time in "close() waits for its own stream's close" specifically, at the cleanup line, after every assertion in the test had already passed (duration_ms: 4, fd already null by the time it was checked). This is not the bug the previous commit fixed reappearing: waiting for fd to go null is necessary but not sufficient on Windows, where a real-time AV/backup scan can grab a file again briefly right after Node's own close completes and fd is nulled -- a well-documented Windows-specific aftermath of a close that already finished correctly, not evidence the close was skipped or awaited wrong. The test's own assertions (the actual thing under test) all passed before cleanup ran. fs.rmSync's maxRetries/retryDelay exist for exactly this: retrying a directory removal that races a transient lock outside the caller's control. This is the test's own temp-directory cleanup, not production code masking a leak -- the distinction matters, since retrying inside close()/setEnabled() itself would have been exactly the disguised-tolerance anti-pattern this whole review was about. Reverified the three named reversions still go red with this in place (2, 3, and 2 failures respectively, matching every prior run) -- the retry only smooths a real OS race in cleanup, it does not touch what the tests assert. 51/51 passing locally across 3 runs.
3bc1c50 to
c3b4dc7
Compare
…ot enough Third CI run, same single test, same shape again: ENOTEMPTY on rmSync in "close() waits for its own stream's close", now after 802ms (fs.rmSync's retry backoff is linear -- maxRetries:5, retryDelay:50 sums to 750ms, meaning all 5 retries ran and the lock still had not cleared). Not a different bug: the previous commit's diagnosis holds, the budget was just too small for how long this runner's transient lock can last. maxRetries:10, retryDelay:100 (linear backoff, ~5.5s worst case, paid only when a retry is actually needed -- the common case is one immediate successful rmSync with no added cost). Reverified: the three named reversions still go red (spot-checked here against the pendingRotationCloses removal, the subtlest of the three); 51/51 green with the fix restored.
…s .fd
Fourth CI run, same single test again, now failing all the way
through a 5.5s retry budget (duration_ms: 5593) -- not a transient
lock clearing eventually, something wrong with the wait itself.
stream.fd reads the same way (undefined) both before a stream has
ever opened and after it has fully closed -- fs.WriteStream assigns
fd asynchronously on its own 'open' event, not synchronously at
construction. In "close() waits for its own stream's close" nothing
is ever written before close() runs, so the stream can still be
mid-open when the .fd check runs; reading undefined there means
"not open yet", not "already closed", and the wait returned true
immediately for the wrong reason -- exactly why every prior run
showed this specific test resolving to done in a few milliseconds and
still hitting ENOTEMPTY. The other four new tests all call t.trace()
before touching close(), which forces a real write and therefore a
real completed open, masking the same defect in their own cleanup by
coincidence of ordering, not because they were actually correct.
Replaced the .fd poll with a genuine, unintercepted s.on('close', ...)
listener per stream (interceptOnceClose only overrides .once, not
.on, so this reaches the real event regardless of what production
code does) and wait for that instead. This is what the retry-budget
commits should have targeted from the start; they were retrying
against a condition that was already reporting true when it should
not have been.
Reverified the three named reversions still go red: rotate() reverted
(2 failures), close()'s own stream reverted (3 failures),
afterRotationCloses wrapping removed (2 failures) -- unchanged from
every prior verification. 51/51 green across 3 runs.
|
Adversarial review addressed, CI green (all jobs completed, not just triggered). MAJEUR 1 (tests didn't discriminate) — closed. interceptOnceClose()
51/51 green with the fix restored, every time. Getting there took three more rounds than expected, each a real bug in
MAJEUR 2 (no exit door on the close wait) — closed. MINEUR 3 — corrected. PR body no longer quotes point-in-time file/ CI, this push, all jobs completed: |
…(false, ...)
Fourth mutation from the review, proven invisible before this commit:
setEnabled(false, ...) and close() build the same guardedDone/finish
shape independently, but only one fallback test existed and it
covered close() only. Removing setEnabled's exit door entirely
(finish = () => afterRotationCloses(() => { if (done) done(); }),
dropping guardedDone) left the full suite green -- the gap mattered
more than the count suggested: main.js's shutdown path calls close()
with no callback at all, so its guard never actually runs in
production. The only caller that ever passes one is the
set-activity-trace-enabled IPC handler, which calls setEnabled. The
tested path was the one production doesn't use; the used path was
untested.
Mutation applied verbatim from the review (setEnabled's finish only,
close() untouched, verified with node --check and a grep for the
remaining single guardedDone/guard.settle() pair in close()): 51/51 ->
1 failure, the new test, "must recover with a bounded fallback, not
hang forever" / actual false, expected true. Restored from a
byte-exact pre-mutation copy (no git checkout --): 52/52 across 3 runs.
Also documents, per the review's two informational findings -- neither
changed:
- currentFile() stays stale during the degraded window on purpose:
clearing it early would remove the protection against the panel
deleting a file that might still be open, which is exactly what
currentPath's lifetime exists for. Cosmetic UI staleness is the
smaller cost.
- guardedDone's timer is unref()'d, so a bare process with no other
handle can exit before it fires. Not a concern in the Electron main
process (always has other open handles), but an implicit assumption
worth stating for any future caller in a shorter-lived process.
|
Fourth mutation (setEnabled(false, ...)'s exit door, distinct from close()'s Mutation applied, exactly as specified — const finish = () => afterRotationCloses(() => { if (done) done(); });(dropping the Result before the new test: 52 tests, only the new The two informational observations — documented, not changed:
CI on this push, all jobs completed: |
Summary
Four independent tooling defects, no production code touched (see the
follow-up section below for two production fixes added after review).
test.ymlcallsnpm run coverage; npm onlychains
pretestin front oftest, so thepretest-> lint hook neverfired for
coverage. Fixed with a dedicatedlintjob instead of aprecoveragescript - a separate job is a visible check in the PR listand can't be silently orphaned by a future script rename the way the
npm-hook chain was.
build.ymlalready buildswindows-2022;test.ymlonly ranubuntu-latest. Addedwindows-2022to the test matrix. The patch-coverage gate step is pinned to
ubuntu-latestso it doesn't run twice on Node 22 PRs..claude/**was missing fromeslint.config.js's ignore list (.work-files/**was already there),so
eslint .walked every nested worktree under.claude/worktrees/-555 extra files / ~49k extra lines on top of the real codebase. Verified
with a throwaway fixture (create a duplicate
main.jsunder.claude/worktrees/<name>/, confirm it's linted before the fix and goneafter) rather than a fixed file count:
main's own file count moves withevery merge, so a point-in-time number here would just go stale (it
already has, twice, since this PR opened).
.gitignoregained.claude/worktrees/and.worktrees/(task test-pr's scratch dir) -.claude/commands/*.mdstays tracked, confirmed withgit check-ignore.engines/.nvmrc. Addedengines.nodematching the CI matrix(20-22) and
.nvmrcpinned to 20 (the version build.yml actually ships).test/dom-subagent-ttl-tick.test.js(the only test file in scope per the task brief). It mocked
setTimeoutbut left
Date.now()real; the TTL re-arm delay is computed from twoseparate
Date.now()reads in the same call stack, and the test assertedthe result against a hardcoded constant with a +-50ms tolerance - a
window that only exists to absorb OS scheduling jitter between those two
reads. Reproduced standalone: ~55ms of injected jitter between the reads
flips the assertion, well within what memory/CPU contention can cause.
Fixed by injecting a fully controlled, advanceable clock and tightening
the assertion to the exact expected value. Proven red/green by mutating
one expected value by 5ms (fails) and reverting (passes).
Concurrency measurement (no code change applied)
Investigated whether
node --test's default one-worker-per-coreconcurrency (8 here) explains the reported intermittent failures, per the
task brief. Measured on the shared dev machine (3 other agents active
throughout, free RAM fluctuating 0.4-3.5 GB over the session):
--test-concurrency=16/6 full runs clean at both extremes, and default was consistently ~2.6x
faster. No concurrency bound applied anywhere (package.json, Taskfile, or
CI): the data doesn't show a problem, and a bound imposed without evidence
would only slow every run down. This does not clear the hypothesis for
the deeper tail - I deliberately never launched a run below ~2.3 GB free,
which is where the previous OOM kills (1.9 GB) actually happened; doing
that deliberately on a machine three other agents were using was the one
thing this investigation was trying to avoid causing. The specific flaky
tests named in the brief (
trigger-watcher.test.js: W7/W4/chain/submit-verify) use real, un-mocked
setTimeoutwith tight windows(20-350ms) - structurally the population a concurrency bound would help,
as opposed to
dom-subagent-ttl-tick.test.js's design flaw (fixed above).That file is out of scope here (owned by another in-flight PR) and was
left untouched.
Windows CI failure found by this PR's own matrix (fixed here)
Adding
windows-2022to the test matrix (above) surfaced 5 real failuresin
test/activity-trace.test.js,ENOTEMPTY: directory not emptyonfs.rmSyncright afterclose()/setEnabled(false, ...), Node 20 only.Root cause:
close(),setEnabled(false, ...)androtate()signalledcompletion via
old.end(callback), which fires on the stream'sfinishevent (data flushed) - not
close(fd actually released byautoClose'sinternal
fs.close()). Windows refuses to remove a directory holding anopen handle; POSIX doesn't care, which is why this was invisible before
the Windows leg existed. A second, narrower gap in the same mechanism: a
run with several rapid rotations can have more than one retired stream
mid-close at once, and
close()only waited for its own stream -pendingRotationClosestracks every in-flight rotation close now. Aseparate, purely test-side bug (four
t.close()call sites never awaitedit before
fs.rmSync) was fixed alongside it. Fixed inactivity-trace.jsand
test/activity-trace.test.js;docs/activity-trace.mddocuments both.Adversarial review follow-up
An independent review of the above confirmed the
finish-vs-closediagnosis but found the non-regression guarantee and the wait itself both
wanting. Addressed here, not deferred:
The tests didn't discriminate. Reverting either of the two
activity-trace.jscommits independently left the full suite green(46/46 locally x5 per revert, 903/903 on the full suite x3). The
5/5 triesproof in those commits' messages came from a private probe(
fs.createWriteStreamspied, reading.fd) that was never wired intotest/activity-trace.test.js- it proved the claim at the moment it ran,not that a regression would be caught.
interceptOnceClose()(new, in thetest file) now intercepts the exact
.once('close', fn)registrationproduction code makes, holds it, and asserts the callback under test has
not resolved until it's released. Reapplied each of the three exact
reversions named by the review and confirmed red, then restored:
rotate()->old.end(() => { pruneSegments(); onRotationCloseSettled(); })close()andsetEnabled(false, ...))close()'s ownold.once('close', ...)->old.end(() => { currentPath = null; finish(); })close()tests, plus the timeout-fallback test (finish now fires before the held stream matters at all)afterRotationCloses(...)wrapping removed from bothfinish()definitions (lines then 342/375)51/51 passing with the fix restored after each check.
No exit door on the
closewait. A probe that holds back only anfs.WriteStream'scloseevent (every other event verified to passthrough untouched) showed
close(cb)never calling back - hang confirmedat 4000ms; the same probe against the pre-PR code (waiting on
finish)recovers in 5ms.
main.js:set-activity-trace-enabledawaited this with notimeout of its own - a
closethat never lands would freeze theDiagnostics toggle for the rest of the session, recoverable only by a
restart. The trigger (a Windows AV/backup lock holding the handle) is
plausible, not reproduced - kept as the reviewer's own reservation,
verbatim:
autoCloseemitscloseclose to unconditionally, so forcingits absence needed an artificial probe. What's confirmed is the missing
guard, independent of how rare the trigger turns out to be.
Fixed with a bounded fallback, not a wider tolerance:
close()andsetEnabled(false, ...)now fire their callback exactly once, eitherthrough the real completion or, after
closeTimeoutMs(default 5s,overridable via
options.closeTimeoutMs- the new timeout test uses 30ms),through a fallback that logs via
process.emitWarningwithcode: SWITCHBOARD_TRACE_CLOSE_TIMEOUT.main.js's handler adds its ownindependent 8s bound around the whole call - belt and suspenders against a
bug in the library's own guard, not just against the stream itself.
Degraded (a stray directory entry, a possibly-missed prune) beats the
toggle hanging with no recovery short of a restart.
Stale numbers. The file/warning counts quoted for the ESLint fixture
and the pre-existing lint baseline drifted as
mainadvanced underneaththis PR (measured again just before this update: 271 warnings / 0 errors,
148 files linted - not the 268/140 originally quoted, and not the 271/142
the review measured either, one more merge later). The summary above now
describes the fixture methodology instead of a point-in-time count for
exactly that reason.
Verified vs. unverified
Verified locally: eslint fixture behavior (create/lint/remove, file
present before the
.claude/**ignore and absent after),.gitignorecheck-ignorebehavior for both new patterns,.nvmrc/package.jsonJSONvalidity and LF line endings, YAML parses via
js-yaml,npm run lint0errors throughout (271 warnings as of this update, pre-existing and
unchanged by this PR), the ttl-tick test file mutation-tested red/green,
and the three adversarial-review reversions above each reproduced red then
restored green.
node --check main.jsfor the new IPC-handler timeout.Not verified, only confirmed at first CI run: the new
lintjobactually appearing as a separate check, the
windows-2022leg of the testmatrix actually running
npm ci+npm run coveragesuccessfully, and thepatch-coverage gate firing exactly once on a real PR. (All three have since
been confirmed on this PR's actual CI runs - see the latest run for the
current commit.)