controller: 0.25-0.8 of a CPU core continuously while every worker is idle (0.1.24, Windows host)

[kyle-sexton]

Summary

ci-runner-controller.exe (0.1.24) burns roughly 0.25-0.8 of a CPU core continuously while every worker is idle. Over a 24 h 17 m uptime on melo-lap-001 it had accumulated 62,461 CPU-seconds (about 0.71 cores averaged over the whole day) with zero jobs assigned for most of that window. In a 10 s live sample it was the single largest CPU consumer on the host at 2.5% of a 32-thread machine, ahead of Defender (2.0%) and Docker Desktop (0.4%).

Observations

• Host: melo-lap-001 (i9-13980HX, 24C/32T, Windows 11 26200), AC power, Docker Desktop running, WSL 2.
• ci-runner host status: desired mode enabled, phase ready, six workers all state=idle job=-, pools assigned=0.
• ci-runner host doctor --json: every check healthy except the advisory pending-reboot; listeners acknowledged, capacity 11 and 1, assigned 0.
• Config: controller.reconcileInterval: 5s, shutdownPollInterval: 1s, localProbeTimeout: 15s, desktopProbeTimeout: 45s.
• Over a 15 s window with the controller idle: CPU delta 3.41 s (0.23 cores); no child processes were observed being spawned in that window (no docker, wsl, gh, or shell children appeared), so the cost is inside the controller process itself rather than in CLI probes it launches.
• %LOCALAPPDATA%\ci-runner\diagnostics holds 5,455 entries and logs 2,750; new *-diag.tar.gz and *-resources.json pairs were being written every few minutes for idle workers (four pairs between 01:14 and 01:20 UTC).

Why it matters

This host doubles as an interactive workstation running several concurrent Claude Code sessions, where the dominant latency term is process-creation contention. A permanent 0.25-0.8 core of background CPU from an idle control plane adds directly to that contention and to fan and battery load on the laptop.

Suggested investigation

1. Profile the reconcile loop at reconcileInterval: 5s with all workers idle: which calls run every tick (Docker API list/inspect per worker, GitHub listener polling, capacity reconciliation, diagnostics capture)?
2. Consider an idle back-off: lengthen the reconcile interval when assigned=0 has been stable for N ticks, returning to 5 s on the first job or listener transition.
3. Check whether per-worker diagnostics capture is meant to run while workers are idle, and whether the diagnostics directory has a retention sweep.
4. Expose the controller's own tick cost (or CPU seconds per reconcile) in host status so this can be watched without external sampling.

Verification

Reproduce by sampling Get-Process ci-runner-controller | Select-Object CPU twice 15 s apart with the fleet idle, or via \Process(ci-runner-controller)\% Processor Time in Get-Counter. Expected after a fix: well under 0.05 cores while idle.

No linked issue.

[kyle-sexton]

Defender performance recording points at the state-file rewrite loop

An elevated New-MpPerformanceRecording on melo-lap-001 (2026-09-03, about 8 m 40 s, controller 0.1.24, every worker idle, listeners healthy with assigned=0) makes ci-runner-controller.exe the single largest Defender real-time-scan consumer on the host by an order of magnitude:

Process	Scans	Total scan time	Median per scan
ci-runner-controller.exe	1,179	18,127 ms	15.3 ms
docker-desktop.exe (next largest)	109	1,879 ms	17.3 ms
bash.exe (Git for Windows, all Claude Code hooks)	43	628 ms	14.1 ms

That is about 2.3 scans per second sustained, 18 s of scan wall time in a 520 s window, on top of the controller's own CPU reported above.

Get-MpPerformanceReport -TopProcesses 4 -TopFilesPerProcess 8 attributes every one of the controller's top files to fresh temp files under the state and log directories, each scanned once and never seen again (the atomic write-then-rename pattern):

• %LOCALAPPDATA%\ci-runner\state\.jobs.json-<random> (most entries, 24-29 ms each)
• %LOCALAPPDATA%\ci-runner\state\.runner-assign-times.json-<random>
• %LOCALAPPDATA%\ci-runner\logs\workers\.ci-runner-log-<random>.tmp

Sampling jobs.json once per second confirms the cadence: its LastWriteTime advanced on 6 of 8 consecutive one-second samples with no jobs assigned, and its size drifted by one byte per write (8,388,329 → 8,388,328 → 8,388,327 bytes, about 8.0 MiB). runner-assign-times.json (1,910,447 bytes) was rewritten in the same window and shared the final timestamp. A jobs.json.bak.20260716T142700Z from July is 8,388,578 bytes, so the file has sat at about 8 MiB for at least seven weeks.

So the idle loop appears to serialize and atomically rewrite roughly 10 MiB of JSON about once a second with nothing assigned. That would account for both the CPU cost in this issue and the Defender cost here, since every rename-in temp file is a new file identity that real-time protection has to scan. A Defender exclusion is not the right fix (it would hide the write loop, not remove it); candidates on the controller side are persisting the state only when something material changes, throttling the persist interval to something like the reconcile interval, and bounding jobs.json so completed jobs age out instead of being rewritten forever.

