Skip to content

Commit 874904a

Browse files
committed
Link subagent_end to the in-flight parent turn
Capture parent_trace_id at task/spawn dispatch from the current turn noted at inference.start, instead of the last completed turn. Treat an empty generation sample-rate env as unset, and document that sampling drops opt-in spans with the generation.
1 parent 75df24f commit 874904a

11 files changed

Lines changed: 202 additions & 23 deletions

File tree

docs/TELEMETRY.md

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -109,8 +109,11 @@ Leaf `runSubAgent` workers do not emit `$ai_*`; worker rollups travel on
109109

110110
Successful `$ai_generation` events may be sampled with
111111
`CORBITS_TELEMETRY_GENERATION_SAMPLE_RATE` (a float in `0``1`, default `1.0`
112-
= keep all). Errored generations (`$ai_is_error: true`), `crash`, and
113-
`auth_failure` always ship regardless of the sample rate.
112+
= keep all). An empty env value is treated as unset (keep all), not as `0`.
113+
Errored generations (`$ai_is_error: true`), `crash`, and `auth_failure` always
114+
ship regardless of the sample rate. When a successful generation is sampled
115+
out, opt-in `$ai_span`s for that turn are skipped too — a span without its
116+
parent generation is not useful in PostHog traces.
114117

115118
The trace is **flat**. Every turn gets one `$ai_trace_id` derived from the
116119
runtime's session id and the turn index; the turn's `$ai_generation` and each

src/session/run-sink.ts

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,9 +22,14 @@ export interface RunSinkArgs {
2222
// run goes wrong. The turn index is the collector's current count: the
2323
// in-flight turn is the one that would have been recorded next.
2424
onTurnFailed?: (info: { turnIndex: number; error: string }) => void;
25+
// Fired when inference for a turn begins. The turn index is the collector's
26+
// current count (the in-flight turn that has not completed yet) — used to
27+
// stamp parent_trace_id on subagent_end while tools still run.
28+
onTurnStarted?: (info: { turnIndex: number }) => void;
2529
// Continues a resumed session's persisted run.json turn count instead of
2630
// restarting the collector at zero.
2731
initialTurnCount?: number;
32+
2833
// Fired at every turn boundary so a caller can persist a mid-run run.json
2934
// snapshot. `inference.done` is the turn boundary every reactor cycle
3035
// guarantees; `reactor.done` fires once, at shutdown, and never between
@@ -88,6 +93,7 @@ export function createRunSink(args: RunSinkArgs): RunSink {
8893
hookManager,
8994
onTurnComplete,
9095
onTurnFailed,
96+
onTurnStarted,
9197
initialTurnCount,
9298
onTurnBoundarySnapshot,
9399
} = args;
@@ -148,7 +154,9 @@ export function createRunSink(args: RunSinkArgs): RunSink {
148154
perfObserver.observe(event);
149155
if (event.type === "inference.start") {
150156
turnInFlight = true;
157+
onTurnStarted?.({ turnIndex: turnCollector.getTurnCount() });
151158
}
159+
152160
if (event.type === "reactor.done") {
153161
runCompleted = true;
154162
// Terminal success clears any earlier transient inference error.

src/subagent/agent-fleet.ts

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -75,6 +75,7 @@ import { cleanupSubAgentWorktree, createSubAgentWorktree, WorktreeError } from "
7575
import { NOOP_TELEMETRY, type Telemetry } from "../telemetry/index.js";
7676
import { classifyAgentName } from "../telemetry/classify.js";
7777
import { captureSubagentEnd } from "../telemetry/product-events.js";
78+
import { getCurrentTurnTraceId } from "../telemetry/feedback.js";
7879
import type { DirectorPackage } from "../agent/directors/types.js";
7980

8081
import { formatSubAgentTaskAuthFailureMessage } from "./inference-auth-failure.js";
@@ -538,12 +539,11 @@ export function createSpawnAgentTool(deps: AgentFleetDeps): AgentTool {
538539
});
539540
deps.fleetRecords.register(session.id);
540541
const agentName = classifyAgentName(resolved.directorId);
542+
const parentTraceId = getCurrentTurnTraceId();
541543
telemetry.capture("subagent_start", { agent_name: agentName });
542544
const startedAt = Date.now();
543545
let endResult: RunSubAgentResult | undefined;
544546

545-
546-
547547
const childCtl = new AbortController();
548548
deps.sessions.registerCancel(session.id, () => {
549549
if (!childCtl.signal.aborted) childCtl.abort();
@@ -754,11 +754,12 @@ export function createSpawnAgentTool(deps: AgentFleetDeps): AgentTool {
754754
model: provider.model,
755755
...(endResult?.stopReason !== undefined ? { stopReason: endResult.stopReason } : {}),
756756
...(endResult?.telemetry !== undefined ? { rollup: endResult.telemetry } : {}),
757+
...(parentTraceId !== undefined ? { parentTraceId } : {}),
757758
});
759+
758760
if (!keepWorktreeAlive) void reclaimWorktree();
759761
});
760762

761-
762763
return fleetResult(call.id, JSON.stringify({ agent_id: session.id, status: "running" }));
763764
},
764765
});

