diff --git a/changelog.d/2624.fixed.md b/changelog.d/2624.fixed.md new file mode 100644 index 000000000..be3f5e6c8 --- /dev/null +++ b/changelog.d/2624.fixed.md @@ -0,0 +1 @@ +A trace rotation whose flush is refused no longer prunes the oldest segment, so the last durable trace file stays on disk instead of being deleted while the newer records exist only in memory ([#2624](https://github.com/ThinkFlowLab/FlyBot/issues/2624)). diff --git a/docs/subsystems/timeline.md b/docs/subsystems/timeline.md index 814efe780..28fa93b4c 100644 --- a/docs/subsystems/timeline.md +++ b/docs/subsystems/timeline.md @@ -48,7 +48,7 @@ Everything in `plugins/timeline/`: the recorder, the trace file, the read model 1. Timeline code stays inside `plugins/timeline/`. Events come only from `ctx.flybot` (the activity feed); it never subscribes to DSH `session/event`, never edits `ds-bot/` or `core/src/`. Runtime sources import only this package, Node builtins or `ds-bot` (#153, enforced by `scripts/lint-plugins.mjs`). 2. Metadata only. A trace record holds ids, times, outcomes, tool names, message lengths, cleaned Bot/group names and the model a turn ran on (`te.md`, `provider/model` from the feed's `turn.end.model`, #366). Never message text, tool arguments or tool output; the feed does not carry them and the recorder would not copy them. Tests assert that a secret in any of those never reaches the trace file. 3. Untrusted strings are rebuilt at the plugin's own boundary (`sanitize.js`) on the way in and again on the way out (`window.js`): ids and codes from strict patterns, labels stripped of control and bidi characters, markup brackets and `untrusted` fence markers (also when split or spaced out), and length-capped. An error code is an upper-case word or `UNKNOWN`. -4. Write discipline matches `dev/interop/journal.mjs`: one writer (`writer.lock`, refused again inside one process), a segment is only replaced whole (tmp, fsync, rename, directory fsync). The temporary name is asked as a file first: a symbolic or hard link left there, or a directory, refuses the write with one warning before the first byte, so nothing is written through it and the segment is neither created nor replaced; a missing name is the writer's to create and the plain temp a crashed writer left behind is overwritten. The trace is capped at 3 segments of 2000 records (about 3000 spans) and 24 hours, whichever comes first. A second dsh on the same directory, or an unwritable directory, records in memory only and says so in the response (`trace.persisting`). +4. Write discipline matches `dev/interop/journal.mjs`: one writer (`writer.lock`, refused again inside one process), a segment is only replaced whole (tmp, fsync, rename, directory fsync). The temporary name is asked as a file first: a symbolic or hard link left there, or a directory, refuses the write with one warning before the first byte, so nothing is written through it and the segment is neither created nor replaced; a missing name is the writer's to create and the plain temp a crashed writer left behind is overwritten. The trace is capped at 3 segments of 2000 records (about 3000 spans) and 24 hours, whichever comes first. A rotation whose flush fails keeps the older durable segment: nothing is pruned until a write succeeds (#2624). A second dsh on the same directory, or an unwritable directory, records in memory only and says so in the response (`trace.persisting`). 5. Honest numbers. "Delivered" is when a message reached the recipient's log; there are no read stamps. "Idle" means no running turn; a Bot waiting on a model call or a slow tool is busy. The health flags follow that: `busy` is a share of the window busy, not a count of turns, so a Bot in one long turn that began before the window is `busy`, and `idle` needs no overlapping turn and nothing running; the `errors` rate divides by the larger of the turns that began in the window and the failed turns, so it never reads a failure count above its turn count. "Model" time is turn time outside tool calls (queueing and host overhead included), not a measured model latency. A turn an earlier run left open is closed at the last record before the restart and marked `lost`. "You asked" latency is the length of the turn it started. 6. A friend's Bot is a lane of its own, never a Bot of the local team (#248): it shows as a `friend` lane (its chat's name, else its handle) with messages only. The local side of a friend chat runs no model, so its transport turns are not recorded and it has no utilization row; your line to a friend waits until the friend's next line back (`role: 'remote'`), and a friend's request into one of your Bots is answered by that Bot's turn as a typed line is. Lanes never show a raw session id: a gone Bot or group with no remembered name is `Removed Bot` / `Removed group`. Group rooms are the room Session's own turn (the round), with the members' hidden group turns inside it. 7. The browser poller runs only while a panel holds it open, one request in flight, backing off on errors (4 s to 30 s) and keeping the last good window; a reply of another version is an error state, never drawn from. A request a window change superseded (a new one replaced it) does not clear the in-flight guard of the one that replaced it, so coming back to the tab never doubles the poll. A hidden page loads once (a panel opened in a background tab is never left on Loading…, #259), then stops polling; becoming visible refreshes at once. diff --git a/plugins/timeline/src/store.js b/plugins/timeline/src/store.js index e41976d5c..275cd278d 100644 --- a/plugins/timeline/src/store.js +++ b/plugins/timeline/src/store.js @@ -166,10 +166,11 @@ export function openTrace({ dir, persist = true, now = Date.now, warn = () => {} if (closed) return let segment = newest() if (segment.records.length >= segmentRecords) { - flush() + // A refused write leaves the newest segments undurable: do not delete the last good one. + const saved = flush() segment = fresh() kept.push(segment) - prune() + if (saved) prune() } segment.records.push(record) if (names) { diff --git a/plugins/timeline/test/store.test.js b/plugins/timeline/test/store.test.js index 9d0e5d1ab..9d9a491c9 100644 --- a/plugins/timeline/test/store.test.js +++ b/plugins/timeline/test/store.test.js @@ -206,6 +206,31 @@ test('a missing temporary name is a writer’s to create', (t) => { trace.close() }) +test('a rotation whose flush fails does not prune the last durable segment', (t) => { + const dir = tmp() + t.after(() => rmSync(dir, { recursive: true, force: true })) + const trace = openTrace({ dir, segmentRecords: 2, segments: 2, flushMs: 60_000, now: () => 1_000_000 }) + const disk = () => files(dir).filter(name => /^trace-\d{6}\.json$/.test(name)) + .map(name => [name, JSON.parse(readFileSync(join(dir, name), 'utf8')).records.map(r => r.t)]) + trace.append(rec(1)); trace.append(rec(2)) + assert.equal(trace.flush(), true) + assert.deepEqual(disk(), [['trace-000001.json', [1, 2]]]) + trace.append(rec(3)); trace.append(rec(4)) + // The next write is refused: a link sits where the new segment's temporary file goes. + symlinkSync(join(dir, 'outside'), join(dir, 'trace-000002.json.tmp')) + trace.append(rec(5)) + // The page still shows what it holds, and the durable segment is still there for a restarted host. + assert.deepEqual(trace.records().map(r => r.t).filter(t => t >= 3), [3, 4, 5]) + assert.deepEqual(disk(), [['trace-000001.json', [1, 2]]]) + rmSync(join(dir, 'trace-000002.json.tmp'), { force: true }) + trace.append(rec(6)); trace.append(rec(7)) + assert.equal(trace.flush(), true) + // The next successful rotation applies the cap again, and the newest segments are on disk. + assert.deepEqual(trace.records().map(r => r.t), [5, 6, 7]) + assert.deepEqual(disk(), [['trace-000003.json', [5, 6]], ['trace-000004.json', [7]]]) + trace.close() +}) + test('a plain temporary file a crashed writer left behind (one name) is overwritten', (t) => { const dir = tmp() t.after(() => rmSync(dir, { recursive: true, force: true }))