From d131a1e3c0174d1036b425f81ceeb47dbe7cd2a7 Mon Sep 17 00:00:00 2001 From: Danyang Chen Date: Wed, 21 Oct 2026 11:01:51 +0800 Subject: [PATCH] Timeline: stuck requests, tool use and team health in one change One combined timeline read-model change, replacing the three proposals at the same code line and the same docs row (#535, #539, #568): the window now carries the open requests waiting longest, the tools each Bot used with their failures, and timeline/health reduces the same window to per-Bot signals and flags. Fixes #534 Fixes #538 Fixes #567 --- .../timeline-team-report-fields.added.md | 1 + docs/subsystems/timeline.md | 4 +- plugins/timeline/src/health.js | 47 +++++++++++++++++++ plugins/timeline/src/timeline.js | 8 +++- plugins/timeline/src/window.js | 25 +++++++++- plugins/timeline/test/health.test.js | 42 +++++++++++++++++ plugins/timeline/test/window.test.js | 24 ++++++++++ 7 files changed, 148 insertions(+), 3 deletions(-) create mode 100644 changelog.d/timeline-team-report-fields.added.md create mode 100644 plugins/timeline/src/health.js create mode 100644 plugins/timeline/test/health.test.js diff --git a/changelog.d/timeline-team-report-fields.added.md b/changelog.d/timeline-team-report-fields.added.md new file mode 100644 index 00000000..296fc7a2 --- /dev/null +++ b/changelog.d/timeline-team-report-fields.added.md @@ -0,0 +1 @@ +The timeline window now also reports the open requests waiting longest (#469) and the tools each Bot used with their failures (#359), and `timeline/health` reduces the same window to per-Bot health signals and flags (#357). diff --git a/docs/subsystems/timeline.md b/docs/subsystems/timeline.md index d7987478..8e6a898d 100644 --- a/docs/subsystems/timeline.md +++ b/docs/subsystems/timeline.md @@ -26,7 +26,8 @@ Everything in `plugins/timeline/`: the recorder, the trace file, the read model | `plugins/timeline/src/adapter.js` | The only file that knows the `ctx.flybot` shape. | | `plugins/timeline/src/recorder.js` | Feed events to compact trace records; rebuilds every field from a strict alphabet. | | `plugins/timeline/src/store.js` | The trace: single writer, write-tmp + fsync + rename, capped segments. | -| `plugins/timeline/src/window.js` | Pure read model: records to lanes, turns, tools, arrows, edges, utilization, the token spend per Bot (#357) and per-Bot outcomes and recent failures (#471). | +| `plugins/timeline/src/window.js` | Pure read model: records to lanes, turns, tools, arrows, edges, utilization, the token spend per Bot (#357), per-Bot outcomes and recent failures (#471), the open requests waiting longest (#469) and the tools each Bot used (#359). | +| `plugins/timeline/src/health.js` | Team health (#357): pure `buildHealth(window)` turning the window into per-Bot signals and flags. | | `plugins/timeline/client.js` | Browser entry (`@flybot/timeline`): the 2 s poller exposed as `ctx.flybot.timeline`, the geometry functions (`layoutSwimlanes`, `layoutMap`, `waitRows`, `utilizationRows`) and the panel (swimlanes, who waits on whom, utilization), opened from its `flybot.sidebar.section` row, the only entry (not in the + menu, #269). | | `plugins/timeline/src/sanitize.js` | The cleaners for ids, labels, codes, times, counts. | | `plugins/timeline/src/otel.js` | OTLP export: maps trace records to OpenTelemetry GenAI spans (`spansFrom`, `otlpPayload`) and a cursor exporter (`createExporter`). Off unless `config.exporter` is set. | @@ -36,6 +37,7 @@ Everything in `plugins/timeline/`: the recorder, the trace file, the read model - `plugins/timeline/index.js` — loaded as `@flybot/timeline`. - Endpoint `timeline/window` (wire name `flybot/timeline/window`), registered `{ read: true }` so a read-only host still answers. Body `{ windowMs?, to? }`; window 30 s to 24 h, default 15 min. - Endpoint `timeline/export` (#357, read-only): the current trace mapped to one OTLP/HTTP JSON payload (`resourceSpans`), the same mapping the timer exporter uses. Ids only unless the body sets `names: true` (#483); `serviceName` overrides the default. The panel or an automation can pull it on demand instead of waiting for the next flush. +- Endpoint `timeline/health` (#357, read-only): the same window reduced to per-Bot signals and flags (`errors`, `busy`, `idle`, `waiting`) and a team `ok`; the action view over the numbers the panel draws. Body `{ windowMs?, to? }` like `timeline/window`. ## Invariants diff --git a/plugins/timeline/src/health.js b/plugins/timeline/src/health.js new file mode 100644 index 00000000..e1f3fedf --- /dev/null +++ b/plugins/timeline/src/health.js @@ -0,0 +1,47 @@ +// A team-health read model (#357): the window's raw numbers turned into per-Bot signals and a +// short set of flags a person can act on, so observability becomes a decision instead of a chart. +// Pure: a window in, a plain object out. It reads only what the window already carries (turns, +// errors, utilization, waits), so it records nothing new and never touches a Session. +const ERROR_RATE_MIN = 0.5 +const ERROR_TURNS_MIN = 3 +const BUSY_SHARE = 0.9 + +const share = (part, whole) => (whole > 0 ? part / whole : 0) +const round = value => Math.round(value * 1000) / 1000 + +/** + * `window` is a `timeline/window` answer. Resolves `{ version, now, windowMs, live, ok, bots, + * unhealthy }`. Each Bot carries its turns, errors, error rate, share of the window it was busy, + * whether it is running now, how many of its requests are unanswered, and flags + * (`errors` / `busy` / `idle` / `waiting`). `ok` is false when any Bot has an `errors` or + * `waiting` flag; `unhealthy` names them. + */ +export function buildHealth(window = {}) { + const lanes = new Map((window.lanes ?? []).map(lane => [lane.id, lane])) + // Unanswered requests per sender Bot: where a Bot's work is waiting on someone else. + const waitingOn = new Map() + for (const edge of window.edges ?? []) { + if (!(edge?.unanswered > 0) || typeof edge.from !== 'string') continue + waitingOn.set(edge.from, (waitingOn.get(edge.from) ?? 0) + edge.unanswered) + } + const bots = (window.utilization ?? []).map((use) => { + const lane = lanes.get(use.lane) + const errorRate = share(use.errors, use.turns) + const busyShare = share(use.busyMs, use.windowMs) + const waiting = waitingOn.get(use.lane) ?? 0 + const flags = [] + if (use.turns >= ERROR_TURNS_MIN && errorRate >= ERROR_RATE_MIN) flags.push({ code: 'errors', detail: `${use.errors} of ${use.turns} turns failed` }) + if (use.turns > 0 && busyShare >= BUSY_SHARE) flags.push({ code: 'busy', detail: `busy ${Math.round(busyShare * 100)}% of the window` }) + if (use.turns === 0) flags.push({ code: 'idle', detail: 'no turns in the window' }) + if (waiting > 0) flags.push({ code: 'waiting', detail: `${waiting} request(s) unanswered` }) + return { + id: use.lane, + name: lane?.name ?? use.lane, + ...(lane?.main === true ? { main: true } : {}), + turns: use.turns, errors: use.errors, errorRate: round(errorRate), busyShare: round(busyShare), + running: use.running === true, waiting, flags, + } + }) + const unhealthy = bots.filter(bot => bot.flags.some(flag => flag.code === 'errors' || flag.code === 'waiting')).map(bot => bot.id) + return { version: 1, now: window.now ?? null, windowMs: window.windowMs ?? null, live: window.live === true, bots, unhealthy, ok: unhealthy.length === 0 } +} diff --git a/plugins/timeline/src/timeline.js b/plugins/timeline/src/timeline.js index 35cb2fe8..e3c50824 100644 --- a/plugins/timeline/src/timeline.js +++ b/plugins/timeline/src/timeline.js @@ -3,9 +3,11 @@ import { createRecorder } from './recorder.js' import { openTrace, TraceLocked } from './store.js' import { buildWindow, clampWindow } from './window.js' import { createExporter, otlpPayload, spansFrom } from './otel.js' +import { buildHealth } from './health.js' export const ENDPOINT = 'timeline/window' export const EXPORT_ENDPOINT = 'timeline/export' +export const HEALTH_ENDPOINT = 'timeline/health' export function createTimeline(adapter, { dir, persist = true, now = Date.now, exporter, ...limits } = {}) { let trace @@ -49,12 +51,16 @@ export function createTimeline(adapter, { dir, persist = true, now = Date.now, e // sends another home's names by accident. const exportWindow = (body = {}) => otlpPayload(spansFrom(trace.records(), { names: body?.names === true ? trace.names() : {} }), { serviceName: body?.serviceName }) const offExport = adapter.handle(EXPORT_ENDPOINT, exportWindow) + // Team health (#357): the same window, reduced to per-Bot signals and flags. Read-only. + const health = (body = {}) => buildHealth(window(body)) + const offHealth = adapter.handle(HEALTH_ENDPOINT, health) return { - trace, recorder, window, exportNow, exportWindow, + trace, recorder, window, exportNow, exportWindow, health, dispose() { if (exportTimer !== undefined) clearInterval(exportTimer) offEndpoint() offExport() + offHealth() off() trace.close() }, diff --git a/plugins/timeline/src/window.js b/plugins/timeline/src/window.js index 154dbe28..b45c105f 100644 --- a/plugins/timeline/src/window.js +++ b/plugins/timeline/src/window.js @@ -260,6 +260,22 @@ export function buildWindow(records, { now = Date.now(), to, windowMs, bots = [] return { lane: lane.id, calls: calls.length, input: sum('in'), output: sum('out'), cacheRead: sum('cr'), cacheWrite: sum('cw') } }) + // ---- which tools each Bot used, and how often they failed (#357/#359 connectors) + const toolUse = lanes.filter(lane => lane.kind === 'bot').map((lane) => { + const counts = new Map() + for (const turn of turnList) { + if (turn.bot !== lane.id || turn.place === 'room') continue + for (const tool of toolsOf.get(turn.id) ?? []) { + const name = cleanLabel(tool.name, 60) || 'tool' + const entry = counts.get(name) ?? { name, calls: 0, failed: 0 } + entry.calls += 1 + if (tool.ok === false) entry.failed += 1 + counts.set(name, entry) + } + } + const tools = [...counts.values()].sort((a, b) => b.calls - a.calls || a.name.localeCompare(b.name)).slice(0, 20) + return { lane: lane.id, tools } + }) // ---- communication map: directed edges, "A waits on B" from request -> reply latencies const edgeMap = new Map() for (const arrow of exchanges) { @@ -287,12 +303,19 @@ export function buildWindow(records, { now = Date.now(), to, windowMs, bots = [] .slice(0, FAILED_KEPT) .map(turn => ({ id: turn.id, bot: turn.bot, at: turn.t1, outcome: turn.outcome, ...(turn.errorCode ? { code: cleanCode(turn.errorCode) } : {}) })) + // ---- waiting too long (#469): the open requests, worst first, so a stuck handoff surfaces + const STUCK_KEPT = 20 + const stuck = exchanges + .filter(arrow => arrow.waiting === true && Number.isFinite(arrow.t)) + .map(arrow => ({ id: arrow.id, from: arrow.from, to: arrow.to, role: arrow.role, waitedMs: Math.max(0, now - arrow.t) })) + .sort((a, b) => b.waitedMs - a.waitedMs) + .slice(0, STUCK_KEPT) return { version: 1, now, from: lo, to: hi, windowMs: windowMsActual, live, coverage: { oldest: oldest ?? null, newest: last || null, complete: oldest !== undefined && oldest <= lo }, trace: stats ?? null, truncated, - lanes, turns: shapedTurns, rounds, exchanges, utilization, edges, usage, outcomes, failures, + lanes, turns: shapedTurns, rounds, exchanges, utilization, edges, usage, outcomes, failures, stuck, toolUse, } } diff --git a/plugins/timeline/test/health.test.js b/plugins/timeline/test/health.test.js new file mode 100644 index 00000000..9452018b --- /dev/null +++ b/plugins/timeline/test/health.test.js @@ -0,0 +1,42 @@ +import assert from 'node:assert/strict' +import { test } from 'node:test' +import { buildHealth } from '../src/health.js' + +const make = (extra = {}) => ({ + version: 1, now: 1000, windowMs: 1000, live: true, + lanes: [{ id: 'user', kind: 'user', name: 'You' }, { id: 'a', kind: 'bot', name: 'Chief', main: true }, { id: 'b', kind: 'bot', name: 'Writer' }], + utilization: [], edges: [], ...extra, +}) + +test('health: a Bot with many failed turns is flagged, and the team is unhealthy', () => { + const health = buildHealth(make({ + utilization: [ + { lane: 'a', windowMs: 1000, busyMs: 900, turns: 4, errors: 3, running: false }, + { lane: 'b', windowMs: 1000, busyMs: 100, turns: 2, errors: 0, running: true }, + ], + edges: [{ from: 'b', to: 'a', requests: 1, replies: 0, unanswered: 1 }], + })) + const a = health.bots.find(bot => bot.id === 'a') + assert.deepEqual(a.flags.map(flag => flag.code), ['errors', 'busy']) + assert.equal(a.errorRate, 0.75) + assert.equal(a.name, 'Chief') + assert.equal(a.main, true) + const b = health.bots.find(bot => bot.id === 'b') + assert.deepEqual(b.flags.map(flag => flag.code), ['waiting']) + assert.equal(b.waiting, 1) + assert.equal(b.running, true) + assert.equal(health.ok, false) + assert.deepEqual(health.unhealthy, ['a', 'b']) +}) + +test('health: an idle Bot is flagged but does not make the team unhealthy', () => { + const health = buildHealth(make({ utilization: [{ lane: 'b', windowMs: 1000, busyMs: 0, turns: 0, errors: 0, running: false }] })) + const b = health.bots.find(bot => bot.id === 'b') + assert.deepEqual(b.flags, [{ code: 'idle', detail: 'no turns in the window' }]) + assert.equal(health.ok, true) + assert.deepEqual(health.unhealthy, []) +}) + +test('health: an empty window is ok and has no Bots', () => { + assert.deepEqual(buildHealth({}), { version: 1, now: null, windowMs: null, live: false, bots: [], unhealthy: [], ok: true }) +}) diff --git a/plugins/timeline/test/window.test.js b/plugins/timeline/test/window.test.js index a245f02f..35133f9b 100644 --- a/plugins/timeline/test/window.test.js +++ b/plugins/timeline/test/window.test.js @@ -274,3 +274,27 @@ test('outcomes: per-Bot turn endings and the recent failures (#357/#471)', () => assert.deepEqual(win.outcomes.find(entry => entry.lane === 'b').aborted, 1) assert.deepEqual(win.failures.map(f => [f.id, f.bot, f.outcome, f.code]), [['b#1', 'b', 'aborted', undefined], ['a#2', 'a', 'error', 'RATE_LIMIT']]) }) + +test('stuck: open requests are listed worst-first (#469)', () => { + const win = build() + assert.ok(win.stuck.length >= 1) + assert.ok(win.stuck.some(entry => entry.id === 'x3'), JSON.stringify(win.stuck)) + assert.ok(win.stuck.every(entry => entry.waitedMs >= 0)) + for (let i = 1; i < win.stuck.length; i += 1) assert.ok(win.stuck[i - 1].waitedMs >= win.stuck[i].waitedMs) +}) + +test('toolUse: which tools a Bot used, and how often they failed (#357/#359)', () => { + const recs = [ + { r: 'ts', t: at(1000), id: 'a#1', pl: 'chat', bot: 'a' }, + { r: 'ks', t: at(1100), id: 'c1', tid: 'a#1', nm: 'web_search', bot: 'a' }, + { r: 'ke', t: at(1200), id: 'c1', tid: 'a#1', ok: true }, + { r: 'ks', t: at(1300), id: 'c2', tid: 'a#1', nm: 'mcp__github__search', bot: 'a' }, + { r: 'ke', t: at(1400), id: 'c2', tid: 'a#1', ok: false }, + { r: 'te', t: at(2000), id: 'a#1', o: 'completed' }, + ] + const win = buildWindow(recs, { now: at(10_000), bots, rooms }) + const a = win.toolUse.find(entry => entry.lane === 'a') + const byName = Object.fromEntries(a.tools.map(tool => [tool.name, [tool.calls, tool.failed]])) + assert.deepEqual(byName.web_search, [1, 0]) + assert.deepEqual(byName['mcp__github__search'], [1, 1]) +}) \ No newline at end of file