src/subagent/task-tool.ts

Lines changed: 8 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -58,6 +58,7 @@ import { currentTurnId } from "../perf/reactor-spans.js";
5858
import { classifyAgentName } from "../telemetry/classify.js";
5959
import { NOOP_TELEMETRY, type Telemetry } from "../telemetry/index.js";
6060
import { captureSubagentEnd } from "../telemetry/product-events.js";
61+
import { getCurrentTurnTraceId } from "../telemetry/feedback.js";
6162

6263
import { join } from "node:path";
6364
import type {
@@ -69,7 +70,6 @@ import type {
6970
SubAgentTelemetryRollup,
7071
} from "./types.js";
7172

72-
7373
const log = getLogger([LOG_NAMESPACE_ROOT, "subagent", "task-tool"]);
7474

7575
export const TaskToolArgs = type({
@@ -926,12 +926,12 @@ export function createTaskTool(deps: TaskToolDeps): AgentTool {
926926
},
927927
});
928928
const subagentStartedAt = Date.now();
929-
// Profile ids come from project and plugin directories, so only the
930-
// runtime's own "worker" fallback is reportable by name; anything else
931-
// is bucketed. Sub-agents run in this process against the same session
932-
// id, so there is no parent id worth sending — it would always equal
933-
// the session_id already on the payload.
929+
// Profile / director ids are classified: first-party DIRECTOR_IDS (and
930+
// legacy "worker") report by name; project/plugin profiles become custom.
931+
// Capture the in-flight parent turn trace at dispatch — getLastTurnTraceId
932+
// would be the previous completed turn while this tool still runs.
934933
const agentName = classifyAgentName(agentLabel);
934+
const parentTraceId = getCurrentTurnTraceId();
935935
telemetry.capture("subagent_start", { agent_name: agentName });
936936
let subagentStatus: "completed" | "cancelled" | "failed" = "completed";
937937
let endRollup: SubAgentTelemetryRollup | undefined;
@@ -1138,7 +1138,9 @@ export function createTaskTool(deps: TaskToolDeps): AgentTool {
11381138
...(endModel !== undefined ? { model: endModel } : { model: provider.model }),
11391139
...(endStopReason !== undefined ? { stopReason: endStopReason } : {}),
11401140
...(endRollup !== undefined ? { rollup: endRollup } : {}),
1141+
...(parentTraceId !== undefined ? { parentTraceId } : {}),
11411142
});
1143+
11421144
}
11431145

11441146
},

src/telemetry/ai-observability.test.ts

Lines changed: 30 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
1-
import { describe, expect, test } from "bun:test";
21
import type { ToolCall, ToolResult } from "@intx/types/runtime";
2+
import { afterEach, describe, expect, test } from "bun:test";
33
import type { Telemetry } from "./index.js";
4+
import { generationSampleRate } from "./index.js";
45
import type { TurnContext } from "../session/hooks.js";
56
import {
67
aggregateToolCalls,
@@ -12,11 +13,17 @@ import {
1213
secondsFromMs,
1314
turnTraceId,
1415
} from "./ai-observability.js";
16+
import { getCurrentTurnTraceId, resetFeedbackStateForTests } from "./feedback.js";
1517

1618
const SUBAGENT_TOOL_NAME = "task";
1719
const SESSION_ID = "0199-parent-session";
1820

21+
afterEach(() => {
22+
resetFeedbackStateForTests();
23+
});
24+
1925
function fakeTelemetry(): {
26+
2027
telemetry: Telemetry;
2128
captured: { event: string; properties: Record<string, unknown> }[];
2229
} {
@@ -210,6 +217,21 @@ describe("createTurnObserver", () => {
210217
expect(captured[1]?.properties.$ai_provider).toBe("codex");
211218
expect(captured[1]?.properties.$ai_model).toBe("model-y");
212219
});
220+
221+
test("onTurnStarted notes the in-flight turn for subagent parent_trace_id", () => {
222+
const { telemetry } = fakeTelemetry();
223+
const observer = createTurnObserver({
224+
telemetry: () => telemetry,
225+
getSessionId: () => SESSION_ID,
226+
getSource: () => ({ provider: "openai-compatible", model: "model-x" }),
227+
subagentToolName: SUBAGENT_TOOL_NAME,
228+
});
229+
230+
observer.onTurnStarted({ turnIndex: 2 });
231+
expect(getCurrentTurnTraceId()).toBe(`${SESSION_ID}:turn:2`);
232+
observer.onTurnComplete(fakeTurnContext({ turnIndex: 2, toolCalls: [], toolResults: [] }));
233+
expect(getCurrentTurnTraceId()).toBeUndefined();
234+
});
213235
});
214236

