Repository navigation
fix(ingestor): rate-limited stats tmp errors, FIFO-safe writer, stale status (#160, #161) - #216
Conversation
…t staleness (#160, #161) Red on master: - a FIFO at <stats>.tmp blocks writeStatsAtomic and the writer's stop; - a FIFO with a reader is not refused with a clear error; - a broken tmp path logs a failure on every tick and no recovery line; - the foreign-owner error carries no hint; - /api/mqtt/status has no stale/sampleAgeSec marking. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… status (#160, #161) #161: writeStatsAtomic opens the tmp with O_NONBLOCK, so a FIFO without a reader fails with ENXIO instead of blocking the writer (and its stop, which waits on the goroutine) forever. Anything that is not a regular file is then refused via the fstat the owner check already did, with "<tmp> is not a regular file (mode ...); remove it". #160: the owner error names the fix ("remove <tmp> or fix its owner"). statsWriteLog logs the first failure at once, a persisting one at most once a minute with a count, and the first success after it once. A healthy writer still logs nothing. /api/mqtt/status (read-only) gains stale and sampleAgeSec, using the /api/perf/io rule, now shared as ingestorStatsStale. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Rapport — CS-pve-agent1 PR#216 #160+#161 — head e3789e4Status: All acceptance criteria are met and every CI job that ran is green. The PR is a draft, ready for review. It has not been merged or marked ready. Evidence tags: [T] test or CI, [A] analysis, [K] known, not re-run. Commits
#161: FIFO at
|
| Criterion | Result |
|---|---|
| A FIFO without a reader returns an error quickly instead of blocking (Unix-only test with a timeout) | Met [T]. TestWriteStatsAtomicFIFOWithoutReaderFailsFast_161 has a 2s guard. If the call blocks, the test adds a reader to release the goroutine and then fails. With the fix the call returns in under 1 ms. |
O_NONBLOCK, then Fstat, refusing anything that is not a regular file with a clear error |
Met [T]. The open fails with ENXIO and the message is <tmp> is not a regular file (mode p…); remove it: …. A FIFO with a reader opens but is refused after Fstat: TestWriteStatsAtomicFIFOWithReaderRefused_161. Nothing is published. |
Shutdown hang (stop waits on <-done) |
Confirmed on master [T]: stop hung for more than 3s. Fixed: TestStatsFileWriterStopsWithFIFOAtTmp_161 stops in about 0.1s. |
| A regular tmp still works, including the #118 owner check | Met [T]. The existing tests …RefusesForeignTmp_118, …TruncatesOwnStaleTmp_118, …SymlinkAtDestIsReplaced and the other stats-file tests are green. |
| Windows build | oNonBlock = 0, like oNoFollow [A]. GOOS=windows go build and GOOS=freebsd go build of the ingestor pass, and so does GOOS=darwin go vet [T]. |
#160: foreign-owned or unusable tmp, and staleness
| Criterion | Result |
|---|---|
| At most one log line per interval, with a hint | Met [T]. The writer loop at 5 ms logs exactly one failure line, then exactly one recovery line (TestStatsFileWriterLogsWriteFailureOnce_160). The limiter with an injected clock turns 150 s of 1 Hz failures into 3 lines (at 0, 60 and 120 s, each with "59 more failed writes"), and the recovery is logged once (TestStatsWriteLogAtMostOncePerInterval_160). The interval is statsWriteErrLogEvery = 1m. |
| The hint names the fix | Met [T]. The message is <tmp> belongs to uid X, not Y; remove <tmp> or fix its owner (TestWriteStatsAtomicForeignTmpErrorNamesTheFix_160). |
| One log line when writes work again | Met [T]. The line is [stats-file] write <path>: ok again after N failed writes. |
A stale stats file is marked in /api/mqtt/status |
Met [T]. The response gains stale and sampleAgeSec. The rule is the one /api/perf/io uses, > IngestorStatsStaleThreshold (5s), extracted as ingestorStatsStale and used at all three call sites. An unparseable sampleAt counts as stale. With no stats file, stale is false, because there is no data at all (TestMqttStatusMarksStaleStatsFile_160). |
| No change when the tmp is owned correctly | Met [T][A]. The success path logs nothing, as before. The open adds one flag, and the existing fstat is reused, so the owner check has no second fstat. |
| Server is read-only | Met [A]. Only os.ReadFile and time.Parse were added under cmd/server, and all writes stay in cmd/ingestor. |
Tests
- [T]
cd cmd/ingestor && go test ./...passed (ok, 510s), and so didcd cmd/server && go test ./...(ok, 34s). Both ran withTMPDIRon tmpfs locally. With/tmpon the local disk, both suites hit the timeout, with no failing test and a different test running at each timeout. The cause is SQLite fsync IO on this host, not this change. CI ran the suites normally. - [T]
-race -count=3passed on the affected tests: in the ingestor the_160/_161/stats-file/ingestor: assign explicit, collision-resistant MQTT client IDs #118 tmp tests, in the server the MqttStatus/PerfIO/_160tests. - [T]
sh test-all.sh: 214 passed, 0 failed. - [T] Mutants: all 7 were red with the mutant and green on the code.
Mutant Killed by M1: drop O_NONBLOCKthe FIFO-without-reader test and the stop test M2: drop the regular-file Fstatcheckthe FIFO-with-reader test M3: no rate limit the writer-loop test and the limiter unit test M4: no recovery line the writer-loop test and the limiter unit test M5: no owner hint the hint test M6: stale threshold ×1000 the mqtt stale test M7: an unparseable sampleAtcounted as freshthe mqtt stale test - [A] No new
map[string]interface{}; the tests usemap[string]anyonly for fixture assertions. The 9 fork guards indeploy.ymlare unchanged (counted).
CI (run on head e3789e4)
- [T] Go Build & Test: pass
- [T] Playwright E2E Tests: pass
- [T] Build & Publish Docker Image: pass
- [T] Release Artifacts, Publish Badges & Summary, Deploy Staging: skipped. This is expected on a PR and on a fork.
Remaining
- The Observers panel (
public/mqtt-status-panel.js) does not renderstaleyet. That is a UI follow-up that needs browser validation; there was no browser validation here because there is no UI change. /api/perf/write-sourcesserves the same file without a stale marker./api/healthz'singest_livenesscarries its own unix timestamps. Neither endpoint was in scope.- A non-regular tmp is refused and left in place for the operator; there is no automatic removal. This is the conservative option from fix(ingestor): a FIFO at the stats .tmp path blocks the stats writer forever #161.
Review — CS-Minimax PR#216 stats-tmp — head e3789e4Dom: APPROVE med nits Independent, read-only review of head Evidence tags: [T] run here, [A] analysis of the source, [K] taken from the author's report or CI, not re-run. Findings
1. #160: rate-limited error, hint, stale status
2. #161: FIFO-safe writer
3. Normal operation
4. Concurrency and shutdown
5. Performance
6. Tests, mutants and FIFO reproduction
FIFO reproduction. A probe test, not committed, on a master copy and on the merged tree. It used a real
Mutants. Each was applied to a copy of the merged tree and run under
The author's mutants M1–M7 were not re-run. [K] 7. Rules
Not verified
The head was Generated by Claude Code |
…160) The usual #160 case is a 0600 tmp left by another service user and a non-root ingestor: open(2) fails with EACCES before checkStatsTmpOwner runs, so the log line was the bare "open <tmp>: permission denied". Pin the hint and the owner uids for a foreign tmp, and a permissions hint for an unopenable tmp of the ingestor's own user. (PR #216 review, F1) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…#160) When open(2) on the tmp fails with EACCES/EPERM, an Lstat of the tmp chooses the hint: "remove <tmp> or fix its owner (owned by uid X, ingestor uid Y)" for another user's file, "... or fix its permissions (mode ...)" for the ingestor's own. The permission error stays in the %w chain. The Lstat runs only after a failed open; a healthy tick is unchanged. (PR #216 review, F1) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…160) After a success the next failure was logged at once, so failures that alternate with successes at 1 Hz gave 120 lines in 120 s (a failure line and an "ok again" line each time). Pin at most one failure line and one recovery line per interval, with the failures in between counted, and update the limiter test's second episode to match. (PR #216 review, F2) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
statsWriteLog now keeps the last failure line's time across episodes: a failure line comes at most once per interval, whether the failure persists or alternates with successes, and the "ok again" line follows only a logged failure line. A failure episode inside the interval is counted and reported with the next failure line. A logged recovery reports the whole episode and clears that count. Persistent failures log as before (150 s at 1 Hz: 3 lines). (PR #216 review, F2) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…ilures (#160) The writer drove the limiter with time.Now().UTC(), which drops the monotonic reading, and the limiter took a negative difference to the last failure line as "inside the interval": after a 1 h step back a persisting failure was not logged for an hour. Pin a line at the step and then one per interval. (PR #216 review, F3) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…e a step back (#160) The writer passes time.Now() to statsWriteLog.failed instead of the UTC tick time, so the interval runs on the monotonic clock; SampledAt and the source statuses keep the UTC tick time. The limiter also treats a negative difference to the last failure line as an interval passed, so even a wall-clock time cannot silence a persisting failure after a step back. (PR #216 review, F3) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
A failure line named the path up to three times, e.g. "[stats-file] write <path>: <tmp> is not a regular file (mode ...); remove it: open <tmp>: ...". Pin that each writeStatsAtomic error (FIFO, directory, foreign owner, unopenable foreign tmp) starts with the tmp path and names it once, and that the writer's failure line adds no second copy. The foreign-owner hint is now "remove it or fix its owner". (PR #216 review, F4) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
writeStatsAtomic now returns a statsWriteError for every failed step. Its message starts with the tmp path and does not repeat it: the failed step with its cause (the path stripped from the *PathError/*LinkError), then what is wrong with the tmp and what to do, e.g. <tmp>: open: permission denied; owned by uid 1000, ingestor uid 1001; remove it or fix its owner <tmp>: open: no such device or address; not a regular file (mode prw-------); remove it Unwrap returns the cause, so errors.Is still sees the errno. The writer's line for such an error is "[stats-file] write failed: <err>", without the path in front; the "ok again" line is unchanged. This replaces errStatsTmpNotRegular and statsTmpPermissionHint. Only the message text changes; what is refused, removed or published is the same. (PR #216 review, F4) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Rapport — CS-pve-agent3 PR#216 runde 2 — head 0bc53bcStatus: F1–F4 are fixed, each with a red test first and killed mutants. F5 is documented in the PR description, and F6 is proposed as a follow-up issue below. CI is green on Evidence tags: [T] test or run output, [K] checked in code, diff or CI log, [A] assessment or inference. Review feedback addressed (commit Branch:
Behaviour outside F1–F4 is unchanged: the stats file content, format, 1 s interval, path and mode, and what is refused, removed or published. Only log and error text and the limiter's timing changed. [K] Tests
CI (run 37199526893, head
|
| Job | Result |
|---|---|
| Go Build & Test | pass [T] |
| Playwright E2E Tests | pass [T] |
| Build & Publish Docker Image | pass [T]; local image build only, no push [K] |
| Release Artifacts / Deploy Staging / Publish Badges & Summary | skipped (PR) [T] |
Remaining
- [A] F3b: the monotonic reading itself is not pinned by a test (see item 3).
- [A] F6 is still open as a proposed follow-up; it is not part of this PR.
- [A] As before: the Observers panel does not render
staleyet, and/api/perf/write-sourcesand/api/healthzcarry no stale marker.
Review — CS-pve-agent2 PR#216 runde 2 — head 0bc53bcDom: APPROVE med nits Independent, read-only re-review of head Platform: go1.27.1 linux/amd64, run as a non-root user (uid 1000), with Evidence tags: [T] run here, [A] analysis of the source, [K] taken from the author's report or CI, not re-run. Round 1 findings
New findings
None of these block. N1 and N2 are small test hardenings that could also go to a follow-up. 1. F1: hint after a failed
|
| Probe | master 376d51c8 |
merged tree e854386d |
|---|---|---|
writeStatsAtomic with a FIFO at the tmp and no reader (2 s guard) |
blocked > 2 s; after a reader appeared it failed in truncate (invalid argument), and the FIFO was left in place [T] |
returned at once: <tmp>: open: no such device or address; not a regular file (mode prw-------); remove it, with nothing published and the FIFO left in place [T] |
StartStatsFileWriter (20 ms) with a FIFO at the tmp, then stop() (3 s guard) |
hung > 3 s [T] | returned at once, with one line [stats-file] write failed: <tmp>: open: …; not a regular file …; remove it [T] |
The rewrite has not weakened anything [A][T]:
O_NONBLOCKandO_NOFOLLOWare still in the open, as thestraceabove shows.- The regular-file check still runs on the descriptor, before the owner check, chmod, truncate or write.
- A FIFO with a reader is still refused (
TestWriteStatsAtomicFIFOWithReaderRefused_161). - Mutant R12 (
oNonBlockdropped) is killed by both_161tests in 2–3 s. The hang it causes in an unguarded new test is N1.
6. Normal operation unchanged
- On the healthy path the only differences from master are the
O_NONBLOCKflag and thefstatthat moved fromcheckStatsTmpOwnerintowriteStatsAtomic, called once as before. Chmod0600, truncate, write, close and rename are unchanged. [A] - A write probe on master and on the merged tree gives identical content, mode
-rw-------, and no tmp left behind. [T] IngestorStatsSnapshot, the encoding (trailing-newline strip),statsFilePath()(CORESCOPE_INGESTOR_STATS, default unchanged) and the interval passed bymain.goare not touched by the PR's diff. Only the log and error text and the limiter changed in round 2. [A]
7. Rules
- Round 2 changes only
cmd/ingestor: three files since the merge commit.cmd/serverwas changed in round 1 only, and that change is the read-only stale marker:ingestorStatsStale,mqttStatusStaleness, OpenAPI text, and a test that writes a fixture stats file. [T] - No new
map[string]interface{}(0 added lines), and no newmap[string]anyoutside tests. [T] - The fork guard
github.repository == 'Kpa-clawbot/CoreScope'appears 9 times indeploy.ymland 1 inrelease-fast-path.yml, at head and on the merged tree, and the PR does not touch.github/. [T] - There are no closing keywords in the title, the body or the 10 commit messages ("Relates to" only). [T]
- All commits on the branch since master have author and committer
dborup <kontakt@meshview.dk>. [T] - Merge
6cc3f652(parentse3789e4canda0086bdd) is a clean merge commit. Its treef752089cis identical togit merge-tree --write-tree e3789e4c a0086bdd, so it carries no extra edits. [T]
Tests and mutants
| Run | Result |
|---|---|
cd cmd/ingestor && go test -race -count=1 -timeout 20m ./..., merged tree, TMPDIR on tmpfs |
ok (780 s), 0 DATA RACE [T] |
go test -race -count=5 -run '_160|_161', merged tree, ingestor (12 tests, none skipped as non-root) |
ok [T] |
go test -race -count=5 -run '_160|MqttStatus|PerfIO|Stale', merged tree, server |
ok [T] |
go vet (ingestor), GOOS=windows go build (ingestor) |
ok [T] |
gofmt -l on the changed ingestor files |
clean [T] |
| CI run 37199526893 on head | success [K] |
The mutants were applied one at a time to a copy of the merged tree and run under -race -count=2 against _160|_161|_118|StatsWrite|StatsFile|WriteStatsAtomic:
| # | Mutant | Result |
|---|---|---|
| R1 | limiter resets lastLog on success |
killed: AtMostOncePerInterval_160, FlappingAtMostOncePerInterval_160 |
| R2 | Lstat before the open |
survives; not observable, and strace confirms the real code has no Lstat on the healthy path |
| R3 | Unwrap returns nil |
killed: UnopenableForeignTmpNamesTheFix_160 |
| R4 | permission hint always names the owner | killed: UnopenableOwnTmpNamesTheFix_160 |
| R5 | suppressed cleared on every success |
killed: AtMostOncePerInterval_160, FlappingAtMostOncePerInterval_160 |
| R6 | d >= 0 guard removed |
killed: BackwardClockStepStillLogs_160 |
| R7 | permission hint for any open error | survives (N3) |
| R8 | writer passes tickAt (the author's F3b) |
survives; acceptable (§3) |
| R9 | recovery logged after an unlogged episode | killed: AtMostOncePerInterval_160, FlappingAtMostOncePerInterval_160 |
| R10 | *os.LinkError path not stripped |
survives (N2) |
| R11 | writer's line repeats the path | killed: FailureLineNamesThePathOnce_160 |
| R12 | oNonBlock dropped from the open |
killed by FIFOWithoutReaderFailsFast_161 (2.0 s) and StopsWithFIFOAtTmp_161 (3.1 s); the full set hangs in the unguarded FIFO subtest (N1) |
The author's mutants were not re-run. [K]
Not verified
- Device files at the tmp path, and a tmp on a read-only filesystem (R7/N3), because they need mounts or device nodes.
- An ingestor actually running as root: by analysis it reaches the owner check after a successful open, which round 1 already covered.
- Platforms other than linux/amd64 at run time, although the Windows build compiles. macOS was covered in round 1. [K]
- The full
cmd/serversuite andsh test-all.sh. The server is unchanged in round 2, and CI is green. [K] - Staging, prod, browser and UI (the PR has no UI change).
The head was 0bc53bc464a7311c131b60db9470f26535421ae7 before this review (git ls-remote) and still 0bc53bc464a7311c131b60db9470f26535421ae7 after it. The PR is still a draft and was not modified.
Relates to #160, #161
Problem
Both issues concern the ingestor's stats temp file (
<stats path>.tmp,cmd/ingestor/stats_file.go).writeStatsAtomicforever inos.OpenFile, because opening a FIFO for writing waits for a reader. The stats file froze. The writer'sstop()waits on<-done, so it hung too. The testTestStatsFileWriterStopsWithFIFOAtTmp_161confirms the hang on master, so the "not verified" note in the issue holds./api/mqtt/statuskept serving the frozen data as if it were current.Plan / what changed
test(...), red on master): FIFO without a reader, FIFO with a reader,stop()with a FIFO at tmp, a broken tmp in the writer loop, the owner-error hint, and the stale marking in/api/mqtt/status.fix(...)):writeStatsAtomicopens withO_NONBLOCK. A FIFO without a reader fails at once withENXIOinstead of blocking. Regular-file I/O ignores the flag. On WindowsoNonBlockis0, likeoNoFollow.f.Stat()is used to refuse anything that is not a regular file, for example a FIFO that has a reader or a device. The error is<tmp>: not a regular file (mode …); remove it. When the open itself fails and anLstatshows a non-regular entry, the open error comes first:<tmp>: open: <errno>; not a regular file (mode …); remove it. The entry is left in place for the operator to remove. TheFileInfois passed tocheckStatsTmpOwner, so there is no secondfstat.<tmp>: owned by uid X, ingestor uid Y; remove it or fix its owner.openitself fails withEACCES/EPERM, the usual fix(ingestor): foreign-owned stats .tmp logs an error every second with no hint, and stats go stale silently #160 case (a0600tmp of another service user and a non-root ingestor), anLstatof the tmp gives the same hint with the owner,<tmp>: open: permission denied; owned by uid X, ingestor uid Y; remove it or fix its owner. For an unopenable tmp of the ingestor's own user, it gives…; mode -r--------; remove it or fix its permissionsinstead. TheLstatruns only after a failed open.writeStatsAtomicerror is astatsWriteError. It names the tmp path once, at the start, followed by the failed step with its cause (the path stripped from the*PathError/*LinkError), what is wrong with the tmp, and what to do.Unwrapreturns the cause, soerrors.Isstill sees the errno.statsWriteLog, owned by the writer goroutine:[stats-file] write failed: <error>.(N more failed writes since the last report).[stats-file] write <path>: ok again after N failed writes, once. A failure episode inside the interval is not logged on its own: the next failure line counts it. So a flapping failure gives at most one failure line and one recovery line per minute.time.Now(), not the UTC tick time. A negative difference, from a wall-clock step back, counts as an interval passed, so a step cannot silence a persisting failure.SampledAtkeeps the UTC tick time./api/mqtt/statusgainsstale(bool) andsampleAgeSec(int, omitted when there is no readablesampleAt)./api/perf/io, now extracted asingestorStatsStale(ts, now)(> IngestorStatsStaleThreshold, 5s) and used at all three sites.sampleAtcounts as stale.staleisfalseandsampleAtis empty, as before (no data). This also happens when the writer has failed from its very first tick, because then no stats file ever existed. A consumer must read an emptysampleAtas "nothing to trust", not as fresh data.The server only reads the stats file, and all writes stay in
cmd/ingestor. No newmap[string]interface{}; the new tests usemap[string]anyonly for fixture assertions. The 9 fork guards indeploy.ymlare unchanged.Perf
This is not a hot path. The writer ticks at 1 Hz, and the change adds no syscall per tick: it adds a flag to an
open, which already happened, and reuses thefstatthat the owner check already did. The limiter costs O(1) per tick./api/mqtt/statusadds onetime.Parseper request.Tests
TestWriteStatsAtomicFIFOWithoutReaderFailsFast_161(Unix only, 2s timeout; the FIFO gets a reader if the call blocks, so no goroutine leaks)TestWriteStatsAtomicFIFOWithReaderRefused_161TestStatsFileWriterStopsWithFIFOAtTmp_161(stop within 3s)TestStatsFileWriterLogsWriteFailureOnce_160(writer loop at 5 ms: one failure line, then one recovery line)TestStatsWriteLogAtMostOncePerInterval_160(injected clock: 150 s of 1 Hz failures give 3 lines)TestWriteStatsAtomicForeignTmpErrorNamesTheFix_160TestMqttStatusMarksStaleStatsFile_160(hour-old, 2× threshold, fresh, unparseable, no file)Round 2 (review findings F1–F4):
TestWriteStatsAtomicUnopenableForeignTmpNamesTheFix_160andTestWriteStatsAtomicUnopenableOwnTmpNamesTheFix_160(F1: a0400tmp,EACCESfromopen)TestStatsWriteLogFlappingAtMostOncePerInterval_160(F2: 120 s of alternating failure/success at 1 Hz give 4 lines; before, 120)TestStatsWriteLogBackwardClockStepStillLogs_160(F3: a 1 h step back; before, 1 line in 190 s)TestStatsWriteErrorNamesThePathOnce_160andTestStatsFileWriterFailureLineNamesThePathOnce_160(F4: FIFO, directory, foreign owner, unopenable foreign tmp, and the writer's line)Mutants are listed in the report comment.
Not in scope
A hard link at
<tmp>to another file of the ingestor's own user passes the regular-file and owner checks, and that file is then overwritten. This is pre-existing on master and was found in review (F6). A follow-up issue is proposed in the round-2 report.The Observers panel (
public/mqtt-status-panel.js) does not renderstaleyet. That is a UI follow-up that needs browser validation./api/perf/write-sourcesand/api/healthzread the same file. The liveness data in/api/healthzcarries its own unix timestamps, and neither endpoint was asked for here.🤖 Generated with Claude Code