feat(bin): add fseventsd footprint early warning to the fleet watcher - #73
Merged
Conversation
… on write failure
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Intent
Add an fseventsd footprint early-warning to fleet monitoring exactly per the accepted review at /Users/ivan/Projects/firstmate/data/fseventsd-growth-review-r4/report.md. Section 7 owns the thresholds and design, and the whole report must be read first. This changes Firstmate shared tracked material and must follow the firstmate-coding-guidelines skill. Scope is only the monitoring and early-warning integration recommended by section 7: threshold checks on fseventsd footprint growth surfaced through the fleet existing monitoring path, with colocated behavioral regression tests, and nothing beyond that recommendation. The fm-pending-reply, fm-tool-update-check, and fm-wake-queue regression failures were each reproduced with these changes absent on clean current main at 6545983; they are pre-existing baseline failures with fixes already in flight in other tasks, so do not modify those unrelated subsystems in this task and use the validation gate documented baseline-failure path or wait for those fixes if the pipeline cannot proceed.
What Changed
bin/fm-telemetry.shgains anfseventsd-checksubcommand that samples the host's fseventsd memory footprint viatop, plus memory-pressure level and swap usage viasysctl, keeps a bounded three-hour sample history understate/telemetry/fseventsd-samples, and emits aWARNING/ACTION/EMERGENCYline only when a newly higher level is reached (tracked infseventsd-alert), so a level that merely stays true does not re-alert. Thresholds follow the accepted review: 512 MiB twice or >256 MiB/hour over two hours for warning; >2 GiB, an hourly doubling above the warning floor, or a warning combined with warning-or-worse memory pressure or >8 GiB swap for action; sustained growth from the action range with memory pressure at warning-or-worse for emergency. Every condition that holds is reported in the reason string, and a sample whose history cannot be persisted still alerts, with the persistence failure logged as a diagnostic.bin/fm-watch.shinvokes the check on its existing bounded slow-check cadence viarun_check_capture, and surfaces any output as acheck: fseventsd: <out>wake through the normal wake-append path.tests/fm-telemetry.test.shcovering cadence, each threshold, the kernel pressure encoding, irregular sample spacing, and the disable seam, plus two intests/fm-watcher-lock.test.shfor the watcher wake path and for proving watcher tests never sample the live host;tests/lib.shexportsFM_TELEMETRY_FSEVENTSD_DISABLE=1so unrelated watcher suites stay isolated from the real fseventsd. Docs indocs/architecture.mdanddocs/scripts.mdwere updated to describe the new wake reason and subcommand.Risk Assessment
✅ Low: The change is purely additive to bin/fm-telemetry.sh (no removed lines), gated behind a bounded 300s cadence and a dedupe file, wired into the watcher through the existing run_check_capture path whose failure modes cannot kill the watcher, and every accepted section-7 threshold plus each fix round's claim traces correctly against concrete sample sequences and is covered by behavioral regression tests.
Testing
Ran the two colocated suites (fm-telemetry and fm-watcher-lock) and both pass in full, then went past pass/fail to produce the actual operator surface: a walkthrough that seeds the durable fseventsd sample history and runs the unmodified fleet watcher and wake-drain with only pgrep/top/sysctl faked, capturing the exact wake text for every section-7 tier from healthy silence through WARNING, both ACTION forms and EMERGENCY, plus the persisted samples and alert files behind each. A final unfaked run against this Mac's real fseventsd confirmed the healthy daemon stays silent and its 5904K footprint is parsed correctly. No failures, no flakiness, and the unrelated pre-existing baseline failures were deliberately not exercised.
Evidence: End-to-end fleet walkthrough transcript (all six alert tiers through the real watcher + wake drain)
Source: End-to-end fleet walkthrough transcript (all six alert tiers through the real watcher + wake drain)
=== 2. WARNING - two consecutive samples above 512 MiB === $ bin/fm-watch.sh check: fseventsd: WARNING: fseventsd MEM=640.00 MiB; two consecutive samples above 512 MiB $ bin/fm-wake-drain.sh 1787577141\t1\tcheck\tfseventsd\tcheck: fseventsd: WARNING: fseventsd MEM=640.00 MiB; two consecutive samples above 512 MiB === 4. ACTION - past 2 GiB, doubled within the hour, yellow memory pressure === check: fseventsd: ACTION: fseventsd MEM=2500.00 MiB; two consecutive samples above 512 MiB; MEM above 2 GiB; doubling within one hour; warning plus yellow memory pressure; pressure_level=2 swap_used=0.00 GiB === 6. EMERGENCY - sustained climb toward 4 GiB with worsening pressure === check: fseventsd: EMERGENCY: fseventsd MEM=3500.00 MiB; two consecutive samples above 512 MiB; MEM above 2 GiB; warning plus red critical memory pressure; warning plus more than 8 GiB swap; sustained growth toward 4 GiB plus worsening memory pressure; pressure_level=4 swap_used=8.79 GiB; stop launching new work, save state, and reduce workload before the machine wedgesEvidence: Reproducible E2E walkthrough script
Source: Reproducible E2E walkthrough script
Evidence: Live-host check against the real fseventsd daemon (PID 342, 5904K) — healthy, stays silent
Source: Live-host check against the real fseventsd daemon (PID 342, 5904K) — healthy, stays silent
$ top -l 1 -pid 342 -stats pid,command,mem,rsize,compressed,cpu,time,threads PID COMMAND MEM MEM CMPRS %CPU TIME #TH 342 fseventsd 5904K 5904K 1648K 0.0 06:26.37 19 $ FM_TELEMETRY_FSEVENTSD_DISABLE=0 bin/fm-telemetry.sh fseventsd-check # real host, no fakes (exit 0, no alert text: healthy daemon stays silent) $ cat state/telemetry/fseventsd-samples 1787577203 6225920 1 8739818045Pipeline
Updates from git push no-mistakes
✅ **intent** - passed
✅ No issues found.
✅ **Rebase** - passed
✅ No issues found.
bin/fm-telemetry.sh:494- The memory-pressure escalation treatskern.memorystatus_vm_pressure_level >= 1as "yellow memory pressure", but on macOS that sysctl uses the dispatch memory-pressure encoding NORMAL=1, WARN=2, CRITICAL=4 (see MacOSX26.5.sdk/usr/include/dispatch/source.h:254-256). Verified live on this host: the sysctl returns1whilememory_pressurereports "System-wide memory free percentage: 50%", i.e. normal. Concrete trace: fseventsd at 600 MiB on two consecutive 5-minute samples on a completely healthy Mac sets warning=1, then line 494 sees pressure_level=1 and emitsACTION: fseventsd MEM=600.00 MiB; two consecutive samples above 512 MiB; warning plus yellow memory pressureinstead of the acceptedWARNINGtier. Because level 1 is the steady-state value, the warning tier of section 7 is unreachable on real macOS and every 512 MiB warning is mislabeled as ACTION - exactly the collapse of the two tiers the report warns against ("Keep the previous report's 2 GiB threshold as the operational action boundary rather than the first alert"). The same off-by-one tier is in the emergency guard at line 510 and in the header comment at line 45 ("warning-or-worse memory pressure"). The colocated tests bake in the wrong encoding too: they feed FM_FAKE_PRESSURE_LEVEL=0 for "no pressure" and 3 for "critical" (tests/fm-telemetry.test.sh:80, 240, 260), values the kernel never returns, so no test would catch this. Fix: compare against >= 2 (warn) for the action escalation and the emergency guard, and use 1/2/4 in the fakes.bin/fm-telemetry.sh:482- The doubling rule fires on any sample that is >= 2x any sample in the previous hour, with no absolute floor. fseventsd's healthy footprint is ~5 MiB (report section 1; measured 5664K on this host right now), and it starts far smaller right after boot. Concrete trace: after a reboot the watcher samples fseventsd at 1.5 MiB, and 30 minutes later it has settled at its normal 4.8 MiB. Line 482 matches (4.8 >= 2 * 1.5), so severity becomesactionand the fleet is woken withACTION: fseventsd MEM=4.80 MiB; doubling within one hourfor a completely healthy daemon. Because the alert file then holds rank 2, a genuine 512 MiB warning later in the same episode is also suppressed by fseventsd_publish_alert. Section 7 states the doubling rule without a floor, so gating it on an absolute minimum (e.g. only evaluate doubling once MEM is above the 512 MiB warning boundary) is a deliberate deviation from the accepted thresholds and needs the author's call.bin/fm-telemetry.sh:509- The emergency tier requires the pressure level to strictly increase between the previous sample and the current one (FSEVENTSD_PRESSURE_LEVEL -gt prev_pressure) in the same cycle where three consecutive rising samples above 2 GiB are observed. Concrete trace: the machine crosses into warn pressure at 10:02, the watcher samples at 10:00 and 10:05 (both warn), fseventsd climbs 2.6 -> 3.0 -> 3.5 GiB across 10:05/10:10/10:15 - every growth condition holds at 10:10 and 10:15 but prev_pressure == current pressure at both, so no EMERGENCY is ever emitted for a machine that is sustainedly degrading toward the wedge the report describes. Only the single sample where the transition happens to land can qualify, and at that sample the three-sample growth chain may not yet hold. Section 7 says "sustained growth toward 4 GiB plus worsening memory pressure"; reading "worsening" as sustained elevated pressure (level >= warn) rather than a per-sample delta is a threshold-semantics decision for the author.bin/fm-telemetry.sh:469- The two-hour growth rate is computed only against samples landing in the 300-second window [now-7500, now-7200]. Sample spacing is >= 300s by the cadence guard at line 445 and in practice slightly more (fm-watch.sh's CHECK_INTERVAL is 300s plus poll and processing time), so the spacing can exceed the window width and no sample lands inside it. Concrete case: samples at now-7150 and now-7480 with 330s spacing - neither is in [7200,7500] on some cycles, so the 256 MiB/hour rule silently evaluates to "no growth" even while growth is real. It self-corrects on a later cycle, so impact is a delayed warning rather than a lost one, but selecting the newest retained sample at least 7200s old (the history already keeps 3 hours) would make the rule deterministic.bin/fm-watch.sh:1028- The fseventsd check is placed first in the slow-check block and its output path callswake, which exits the watcher process (bin/fm-push-transition-lib.sh:88-108) after touching.last-check. So the first cycle in which an fseventsd level is newly reached skips every*.check.shsweep - including PR merge polling - and defers them by a full CHECK_INTERVAL. Alert dedupe keeps this to one cycle per escalation, so this is an accepted one-shot cost rather than a defect; noting it because the surrounding comment block explains that check ordering was chosen specifically to avoid starvation.bin/fm-telemetry.sh:429-FM_TELEMETRY_NOWis a new environment-controlled clock override read in production code, but unlike the sibling seamFM_TELEMETRY_RECORD_ONCEit is not listed in the script header's environment section (lines 48-58). Per the repo guideline that a script's header plus --help owns exact env mechanics, add a one-line entry describing it as a test seam.🔧 Fix: fix fseventsd pressure encoding, doubling floor, growth window
3 infos still open:
bin/fm-telemetry.sh:517- The emergency guard's second disjunct is unreachable. The condition already requiresFSEVENTSD_PRESSURE_LEVEL -ge 2on line 515, so in the{ [ "$prev_pressure" -ge 2 ] || [ "$FSEVENTSD_PRESSURE_LEVEL" -gt "$prev_pressure" ]; }compound, whenever the first test is false (prev_pressure is -1, 0 or 1) the second is necessarily true (current >= 2 > prev). prev_pressure is always a numeric field read from the history file, so there is no third case. The compound is a tautology and can be deleted. The header at line 48 also documents "or is still rising" as a distinct emergency path that cannot actually decide the outcome, so it should be dropped alongside it.tests/fm-watcher-lock.test.sh:775- The fix round corrected the pressure fakes in tests/fm-telemetry.test.sh to the kernel's 1/2/4 encoding but left this watcher-path fake returning0, a valuekern.memorystatus_vm_pressure_levelnever emits. The test still passes because 0 and the real steady-state 1 both sit below the warn threshold, so it does not mask a defect, but the fake now contradicts the encoding the production code and the sibling test suite are built around and will mislead the next person editing this path. Change it to1.bin/fm-telemetry.sh:499- TheMEM above 2 GiB(line 496) anddoubling within one hour(line 499) branches assign toreasonsrather than appending, discarding any warning evidence already accumulated. Concrete trace: fseventsd samples 600 MiB then 1.3 GiB five minutes later. Line 464 sets warning=1 with reasons='two consecutive samples above 512 MiB', line 487 sets doubling=1, then line 499 overwrites reasons, so the operator seesACTION: fseventsd MEM=1331.20 MiB; doubling within one hour; pressure_level=1 swap_used=0.00 GiBwith no mention of the sustained 512 MiB breach or (in the growth case) the measured MiB/hour rate. The alert is correctly tiered but reports less than it measured; the sibling pressure/swap branches at lines 500-506 already append instead of overwrite. Since this changes user-facing alert text, confirm with the author before switching these two branches to append.🔧 Fix: retain fseventsd action evidence, drop dead pressure clause
2 infos still open:
bin/fm-telemetry.sh:519- The emergency branch assignsreasons='sustained growth toward 4 GiB plus worsening memory pressure', discarding every reason accumulated for the same sample, and the emergency message at line 535 also omits thepressure_level=/swap_used=suffix that the ACTION message at line 533 carries. Concrete trace (the suite's own emergency scenario, tests/fm-telemetry.test.sh:278-284: 2600M/3000M/3500M at pressure 2): line 464 sets warning=1 with reasons='two consecutive samples above 512 MiB', line 496 appends 'MEM above 2 GiB', then line 519 overwrites both, so the operator seesEMERGENCY: fseventsd MEM=3500.00 MiB; sustained growth toward 4 GiB plus worsening memory pressure; stop launching new work...with no 512 MiB breach, no measured MiB/hour rate, no pressure level and no swap figure. The highest tier therefore reports strictly less than the ACTION tier below it - the same evidence-dropping the previous round's decision ("ACTION alerts must append and retain all same-sample warning evidence ... so crash-forensics output remains diagnosable") corrected at lines 496 and 499 but did not extend here. Fix would be to append the emergency reason and add the pressure/swap suffix to the emergency message; since it changes user-facing alert text, confirm with the author.docs/scripts.md:107- Thefm-telemetry.shrow still reads "Arm, disarm, or report the never-auto-armed detached host resource-snapshot recorder...", which no longer covers the script's second responsibility: thefseventsd-checksubcommand (bin/fm-telemetry.sh:899) that the watcher now calls on its slow-check path (bin/fm-watch.sh:1028) and whose output becomes a user-visiblecheck: fseventsd:wake reason. The script header and--helpwere updated; this shared index entry was not, so the repo's one-line-per-script map understates what the script owns.🔧 Fix: retain fseventsd emergency evidence, update scripts index
2 infos still open:
bin/fm-telemetry.sh:504- The pressure escalation branch correctly fires at warn-or-worse (FSEVENTSD_PRESSURE_LEVEL -ge 2), but its reason string is hardcoded to 'warning plus yellow memory pressure'. macOS encodes 4 as CRITICAL (red), not warning/yellow. Concrete trace, which the suite itself exercises (tests/fm-telemetry.test.sh:322-327): two consecutive 600 MiB samples with FM_FAKE_PRESSURE_LEVEL=4 emitACTION: fseventsd MEM=600.00 MiB; two consecutive samples above 512 MiB; warning plus yellow memory pressure; pressure_level=4 swap_used=0.00 GiB. The operator is told the machine is at yellow pressure while the kernel is reporting critical. The numericpressure_level=4in the suffix keeps the alert diagnosable, so this is a wording defect rather than a lost signal; a level-aware phrase (e.g. 'warning plus warn-or-worse memory pressure', or yellow/red selected from the level) would match what was measured. Since this is user-facing alert text derived from the accepted report's 'yellow memory pressure' wording, confirm with the author.bin/fm-telemetry.sh:504- Lines 504 and 507 prepend;unconditionally (reasons="${reasons}; warning plus ..."), unlike every sibling reason append at 496, 500 and 519 which use the[ -z "$reasons" ] || reasons="$reasons; "guard. Today this is safe only because both branches are gated onwarning -eq 1, and warning is set to 1 exclusively alongside a non-emptyreasonsat line 471 or 485 - a non-local invariant. If a future warning condition is added that does not also write a reason, the alert emits a leading '; ' (ACTION: fseventsd MEM=600.00 MiB; ; warning plus more than 8 GiB swap; ...). Not reachable with the current code; worth aligning with the sibling pattern while the two forms sit four lines apart.🔧 Fix: label fseventsd pressure by level, guard reason separators
1 info still open:
bin/fm-telemetry.sh:498- The ACTION tier is an if/elif chain, so exactly one action reason is ever recorded even when several action conditions hold in the same sample. Concrete trace: fseventsd samples 600 MiB at t, then 2500 MiB at t+300 with pressure 4 and 9 GiB swap. Line 464 sets warning=1 ('two consecutive samples above 512 MiB'); line 487 sets doubling=1 (2500M >= 2*600M and above the 512 MiB floor); the pressure and swap action conditions also hold. The chain takes the first branch (line 496, 'MEM above 2 GiB') and lines 498/503/509 never execute, so the emitted alert isACTION: fseventsd MEM=2500.00 MiB; two consecutive samples above 512 MiB; MEM above 2 GiB; pressure_level=4 swap_used=8.79 GiB. The pressure and swap evidence survives numerically in the suffix, but the measured doubling-within-one-hour signal is computed and then silently discarded - nothing in the output says the footprint doubled. That is the same evidence-dropping class the author ruled on in round 2 ('ACTION alerts must append and retain all same-sample warning evidence before adding the ACTION reason, so crash-forensics output remains diagnosable') and in round 3 for the emergency tier; the fix rounds converted assignment to append but left the four action conditions mutually exclusive. Fix would be to evaluate the four action conditions independently and append each reason that holds instead of elif-chaining them. Since it changes user-facing alert text, confirm with the author.🔧 Fix: report every fseventsd action reason that holds
2 issues (1 warning, 1 info) still open:
bin/fm-watch.sh:1028- The fseventsd check is unconditional at the top of the slow-check block, andage_ofreturns 999999 for a missing file (bin/fm-watch.sh:588-592), so.last-checkbeing absent makesage_of >= CHECK_INTERVALtrue on the FIRST cycle of every watcher spawn — even for the many tests that set FM_CHECK_INTERVAL=999999 specifically to suppress the sweep. Every one of the ~90$WATCHspawns across tests/fm-watch-triage.test.sh (56), tests/fm-watcher-lock.test.sh (14), tests/fm-pr-check-security.test.sh (9), tests/fm-wake-queue.test.sh (6) and others therefore executes the realpgrep -x fseventsd+top -l 1 -pid ...against the live host, because those tests prepend a fakebin that contains nopgrep/top(e.g. tests/fm-watch-triage.test.sh:50). Two concrete consequences. (1) Host coupling: theMEM above 2 GiBrule fires on a single sample with empty history (bin/fm-telemetry.sh:494), so on a machine where fseventsd has actually grown past 2 GiB — precisely the incident this monitors — every watcher-spawning test gets an unexpectedcheck: fseventsd: ACTION ...wake and the watcher exits at cycle 1, failing dozens of unrelated tests for reasons invisible in their assertions. (2) Cost/timing:top -l 1 -pid 342 -stats pid,command,memmeasured 0.95s wall on this host, so roughly 90 seconds is added to the suite and ~1s of unmodelled latency is inserted into the first cycle of poll-timing-sensitive triage tests. The new colocated test (tests/fm-watcher-lock.test.sh:754) correctly fakes the samplers; the other watcher tests have no such isolation. Needs an author decision on the seam (a fake-sampler default in the shared watcher test harness, or an explicit opt-out env the tests set), so flagging rather than fixing.bin/fm-telemetry.sh:534-fseventsd_record_sample ... || return 0discards the computed alert whenever persisting the history sample fails.fseventsd_record_sample(bin/fm-telemetry.sh:397-412) returns non-zero onmktempfailure, on the pruneawkfailing, on the appendprintffailing, or onmv -ffailing — i.e. exactly the disk-full / state-directory-unwritable conditions that correlate with a host already degrading. Concrete trace: fseventsd is at 3.5 GiB on the third consecutive rising sample with pressure level 2,severity=emergencyand the full reason string are built, then the root volume is full somktemp "$TELEMETRY_DIR/.fseventsd-history.XXXXXX"fails and the function returns 0 without ever callingfseventsd_publish_alert. The operator gets no EMERGENCY and no diagnostic — the watcher sees empty output and treats the cycle as healthy. Emitting the alert is strictly safer than swallowing it:fseventsd_publish_alertdedupes off$FSEVENTSD_ALERT, which is a separate file, so a failed history write cannot cause repeat alerts. Suggested fix: record the sample, and on failure still publish the alert (optionally viadiagnosticfor the persistence failure) instead of returning early.🔧 Fix: isolate watcher tests from live fseventsd, alert on write failure
1 info still open:
tests/lib.sh:43- The isolation seam is exported from tests/lib.sh, so it only reaches suites that source that library. Three opt-in live e2e suites spawn the real watcher without sourcing it — tests/fm-grok-continuity-live-e2e.test.sh:71, tests/fm-opencode-primary-live-e2e.test.sh:301 and tests/fm-pi-primary-live-e2e.test.sh:260 eachcp "$ROOT/bin/fm-watch-arm.sh"into the fixture project and have the agent run it, and none of them set FM_TELEMETRY_FSEVENTSD_DISABLE (grep returns 0 hits for FM_TELEMETRY in all three). Those watchers therefore still execute the real pgrep/top against this host on their first cycle, and on a machine where fseventsd has actually crossed 2 GiB the single-sampleMEM above 2 GiBrule (bin/fm-telemetry.sh:501) would wake and exit the watcher mid-test. The blast radius is bounded: all three are gated behind FM_GROK_LIVE_E2E / FM_OPENCODE_LIVE_E2E / FM_PI_LIVE_E2E and skip by default, and by design they already drive real agents on the real host. tests/fm-claude-stop-autoarm-live-e2e.test.sh substitutes its own fake fm-watch-arm.sh so it is unaffected. Noting this as the known limit of the round-6 seam rather than asking for the three unrelated live suites to be touched in this task.✅ **Test** - passed
✅ No issues found.
bash tests/fm-telemetry.test.sh— all 28 cases pass, including the 13 new fseventsd cadence/warning/action/emergency/pressure-encoding/persistence-failure casesbash tests/fm-watcher-lock.test.sh— all cases pass, includingtest_watcher_surfaces_fseventsd_warning_on_slow_check_pathandtest_watcher_tests_never_sample_the_live_fseventsdManual E2E:FM_EVIDENCE_ROOT=<repo> /Users/ivan/.no-mistakes/evidence/01M0SQSCDK191W0FGA39ASB6G1/e2e-fseventsd-early-warning.sh— six scenarios, each seeding durable state/telemetry/fseventsd-samples history then running the realbin/fm-watch.shand the realbin/fm-wake-drain.shLive-host check:FM_TELEMETRY_FSEVENTSD_DISABLE=0 bin/fm-telemetry.sh fseventsd-checkagainst the machine's actual fseventsd (PID 342), plustop -l 1 -pid 342 -stats pid,command,mem,rsize,compressed,cpu,time,threadsto confirm the parsed footprint matchedgit status --porcelain— worktree clean, no transient artifacts left✅ **Document** - passed
✅ No issues found.
✅ **Lint** - passed
✅ No issues found.
✅ **Push** - passed
✅ No issues found.