Capture details: light host load during the window (11% CPU, seven claude/node processes), so the controller numbers are not inflated by contention; the same report ranks the hook spawn chain (bash.exe above, jq.exe at 5 scans / 35 ms) as negligible by comparison.

[kyle-sexton]

Code pointers for the idle write loop

Following up my Defender comment above with the source sites, so this does not need re-deriving. I traced the write path but did NOT trace which caller fires on the idle tick, so the last section is a hypothesis rather than a finding.

The three temp-file families Defender scanned map one-to-one onto three durable-write sites:

Scanned temp file	Source
state\.jobs.json-<n>	internal/jobindex/file_store.go, TemporaryPattern: ".jobs.json-*"
state\.runner-assign-times.json-<n>	internal/jobindex/assign_times.go, "create temporary assign-times sidecar"
logs\workers\.ci-runner-log-<n>.tmp	internal/runtime/docker/artifacts.go, "create temporary worker log"

One structural detail explains why the two state files always moved together in my sampling. The jobs.json save's AfterReplace hook calls saveAssignTimesUnlocked unconditionally, so every catalog commit also rewrites the assign-times sidecar. At the sizes on this host that is 8.0 MiB plus 1.9 MiB per commit, and the durable-write path is a full encode-write-fsync-rename of the whole catalog rather than an incremental append.

The part I did not prove

Upsert is the mutation entrypoint and it commits through Merge(existing, patch, now). What I did not establish is which caller runs on the idle tick. Two shapes fit the evidence and they want different fixes, so this is worth deciding before any patch:

1. The write is genuinely unnecessary — the merged record is byte-identical to the existing one and the save happens anyway. Fix is an equality check before committing, and it is small.
2. The write is "necessary" but disproportionate — a periodic patch legitimately moves one small field such as a heartbeat or last-seen timestamp, and that one field costs a rewrite of the entire 10 MiB. Fix is structural: keep high-frequency fields out of the main catalog, or coalesce commits on an interval instead of per mutation.

My money is on the second, because option 1 would be an obvious bug and this code is otherwise careful, but I did not verify it and the distinction decides the whole approach.

Why the size matters independently

jobs.json has sat at roughly 8 MiB for at least seven weeks; the jobs.json.bak.20260716T142700Z alongside it is 8,388,578 bytes. internal/healthwatch/check.go already reasons about a save cap and about records that capacity compaction cannot reclaim, so the growth is a known axis. Whatever the commit-frequency fix turns out to be, a catalog that only grows makes every commit worse over time.

I am not opening a PR. This is shared CI infrastructure and the fix depends on a design call that belongs to whoever owns the job index.

[kyle-sexton]

Busy-load recording: the controller row is load-independent, and there is a third state file

Repeated the Defender performance recording on melo-lap-001 on 2026-09-04 (elevated, 14 m 27 s / 867 s, controller 0.1.24), this time with the machine genuinely busy rather than quiet. Two things for this issue.

The controller's cost does not depend on load. 1,413 scans and 23,035 ms of real-time scan wall time in 867 s, which is 57.6% of all attributed scan time in the window, with every worker still idle. Normalised against the 2026-09-03 light-load run it is 26.6 ms/s against 34.9 ms/s — the same order, slightly lower, and still first place by roughly 3.5x over the next process. Every other candidate I chased moved with load; this one does not, which is consistent with the idle write loop being the cause rather than anything the workers do.

observed.json is a third file in the same loop. The light-load capture attributed the controller's scans to state\.jobs.json-<n> and state\.runner-assign-times.json-<n>. This capture also shows state\.observed.json-<n> in the top-files list, at 26.0 ms for a single scan.

That is not a fourth durable-write site to go find. Store.save in internal/state/fs/store.go:272 builds the pattern generically:

TemporaryPattern: "." + name + "-*",

so every file the state store writes — observed.json included, via SaveObserved at store.go:123 — rides the same create-temp-then-rename path as the two jobindex sites in my earlier comment, and each rename-in file is a new identity for real-time protection.

Size is not the driver, identity is. On disk right now: observed.json is 2,991 bytes, jobs.json is 8,388,592 bytes. Both scan at about 26 ms. So bounding jobs.json's history would cut the bytes written but not much of the scan cost; what removes the scan is not writing when nothing changed. That points the fix at persist-on-change for all three files rather than at the job-history bound alone, which is a slightly different shape than my first comment implied.

No exclusion is warranted here and I am not proposing one — this is a write-frequency question on the controller side.

