feat(bridge): behavior_v2 run-log format, --convert CLI, log_control ack (PR 1 of 3)

docs/development/runlog-behavior-v2-plan.md

@@ -1,8 +1,10 @@
-# Run-log format `behavior_v2` + large-file commit path — PLAN (not started)
+# Run-log format `behavior_v2` + large-file commit path — PLAN (PR 1 bridge shipped; PRs 2–3 pending)
 
 Owner: Michael. Drafted 2026-09-06 from the analysis of rig03-sr run `rydc2tql`
-(40 s trials, 51.4 MB, failed to auto-commit). Status: **approved direction, no code
-yet**. Implementation lands as three PRs (bridge, Studio, dashboard) in that order.
+(40 s trials, 51.4 MB, failed to auto-commit). Status: **PR 1 (bridge) implemented
+2026-09-06** — see "PR 1 implementation notes" at the end; PR 2 (Studio) and PR 3
+(dashboard/readers) not started. Implementation lands as three PRs (bridge, Studio,
+dashboard) in that order.
 
 ## Problem
 
@@ -183,3 +185,44 @@ hour-long runs — hence Part 2.
 - Convert the existing course-repo logs to v2+gz, or leave history as is?
 - Default log level after the release: `behavior_v2` everywhere, including course
   benches (recommend yes; readers handle both).
+
+## PR 1 implementation notes (bridge, 2026-09-06)
+
+What shipped in `fictrac-bridge/bridge.py` (BRIDGE_VERSION 3.0), and the facts the
+Studio (PR 2) and reader (PR 3) work must build on:
+
+- **The compact line is exactly** `["a", t_off, dt, hex, status, rx_off]` with a 7th
+  element only when v1 `error` is non-null. `t0` is the `ms` of the session line the
+  file opened with (`_open` emits session + schema together). The v1 object is
+  restored in the original key order `type, event, t, dt, len, head, status, echo,
+  ok, error, dir, rx_ms`.
+- **Correction to the plan's derivation rule:** on a timeout the real v1 lines have
+  `status: null, echo: null, ok: null` (js/arena-session.js `_logCommand` sets all
+  three from the decoded reply or leaves all three null). So `expandV2Line` must
+  emit `echo = ok = null` when `status` is null, and `echo = command byte`
+  (`head` byte 1), `ok = (status === 0)` otherwise — NOT `ok: false` on timeout.
+  The corpus has 33 such lines (rig2 `spzae5dn`), all with a non-null `error`.
+- **Lossless by construction, not by assumption:** `compact_arena_command` verifies
+  every invariant it later relies on (fixed 12-key set, `dir`, int `t`/`rx_ms`,
+  spaced lowercase hex `head` with `len` = byte count, `echo`/`ok` consistency).
+  A line that does not fit is written **verbatim** by the live bridge (stderr
+  warning) and **raises** under `--convert`/the corpus gate. Readers must therefore
+  accept a v1-shaped `arena_command` object inside a v2 file (e.g. a bulk command
+  whose `head` carries the ` …` truncation marker).
+- **Files without a v1 schema line** (pre-#140 logs, `full` level) convert to v2 with
+  a schema line inserted after the first session line carrying `"cols": null`
+  (no positional frame rows in this file); the reverse drops it. Readers: `cols`
+  may be null.
+- **Level negotiation:** `hello` → `hello_ack {bridge, levels:[behavior_v2,
+  behavior_v1, full], level, logging}`; `log_control` → `log_control_ack {enabled,
+  level, requested, file}` where `level` is the one actually in force (an unknown
+  `requested` is ignored, not applied). Old Studios ignore unknown message types
+  (`fictrac-bridge-client.js` dispatches only `frame`/`log_export_result`). Old
+  bridges never reply to `hello` — the Studio should treat "no hello_ack" as
+  "behavior_v1-only bridge".
+- **`run_metadata.log_format`** (Part 1 §3) is a Studio-side field (the Studio
+  composes that line and now knows the acked level); the bridge does not inject it,
+  so the v1↔v2 round trip stays exact.
+- **Corpus result (164 logs, 1.28 GB, origin/main of cshl-2026-course):** all pass;
+  totals in PR 1's description (1281.6 MB v1 → 655.6 MB v2 → 211.3 MB v2.gz at gzip
+  level 6). The 51 MB `rydc2tql` run → 20.4 MB v2 → 6.2 MB v2.gz.

