Observability inventory: what can we watch mid-run? #55

New Issue

2026-08-21T22:36:46+02:00

SirStone commented

2026-08-21 22:36:46 +02:00

Child of the map Overnight Training Campaign — SAC_LSTM_Bot.

Question

What training/health signals does a running campaign expose, and how do we distinguish "crashed/stalled" from "slow learner" from "healthy"? Inventory from local resources only (sac_train.sh, integration.nim logging, tools/training_runner/RunTraining.java output, weights/ artifacts like best_score.txt and round_counter.txt, eval logs): signal list with format/location/update cadence; then propose the minimal watch-set plus concrete unhealthy thresholds (e.g. battle-chunk crash loop, zero transitions over N minutes, frozen round counter, eval-score regression window). Consumed by Lock campaign-v1 config and launch overnight run to define its monitoring loop.

Child of the map *Overnight Training Campaign — SAC_LSTM_Bot*. ## Question What training/health signals does a running campaign expose, and how do we distinguish "crashed/stalled" from "slow learner" from "healthy"? Inventory from local resources only (`sac_train.sh`, `integration.nim` logging, `tools/training_runner/RunTraining.java` output, weights/ artifacts like `best_score.txt` and `round_counter.txt`, eval logs): signal list with format/location/update cadence; then propose the minimal watch-set plus concrete unhealthy thresholds (e.g. battle-chunk crash loop, zero transitions over N minutes, frozen round counter, eval-score regression window). Consumed by *Lock campaign-v1 config and launch overnight run* to define its monitoring loop.

SirStone added the wayfinder:research label 2026-08-21 22:36:46 +02:00

SirStone referenced this issue

2026-08-21 22:37:33 +02:00

Lock campaign-v1 config and launch overnight run #56

SirStone self-assigned this 2026-08-21 22:45:05 +02:00

SirStone commented

2026-08-21 22:47:38 +02:00

Resolution — observability inventory (local sources only)

Sources read: SAC_LSTM_Bot/sac_train.sh, src/SAC_LSTM_Bot/integration.nim, src/SAC_LSTM_Bot.nim, network.nim (isEvalMode), weights.nim (save mechanics), tools/training_runner/RunTraining.java, plus real smoke-run artifacts from #49 (weights/*, training_log.jsonl, eval_log.jsonl).

Signal table

