Story 1374: Measure What Users Actually Get From the Atlas Rail

Bug-1372 hung Step-5 ("thinking" forever) for ~15% of runs, and a human found it after a marathon. Direct-invoke, unit tests, and CI were all green the entire time. Nothing was wrong with the code paths anyone tested — what was broken was delivery: the terminal frame that settles the UI never reached the reconnected browser, and nothing measured that. This Story makes the rail report, per run, whether the user actually got their terminal frame — and pages on the first one who doesn't.

Why this matters (the catastrophe avoided)

A smoke detector that only tests itself is not a smoke detector. The old observability watched components: the brain completed, the worker invoked, the run persisted succeeded in the DB. Every one of those was green during Bug-1372. The thing that was on fire — "did a terminal frame reach a live socket?" — was the one thing no signal watched. So the fix is not another synthetic probe (that is a backstop); the fix is to instrument the real traffic at the exact seam where delivery succeeds or fails, define an SLO on it, and alarm when real users stop getting frames.

🛰️ Satellite: where a run is born and where it must land

  WS $default (app_api)        Clerk worker (this repo)            Browser
  ───────────────────          ────────────────────────           ───────
  stamps launched_at_ms   →    invokes brain, streams,        →   run.done lands
  on the launch command        pushes frames to the socket        on a LIVE socket
                               ── on 410 Gone, re-resolves         = DELIVERED
                                  the live socket (Bug-1372) ──    (or it hangs)
    

The clock starts when the client hits the WS edge and stops when a live socket accepts the terminal frame. That span — launch to delivered — is the latency the user feels. Component time (brain completion) is not; a slow rail can hide behind a fast brain.

✈️ Airplane: the seam already knew the answer — we just never asked it

The _FramePusher (built in #356 for the Bug-1372 recovery) already returns whether a terminal frame reached a live socket: True from the launch connection or a re-resolved live one, and it falls through when no live connection exists. That fall-through is the hang. We taught the pusher to remember two facts:

The three combine into one outcome the SLO reads:

🔬 Microscopic: two lines that stop the metric from ever lying

A delivery metric is only trustworthy if it always fires and measures the right instant. Two deliberate choices in src/clerk_worker/runner.py:

1. Emitted in a finally — a hard hang can never read as "no traffic."

  try:
      body = _invoke_brain(command, deps)
      outcome = await _consume_stream(body, command, deps, pusher)
  except Exception as exc:
      await _fail_run(deps, ..., pusher=pusher)   # brain/infra failure → run.failed truth
      outcome = "failed"
  finally:
      _emit_run_delivery(pusher, launched_at_ms=launched_at_ms, ...)   # ALWAYS one outcome
    

Whatever happens inside the launch — success, brain failure, the Bug-1345 mid-stream stall, an unexpected raise — exactly one atlas_run outcome is emitted. If the run never reached terminal, it emits error, never silence. The only escape is a Lambda hard SIGKILL, and the new pramaan-clerk-worker-errors alarm backstops that.

2. The latency clock stops at DELIVERED, not at the DB write.

  async def push(self, frame_type, payload):
      delivered = await self._deliver(frame_type, payload)   # True iff a LIVE socket accepted it
      if frame_type in self._RUN_TERMINAL:
          self.terminal_seen = True
          if delivered and not self.terminal_delivered:
              self.terminal_delivered = True
              self.terminal_delivered_at_ms = self._deps.wall_clock() * 1000.0
    

time_to_terminal_frame_ms = terminal_delivered_at_ms − launched_at_ms. Because the timestamp is captured the moment _deliver returns True — a live socket accepted the frame — the latency is launch-to-delivered, not brain-completion. A run that completes in the DB but never reaches the user contributes zero latency samples and one hung count, exactly as it should.

From metric to pager

The worker emits EMF: AtlasRunDelivery{result} (count) and AtlasRunTimeToTerminalFrameMs (delivered runs only). provision-rail-delivery-alarms.yml turns them into SLO alarms on the existing pramaan-bridge-alarms topic (pramaan-docs ADR-028):

One structured line per run, clerk.run_delivery: <result> keyed by correlation_id + run_id (pramaan-docs ADR-104), makes a stall a one-query root cause.

The backstop, kept in its place

Scope discipline