fictrac-bridge/README.md

@@ -116,14 +116,24 @@ bridge → browser:  {"type":"frame", "index":<int>, "seq":<int>, "t":<ms>,
                      hardware clock — NANOSECONDS on our rigs — normalized here via
                      FT_TS_NS_PER_MS. `ms` is the bridge wall-clock (display axis); `ft`
                      is the velocity time base (per-frame differences, drop-safe).
+                   {"type":"hello_ack", "bridge":<str>, "levels":[<str>…], "level":<str>,
+                    "logging":<bool>}
+                     (reply to hello — the log levels this bridge can write, so the
+                      browser can tell a stale bridge before a run; an old bridge
+                      never replies to hello)
+                   {"type":"log_control_ack", "enabled":<bool>, "level":<str>,
+                    "requested":<str|null>, "file":<str|null>}
+                     (reply to log_control — `level` is the level ACTUALLY in force;
+                      an unknown requested level is ignored and this is how you know)
                    {"type":"log_export_result", "name":<str>, "content":<str>}
                      (reply to log_export; {"error":<str>} when nothing was written)
 browser → bridge:  {"type":"hello", "client":"arena_console", "v":1}   (on connect)
                    {"type":"config", "fictrac_port":<int>, "gain":<float>,
                                      "offset":<float>, "frames":<int>}  (any subset)
-                   {"type":"log_control", "enabled":<bool>, "level":"behavior_v1"|"full"}
+                   {"type":"log_control", "enabled":<bool>,
+                                          "level":"behavior_v2"|"behavior_v1"|"full"}
                                                               (open the log file; level
-                                                               picks the frame-row format)
+                                                               picks the log format)
                    {"type":"log", "event":<str>, ...arbitrary fields, "ms":<int>}
                    {"type":"log_export"}   (close the active log, stream it back whole)
 ```
@@ -135,25 +145,57 @@ re-binds the FicTrac input when `fictrac_port` changes. `log_control{enabled:tru
 **starts a new timestamped log file** and re-zeroes the behavior_v1 `ms`/`ft`
 clocks (false closes it; `--log-dir` picks where on-demand files land, default CWD).
 The log is **uniform NDJSON** — one JSON value per line; a reader parses each line
-and dispatches on `Array.isArray` (frame array vs event object). While logging is
-active the bridge records:
-
-- a one-time schema line `{"type":"frame_schema","level":"behavior_v1",
-  "cols":["ms","fc","idx","ft","x","y","hd"]}`, then **every** FicTrac record it
+and dispatches on `Array.isArray` (positional array vs event object), then on
+`arr[0]` (`"a"` = arena echo, a number = frame). While logging is active the bridge
+records:
+
+- a one-time schema line — `{"type":"frame_schema","level":"behavior_v2",
+  "cols":["ms","fc","idx","ft","x","y","hd"],"arena_cols":["t_off","dt","hex",
+  "status","rx_off"],"t0":<epoch ms>}` (default) or the `behavior_v1` form without
+  `arena_cols`/`t0` — then **every** FicTrac record it
   receives (before WS coalescing) as the positional array `[ms, fc, idx, ft, x, y, hd]`
   — `ms` bridge-relative ms, `fc` FicTrac frame counter (col 1), `idx` displayed
   arena index, `ft` FicTrac timestamp (col 22) as relative ms (**not** col-24 dt,
   which can't recover elapsed time across a dropped frame), `x`/`y`/`hd` integrated
   position + heading (rad, 5-decimal). The live scope + offline dashboard recompute
   every derived channel (turning/forward/side/speed/dir) from this via
-  `js/kinematics.js`. The **browser picks the level** per run via `log_control`'s
-  `level` (Arena Studio's runner asserts the level chosen in File ▾ → Run logging,
-  default `behavior_v1`, overriding `--log-frames`) — `--log-frames` only sets the
-  launch default. `full` logs the whole 25-column record
-  (`{"type":"fictrac_frame", ..., "fictrac":[…25…]}`) for debug/archival.
-- inbound browser `log` messages (e.g. `{"event":"arena_command", ...}` for every
-  Web Serial command, or Arena Studio's `{"event":"run_metadata", ...}` header
-  line at recorded-run start), each stamped with `dir` and `rx_ms`.
+  `js/kinematics.js`. The frame array is identical in `behavior_v1` and `behavior_v2`.
+  The **browser picks the level** per run via `log_control`'s `level` (Arena
+  Studio's runner asserts the level chosen in File ▾ → Run logging, overriding
+  `--log-level`); the bridge answers with `log_control_ack` naming the level it
+  will actually write. `full` logs the whole 25-column record
+  (`{"type":"fictrac_frame", ..., "fictrac":[…25…]}`) for debug/archival, with no
+  schema line.
+- inbound browser `log` messages (e.g. Arena Studio's `{"event":"run_metadata", ...}`
+  header line at recorded-run start), each stamped with `dir` and `rx_ms`, as
+  verbatim JSON objects.
+- the browser's `{"event":"arena_command", ...}` echo of every Web Serial command
+  (one per closed-loop 0x70 frame command, ~100 Hz — 76 % of a `behavior_v1` file's
+  bytes). Under **`behavior_v2`** each becomes the compact array
+  `["a", t_off, dt, hex, status, rx_off]` (+ a 7th `error` string when non-null):
+  `t_off`/`rx_off` are ms offsets from the schema line's `t0`, `hex` is the `head`
+  bytes without spaces, `status` is the reply status or `null` on timeout. The
+  constant/derivable v1 fields (`type`, `event`, `dir`, `len`, `echo` = the command
+  byte, `ok` = `status === 0`; all three of `status`/`echo`/`ok` are `null` when no
+  reply decoded) are restored on expansion — **lossless**, verified per line: an
+  echo that does not fit the fixed shape is written verbatim instead. Measured on
+  the course corpus (164 logs, 1.28 GB): v2 is 0.51× the v1 bytes overall and 0.38×
+  on closed-loop P3 runs; v2.gz is 0.17× overall.
+  `behavior_v1` writes the echo as the full object (the pre-2026-09 format).
+
+**Converting existing files** (migration + testing readers on real data before a rig
+produces v2), no sockets needed:
+
+```bash
+pixi run bridge -- --convert runlogs/rig1/run.jsonl run.v2.jsonl.gz   # v1 → v2 (+gzip)
+pixi run bridge -- --convert run.v2.jsonl.gz run.v1.jsonl             # and back
+```
+
+Direction is auto-detected from the `frame_schema` line (`--to v1|v2` forces it);
+`.gz` on either side is handled. The conversion is strict — an `arena_command` with
+an unexpected key set aborts instead of dropping a field. `tests/test-bridge-behavior.py`
+holds the round-trip unit tests; `scripts/runlog-v2-corpus.py` runs the same round
+trip over every log in a course-repo clone and prints the size table.
 
 `log_export` (Arena Studio's course pipeline) **closes** the active log —
 guaranteeing complete, flushed content — and streams the whole file back to the
@@ -191,7 +233,9 @@ sends it automatically when you load a Mode-3 pattern.
 | `--gain` | `1.8` | Degrees of heading per frame index (360/200); negative reverses. Re-settable live. |
 | `--offset` | `0.0` | Heading offset in degrees. |
 | `--log PATH` | on demand | Append log events (JSONL). If unset, opened when the browser enables logging. |
-| `--log-frames` | off | Log the FULL 25-column FicTrac record per frame (debug/archival) instead of the default compact `behavior_v1` array `[ms,fc,idx,ft,x,y,hd]`. |
+| `--log-level {behavior_v2,behavior_v1,full}` | `behavior_v2` | Launch default for the log format; the browser's `log_control` overrides it per run (acknowledged in `log_control_ack`). |
+| `--log-frames` | off | Alias for `--log-level full` (the 25-column FicTrac record per frame, debug/archival). |
+| `--convert IN OUT [--to v1\|v2]` | — | Offline: re-encode a run log v1 ⇄ v2 (`.jsonl` or `.jsonl.gz` either side) and exit. |
 
 ## Replaying a recorded FicTrac log