diff --git a/SAC_LSTM_Bot/docs/campaign_notebook.md b/SAC_LSTM_Bot/docs/campaign_notebook.md index 3d28a70..b0440d0 100644 --- a/SAC_LSTM_Bot/docs/campaign_notebook.md +++ b/SAC_LSTM_Bot/docs/campaign_notebook.md @@ -11,7 +11,7 @@ Launch command (tmux session `sac_campaign`, stdout teed to `campaign_stdout.log ```bash SAC_OPPONENTS='Corners:3,Crazy:2,RamFire:1,Target:1,SacTwin:1' \ SAC_EVAL_OPPONENT=Corners \ -SAC_TOTAL_ROUNDS=2000 \ +SAC_TOTAL_ROUNDS=25000 \ SAC_CHUNK_SIZE=10 \ SAC_EVAL_INTERVAL=2 \ SAC_EVAL_ROUNDS=10 \ @@ -19,7 +19,7 @@ SAC_MAX_CRASHES=5 \ SACLSTM_HIDDEN_SIZE=256 \ SACLSTM_BATCH_SIZE=16 \ SACLSTM_UTD_RATIO=1 \ -SACLSTM_SAVE_INTERVAL=20 \ +SACLSTM_SAVE_INTERVAL=5 \ ./sac_train.sh 2>&1 | tee -a campaign_stdout.log ``` @@ -27,26 +27,30 @@ SACLSTM_SAVE_INTERVAL=20 \ |------|-------|--------------------| | `SAC_OPPONENTS` | `Corners:3,Crazy:2,RamFire:1,Target:1,SacTwin:1` | Working recommendation kept. Twin pinned at **1 not 2**: #54 showed mirror battles end early ⇒ fewer transitions per chunk; weight 2 would starve the replay buffer. | | `SAC_EVAL_OPPONENT` | `Corners` | Pinned explicitly (= first pool entry default, #54 note) — removes reorder footgun. | -| `SAC_TOTAL_ROUNDS` | `2000` | Sized so the **wall-clock ceiling binds first** (~100–150 rounds/h observed incl. evals ⇒ ~13–20 h of headroom). | +| `SAC_TOTAL_ROUNDS` | `25000` | Sized so the **wall-clock ceiling binds first**: measured throughput ~3400 rounds/h early (drops as battles lengthen) ⇒ 2000 would have exhausted in ~1 h. | | `SAC_CHUNK_SIZE` | `10` | Harness default. | -| `SAC_EVAL_INTERVAL` | `2` | Harness default — eval every ~20 rounds ≈ every ~10 min. | +| `SAC_EVAL_INTERVAL` | `2` | Harness default — eval every ~20 rounds. | | `SAC_EVAL_ROUNDS` | `10` | Harness default. | | `SAC_MAX_CRASHES` | `5` | Harness self-abort; monitor intervenes earlier at ≥3 consecutive crashes (#55). | | `SACLSTM_HIDDEN_SIZE` | `256` | Module default (`network.nim`); real capacity vs #49 smoke's 32; under `MaxHidden`=512 cap. | | `SACLSTM_BATCH_SIZE` | `16` | Module default (`integration.nim`). | | `SACLSTM_UTD_RATIO` | `1` | Module default. | -| `SACLSTM_SAVE_INTERVAL` | `20` | **Deviation** from default 500: #54 proved the shutdown save never reaches disk in harness context — only mid-battle interval saves persist; 10–20 fired reliably, 50 did not in twin chunks. 20 = top of proven range, least IO. | +| `SACLSTM_SAVE_INTERVAL` | `5` | **Deviation** from default 500 and from #54's "10–20": at hidden 256 a gradient step takes ~1 s and a chunk process fits only ~10–18 steps (see incident below) — interval must sit **inside the per-process step budget**. 5 ⇒ checkpoint every ~5–10 s of active training; IO trivial (10.5 MB zip, atomic replace). | | *(not pinned)* | module defaults | `LR_ACTOR/LR_CRITIC/LR_ALPHA=3e-4`, `GAMMA=0.99`, `TAU=0.005`, `TARGET_ENTROPY=-4.0`, `BUFFER_CAPACITY=500000`, `BURN_IN=8`, `TRAIN_WINDOW=16`. | -**Budget**: generous wall-clock **ceiling, not a deadline** — **T+12 h** from launch. While HEALTHY per #55 discrimination rules the run continues; a monitor kills the tmux session at the ceiling or on an intervene threshold. +**Budget**: generous wall-clock **ceiling, not a deadline** — **T+12 h** from launch 00:21:55 CEST 2026-08-22 ⇒ ceiling **12:22 CEST 2026-08-22** (epoch 1787394115). While HEALTHY per #55 discrimination rules the run continues; a monitor kills the tmux session at the ceiling or on an intervene threshold. -**Fresh start**: pre-campaign `weights/` held #49-smoke 32-hidden checkpoints, incompatible with hidden=256. Archived to `weights_smoke49_backup/`; baseline re-established by a 10-round bootstrap battle vs Corners (also created the seed for `make_twin.sh`). +**Fresh start**: pre-campaign `weights/` held #49-smoke 32-hidden checkpoints, incompatible with hidden=256. Archived to `weights_smoke49_backup/`; campaign baseline re-established by probe battles vs Corners (random-init hidden-256 checkpoint, `best_score.txt` reset then re-raised to 20 by a genuine eval). Twin regenerated via `./make_twin.sh` from that baseline (md5 `61521cff…` verified seed). ## Phase log -- **2026-08-21 ~23:30** — Config locked (this file), claim posted on #56 (comment 471). Smoke weights archived. -- **2026-08-21 ~23:4x** — Bootstrap battle vs Corners done; baseline checkpoint + `best_score.txt` written; twin regenerated via `./make_twin.sh` from the campaign-v1 baseline. -- **2026-08-21 ~23:5x** — Launched tmux `sac_campaign`. First-health-check: see *Incidents & checks* below. +- **2026-08-21 23:22** — Claim posted on #56 (comment 471). Config locked, notebook committed (`2f49cb2`). +- **2026-08-21 23:27** — Smoke weights archived; release build; bootstrap + probe battles vs Corners established a hidden-256 baseline checkpoint (`sac_latest.zip`, 10.5 MB) and twin seed. +- **2026-08-21 23:32** — Twin regenerated (md5-verified). **Launch attempt 1** (SAVE_INTERVAL=20, TOTAL_ROUNDS=2000): ran 16+ chunks, evals every 2 chunks — but **zero checkpoints persisted** (see incident). Killed 23:48. +- **2026-08-21 23:52–00:10** — Diagnosis (see incident): interval=1 fired, interval=2/20 never; instrumentation + /proc thread forensics ⇒ per-process step budget ~10–18 at ~1 s/step; save check ran only between drain-burst passes. +- **2026-08-22 00:12** — Fix: save check moved inside the gradient-step loop, committed `2653671`. Validated: interval=5 save fired ~12 s into a battle. +- **2026-08-22 00:21:55** — **Launch (final)**: tmux `sac_campaign`, config above. First campaign save on disk at t+54 s; eval #1 on cadence. +- **2026-08-22 00:30** — HEALTHY checklist passed (see below). ## Decision-issue index @@ -54,18 +58,54 @@ SACLSTM_SAVE_INTERVAL=20 \ |-------|-----------------| | #37–#48 | Bot built: skeleton, state, actions, rewards, LSTM network, weights, SAC+LSTM training, integration. | | #49 | Training harness + smoke run (toy hyperparams: hidden 32). | -| #54 | Mirror-twin sparring partner; SAVE_INTERVAL ≤20 rule; eval opponent = first pool entry. | +| #54 | Mirror-twin sparring partner; SAVE_INTERVAL persistence rule; eval opponent = first pool entry. | | #55 | 9-signal observability inventory; CRASHED/STALLED/SLOW-LEARNER/HEALTHY discriminators; monitor thresholds. | -| #56 | This campaign: locked config + launch (this notebook). | +| #56 | This campaign: locked config + launch + the save-check fix (`2653671`). | | #57 | Morning verdict — consumes this notebook + logs. | ## Incidents & checks -*(appended during the run)* +### Incident 1 — zero checkpoint persistence at production sizes (launch blockers, fixed) -### Launch health check (first chunks) +**Symptom**: campaign ran 26+ chunk processes across two attempts without a single `sac_latest.zip` update, while rounds/evals flowed normally. #54's rule ("keep `SACLSTM_SAVE_INTERVAL` well below per-chunk gradient-step counts, 10–20 fired in smokes") silently broke at hidden 256. -Pending — filled right after launch. +**Diagnosis chain** (all reproducible): +1. Interval=1 saved within seconds; interval=2 and 20 never saved — through the *same* harness ⇒ not env propagation. +2. Temporary step instrumentation (bot stderr via a one-line `SAC_LSTM_Bot.sh` redirect — the vendored runner swallows bot stderr, #55 gap S9-adjacent): steps cost **~1.06 s each**; a drain burst queued 53 steps; logging stopped mid-pass while rounds kept completing. +3. `/proc//task` sampling: training thread alive and RUNNING (~13 s CPU per ~40 s process) — not deadlocked, just slow ⇒ **per-process step budget ≈ 10–18 steps**. +4. The save check lived *between* drain-burst passes; with bursts queueing minutes of steps, `stepCount` never reached `nextSave` before process teardown. Smoke runs masked this: hidden 32 steps were sub-millisecond, so hundreds of steps fit per chunk. + +**Fix** (commit `2653671`): save check relocated **inside** the step loop (checked every gradient step; `packFull`+`trySend` unchanged). Validated: interval=5 save fires ~12 s into a battle; campaign save fired 54 s after launch. + +**Config consequences**: `SACLSTM_SAVE_INTERVAL=5` (inside the per-process budget; #54's 10–20 was derived at smoke speeds). `SAC_TOTAL_ROUNDS=25000` (throughput measured ~3400 rounds/h, so 2000 was a 1-hour budget, not an overnight one). OMP_NUM_THREADS=1 tested and **not** needed (hang was step-budget exhaustion, not OpenMP). + +### Launch health check (t+9 min, 00:30:16) — **HEALTHY** per #55 checklist + +| Signal | Reading | Verdict | +|--------|---------|---------| +| S1 harness stdout | teed to `campaign_stdout.log`; **0** `crash`/`aborted` banners | ✓ | +| S4 round_counter | 1890, +460 in 9 min (~51 rounds/min) | ✓ advancing | +| S6 sac_latest.zip mtime | **6 s old**; first save at t+54 s | ✓ fresh | +| S2 training_log.jsonl | 1492 lines, growing; last ticks=668, plausible | ✓ | +| S3 eval_log.jsonl | age 3 s (atomic replace); eval every 2 chunks | ✓ on cadence | +| S5 best_score | 20 (from a genuine campaign-1 eval; non-decreasing) | ✓ | +| Sampling | 112 chunks: Corners 41 / Crazy 25 / RamFire 15 / SacTwin 16 / Target 15 ≈ weights 3:2:1:1:1 | ✓ plausible | +| Disk | 418 GB free | ✓ | + +Early evals 0% vs Corners — expected for a near-random policy minutes in; SLOW-LEARNER watch rule (flat ≥5 evals = watch) applies, never intervene. + +## Check-in procedure (for monitor sessions) + +```bash +tmux capture-pane -p -t sac_campaign | tail -5 # S1: banners, crashes +cat ~/Projects/SirRoboGarage/SAC_LSTM_Bot/weights/round_counter.txt +stat -c '%Y' ~/Projects/SirRoboGarage/SAC_LSTM_Bot/weights/sac_latest.zip # age <~600s = training alive +tail -1 ~/Projects/SirRoboGarage/SAC_LSTM_Bot/training_log.jsonl +tail -3 ~/Projects/SirRoboGarage/SAC_LSTM_Bot/campaign_stdout.log # eval results / new best +cat ~/Projects/SirRoboGarage/SAC_LSTM_Bot/weights/best_score.txt +``` + +Intervene per #55 thresholds: ≥3 consecutive `crash #N` banners; ΔS4=0 over ≥15 min; zip mtime >10 min stale while S4 advances (STALLED); disk <1 GB. At the **ceiling (12:22 CEST Aug 22)**: `tmux kill-session -t sac_campaign` if still running — final state is in `weights/`, logs, and this notebook. ## Results