Documentation
¶
Overview ¶
Package trace records per-turn timing for a Zero agent run.
Tracing is opt-in. A *Recorder is attached to agent.Options and threaded through the run via context (see FromContext / WithContext). When the recorder is nil, every stamp is a no-op and the agent loop, providers, and tools are byte-identical to an untraced run.
The emitted NDJSON is compatible with internal/agenteval's trace contract: one JSON object per line carrying a "type" (and usually "name") field, so agenteval.ParseTraceEventKeys / MissingTraceEvents can validate a run.
Attribution model. Each stamp records a wall interval [start, end]. Spans that run concurrently or are nested (e.g. provider_connect inside generation, permission_wait inside tool_execution) are NOT summed into each other. The recorder derives a parent for each span by interval containment and computes per-span exclusive time (duration minus the union of its children's intervals). AttributedDuration is the sum of top-level (non-nested) spans — the time accounted for without double-counting. Coverage is the fraction of wall covered by the union of all span intervals; it is the honest "≥95% of wall accounted for" metric and never exceeds 1.
Index ¶
- Constants
- func OptionalEventKeys() []string
- func RequiredEventKeys() []string
- func WithContext(ctx context.Context, r *Recorder) context.Context
- func WriteNDJSON(w io.Writer, t *TurnTrace) error
- func WriteText(w io.Writer, t *TurnTrace) error
- type Counter
- type NDJSONSink
- type PrefixHash
- type Recorder
- func (r *Recorder) Counter(name string, n int64)
- func (r *Recorder) EmitPrefixHash(p PrefixHash)
- func (r *Recorder) Finish() *TurnTrace
- func (r *Recorder) RecordSpan(name string, d time.Duration)
- func (r *Recorder) Span(name string) *SpanHandle
- func (r *Recorder) StampFirstToken()
- func (r *Recorder) StampFirstUsefulAction()
- func (r *Recorder) StampFirstVisibleEvent()
- func (r *Recorder) Start()
- type Sink
- type Span
- type SpanHandle
- type TextSink
- type TurnTrace
- func (t *TurnTrace) AttributedDuration() time.Duration
- func (t *TurnTrace) AttributionRatio() float64
- func (t *TurnTrace) Counter(name string) int64
- func (t *TurnTrace) Coverage() float64
- func (t *TurnTrace) Exclusive(name string) time.Duration
- func (t *TurnTrace) Span(name string) time.Duration
- func (t *TurnTrace) WallDuration() time.Duration
Constants ¶
const ( SpanToolPartition = "tool_partition" // partitioning the tool set for the prompt SpanProviderConnect = "provider_connect" // client.Do in the provider seam SpanProviderQueue = "provider_queue" // pre-send OAuth/token resolve SpanGeneration = "generation" // streaming a model completion SpanToolExecution = "tool_execution" // executing tool calls SpanPermissionWait = "permission_wait" // waiting on a permission prompt SpanVerification = "verification" // self-correct verify pass SpanCompaction = "compaction" // context compaction )
Span names. These are the "name" keys emitted in the NDJSON event stream (e.g. {"type":"span","name":"generation","duration_ms":123.4}) and the vocabulary a run's wall time is attributed to. Only names that are actually stamped appear here: phases without a real stamp are omitted so readers do not trust empty categories. RequiredEventKeys lists the subset guaranteed in any successful model turn; OptionalEventKeys lists the rest.
const ( CounterModelRequests = "model_requests" CounterToolCalls = "tool_calls" CounterRetryCount = "retry_count" CounterReconnectCount = "reconnect_count" CounterCompactionCount = "compaction_count" CounterCompletionNudges = "completion_nudges" CounterAcceptanceChecks = "acceptance_checks" CounterPollingTurn = "polling_turn" CounterModelSwitches = "model_switches" CounterInputTokens = "input_tokens" CounterCachedInputTokens = "cached_input_tokens" CounterOutputTokens = "output_tokens" )
Counter names. Emitted as {"type":"counter","name":"tool_calls","value":7}.
Variables ¶
This section is empty.
Functions ¶
func OptionalEventKeys ¶
func OptionalEventKeys() []string
OptionalEventKeys are event keys a traced run MAY emit depending on what the run does (it may call no tools, need no permission, never compact, etc.). Callers must not treat their absence as a failure.
func RequiredEventKeys ¶
func RequiredEventKeys() []string
RequiredEventKeys is the set of span/counter event keys guaranteed in any successful single-turn traced run, regardless of provider or auth path. Tests assert via agenteval.MissingTraceEvents that a run produces all of these. Phases that are conditional (tools, permission, compaction, verification) are in OptionalEventKeys, not here, so a healthy short trace does not false-fail.
func WithContext ¶
WithContext returns a copy of ctx that carries r, so the providerio seam and other lower layers can reach the recorder without changing their function signatures. Passing a nil recorder still injects a value (a nil *Recorder), but FromContext returns nil for it so downstream no-op guards see nil.
func WriteNDJSON ¶
WriteNDJSON emits the trace as newline-delimited JSON compatible with the internal/agenteval trace contract: one object per line carrying a "type" and (for spans/counters) a "name" so ParseTraceEventKeys keys them.
The first line is a "trace" summary (name "run"), followed by one "span" line per span occurrence and one "counter" line per counter. Span lines carry the wall interval (start/end), inclusive duration, exclusive duration, and parent — the data the harness needs to rank latency sources without double-counting nested/concurrent work. Spans are emitted in stable (name, then start) order for deterministic output; counters are sorted.
Types ¶
type NDJSONSink ¶
NDJSONSink adapts an io.Writer as a Sink emitting NDJSON.
func (NDJSONSink) Emit ¶
func (s NDJSONSink) Emit(t *TurnTrace) error
type PrefixHash ¶
type PrefixHash struct {
BaseInstructionsHash string `json:"base_instructions"`
ConfirmationPolicyHash string `json:"confirmation_policy"`
ProjectContextHash string `json:"project_context"`
SkillsHash string `json:"skills"`
ToolsHash string `json:"tools"`
SchemaHash string `json:"schema"`
CompletePrefixHash string `json:"complete_prefix"`
}
PrefixHash is one fingerprint of the prompt prefix emitted by an agent run. The seven fields decompose the cacheable part of the request so a downstream observer can detect which sub-component drifted turn-over-turn: base_instructions (the embedded core system prompt), confirmation_policy, project_context (AGENTS.md / ZERO.md chain), skills, tools, schema (tool JSON schemas), and complete_prefix (SHA-256 of the canonical concatenation of the other six). All hashes are hex-encoded SHA-256.
Scope: the fingerprint covers 4 of 11 sections of buildSystemPrompt. The seven sections NOT covered — modelPromptAddendum, sessionRuntimeContext, approvedCommandPrefixContext, workspaceSeedContext, userGuidelines, specialistDelegationContext, responseStyleContext — fire only for non-default Options. For default Options (the common case), the four captured substrings are the full prompt and the fingerprint is accurate.
A run with a stable CompletePrefix across turns means the four captured sub-components are byte-identical. A run where CompletePrefix changes names the captured sub-component that drifted, but does NOT rule out drift in the seven uncaptured sections. modelPromptAddendum in particular changes on a model switch (a model_switches counter the trace already emits), so a consumer correlating CompletePrefix stability with cached_input_tokens must cross-check the model_switches counter to disambiguate "no drift" from "drift in an uncaptured section." The fields are emitted as a "prefix_hash" event in the NDJSON trace (see WriteNDJSON).
type Recorder ¶
type Recorder struct {
// contains filtered or unexported fields
}
Recorder is the in-process handle one agent.Run stamps spans and counters into. It is concurrency-safe: parallel tool execution, provider reconnects, and async streaming stamp concurrently from different goroutines.
A nil *Recorder is valid to call: the no-op helpers below route every stamp through a nil check so callers can write `options.Trace.Start()` unconditionally and pay nothing when tracing is off.
Spans are stored as occurrences (one entry per stamp) with their wall interval. Parent/child nesting and exclusive time are derived at Finish by interval containment, so concurrent (provider_connect inside generation) and nested (permission_wait inside tool_execution) spans are not double-counted.
func FromContext ¶
FromContext returns the recorder carried by ctx, or nil if none is present (or if the carried value is nil). Callers must guard all stamps with a nil check; the recorder methods are themselves nil-safe.
func NewRecorder ¶
NewRecorder returns a ready recorder. sessionID correlates with the agent session (Options.SessionID); runID is a per-Run sequence; profile is an optional label (e.g. "cold", "warm") for benchmark runs.
func (*Recorder) EmitPrefixHash ¶
func (r *Recorder) EmitPrefixHash(p PrefixHash)
EmitPrefixHash records one prompt-prefix fingerprint on the trace. Multiple calls are allowed within a run (one per turn, typically) and accumulate in order. The first call after Finish is a no-op; later calls are also no-ops because the trace has been sealed.
func (*Recorder) Finish ¶
Finish stamps CompletedAt, derives each span's parent (by interval containment) and exclusive time, and returns a snapshot of the trace. Calling Finish more than once returns the same snapshot.
func (*Recorder) RecordSpan ¶
RecordSpan commits an already-measured duration to name as a synthesized sequential occurrence. Use this when the caller already holds a duration (for example, in tests) rather than a live interval; production code uses Span/End, which record the real wall interval. Synthesized occurrences chain from the recorder's StartedAt (or a moving cursor) so coverage and exclusive math remain consistent. Each stamp is its own entry.
func (*Recorder) Span ¶
func (r *Recorder) Span(name string) *SpanHandle
Span begins a named span and returns a handle. Caller is responsible for calling End when the span completes. Example:
span := r.Span(trace.SpanGeneration) defer span.End()
func (*Recorder) StampFirstToken ¶
func (r *Recorder) StampFirstToken()
StampFirstToken records the time of the first output token. Only the first call wins; later calls are no-ops.
func (*Recorder) StampFirstUsefulAction ¶
func (r *Recorder) StampFirstUsefulAction()
StampFirstUsefulAction records the first tool call or substantive action. First call wins.
func (*Recorder) StampFirstVisibleEvent ¶
func (r *Recorder) StampFirstVisibleEvent()
StampFirstVisibleEvent records the first event visible to the user. First call wins.
type Sink ¶
Sink is the abstraction a finished TurnTrace is written to. The NDJSON and text sinks are implemented here; an OpenTelemetry sink is a documented future addition (see opentelemetrySink below) and is intentionally not pulled in as a dependency.
type Span ¶
type Span struct {
Name string `json:"name"`
Start time.Time `json:"start,omitempty"`
End time.Time `json:"end,omitempty"`
Duration time.Duration `json:"duration"`
Parent string `json:"parent,omitempty"`
Exclusive time.Duration `json:"exclusive,omitempty"`
}
Span is one named wall interval attributed to part of a run. Each stamp is its own entry (spans are not merged by name): a run that streams two model completions has two generation entries, which lets the recorder derive parent/child nesting by interval containment and compute exclusive time.
Duration is the inclusive wall time (End - Start). Exclusive is Duration minus the union of this span's children's intervals — the time uniquely attributable to this phase rather than to a nested sub-phase. Parent is the name of the tightest containing span, or "" for a top-level span.
type SpanHandle ¶
type SpanHandle struct {
// contains filtered or unexported fields
}
SpanHandle is a live timing span. Call End exactly once to commit it; a second End is a no-op. Not calling End leaks the span (it is dropped).
func (*SpanHandle) End ¶
func (s *SpanHandle) End()
End commits the span's wall interval to the recorder. Each stamp is its own occurrence (spans are not merged by name); exclusive time is derived at Finish from the recorded intervals.
type TurnTrace ¶
type TurnTrace struct {
SessionID string `json:"session_id"`
RunID string `json:"run_id"`
Profile string `json:"profile,omitempty"`
StartedAt time.Time `json:"started_at"`
FirstVisibleEventAt time.Time `json:"first_visible_event_at,omitempty"`
FirstUsefulActionAt time.Time `json:"first_useful_action_at,omitempty"`
FirstTokenAt time.Time `json:"first_token_at,omitempty"`
CompletedAt time.Time `json:"completed_at"`
Spans []Span `json:"spans"`
Counters []Counter `json:"counters"`
PrefixHashes []PrefixHash `json:"prefix_hashes,omitempty"`
}
TurnTrace is the finished record for one agent.Run. It is the value emitters serialize; it is not mutated after Finish returns a snapshot.
func ReadNDJSON ¶
ReadNDJSON parses an NDJSON trace emitted by WriteNDJSON back into a TurnTrace. It is the inverse of WriteNDJSON and is used by the benchmark harness to turn a captured trace file into structured per-span stats.
It fails loudly on a corrupt file rather than silently returning an empty trace. Empty or blank-only input is an error (an empty trace file means emission never happened — e.g. the agent crashed before writing the header or --trace was not honored — and must not masquerade as a valid zero- attribution sample). A non-empty input must contain a "type":"trace" header line; span/counter lines before it are an error; and a header that yields no spans and no counters is treated as corrupt. Individual span/counter lines with bad JSON are skipped only when a valid "trace" header has already been seen — a truncated middle of a real trace should not fatal a run.
Numbers are decoded with UseNumber so counter values round-trip as exact int64s rather than going through float64 (which loses precision above 2^53).
func (*TurnTrace) AttributedDuration ¶
AttributedDuration is the sum of top-level (non-nested) span durations — the wall time accounted for without double-counting nested or concurrent sub- phases. For a well-instrumented sequential run this is close to WallDuration (gaps are uninstrumented regions); it does not inflate from nested children.
func (*TurnTrace) AttributionRatio ¶
AttributionRatio is Coverage — the fraction of wall covered by span intervals. A run is considered well-attributed when this is >= 0.95. It never exceeds 1, so it is a sound denominator for "share of attributed time".
func (*TurnTrace) Coverage ¶
Coverage is the fraction of WallDuration covered by the union of all span intervals, capped at 1.0. This is the honest "what fraction of wall time did we account for" metric: overlapping or nested spans do not push it above 1. Returns 0 when wall is zero or no span has a usable interval.
func (*TurnTrace) Exclusive ¶
Exclusive returns the total exclusive duration recorded for name across all its occurrences (each occurrence's Duration minus its children), or zero.
func (*TurnTrace) Span ¶
Span returns the total inclusive duration recorded for name across all its occurrences, or zero if absent.
func (*TurnTrace) WallDuration ¶
WallDuration is the total traced wall time of the run.