#	Name	Location	Format	Update cadence / trigger	Healthy signature	Unhealthy signature
S1	Harness stdout	sac_train.sh stdout (not persisted — launcher must `tee`)	Human text: `=== Chunk i/N …`, `crash #k — restarting chunk`, `>>> [eval] win rate: W/R (P%)`, `new best (P%)`, `>>> aborted: …`	Per chunk / eval / crash	Steady chunk banners; occasional `new best`	`aborted: N consecutive crashes`, `[eval] crashed`, `[eval] no results`
S2	Training log	`SAC_LSTM_Bot/training_log.jsonl` (append-only)	One JSON/round from RunTraining.java: `{"type":"game","round":N,"ticks":N,"score":N,"total_score":N,"win":bool,"opponent":"str"}`; `round` restarts at 1 each battle	Per RoundEnded event (~seconds)	Line count grows between check-ins; ticks ~300–900; wins trend up	File stops growing while harness alive (stall); score pinned at 0 for many battles (learner)
S3	Eval log	`SAC_LSTM_Bot/eval_log.jsonl`	Same format, EVAL_ROUNDS lines (default 10); replaced atomically (`mv .tmp`) per successful eval	Every `SAC_EVAL_INTERVAL` chunks	Fresh mtime on eval cadence; win rate non-decreasing trend	Stale mtime past 2× expected eval interval; `>>> [eval] crashed` in S1 (old log kept)
S4	Round counter	`weights/round_counter.txt`	Plain int, +1 per round end (`bumpRoundCounter()` in onRoundEnded, main thread, fires in eval battles too); monotonic, never auto-reset	Per round (~seconds)	Advances steadily during active windows	Frozen ≥2 agent check-ins (≥15 min apart) during scheduled active time
S5	Best score	`weights/best_score.txt`	Int percent; written only on strict improvement of eval win rate	Per improving eval	Non-decreasing; increments = learning	⚠️ Flat ≠ broken (plateau is normal — see discrimination rules). Trap: value `0` + `sac_best.zip` present means "best-so-far is 0%", seen in #49 smoke run
S6	Latest checkpoint	`weights/sac_latest.zip`	Zip, fixed size (~270 KB, 43 `.npy`: actor+c1+c2+tc1+tc2+alpha). Atomic write (.tmp+move). Written by I/O thread every `SACLSTM_SAVE_INTERVAL`=500 gradient steps (UTD=1 ⇒ ≈500 transitions ≈ every ~20–60 s of active play)	Per save interval	mtime fresh (<~5 min) during active run	mtime stale while S4 advances ⇒ training/I-O thread wedged (the STALLED discriminator)
S7	Best checkpoint	`weights/sac_best.zip`	Copy of sac_latest.zip at moment of new-best eval	Only on eval improvement	mtime ages slowly, refreshes on improvement	Very old mtime = long plateau (watch, not act)
S8	Crash events	S1 text only (no dedicated file)	`crash #k` banners; harness hard-aborts at `SAC_MAX_CRASHES`=5	Per failed chunk	0 banners	≥3 consecutive without a successful chunk (alert before the harness's own 5-abort)
S9	Bot stderr	bot process stderr	Single rare line: `[sac] checkpoint load failed (…) — random init`	On corrupt/unloadable checkpoint	Absent	Present ⇒ silent quality reset to random init

Minimal watch-set for the periodic check-in agent (order matters, <1 min)

S1 tail — any >>> aborted or dead process? → likely CRASHED, stop here.
S4 — read round_counter.txt, compare to previous check-in: Δ=0 over ≥15 min in active window → CRASHED/STALLED.
S6 mtime — stat -c %Y weights/sac_latest.zip: fresh ⇒ training thread alive; stale while S4 advanced ⇒ STALLED (learning stopped, motion continues — S4 alone cannot detect this because it's bumped by the bot's event thread, independent of the training thread).
S2 — line-count delta + last line's ticks/score plausibility.
S3+S5 — eval cadence kept? win rate trend vs best?
Disk — df headroom on the repo volume.

Concrete thresholds (for the monitoring loop)

Crash loop: intervene at ≥3 consecutive crash #N banners with no intervening successful chunk (harness self-aborts at 5; don't wait for it). Process absent + nonzero exit ⇒ intervene immediately.
Frozen round counter: Δ(S4)=0 across 2 check-ins ≥15 min apart during scheduled active time. (Runner's own in-battle guard is much tighter: 10 harness rounds AND ≥10 s — trust it for mid-chunk death; the coarse window is for between-chunk hangs.)
Zero transitions (proxy — there is no direct transition counter, see gaps): sac_latest.zip mtime older than max(10 min, 3× median observed inter-save gap) while rounds still complete ⇒ training pipeline stalled. Allow one warm-up grace period after launch (buffer needs ≥ batch×seq-len transitions before first step; canSample gate).
Eval score: 'watch' = best_score.txt flat over ≥5 consecutive evals (≈10 chunks). 'intervene' = 3 consecutive evals each scoring <50% of the established best after a best ≥10% was reached (real regression), or S9 fired (silent random re-init). Best-not-improving alone is NEVER intervene.
Disk floor: campaign footprint is tiny — logs ~0.13 KB/round (≈11 MB/day absolute worst case at 24 h continuous play), zips fixed 0.54 MB combined, no growth. Warn <1 GB free, intervene <100 MB (generous floor covers unexpected server/core dumps).
Growth projection: sac_*.zip sizes are architecture-fixed and overwritten in place — zero growth, no rotation needed. Only S2/S3 (and the launcher's stdout capture, if redirected) grow, linearly in rounds.

Four-way discrimination

CRASHED — S1 shows abort/dead process, OR (ΔS4=0 ∧ ΔS2=0 ∧ ΔS6-mtime=0) across check-ins: nothing moves.
STALLED — process alive ∧ S4 advancing ∧ S2 growing, but S6 mtime stale >10 min: bot plays, learning/persistence is wedged (or S9 fired: weights silently reset to random).
SLOW-LEARNER — all liveness green (S4 rate, S6 fresh mtime, S3 on cadence) ∧ S5 flat ≥5 evals or mild WR decline: watch, don't touch.
HEALTHY — S4 advancing at expected pace ∧ S6 mtime <5 min ∧ S2 growing with plausible ticks ∧ S3 firing on schedule ∧ S5 non-decreasing.

Observability gaps worth flagging

No training-thread metrics exist. No actor/critic loss, alpha, gradient-step count, buffer size, or transitions/sec is logged anywhere. RunTraining.java's header claims the bot writes "actorLoss, valueLoss…" to the shared log — true for PPO_Bot, false for SAC_LSTM_Bot (inherited-comment trap). All learning-health inference above is proxy-based. Cheapest future fix: log {stepCount,buf.len,alpha} per save in ioThreadEntry.
Silent channel drops: cap-256 train channel and cap-1 save channel discard on overflow (trySend result ignored) — backpressure is undetectable externally.
Eval battles train too: nothing gates sendTrainingMsg on isEvalMode() — deterministic-eval rounds feed the replay buffer and consume save-interval budget; eval WR is measured on a moving policy.
Adam momentum resets every restart (trainerFromFull carries no optimizer state) — post-crash-loss transient invisible.
No timestamps inside JSONL lines — file mtimes are the only clocks.
Harness stdout unpersisted by design — launch command MUST redirect (… | tee run.out) or S1/S8 are lost to the AFK operator.

— Research artifact for Lock campaign-v1 config and launch overnight run (#56): define its monitor loop from the watch-set + thresholds above.

## Resolution — observability inventory (local sources only) Sources read: `SAC_LSTM_Bot/sac_train.sh`, `src/SAC_LSTM_Bot/integration.nim`, `src/SAC_LSTM_Bot.nim`, `network.nim` (isEvalMode), `weights.nim` (save mechanics), `tools/training_runner/RunTraining.java`, plus real smoke-run artifacts from #49 (`weights/*`, `training_log.jsonl`, `eval_log.jsonl`). ### Signal table | # | Name | Location | Format | Update cadence / trigger | Healthy signature | Unhealthy signature | |---|------|----------|--------|--------------------------|-------------------|---------------------| | S1 | Harness stdout | sac_train.sh stdout (**not persisted — launcher must `tee`**) | Human text: `=== Chunk i/N …`, `crash #k — restarting chunk`, `>>> [eval] win rate: W/R (P%)`, `new best (P%)`, `>>> aborted: …` | Per chunk / eval / crash | Steady chunk banners; occasional `new best` | `aborted: N consecutive crashes`, `[eval] crashed`, `[eval] no results` | | S2 | Training log | `SAC_LSTM_Bot/training_log.jsonl` (append-only) | One JSON/round from RunTraining.java: `{"type":"game","round":N,"ticks":N,"score":N,"total_score":N,"win":bool,"opponent":"str"}`; `round` restarts at 1 each battle | Per RoundEnded event (~seconds) | Line count grows between check-ins; ticks ~300–900; wins trend up | File stops growing while harness alive (stall); score pinned at 0 for many battles (learner) | | S3 | Eval log | `SAC_LSTM_Bot/eval_log.jsonl` | Same format, EVAL_ROUNDS lines (default 10); **replaced atomically** (`mv .tmp`) per successful eval | Every `SAC_EVAL_INTERVAL` chunks | Fresh mtime on eval cadence; win rate non-decreasing trend | Stale mtime past 2× expected eval interval; `>>> [eval] crashed` in S1 (old log kept) | | S4 | Round counter | `weights/round_counter.txt` | Plain int, +1 per round end (`bumpRoundCounter()` in onRoundEnded, main thread, fires in eval battles too); monotonic, never auto-reset | Per round (~seconds) | Advances steadily during active windows | Frozen ≥2 agent check-ins (≥15 min apart) during scheduled active time | | S5 | Best score | `weights/best_score.txt` | Int percent; written **only on strict improvement** of eval win rate | Per improving eval | Non-decreasing; increments = learning | ⚠️ Flat ≠ broken (plateau is normal — see discrimination rules). Trap: value `0` + `sac_best.zip` present means "best-so-far is 0%", seen in #49 smoke run | | S6 | Latest checkpoint | `weights/sac_latest.zip` | Zip, **fixed size** (~270 KB, 43 `.npy`: actor+c1+c2+tc1+tc2+alpha). Atomic write (.tmp+move). Written by I/O thread every `SACLSTM_SAVE_INTERVAL`=500 gradient steps (UTD=1 ⇒ ≈500 transitions ≈ every ~20–60 s of active play) | Per save interval | **mtime fresh (<~5 min) during active run** | mtime stale while S4 advances ⇒ training/I-O thread wedged (the STALLED discriminator) | | S7 | Best checkpoint | `weights/sac_best.zip` | Copy of sac_latest.zip at moment of new-best eval | Only on eval improvement | mtime ages slowly, refreshes on improvement | Very old mtime = long plateau (watch, not act) | | S8 | Crash events | S1 text only (no dedicated file) | `crash #k` banners; harness hard-aborts at `SAC_MAX_CRASHES`=5 | Per failed chunk | 0 banners | ≥3 consecutive without a successful chunk (alert before the harness's own 5-abort) | | S9 | Bot stderr | bot process stderr | Single rare line: `[sac] checkpoint load failed (…) — random init` | On corrupt/unloadable checkpoint | Absent | Present ⇒ silent quality reset to random init | ### Minimal watch-set for the periodic check-in agent (order matters, <1 min) 1. **S1 tail** — any `>>> aborted` or dead process? → likely CRASHED, stop here. 2. **S4** — read `round_counter.txt`, compare to previous check-in: Δ=0 over ≥15 min in active window → CRASHED/STALLED. 3. **S6 mtime** — `stat -c %Y weights/sac_latest.zip`: fresh ⇒ training thread alive; stale while S4 advanced ⇒ STALLED (learning stopped, motion continues — S4 alone cannot detect this because it's bumped by the bot's *event* thread, independent of the training thread). 4. **S2** — line-count delta + last line's ticks/score plausibility. 5. **S3+S5** — eval cadence kept? win rate trend vs best? 6. **Disk** — `df` headroom on the repo volume. ### Concrete thresholds (for the monitoring loop) - **Crash loop**: intervene at **≥3 consecutive `crash #N` banners** with no intervening successful chunk (harness self-aborts at 5; don't wait for it). Process absent + nonzero exit ⇒ intervene immediately. - **Frozen round counter**: **Δ(S4)=0 across 2 check-ins ≥15 min apart** during scheduled active time. (Runner's own in-battle guard is much tighter: 10 harness rounds AND ≥10 s — trust it for mid-chunk death; the coarse window is for between-chunk hangs.) - **Zero transitions** (proxy — there is **no direct transition counter**, see gaps): `sac_latest.zip` mtime older than **max(10 min, 3× median observed inter-save gap)** while rounds still complete ⇒ training pipeline stalled. Allow one warm-up grace period after launch (buffer needs ≥ batch×seq-len transitions before first step; `canSample` gate). - **Eval score**: **'watch'** = `best_score.txt` flat over **≥5 consecutive evals** (≈10 chunks). **'intervene'** = 3 consecutive evals each scoring **<50% of the established best** after a best ≥10% was reached (real regression), or S9 fired (silent random re-init). Best-not-improving alone is NEVER intervene. - **Disk floor**: campaign footprint is tiny — logs ~0.13 KB/round (≈11 MB/day absolute worst case at 24 h continuous play), zips fixed 0.54 MB combined, no growth. Warn **<1 GB free**, intervene <100 MB (generous floor covers unexpected server/core dumps). - **Growth projection**: `sac_*.zip` sizes are architecture-fixed and overwritten in place — **zero growth, no rotation needed**. Only S2/S3 (and the launcher's stdout capture, if redirected) grow, linearly in rounds. ### Four-way discrimination - **CRASHED** — S1 shows abort/dead process, OR (ΔS4=0 ∧ ΔS2=0 ∧ ΔS6-mtime=0) across check-ins: nothing moves. - **STALLED** — process alive ∧ S4 advancing ∧ S2 growing, but **S6 mtime stale >10 min**: bot plays, learning/persistence is wedged (or S9 fired: weights silently reset to random). - **SLOW-LEARNER** — all liveness green (S4 rate, S6 fresh mtime, S3 on cadence) ∧ S5 flat ≥5 evals or mild WR decline: watch, don't touch. - **HEALTHY** — S4 advancing at expected pace ∧ S6 mtime <5 min ∧ S2 growing with plausible ticks ∧ S3 firing on schedule ∧ S5 non-decreasing. ### Observability gaps worth flagging 1. **No training-thread metrics exist.** No actor/critic loss, alpha, gradient-step count, buffer size, or transitions/sec is logged anywhere. `RunTraining.java`'s header claims the bot writes "actorLoss, valueLoss…" to the shared log — true for PPO_Bot, **false for SAC_LSTM_Bot** (inherited-comment trap). All learning-health inference above is proxy-based. Cheapest future fix: log `{stepCount,buf.len,alpha}` per save in `ioThreadEntry`. 2. **Silent channel drops**: cap-256 train channel and cap-1 save channel discard on overflow (`trySend` result ignored) — backpressure is undetectable externally. 3. **Eval battles train too**: nothing gates `sendTrainingMsg` on `isEvalMode()` — deterministic-eval rounds feed the replay buffer and consume save-interval budget; eval WR is measured on a moving policy. 4. **Adam momentum resets every restart** (`trainerFromFull` carries no optimizer state) — post-crash-loss transient invisible. 5. **No timestamps inside JSONL lines** — file mtimes are the only clocks. 6. **Harness stdout unpersisted by design** — launch command MUST redirect (`… | tee run.out`) or S1/S8 are lost to the AFK operator. — Research artifact for *Lock campaign-v1 config and launch overnight run* (#56): define its monitor loop from the watch-set + thresholds above.

SirStone closed this issue

2026-08-21 22:48:30 +02:00

SirStone referenced this issue

2026-08-21 22:50:37 +02:00

Overnight Training Campaign — SAC_LSTM_Bot #53

SirStone referenced this issue

2026-08-21 23:22:15 +02:00

Lock campaign-v1 config and launch overnight run #56

SirStone referenced this issue

2026-08-22 00:32:17 +02:00

Lock campaign-v1 config and launch overnight run #56

SirStone referenced this issue