215237
describe("emitAiObservability", () => {
@@ -378,6 +400,13 @@ describe("emitAiObservability", () => {
378400
expect(captured).toHaveLength(1);
379401
expect(captured[0]?.event).toBe("$ai_generation");
380402
});
403+
404+
test("empty CORBITS_TELEMETRY_GENERATION_SAMPLE_RATE is treated as unset (1.0)", () => {
405+
expect(generationSampleRate({ CORBITS_TELEMETRY_GENERATION_SAMPLE_RATE: "" })).toBe(1);
406+
expect(generationSampleRate({ CORBITS_TELEMETRY_GENERATION_SAMPLE_RATE: " " })).toBe(1);
407+
expect(generationSampleRate({})).toBe(1);
408+
expect(generationSampleRate({ CORBITS_TELEMETRY_GENERATION_SAMPLE_RATE: "0" })).toBe(0);
409+
});
381410
});
382411

383412
describe("emitAiTurnFailure", () => {

src/telemetry/ai-observability.ts

Lines changed: 13 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,8 @@
99
// CORBITS_TELEMETRY_AI_SPANS for debugging.
1010

1111
import type { TurnContext } from "../session/hooks.js";
12-
import { noteLastTurnTraceId } from "./feedback.js";
12+
import { noteLastTurnTraceId, noteCurrentTurnTraceId, clearCurrentTurnTraceId } from "./feedback.js";
13+
1314
import {
1415
aiSpansEnabled,
1516
generationSampleRate,
@@ -133,7 +134,11 @@ export function emitAiObservability(
133134
// is a no-op because this call still computes the id).
134135
noteLastTurnTraceId(traceId);
135136

136-
if (!shouldSampleSuccessfulGeneration(env, random)) return;
137+
if (!shouldSampleSuccessfulGeneration(env, random)) {
138+
// Sampling drops the whole turn package, including opt-in `$ai_span`s —
139+
// a span without its parent generation is not useful in PostHog traces.
140+
return;
141+
}
137142

138143
const aggregates = aggregateToolCalls(ctx, options.subagentToolName);
139144

@@ -226,17 +231,23 @@ export interface CreateTurnObserverOptions {
226231
// plain callbacks and keeping the "read it now, do not capture it" rule in
227232
// one place instead of at each call site.
228233
export function createTurnObserver(options: CreateTurnObserverOptions): {
234+
onTurnStarted: (info: { turnIndex: number }) => void;
229235
onTurnComplete: (ctx: TurnContext) => void;
230236
onTurnFailed: (info: { turnIndex: number; error: string }) => void;
231237
} {
232238
return {
239+
onTurnStarted: (info) => {
240+
noteCurrentTurnTraceId(turnTraceId(options.getSessionId(), info.turnIndex));
241+
},
233242
onTurnComplete: (ctx) => {
243+
clearCurrentTurnTraceId();
234244
emitAiObservability(options.telemetry(), ctx, {
235245
sessionId: options.getSessionId(),
236246
subagentToolName: options.subagentToolName,
237247
});
238248
},
239249
onTurnFailed: (info) => {
250+
clearCurrentTurnTraceId();
240251
emitAiTurnFailure(options.telemetry(), {
241252
sessionId: options.getSessionId(),
242253
source: options.getSource(),

src/telemetry/feedback.ts

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -138,6 +138,8 @@ export function feedbackResultMessage(
138138

139139
let feedbackCapturePending = false;
140140
let lastTurnTraceId: string | undefined;
141+
/** In-flight primary turn — set at inference.start, cleared when the turn settles. */
142+
let currentTurnTraceId: string | undefined;
141143

142144
/** Arm after bare `/feedback` so the next non-command submit is treated as feedback. */
143145
export function armFeedbackCapture(): void {
@@ -169,8 +171,26 @@ export function getLastTurnTraceId(): string | undefined {
169171
return lastTurnTraceId;
170172
}
171173

174+
/**
175+
* Remember the in-flight turn's `$ai_trace_id` so `subagent_end` can link to the
176+
* turn that is still running when `task` / `spawn_agent` dispatch (not the
177+
* previous completed turn).
178+
*/
179+
export function noteCurrentTurnTraceId(traceId: string): void {
180+
if (traceId.length > 0) currentTurnTraceId = traceId;
181+
}
182+
183+
export function getCurrentTurnTraceId(): string | undefined {
184+
return currentTurnTraceId;
185+
}
186+
187+
export function clearCurrentTurnTraceId(): void {
188+
currentTurnTraceId = undefined;
189+
}
190+
172191
/** Test helper — reset module state between cases. */
173192
export function resetFeedbackStateForTests(): void {
174193
feedbackCapturePending = false;
175194
lastTurnTraceId = undefined;
195+
currentTurnTraceId = undefined;
176196
}

src/telemetry/index.ts

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -206,7 +206,11 @@ export function aiSpansEnabled(env: NodeJS.ProcessEnv = process.env): boolean {
206206
export function generationSampleRate(env: NodeJS.ProcessEnv = process.env): number {
207207
const raw = env[TELEMETRY_GENERATION_SAMPLE_RATE_ENV];
208208
if (raw === undefined) return 1;
209-
const parsed = Number(raw);
209+
const trimmed = raw.trim();
210+
// Empty env ("CORBITS_TELEMETRY_GENERATION_SAMPLE_RATE=") is unset, not 0 —
211+
// Number("") is 0 and would silently drop every successful generation.
212+
if (trimmed.length === 0) return 1;
213+
const parsed = Number(trimmed);
210214
if (!Number.isFinite(parsed)) return 1;
211215
return Math.min(1, Math.max(0, parsed));
212216
}

src/telemetry/product-events.ts

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,6 @@ import type { ForcedStopReason } from "../subagent/stop-policy.js";
55
import type { SubAgentTelemetryRollup } from "../subagent/types.js";
66
import type { Telemetry } from "./index.js";
77
import { classifyCommandName } from "./classify.js";
8-
import { getLastTurnTraceId } from "./feedback.js";
98

109
/** Emit slash_command with a classified first-party (or `custom`) name. */
1110
export function captureSlashCommand(telemetry: Telemetry, commandName: string): void {
@@ -22,16 +21,17 @@ export type CaptureSubagentEndArgs = {
2221
model?: string;
2322
stopReason?: ForcedStopReason;
2423
rollup?: SubAgentTelemetryRollup;
25-
/** Override for tests; defaults to the last parent-turn trace id. */
24+
/**
25+
* Spawn-time parent `$ai_trace_id` (in-flight turn). Callers must capture
26+
* this at dispatch — never default to the last *completed* turn.
27+
*/
2628
parentTraceId?: string | undefined;
2729
};
2830

2931
/** Build allowlisted `subagent_end` properties from a finished run. */
3032
export function buildSubagentEndProperties(
3133
args: CaptureSubagentEndArgs,
3234
): Record<string, unknown> {
33-
const parentTraceId =
34-
args.parentTraceId !== undefined ? args.parentTraceId : getLastTurnTraceId();
3535
const props: Record<string, unknown> = {
3636
agent_name: args.agentName,
3737
status: args.status,
@@ -43,8 +43,8 @@ export function buildSubagentEndProperties(
4343
if (args.stopReason !== undefined) {
4444
props.stop_reason = args.stopReason;
4545
}
46-
if (parentTraceId !== undefined && parentTraceId.length > 0) {
47-
props.parent_trace_id = parentTraceId;
46+
if (args.parentTraceId !== undefined && args.parentTraceId.length > 0) {
47+
props.parent_trace_id = args.parentTraceId;
4848
}
4949
if (args.rollup !== undefined) {
5050
props.turn_count = args.rollup.turn_count;

src/tui/runner.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1591,6 +1591,7 @@ export async function runTUI(initialConfig: Config): Promise<number> {
15911591
emitter,
15921592
hookManager,
15931593
initialTurnCount: resumeSeed.turnsUsed,
1594+
onTurnStarted: turnObserver.onTurnStarted,
15941595
onTurnComplete: turnObserver.onTurnComplete,
15951596
onTurnFailed: turnObserver.onTurnFailed,
15961597
// persistRunSnapshot is defined below but not invoked until the stream
@@ -1600,6 +1601,7 @@ export async function runTUI(initialConfig: Config): Promise<number> {
16001601
},
16011602
});
16021603

1604+
16031605
// MCP servers connected so far, keyed by name so a reconnect after a failure
16041606
// replaces rather than duplicates the entry.
16051607
let connectedMcpServers: ConnectedMcpServer[] = resumeSeed.mcpServers;

0 commit comments

Comments
 (0)