fix(mcp): place Railway log records by their own time in the first-load timeline

apps/mcp/scripts/first-load-timeline.mjs

@@ -25,13 +25,17 @@ const lines = file => readFileSync(file, 'utf8').split('\n').filter(line => line
 /** Records before the first window's start that still belong to it (discovery right before sending). */
 const LEAD_MS = 2_000;
 
-/** One normalized entry: when, what kind, and the fields worth printing. */
+/**
+ * One normalized entry: when, what kind, and the fields worth printing. An application record's own `at` is when it
+ * happened. Railway's `timestamp` is when Railway collected the line, in batches, so it is only the fallback: preferring
+ * it reorders records and moves them out of the window they belong to.
+ */
 function normalize(raw) {
   const time = Date.parse(raw.timestamp ?? '') || raw.at;
   if (typeof raw.message === 'string' && raw.message.startsWith('{')) {
     try { const record = JSON.parse(raw.message); return {...record, at: record.at ?? time}; } catch { /* plain text line */ }
   }
-  if (raw.event) return {...raw, at: time};
+  if (raw.event) return {...raw, at: typeof raw.at === 'number' ? raw.at : time};
   const path = raw.path ?? raw.attributes?.path;
   if (path !== undefined) return {event: 'edge', at: time, ...raw};
   return undefined;

apps/mcp/test/first-load-timeline.test.ts

@@ -0,0 +1,56 @@
+import assert from 'node:assert/strict';
+import {test} from 'node:test';
+import {execFileSync} from 'node:child_process';
+import {mkdtempSync, rmSync, writeFileSync} from 'node:fs';
+import {tmpdir} from 'node:os';
+import {join} from 'node:path';
+import {fileURLToPath} from 'node:url';
+
+const script = fileURLToPath(new URL('../scripts/first-load-timeline.mjs', import.meta.url));
+const at = (iso: string) => Date.parse(iso);
+
+function timeline(trials: object[], log: object[]) {
+  const dir = mkdtempSync(join(tmpdir(), 'first-load-timeline-'));
+  try {
+    const jsonl = (rows: object[]) => rows.map(row => JSON.stringify(row)).join('\n') + '\n';
+    writeFileSync(join(dir, 'trials.jsonl'), jsonl(trials));
+    writeFileSync(join(dir, 'app.jsonl'), jsonl(log));
+    return execFileSync(process.execPath, [script, join(dir, 'trials.jsonl'), join(dir, 'app.jsonl')], {encoding: 'utf8'});
+  } finally {
+    rmSync(dir, {recursive: true, force: true});
+  }
+}
+
+const trial = {host: 'claude', deploy: 'fresh', card: 'closed', label: 'order', first: 'card', retry: 'n-a',
+  start: '2026-10-30T12:00:10.000Z', end: '2026-10-30T12:00:20.000Z'};
+
+// `railway logs --deployment --json` lifts a JSON record's fields to the top level and adds its own `timestamp`, which is
+// when Railway collected the line, in batches. The record's own `at` is when it happened.
+test('a Railway record is placed by its own time, not the batch timestamp Railway added', () => {
+  const out = timeline([trial], [
+    {event: 'mcp.rpc', rpc: 'resources/read', rid: 'r3', at: at('2026-10-30T12:00:19.500Z'), timestamp: '2026-10-30T12:00:20.400Z', message: ''},
+    {event: 'mcp.rpc', rpc: 'tools/list', rid: 'r1', at: at('2026-10-30T12:00:11.000Z'), timestamp: '2026-10-30T12:00:20.500Z', message: ''},
+    {event: 'mcp.rpc', rpc: 'tools/call', rid: 'r2', at: at('2026-10-30T12:00:15.000Z'), timestamp: '2026-10-30T12:00:20.100Z', message: ''},
+  ]);
+  const lines = out.split('\n').filter(line => /^\s*\+[\d.]+s → /.test(line));
+  assert.deepEqual(lines.map(line => line.trim()), [
+    '+1.00s → tools/list [r1]',
+    '+5.00s → tools/call [r2]',
+    '+9.50s → resources/read [r3]',
+  ]);
+  assert.doesNotMatch(out, /no card read was observed/);
+});
+
+test('a Railway line without its own time falls back to the batch timestamp', () => {
+  const out = timeline([trial], [
+    {event: 'startup', timestamp: '2026-10-30T12:00:12.000Z', message: ''},
+  ]);
+  assert.match(out, /\+2\.00s · startup/);
+});
+
+test('a record wrapped in a Railway message keeps its own time', () => {
+  const out = timeline([trial], [
+    {timestamp: '2026-10-30T12:00:25.000Z', message: JSON.stringify({event: 'mcp.rpc', rpc: 'tools/call', rid: 'w1', at: at('2026-10-30T12:00:13.000Z')})},
+  ]);
+  assert.match(out, /\+3\.00s → tools\/call \[w1\]/);
+});