Full comparison table and the caveats on the busy window are in the provisioning runbook (runbooks/shell-startup-baseline.md, melodic-software/provisioning#367).

[kyle-sexton]

This was generated by AI during triage.

Triage lane claiming this item for the current cycle (instance vm-triage-202609050304). Lease TTL 60 minutes, expires 2026-09-05T04:09:00Z. Claim covers classification and brief-authoring only — this lane does not author fix PRs or merge.

---

Generated by Claude Code

[kyle-sexton]

This was generated by AI during triage.

Triage: confirmed, root-caused in source, one design decision blocks the fix

Verified against 01594bd (default branch). The report reproduces as written at the code level, and the open question left in the second comment above — hypothesis 1 (byte-identical write committed anyway) versus hypothesis 2 (a real but tiny field change costing a full rewrite) — resolves to hypothesis 2, decisively.

The commit is unconditional, and the record is never byte-identical

FileStore.Upsert (internal/jobindex/file_store.go:158) loads the catalog, merges, and then calls s.saveUnlocked(catalog) with no comparison of any kind between the pre-merge and post-merge record. There is no equality gate to fix.

More importantly, adding a naive one would not work. Merge (internal/jobindex/catalog.go:74) ends with:

existing.UpdatedAt = now.UTC()

That stamp is unconditional on every non-tombstoned path, so the merged record always differs from the existing one, even when the patch carries nothing new. A merged == current check would never fire. This is exactly the distinction the earlier comment said "decides the whole approach", and it rules out the small fix.

One precedent already exists in the same function: if existing.TombstonedAt != nil { return existing, nil } returns early without stamping. So a no-op return path is already an accepted shape here.

Why the cadence is about one write per second

saveUnlocked commits through AfterReplace (file_store.go:336), which calls saveAssignTimesUnlocked unconditionally — so every catalog commit rewrites the assign-times sidecar too. At the sizes on melo-lap-001 that is ~8.0 MiB + ~1.9 MiB per commit, full encode → write → fsync → rename, never incremental.

The observed cadence fits one Upsert per worker per reconcile tick: 6 idle workers ÷ 5 s ≈ 1.2 writes/s, which matches jobs.json LastWriteTime advancing on 6 of 8 consecutive one-second samples. That is roughly 12 MiB/s of sustained write-and-fsync churn with zero jobs assigned, and it explains both the CPU figure in this issue and the Defender scan figure, since each rename-in temp file is a new file identity.

observed.json is a separate, legitimate per-tick write: reconciler.go:1006 builds ObservedState with HeartbeatAt: time.Now().UTC() and reconciler.go:1472 persists it every pass. That one is a heartbeat and is supposed to move. Bounding it is not the win; it is 2,991 bytes.

Compaction exists but cannot help here

encodeWithinCapacity (file_store.go:361) does compact, but only under capacity pressure against the 8 MiB maximumJobState cap, and only by dropping tombstoned then completed records. It is a ceiling enforcer, not a retention policy — which is why jobs.json has sat at ~8 MiB for seven weeks. It is pinned at the cap, not growing past it.

The decision a human owns

Three shapes, different durability implications on shared CI infrastructure:

1. RECOMMENDED — semantic-equality gate. Compare merged vs existing ignoring UpdatedAt (and stamp UpdatedAt only when some other field moved). Smallest diff, no schema change, no crash-recovery change; kills the idle loop outright because idle patches carry nothing new. Risk: UpdatedAt stops being a liveness signal for a record — needs a check that nothing consumes it that way.
2. Coalesce commits on an interval. Keep mutating in memory, flush on a timer or on material change. Bigger win under load too, but it widens the crash-recovery window, which is a real durability change on a job index.
3. Split high-frequency fields out of the catalog. Structurally cleanest, largest diff, and it is a schema migration on jobs.json.

Option 1 is reversible and does not touch the on-disk format; options 2 and 3 are not cleanly reversible once shipped.

Classification

• Real: yes, verified in source, not just from host telemetry.
• Work class: work-class: structural — the fix lands on the shared persistence commit path (internal/jobindex + internal/state/fs), and PR refactor(persistence): extract shared atomic-durable-write helper #322 recently refactored that seam.
• Gate: keeping needs-human / status: needs-decision. Not because the code is unclear, but because choosing among the three options above is a durability judgment on shared CI infrastructure, and the original reporter explicitly reserved it ("the fix depends on a design call that belongs to whoever owns the job index"). Once an option is picked, execution is straightforward and delegable.

Relationship to #331

Likely the same root cause. #331's own follow-up comment reports an ~8.39 MB jobs.json and a 3.5-minute controller startup with ~0.7 core burned and no network traffic — consistent with re-reading and re-serialising this catalog. Recommend deciding this issue's option first; #331's startup-latency symptom may resolve as a side effect. Whoever picks up either should read both.

What a cold agent needs to execute, once the option is chosen

• Entry point: internal/jobindex/file_store.go:158 (Upsert), catalog.go:74 (Merge), file_store.go:336 (AfterReplace → saveAssignTimesUnlocked).
• Existing no-op precedent to mirror: the TombstonedAt early return in Merge.
• Verification, per the issue's own stated bar: sample Get-Process ci-runner-controller | Select-Object CPU twice 15 s apart with the fleet idle; expect well under 0.05 cores. Add a regression test asserting that a no-op Upsert performs no durable write — the seam is already test-friendly (durable_test.go fakes the plan hooks).

No fix PR opened; this lane classifies and briefs only.

---

Generated by Claude Code

[kyle-sexton]

This was generated by AI during triage.

Triage lane releasing its claim (instance vm-triage-202609050304). Item is triaged and briefed; labels applied: priority: high, work-class: structural, status: needs-decision, needs-human. Blocked on the design decision described above — not on further investigation.

---

Generated by Claude Code