memory: run 3c had TWO launches — the third was an untimestamped report

brokkr-smithy-dev asked how many times 3c was launched rather than reconstructing it, and their reading was three. It was two. #1 17:53:33 PDT killed by the power loss at step 80/604 #2 20:58:41 PDT stopped deliberately at 21:07:40, healthy The phantom third came from a report I wrote at 23:03 narrating the 21:07 kill in the present tense with no timestamp. Every fact in it was accurate; it was unreadable in sequence against a correctly-observed 22:46 snapshot of an idle GPU. Evidence is ZFS birth times (a `>` redirect truncates the log but keeps its birth, so mtime alone cannot separate "rewritten" from "created"), plus the absence of any mtime under /tank/erp-tune after 21:07:34 — a relaunch would have rewritten three files there. Also pins the outage window to 18:14:45-18:17:00 PDT and corrects the downtime from "~90 minutes" to 1h58m: the last journald entry before a hard power loss is the last time anything wanted to log, not the moment of the loss, and here it was 20 minutes early. Corrects the in-flight header (step 22 -> last-logged step 24, stop deliberate) and its stale "as of" stamp.
2026-08-27 10:59:29 -07:00
parent 98e7d4886a
commit 88d79375f7
3 changed files with 78 additions and 3 deletions
@@ -1,6 +1,9 @@
 # `[2026-08-27]` Anaheim tripped a power breaker — and four guests including the NAS never came back

-Site-wide outage, ~90 minutes. **Operator-confirmed cause: a tripped power breaker**, not a
+Site-wide outage. **ana-ml2 was down 1h58m** — power lost between **18:14:45 and 18:17:00 PDT**,
+boot at **20:13:14** (the "~90 minutes" first recorded here was an estimate; the window is now
+pinned by run 3c's training log and the hourly cron that never ran — see
+[[2026-08-27-run3c-launch-count-reconstruction]]). **Operator-confirmed cause: a tripped power breaker**, not a
 fault and not the tunnel. The discriminator that established scope: `ana-srv1`
 (38.120.12.44:443, Anaheim's PUBLIC address) was dark **from the internet**, so it was not the
 NH3↔ANA IPsec tunnel stranding NH3 — the site was not answering on any path. `ana-ml2` returned
@@ -0,0 +1,71 @@
+# `[2026-08-27]` There were TWO run-3c launches, not three — and the phantom third was my reporting
+
+brokkr-smithy-dev asked, rather than guessed, how many times 3c was launched. Their reading was
+three. **It was two**, and the third was an artifact of a state report I wrote without a
+timestamp.
+
+    #1   launched 2026-08-26 17:53:33 PDT   killed by the power loss at step 80/604
+    #2   launched 2026-08-26 20:58:41 PDT   STOPPED BY ME at 21:07:40, healthy, on operator instruction
+
+**3c did not "die twice". It died once and was stopped once.**
+
+## The evidence, and where it lives
+
+| fact | source |
+|---|---|
+| #1 launched 17:53:33 | `run-03c.log` ZFS **birth** time (`stat -c %w`) |
+| #1 reached step 80/604 | `80/604 [18:15<2:23:38, 16.45s/it]` — read at 20:14, one minute after boot |
+| #2's config rewritten 20:58:36 | `run-03c.json` mtime, same second as harness `0a6bd2e` (save_steps configurable) |
+| #2's output tree is FRESH | `run-03c/` **birth** 20:58:41 — a new tree, not a resume; `checkpoints/` empty |
+| #2 trained 21:01:25 → 21:07:34 | `batch-order.jsonl` mtime → `run-03c.log` mtime |
+| **no #3** | nothing under `/tank/erp-tune` has an mtime after 21:07:34. The launcher redirects with `>`, so a relaunch truncates `run-03c.log` and rewrites `order-manifest.jsonl` + `batch-order.jsonl`. All three still carry launch-#2 stamps. |
+
+`stat`'s **birth** time is what made this tractable — mtime alone cannot distinguish "truncated
+and rewritten" from "created now", and `run-03c.log` was both (born 17:53:33, last written
+21:07:34).
+
+## The outage window, pinned to two minutes
+
+    train start #1        ≈17:56:30   (launch + 2m50s setup, measured on the relaunch)
+    step 80 at 18:15 elapsed ≈18:14:45
+    last journald entry, boot -1  17:54:38   (an ssh logout; the box was idle after, so it logged nothing)
+    the 18:17 hourly cron         never ran
+    boot 0                        20:13:14
+
+**Power was lost between 18:14:45 and 18:17:00 PDT; ana-ml2 was down 1h58m** — not the "~90
+minutes" recorded in [[2026-08-27-anaheim-breaker-and-onboot-gap]], which is corrected there.
+
+⚠ The last journald entry of a hard-power-loss boot is **not** the moment of the loss — it is the
+last time anything wanted to log. Here that was 20 minutes early. The training log's own progress
+line was the tight bound; journald only bracketed it.
+
+## Step 22 vs step 24
+
+I reported "stopped at step 22". The log's last step is 24. My stop command read progress with
+`tail -c 400 | tail -1` and the final flush at 21:07:34 carried 23 and 24 — written between my
+read and the kill at 21:07:40. **24 is true; 22 was a ~20-second-stale tail.** Not evidence of a
+different run.
+
+## ⚠ THE DURABLE FINDING — an event report with no timestamp is a claim about "now"
+
+At 23:03 I wrote *"Run 3c is STOPPED … GPU0 released: 300 W / 89.7 GB / 99% → 45 W / 2 MiB / 0%"*
+in the present tense. That happened at 21:07:40. brokkr had a correctly-observed 22:46 snapshot
+(no process, GPU idle, log last written 21:07) and my untimestamped report; **the only way to
+reconcile them was to invent a launch between the two.**
+
+Every fact in my message was accurate. It was unreadable *in sequence*. Same family as
+[[feedback_confirm_reboot_by_observing_down]] and the two errors caught that night by checking
+effect rather than exit code — the report looked current and nothing forced it to prove it.
+
+**Put the wall clock on every state report.** Where a reading came from a command, quote the
+command's own clock (`uptime`'s `21:07:27 up 54 min` sat in the same tool output as the 300 W
+reading and would have settled this instantly).
+
+## Second-order cost
+
+brokkr's degraded-pool hypothesis was built on *"both 3c attempts have died on a DEGRADED pool"*
+— two data points. There was one, and it has a sufficient cause that is not the pool. They
+retracted the hypothesis as wrong about the cause; it was also **operating on an input I gave
+them wrong**. A bad timestamp does not stay in your own artifact.
+
+Reply: althing msg `01M125XZAB7DESMCD3751T7TTH`, thread `01M10CZSH1RPQSSAJNFZJDJMD5`.