vh
88d79375f7
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.
72 lines
4.0 KiB
Markdown
72 lines
4.0 KiB
Markdown
# `[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`.
|