timeline: export one tool span per turn and call id, not per call id

changelog.d/2539-otel-tool-span-key.fixed.md

@@ -0,0 +1 @@
+A workflow's tool calls are exported one span each even when two turns number a call the same way: the OTLP export pairs a call with its own turn, so no tool span goes missing and none hangs under another turn.

docs/subsystems/timeline.md

@@ -55,7 +55,7 @@ Everything in `plugins/timeline/`: the recorder, the trace file, the read model
 8. The panel draws text only: every string is a React text child or an SVG text node, never markup, and is cleaned again in the browser (`safe`). It polls only while open (and refreshes at once when the tab or window comes back, #259, #271), shows the last good data under an error, and says in a note when the trace is shorter than the window, truncated, memory-only or looking back. Its one-line footnote repeats the honesty rules of invariant 5 (delivered is not read, busy is not idle, model time is not a measured latency). The dialog shrinks to its content and hangs from the top (switching tabs moves nothing above the body), the **Live** control is always shown (pressed while following the latest activity, a call to action when looking back), lanes name what they are under the name (`main`, `group`, `friend`, `removed`) with no icon prefix, and the map puts each name beside or under its node, clipped with the full name in a tooltip (#249). A turn bar's tooltip ends with the model the turn ran on (its model id, `· deepseek-v4-pro`); a running turn, or one recorded before #366, names none (#366). A friend's Bot is named as the sidebar names it (`UiA1415's Chief`, `Helper · UiB1415's Bot`, from the feed's `remote.name` / party `name`), so two Bots called Helper stay apart; a wait label that would run past the plot is right-aligned, and one with no room is left to the arrow's tooltip (#255). The window's range is always in view under the header (`Oct 18 · 13:20:05 – 13:35:05 (15 min)`, dates at both ends across midnight, and whether it is live), and the footnote is two short items, not one line (#279). The wait table below the map prints `–` wherever a number does not exist yet: an edge nobody answered has no median, slowest or total wait, so all three read `–` rather than a measured `0 ms` beside a `Not yet 1`.
 9. Opt-in (#281): `apply` without `config.enabled === true` subscribes to nothing, writes nothing and registers no endpoint; the browser entry draws no sidebar row unless `config.sidebarSection === true` and its poller only runs while a panel is open. A test asserts the host does nothing by default. Docs and the install doctor's default commands do not present it as part of a standard install.
 10. The endpoint reads only. It does not start, stop, send or change anything.
-11. OTLP export (#483) is opt-in and off by default: without `config.exporter` nothing leaves the host. With `exporter: "otlp"` the plugin POSTs OTLP/HTTP JSON to `otlpUrl`; with `"json"` it appends `dir/export.jsonl` (capped at 8 MiB, then it stops and warns). `otlpUrl` must be `https`, or `http` on localhost only (the request may carry an auth header). Only CLOSED spans are exported: a turn needs its `te` and a tool call its `ke`, so an open turn is carried between flushes and exported when it ends, never as a finished success. The exporter reads only the same compact records the panel does (invariant 2 still holds: no message text, arguments or output), maps turns to `invoke_agent` spans and tool calls to `execute_tool` spans under them, and carries every id through the same deterministic hash. Bot and room NAMES are sent only with `exportNames: true`; by default a span carries ids only, so a friend's or another home's name never leaves the host (a name comes from `trace.names()`, which includes friends' Bots and face-room names). The feed has no model name and no token counts, so those GenAI attributes are absent, not guessed. A failed send keeps the cursor, so the next flush retries the same closed spans (tested). The cursor re-reads records at its last timestamp (`>=`), because a `ke` can share the millisecond of its `ks` (or a `te` the time of the last record); a span already sent is deduplicated by id, so a same-millisecond record is neither skipped nor sent twice.
+11. OTLP export (#483) is opt-in and off by default: without `config.exporter` nothing leaves the host. With `exporter: "otlp"` the plugin POSTs OTLP/HTTP JSON to `otlpUrl`; with `"json"` it appends `dir/export.jsonl` (capped at 8 MiB, then it stops and warns). `otlpUrl` must be `https`, or `http` on localhost only (the request may carry an auth header). Only CLOSED spans are exported: a turn needs its `te` and a tool call its `ke`, so an open turn is carried between flushes and exported when it ends, never as a finished success. The exporter reads only the same compact records the panel does (invariant 2 still holds: no message text, arguments or output), maps turns to `invoke_agent` spans and tool calls to `execute_tool` spans under them, pairs a tool call by its turn and call id (`tid`/`id`, the pair the window folds by) so two turns that both call a tool `call_0` still export two spans, and carries every id through the same deterministic hash. Bot and room NAMES are sent only with `exportNames: true`; by default a span carries ids only, so a friend's or another home's name never leaves the host (a name comes from `trace.names()`, which includes friends' Bots and face-room names). The feed has no model name and no token counts, so those GenAI attributes are absent, not guessed. A failed send keeps the cursor, so the next flush retries the same closed spans (tested). The cursor re-reads records at its last timestamp (`>=`), because a `ke` can share the millisecond of its `ks` (or a `te` the time of the last record); a span already sent is deduplicated by id, so a same-millisecond record is neither skipped nor sent twice.
 12. Durable alerts (#584) keep their state in the plugin process, not in the trace: the tracker opens one alert per condition (`errors:<bot>`, `waiting:<bot>`, `stuck:<exchange>`) and resolves it when the condition clears, keeping the resolution readable for a minute so a reader polling slower than the transition still sees that it cleared. `changed` is true only when something opened or resolved; a detail that moves while the alert keeps holding is not a transition. `stuck` uses the same 20 open requests the window already carries and a 15 min default threshold (`stuckMs`), which the issue left open. A window that ends before the last one folded is answered `stale` with the state untouched, so a look-back never resolves a live alert. The state dies with the process: nothing is written, and a restart starts with no alerts rather than replaying old ones.
 
 ## Tests

plugins/timeline/src/otel.js

@@ -30,6 +30,12 @@ const bool = value => ({ boolValue: Boolean(value) })
 
 const nameOf = (names, group, id) => (id && names?.[group]?.[id]) || undefined
 
+// A tool call's id is unique inside its turn, not across turns: the recorder writes `id` and `tid`
+// together and the window folds the pair as `${tid}/${id}` (src/window.js). Two turns of one trace
+// can both call a tool `call_0` — two Bots, or a provider that numbers its calls per request — so
+// the exporter pairs the two records by that same pair, never by `id` alone.
+const toolKey = record => `${record.tid ?? ''}/${record.id}`
+
 const partyAttrs = (prefix, party) => {
   if (!party || typeof party !== 'object') return []
   const out = []
@@ -52,8 +58,8 @@ export function spansFrom(records, { names = {} } = {}) {
     if (!record || typeof record !== 'object') continue
     if (record.r === 'ts') starts.set(record.id, record)
     else if (record.r === 'te') ends.set(record.id, record)
-    else if (record.r === 'ks') toolStarts.set(record.id, record)
-    else if (record.r === 'ke') toolEnds.set(record.id, record)
+    else if (record.r === 'ks') toolStarts.set(toolKey(record), record)
+    else if (record.r === 'ke') toolEnds.set(toolKey(record), record)
   }
   const spans = []
   for (const [id, te] of ends) {
@@ -81,12 +87,12 @@ export function spansFrom(records, { names = {} } = {}) {
       status: { code: te.o === 'error' || te.o === 'aborted' ? STATUS_ERROR : STATUS_OK, ...(te.ec ? { message: te.ec } : {}) },
     })
   }
-  for (const [id, ke] of toolEnds) {
-    const ks = toolStarts.get(id)
+  for (const [key, ke] of toolEnds) {
+    const ks = toolStarts.get(key)
     if (!ks) continue
     spans.push({
       traceId: hexId(`turn:${ks.tid}`, 16),
-      spanId: hexId(`tool-span:${ks.id}`, 8),
+      spanId: hexId(`tool-span:${key}`, 8),
       parentSpanId: hexId(`turn-span:${ks.tid}`, 8),
       name: `execute_tool ${ks.nm}`,
       kind: KIND_INTERNAL,
@@ -135,8 +141,8 @@ export function pendingRecords(records) {
   for (const record of records) {
     if (record?.r === 'ts') openTurns.set(record.id, record)
     else if (record?.r === 'te') openTurns.delete(record.id)
-    else if (record?.r === 'ks') openTools.set(record.id, record)
-    else if (record?.r === 'ke') openTools.delete(record.id)
+    else if (record?.r === 'ks') openTools.set(toolKey(record), record)
+    else if (record?.r === 'ke') openTools.delete(toolKey(record))
   }
   return [...openTurns.values(), ...openTools.values()]
 }

plugins/timeline/test/otel-tool-ids.test.js

@@ -0,0 +1,43 @@
+// A tool call's id is unique inside its turn, not across turns: the recorder writes `ks`/`ke`
+// with both `id` and `tid`, and the window folds them under `${tid}/${id}` (src/window.js). Two
+// turns of one trace — two Bots, or a provider that numbers its calls per request — can both call
+// a tool `call_0`. The exporter keyed its tool records by `id` alone, so the later turn's start
+// replaced the earlier one: one tool span left the batch, its parent was the wrong turn, and an
+// open call in the earlier turn was not carried to the next push. Both halves are read here.
+import assert from 'node:assert/strict'
+import { test } from 'node:test'
+import { pendingRecords, spansFrom } from '../src/otel.js'
+
+const records = [
+  { r: 'ts', t: 1000, id: 'turn-a', bot: 'a', pl: 'dm' },
+  { r: 'ks', t: 1001, id: 'call_0', tid: 'turn-a', nm: 'read', bot: 'a' },
+  { r: 'ke', t: 1005, id: 'call_0', tid: 'turn-a', ok: true },
+  { r: 'te', t: 1010, id: 'turn-a', o: 'completed' },
+  { r: 'ts', t: 2000, id: 'turn-b', bot: 'b', pl: 'dm' },
+  { r: 'ks', t: 2001, id: 'call_0', tid: 'turn-b', nm: 'bash', bot: 'b' },
+  { r: 'ke', t: 2009, id: 'call_0', tid: 'turn-b', ok: false },
+  { r: 'te', t: 2020, id: 'turn-b', o: 'completed' },
+]
+
+const agentOf = span => span.attributes.find(attr => attr.key === 'gen_ai.agent.id')?.value?.stringValue
+
+test('two turns that both call a tool with the same call id export one tool span each', () => {
+  const spans = spansFrom(records)
+  const tools = spans.filter(span => span.name.startsWith('execute_tool'))
+  assert.equal(tools.length, 2, `one span per tool call, saw ${tools.map(span => span.name).join(', ') || 'none'}`)
+  assert.deepEqual(tools.map(span => span.name).sort(), ['execute_tool bash', 'execute_tool read'])
+  assert.equal(new Set(tools.map(span => span.spanId)).size, 2, 'the two calls need two span ids')
+  // Each tool span hangs under its own turn's span, not the other turn's.
+  const turnSpanOf = new Map(spans.filter(span => span.name.startsWith('invoke_agent')).map(span => [agentOf(span), span.spanId]))
+  for (const tool of tools) assert.equal(tool.parentSpanId, turnSpanOf.get(agentOf(tool)), `${tool.name} hangs under its own turn`)
+})
+
+test('a tool call still open in an earlier turn is carried, not replaced by a later one', () => {
+  const open = pendingRecords([
+    { r: 'ts', t: 1, id: 'turn-a' },
+    { r: 'ks', t: 2, id: 'call_0', tid: 'turn-a', nm: 'read' },
+    { r: 'ts', t: 3, id: 'turn-b' },
+    { r: 'ks', t: 4, id: 'call_0', tid: 'turn-b', nm: 'bash' },
+  ])
+  assert.deepEqual(open.filter(record => record.r === 'ks').map(record => record.tid).sort(), ['turn-a', 'turn-b'])
+})