fix(watchdog): rate-based C7 error-storm detection — replace flat-count heuristic#142
Open
ynaamane wants to merge 13 commits into
Open
fix(watchdog): rate-based C7 error-storm detection — replace flat-count heuristic#142ynaamane wants to merge 13 commits into
ynaamane wants to merge 13 commits into
Conversation
… daemon_start_times/recent_starts to LoopReport (PLAN P0-A)
…evel constants (PLAN P0-B)
…ount fallback (PLAN P0-C) Rate path (PATH A): when >=1 parseable ISO daemon-start timestamp exists, count restarts within RATE_WINDOW_S=3600s of the most recent one. If recent_starts >= RATE_STORM_TRIP=5, flag as error respawn storm regardless of stale productive- prune lines in the window (fixes FN). If recent_starts < RATE_STORM_TRIP, rate path is authoritative — flat-count suppressed (fixes FP: scattered recovered errors on a single healthy daemon no longer false-flag). Flat-count fallback (PATH B): unchanged R15 discriminator, fires only when 0 parseable timestamps exist (old daemon versions, malformed lines). Zero regression on pre-ISO-header logs. The futile-prune branch (watchdog.py:187+) is byte-identical — untouched.
…..T-6 (PLAN P0-D)
Import RATE_WINDOW_S and RATE_STORM_TRIP from watchdog. Clean up T-2 docstring.
AC-1 (T-1): storm of 5 rapid respawns flagged despite stale prune lines masking
errors — proven RED at base (FN), GREEN after rate-window fix.
AC-2a (T-2): single healthy daemon with 21 scattered recovered errors NOT flagged —
proven RED at base (FP), GREEN after rate-window fix.
AC-2b (T-3): 6 restarts 4h apart NOT flagged — GREEN at base and after (preserved).
AC-3 (T-4): real f641174c fixture NOT flagged — GREEN at base and after (preserved).
Edge (T-5): no-ISO-timestamp log falls back to flat-count — GREEN at both.
Edge (T-6): mixed parseable/None timestamps; anchor uses latest parseable — proven
RED at base (FN), GREEN after fix.
…sed detection (PLAN docs)
watchdog.py: collapse redundant else-branch in daemon-start parsing loop into a single try/except with conditional expression (R-3/S-2). test_guard_watchdog.py: move _error_cycle/_escalation helpers to module-level alongside _futile_cycle/_good_cycle/_daemon_start (R-1); add datetime/timedelta as module-level imports instead of repeating inside 4 test methods (R-2/S-3); fix T-5 docstring stale '< 2 parseable timestamps' line (A-4/S-4).
…C-2a future-anchor, C-2b midline-regex, M-1 tz, M-3 boundary)
…gate (PLAN P0-C round-2)
C-2a: replace max()-anchored window with a sliding-window algorithm.
Old code anchored to max(parseable): a single forged far-future timestamp
inflated the anchor, collapsing recent_starts to 1 for genuine storm clusters.
New algorithm: sort timestamps, for each t1 count t2 in [t1, t1+RATE_WINDOW_S]
(0 <= delta <= RATE_WINDOW_S), take the max across all t1. A lone outlier
forms its own window of size 1 and cannot suppress a genuine cluster.
O(n^2) in daemon_starts (n < 50 in practice).
C-2b: fix _DAEMON_START_RE anchor for the real "--- Guard daemon started" format.
Previous ^\s* missed the leading dashes. Pattern is now ^(?:---\s*|\s*) to
cover both the dashes form and any whitespace-only prefix variant.
Mid-line injections ("Team 'Guard daemon started at T' state preserved") still
cannot match because text before them is neither dashes nor whitespace.
M-1: tz-aware fromisoformat guard — parsed datetimes with tzinfo set are
treated as None to avoid TypeError when mixing tz-aware and naive in (t2-t1).
C-1: escalation-aware inert gate. When PATH A's recent_starts < RATE_STORM_TRIP
(not a storm), check for a single genuinely stuck daemon: cycle_escalations >= 1
AND cycle_errors >= loop_trip AND cycle_errors > productive_prunes. The C2
escalation line proves the daemon exited for respawn (not a recovered transient).
Adds "inert/erroring guard (escalated)" reason.
Deferred residual: a daemon that errors without ever escalating is not caught
here; tracked in TODO.md for follow-up.
All 32 watchdog tests pass.
Altitude fix (L-2): reason string "in the last Nmin" was misleading for a sliding-window algorithm — the window anchors to the densest cluster in the log, not to the present moment. Changed to "within a Nmin window". Reuse: nothing to reuse (novel algorithm). Simplification: nothing redundant (parseable is a single variable reused correctly). Efficiency: cycle_errors/cycle_escalations findall always runs; required because both fields are public LoopReport fields consumed by callers regardless of path.
The field comment said 'starts within RATE_WINDOW_S of the anchor timestamp' which described the old max()-anchored design (round-2 fixed with a sliding window). Updated to 'max restarts in any RATE_WINDOW_S-second sliding window' which accurately reflects the current algorithm.
…neutral reason, R3-3 PATH A/B asymmetry)
…on comments (PLAN R3-1/R3-2/R3-4)
|
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
2 participants
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.
Problem
guard-watchdog's C7 "erroring/inert-guard" detector classified a respawn/error storm from a flat 256 KB append-mode log tail, with no recency or rate awareness. As noted in #140, every flat-count rule had a residual in one direction or the other because the tail mixes generations:loop_tripscattered transient errors (streak reset each time, never escalated), with its productive prunes scrolled out of the window, flagged as inert.Fix
scan_log_text(watchdog.py) now keys the verdict on restart rate within a time window, using the ISO timestamps on--- Guard daemon started at <ISO> ---lines (PATH A), and keeps the original flat-count as a fallback for timestamp-less old logs (PATH B):RATE_WINDOW_S = 3600-second sliding window ≥RATE_STORM_TRIP = 5. A sliding window (rather than anchoring onmax(timestamps)) is robust to a forged/implausible future-or-past timestamp: a lone outlier forms its own window of size 1 and cannot mask a genuine restart cluster. This is the literal "many restarts close together in time" definition from the issue.cycle_escalations ≥ 1) with ≥loop_tripper-cycle errors anderrors > productive_prunesis flagged as genuinely stuck. A recovered-healthy daemon (never escalated) is not flagged — that's the FP fix, using the "never escalated" discriminator from the issue._DAEMON_START_REis line-anchored (same defence class as_PRUNED_RE) so a mid-line forged--- Guard daemon started at <ISO> ---substring (e.g. inside a team-name log line) can't register as a restart.TypeError.Tests
tests/test_guard_watchdog.py— 14 new tests covering: storm-flagged-despite-stale-prunes (FN), scattered-recovery-not-flagged (FP), spread-out-restarts-not-flagged, the realf641174cfixture preserved, no-timestamp flat-count fallback, escalated-inert-flagged, forged-future-timestamp-still-flags-storm, midline-forged-header-excluded, tz-aware-treated-as-unparseable, inclusive-window-boundary, cause-neutral-reason, and a characterization test pinning the PATH A/PATH B asymmetry.Full suite: 1601 passed, 0 related failures (
--ignore=tests/test_model_detection.py). One unrelated pre-existing concurrency test (test_guard_hardening.py::TestG4_PidfileWriteIsAtomic::test_concurrent_starts_only_one_spawn_wins) is load-flaky under full-suite CPU contention — passes 3/3 in isolation and at this PR's base; the diff does not touch spawn/pidfile code.Scope / known limitations (documented, not silently dropped)
GUARD_CYCLE_ERROR_DEFER_MAX), or a mixed-generation log. This is pinned by a characterization test. A recency-anchored / escalation-independent inert signal would close it — happy to do a focused follow-up if you'd like single-generation inert parity on modern logs.Base:
main@ v1.8.33.Closes #140.