trace

package
v0.4.0 Latest Latest
Warning

This package is not in the latest version of its module.

Go to latest
Published: Jul 17, 2026 License: MIT Imports: 10 Imported by: 0

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

View Source
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.

View Source
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

func WithContext(ctx context.Context, r *Recorder) context.Context

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

func WriteNDJSON(w io.Writer, t *TurnTrace) error

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.

func WriteText

func WriteText(w io.Writer, t *TurnTrace) error

WriteText emits a human-readable trace: a header, one line per span with its exclusive time and share of wall, a coverage line, then counters. It returns the first write error encountered so a failing sink (e.g. a full disk) is not silently swallowed.

Types

type Counter

type Counter struct {
	Name  string `json:"name"`
	Value int64  `json:"value"`
}

Counter is a named integer accumulated during a run (counts and token totals).

type NDJSONSink

type NDJSONSink struct{ W io.Writer }

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

func FromContext(ctx context.Context) *Recorder

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

func NewRecorder(sessionID, runID, profile string) *Recorder

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) Counter

func (r *Recorder) Counter(name string, n int64)

Counter adds n to the named counter, accumulating across calls.

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

func (r *Recorder) Finish() *TurnTrace

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

func (r *Recorder) RecordSpan(name string, d time.Duration)

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.

func (*Recorder) Start

func (r *Recorder) Start()

Start stamps StartedAt. Safe to call at most once; idempotent on repeat.

type Sink

type Sink interface {
	Emit(*TurnTrace) error
}

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 TextSink

type TextSink struct{ W io.Writer }

TextSink adapts an io.Writer as a Sink emitting human-readable text.

func (TextSink) Emit

func (s TextSink) Emit(t *TurnTrace) error

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

func ReadNDJSON(r io.Reader) (*TurnTrace, error)

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

func (t *TurnTrace) AttributedDuration() time.Duration

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

func (t *TurnTrace) AttributionRatio() float64

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) Counter

func (t *TurnTrace) Counter(name string) int64

Counter returns the value recorded for name, or zero if absent.

func (*TurnTrace) Coverage

func (t *TurnTrace) Coverage() float64

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

func (t *TurnTrace) Exclusive(name string) time.Duration

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

func (t *TurnTrace) Span(name string) time.Duration

Span returns the total inclusive duration recorded for name across all its occurrences, or zero if absent.

func (*TurnTrace) WallDuration

func (t *TurnTrace) WallDuration() time.Duration

WallDuration is the total traced wall time of the run.

Jump to

Keyboard shortcuts

? : This menu
/ : Search site
f or F : Jump to
y or Y : Canonical URL