diff --git a/docs/adr/38277-render-awf-steering-events-in-unified-timeline.md b/docs/adr/38277-render-awf-steering-events-in-unified-timeline.md new file mode 100644 index 00000000000..e46617ad628 --- /dev/null +++ b/docs/adr/38277-render-awf-steering-events-in-unified-timeline.md @@ -0,0 +1,44 @@ +# ADR-38277: Render AWF Steering Events in the Unified Log Timeline + +**Date**: 2026-06-10 +**Status**: Draft + +## Context + +The `gh aw view` / `gh aw audit` unified timeline merges JSONL events from the MCP Gateway, the AWF firewall, and the agent session into a single wall-clock-ordered view. The AWF API proxy emits steering events (`token_steering`, `timeout_steering`) when a run approaches its token budget or time limit; these were already counted in `TotalSteeringEvents` metrics but were silently dropped from the timeline, so an operator reading the unified log could see neither when nor why a run was steered. The steering records live in `api-proxy-logs/events.jsonl`, whose schema varies by proxy version — the event name appears under one of four field names (`event`, `type`, `event_name`, `eventName`) — and whose log directory exists in both a canonical (`sandbox/firewall/logs/`) and a legacy (`firewall-audit-logs/`) layout. + +## Decision + +We will surface AWF steering events as first-class entries in the unified timeline by adding a new `TimelineKindSteering` event kind. Concretely: + +1. Steering events are collected by a new `collectSteeringTimelineEvents`, parsed via a `proxyEventsEntry` struct whose `eventName()` helper checks all four field-name variants, and validated against the AWF spec message prefixes (`[AWF TOKEN WARNING]` / `[AWF TIME WARNING]`) before admission. +2. Steering events reuse the existing `TimelineSourceFirewall` source rather than introducing a new source, and encode their subtype in the existing `Status` field (`"token"` / `"time"`) rather than adding new struct fields. +3. The renderer dispatches the new kind to `renderSteeringRow` (table) and a warning-styled `⚠ ` line (stream), and the summary appends `steering=N` to the existing Firewall line only when the count is non-zero. + +This favors extending the established per-kind timeline pattern and reusing the firewall source/status plumbing over introducing parallel structures, keeping steering integration consistent with how gateway and agent events are already handled. + +## Alternatives Considered + +### Alternative 1: Introduce a dedicated `TimelineSourceProxy` source and bespoke struct fields +Model the API proxy as its own timeline source with a new summary line and dedicated fields for steering subtype and message. Rejected because steering is conceptually a firewall/guard concern already grouped under the Firewall summary, and a new source would add a fourth summary block plus renderer branching for a single event kind, increasing surface area without a clear operator benefit. + +### Alternative 2: Parse only the canonical event-name field and single directory layout +Read `event_name` from `sandbox/firewall/logs/api-proxy-logs/events.jsonl` only, treating the other field-name variants and the legacy layout as out of scope. Rejected because real proxy logs in the field use all four field-name spellings and both directory layouts; a strict reader would silently drop steering events from older runs and proxy versions, reintroducing the very gap this change closes. + +## Consequences + +### Positive +- Operators can now see when and why a run was steered directly in the unified timeline, closing the gap between `TotalSteeringEvents` metrics and the visible log. +- Defensive multi-variant field parsing and dual-layout collection make steering rendering robust across proxy versions and historical runs. + +### Negative +- Reusing the `Status` field to carry the steering subtype overloads a field whose semantics now depend on `Kind`, so future readers must know that `Status` means something different for steering events than for other kinds. +- The collector adds another file scan (`events.jsonl`) to every `BuildUnifiedTimeline` call, with the spec-prefix validation and four-field probing duplicating event-name knowledge that must stay in sync with the AWF proxy spec. + +### Neutral +- Steering events are grouped under the existing Firewall summary line rather than a new section; the `steering=N` suffix appears only when non-zero, leaving output unchanged for runs without steering. +- Steering entries with no parseable timestamp sort with a zero time, placing them at the start of the wall-clock ordering. + +--- + +*This is a DRAFT ADR generated by the [Design Decision Gate](https://github.com/github/gh-aw/actions/runs/27252641413) workflow. The PR author must review, complete, and finalize this document before the PR can merge.* diff --git a/pkg/cli/gateway_logs_timeline.go b/pkg/cli/gateway_logs_timeline.go index 872036e2126..171a30c49bf 100644 --- a/pkg/cli/gateway_logs_timeline.go +++ b/pkg/cli/gateway_logs_timeline.go @@ -66,6 +66,9 @@ const ( TimelineKindAssistantMessage TimelineEventKind = "assistant_message" // TimelineKindReasoning is a model reasoning/thinking trace (reasoning or assistant.reasoning event). TimelineKindReasoning TimelineEventKind = "reasoning" + // TimelineKindSteering is a budget or time pressure steering message injected by the AWF + // API proxy (token_steering or timeout_steering event from api-proxy-logs/events.jsonl). + TimelineKindSteering TimelineEventKind = "steering" ) // UnifiedTimelineEvent represents a single event from the MCP Gateway, the AWF @@ -520,9 +523,82 @@ func collectAgentTimelineEvents(logDir string, verbose bool) ([]UnifiedTimelineE return events, nil } +// steeringEntryToTimelineEvent converts a proxyEventsEntry into a +// UnifiedTimelineEvent with Kind == TimelineKindSteering. +// Returns (zero, false) when the entry is not a recognised steering event. +// +// The Status field is set to "token" for token_steering events and "time" for +// timeout_steering events so that the renderer can apply appropriate icons. +// The Reason field carries the full message text. +// The Time field is set from the Timestamp field when present; zero otherwise. +func steeringEntryToTimelineEvent(entry proxyEventsEntry) (UnifiedTimelineEvent, bool) { + name := entry.eventName() + msg := strings.TrimSpace(entry.Message) + if !isSteeringEvent(name, msg) { + return UnifiedTimelineEvent{}, false + } + + var status string + switch name { + case tokenSteeringEventName: + status = "token" + case timeoutSteeringEventName: + status = "time" + } + + var t time.Time + if entry.Timestamp != "" { + if parsed, ok := gatewayTimestampToTime(entry.Timestamp); ok { + t = parsed + } + } + + return UnifiedTimelineEvent{ + Time: t, + Source: TimelineSourceFirewall, + Kind: TimelineKindSteering, + Status: status, + Reason: msg, + }, true +} + +// collectSteeringTimelineEvents reads the api-proxy events.jsonl from logDir and +// returns a slice of TimelineKindSteering timeline events, one per recognised steering +// record. Returns nil (not an error) when no proxy events file is found. +func collectSteeringTimelineEvents(logDir string, verbose bool) ([]UnifiedTimelineEvent, error) { + eventsPath := findAPIProxyEventsFile(logDir) + if eventsPath == "" { + gatewayLogsLog.Printf("No api-proxy events.jsonl found in %s; skipping steering timeline collection", logDir) + return nil, nil + } + + gatewayLogsLog.Printf("Collecting steering timeline events from: %s", eventsPath) + + f, err := os.Open(filepath.Clean(eventsPath)) + if err != nil { + return nil, fmt.Errorf("failed to open proxy events file: %w", err) + } + defer f.Close() + + entries, err := scanSteeringEntries(f) + if err != nil { + return nil, fmt.Errorf("scanner error reading proxy events: %w", err) + } + + events := make([]UnifiedTimelineEvent, 0, len(entries)) + for _, entry := range entries { + if evt, ok := steeringEntryToTimelineEvent(entry); ok { + events = append(events, evt) + } + } + + gatewayLogsLog.Printf("Collected %d steering timeline events from %s", len(events), filepath.Base(eventsPath)) + return events, nil +} + // BuildUnifiedTimeline collects all JSONL events from the MCP Gateway, the AWF -// firewall, and the agent session in logDir, merges them into a single slice, and -// sorts the slice in ascending wall-clock order (oldest first). +// firewall, the agent session, and the AWF API proxy in logDir, merges them into a +// single slice, and sorts the slice in ascending wall-clock order (oldest first). // // If a source is unavailable (no matching file), it is silently skipped; collection // errors are logged but do not prevent events from the other sources from being returned. @@ -542,10 +618,17 @@ func BuildUnifiedTimeline(logDir string, verbose bool) ([]UnifiedTimelineEvent, gatewayLogsLog.Printf("collectAgentTimelineEvents error: %v", agErr) } - events := make([]UnifiedTimelineEvent, 0, len(gatewayEvents)+len(firewallEvents)+len(agentEvents)) + steeringEvents, stErr := collectSteeringTimelineEvents(logDir, verbose) + if stErr != nil { + gatewayLogsLog.Printf("collectSteeringTimelineEvents error: %v", stErr) + } + + events := make([]UnifiedTimelineEvent, 0, + len(gatewayEvents)+len(firewallEvents)+len(agentEvents)+len(steeringEvents)) events = append(events, gatewayEvents...) events = append(events, firewallEvents...) events = append(events, agentEvents...) + events = append(events, steeringEvents...) slices.SortFunc(events, func(a, b UnifiedTimelineEvent) int { switch { @@ -558,8 +641,8 @@ func BuildUnifiedTimeline(logDir string, verbose bool) ([]UnifiedTimelineEvent, } }) - gatewayLogsLog.Printf("Built unified timeline: %d events (gateway=%d, firewall=%d, agent=%d)", - len(events), len(gatewayEvents), len(firewallEvents), len(agentEvents)) + gatewayLogsLog.Printf("Built unified timeline: %d events (gateway=%d, firewall=%d, agent=%d, steering=%d)", + len(events), len(gatewayEvents), len(firewallEvents), len(agentEvents), len(steeringEvents)) return events, nil } diff --git a/pkg/cli/gateway_logs_timeline_render.go b/pkg/cli/gateway_logs_timeline_render.go index 189d9f6757b..074904d4d70 100644 --- a/pkg/cli/gateway_logs_timeline_render.go +++ b/pkg/cli/gateway_logs_timeline_render.go @@ -14,6 +14,7 @@ // TimelineKindAgentToolDone – renderAgentToolDoneRow // TimelineKindAssistantMessage – renderAgentAssistantMessageRow // TimelineKindReasoning – renderAgentReasoningRow +// TimelineKindSteering – renderSteeringRow // // renderTimelineEventRow dispatches to the appropriate primitive and returns a // []string suitable for inclusion in a console.TableConfig.Rows slice. @@ -57,6 +58,8 @@ func timelineEventIcon(kind TimelineEventKind) string { return "●" case TimelineKindReasoning: return "◐" + case TimelineKindSteering: + return "⚠" default: return "·" } @@ -85,6 +88,8 @@ func timelineEventKindLabel(kind TimelineEventKind) string { return "assistant_message" case TimelineKindReasoning: return "reasoning" + case TimelineKindSteering: + return "steering" default: return string(kind) } @@ -338,6 +343,20 @@ func renderAgentReasoningRow(evt UnifiedTimelineEvent) []string { return []string{ts, src, kind, detail, ""} } +// renderSteeringRow renders a TimelineKindSteering event as a table row. +// +// Columns: Time | Src | Kind | Detail | Status +// +// Detail shows a truncated preview of the steering message. Status shows the +// steering type: "token" for token budget warnings, "time" for timeout warnings. +func renderSteeringRow(evt UnifiedTimelineEvent) []string { + ts := formatTimelineTime(evt) + src := timelineSourceLabel(evt.Source) + kind := timelineEventIcon(TimelineKindSteering) + " " + timelineEventKindLabel(TimelineKindSteering) + detail := stringutil.Truncate(evt.Reason, 48) + return []string{ts, src, kind, detail, evt.Status} +} + // renderTimelineEventRow dispatches to the appropriate per-kind rendering primitive and // returns a []string table row with columns: Time | Src | Kind | Detail | Status. func renderTimelineEventRow(evt UnifiedTimelineEvent) []string { @@ -362,6 +381,8 @@ func renderTimelineEventRow(evt UnifiedTimelineEvent) []string { return renderAgentAssistantMessageRow(evt) case TimelineKindReasoning: return renderAgentReasoningRow(evt) + case TimelineKindSteering: + return renderSteeringRow(evt) default: // Fallback for any future event kinds not yet handled. ts := formatTimelineTime(evt) @@ -580,6 +601,11 @@ func renderUnifiedTimelineStream(events []UnifiedTimelineEvent) string { } fmt.Fprintf(&sb, " %s %s%s\n", icon, detail, annotationStr) + case TimelineKindSteering: + icon := streamColor(styles.Warning, timelineEventIcon(TimelineKindSteering)) + msg := stringutil.Truncate(evt.Reason, streamMaxAnnotationLen) + fmt.Fprintf(&sb, " %s %s\n", icon, msg) + default: fmt.Fprintf(&sb, " · [%s] %s %s\n", ts, string(evt.Kind), timelineSourceLabel(evt.Source)) } @@ -604,38 +630,44 @@ func renderUnifiedTimeline(events []UnifiedTimelineEvent) string { // Tally event counts for the summary header. var gwCount, fwCount, agCount int - var toolCalls, difcFiltered, guardBlocked, netAllowed, netBlocked int + var toolCalls, difcFiltered, guardBlocked, netAllowed, netBlocked, steeringCount int var agentTurns, agentToolStarts, agentToolDones, assistantMessages, reasoningCount int for _, evt := range events { switch evt.Source { case TimelineSourceGateway: gwCount++ + switch evt.Kind { + case TimelineKindToolCall: + toolCalls++ + case TimelineKindDIFCFiltered: + difcFiltered++ + case TimelineKindGuardPolicyBlocked: + guardBlocked++ + } case TimelineSourceFirewall: fwCount++ + switch evt.Kind { + case TimelineKindNetworkAllowed: + netAllowed++ + case TimelineKindNetworkBlocked: + netBlocked++ + case TimelineKindSteering: + steeringCount++ + } case TimelineSourceAgent: agCount++ - } - switch evt.Kind { - case TimelineKindToolCall: - toolCalls++ - case TimelineKindDIFCFiltered: - difcFiltered++ - case TimelineKindGuardPolicyBlocked: - guardBlocked++ - case TimelineKindNetworkAllowed: - netAllowed++ - case TimelineKindNetworkBlocked: - netBlocked++ - case TimelineKindAgentTurn: - agentTurns++ - case TimelineKindAgentToolStart: - agentToolStarts++ - case TimelineKindAgentToolDone: - agentToolDones++ - case TimelineKindAssistantMessage: - assistantMessages++ - case TimelineKindReasoning: - reasoningCount++ + switch evt.Kind { + case TimelineKindAgentTurn: + agentTurns++ + case TimelineKindAgentToolStart: + agentToolStarts++ + case TimelineKindAgentToolDone: + agentToolDones++ + case TimelineKindAssistantMessage: + assistantMessages++ + case TimelineKindReasoning: + reasoningCount++ + } } } @@ -651,8 +683,11 @@ func renderUnifiedTimeline(events []UnifiedTimelineEvent) string { gwCount, toolCalls, difcFiltered, guardBlocked) } if fwCount > 0 { - fmt.Fprintf(&sb, " Firewall : %d (allowed=%d, blocked=%d)\n", - fwCount, netAllowed, netBlocked) + fwDetail := fmt.Sprintf("allowed=%d, blocked=%d", netAllowed, netBlocked) + if steeringCount > 0 { + fwDetail += fmt.Sprintf(", steering=%d", steeringCount) + } + fmt.Fprintf(&sb, " Firewall : %d (%s)\n", fwCount, fwDetail) } if agCount > 0 { fmt.Fprintf(&sb, " Agent : %d (turns=%d, tool_start=%d, tool_done=%d, messages=%d, reasoning=%d)\n", diff --git a/pkg/cli/gateway_logs_timeline_test.go b/pkg/cli/gateway_logs_timeline_test.go index 7735309ac50..c4f64ed7aec 100644 --- a/pkg/cli/gateway_logs_timeline_test.go +++ b/pkg/cli/gateway_logs_timeline_test.go @@ -581,6 +581,7 @@ func TestTimelineEventIcon_AllKinds(t *testing.T) { TimelineKindAgentToolDone, TimelineKindAssistantMessage, TimelineKindReasoning, + TimelineKindSteering, } for _, k := range kinds { icon := timelineEventIcon(k) @@ -640,3 +641,320 @@ func TestRenderMessageSnippet_SkipsBlankLines(t *testing.T) { t.Errorf("renderMessageSnippet = %q; want non-blank lines shown", out) } } + +// ─── steeringEntryToTimelineEvent ──────────────────────────────────────────── + +func TestSteeringEntryToTimelineEvent_TokenWarning(t *testing.T) { + entry := proxyEventsEntry{ + Event: tokenSteeringEventName, + Message: awfTokenWarningPrefix + " You have used 80% of your effective token budget.", + } + evt, ok := steeringEntryToTimelineEvent(entry) + if !ok { + t.Fatal("steeringEntryToTimelineEvent returned ok=false; want true for token_steering") + } + if evt.Kind != TimelineKindSteering { + t.Errorf("Kind = %q; want steering", evt.Kind) + } + if evt.Status != "token" { + t.Errorf("Status = %q; want token", evt.Status) + } + if evt.Reason == "" { + t.Error("Reason is empty; want the steering message text") + } + if evt.Source != TimelineSourceFirewall { + t.Errorf("Source = %q; want firewall", evt.Source) + } +} + +func TestSteeringEntryToTimelineEvent_TimeoutWarning(t *testing.T) { + entry := proxyEventsEntry{ + EventNameSnake: timeoutSteeringEventName, + Message: awfTimeWarningPrefix + " You have used 80% of your allotted run time.", + } + evt, ok := steeringEntryToTimelineEvent(entry) + if !ok { + t.Fatal("steeringEntryToTimelineEvent returned ok=false; want true for timeout_steering") + } + if evt.Status != "time" { + t.Errorf("Status = %q; want time", evt.Status) + } +} + +func TestSteeringEntryToTimelineEvent_WithTimestamp(t *testing.T) { + entry := proxyEventsEntry{ + Event: tokenSteeringEventName, + Message: awfTokenWarningPrefix + " 90% used.", + Timestamp: "2024-01-15T10:05:00.000Z", + } + evt, ok := steeringEntryToTimelineEvent(entry) + if !ok { + t.Fatal("expected ok=true") + } + if evt.Time.IsZero() { + t.Error("Time is zero; want parsed timestamp") + } + if evt.Time.UTC().Format("15:04:05") != "10:05:00" { + t.Errorf("Time = %s; want 10:05:00", evt.Time.UTC().Format("15:04:05")) + } +} + +func TestSteeringEntryToTimelineEvent_WithoutTimestamp(t *testing.T) { + entry := proxyEventsEntry{ + Event: tokenSteeringEventName, + Message: awfTokenWarningPrefix + " budget warning.", + } + evt, ok := steeringEntryToTimelineEvent(entry) + if !ok { + t.Fatal("expected ok=true") + } + if !evt.Time.IsZero() { + t.Errorf("Time = %s; want zero time for entry without timestamp", evt.Time) + } +} + +func TestSteeringEntryToTimelineEvent_NonSteering(t *testing.T) { + entry := proxyEventsEntry{ + Event: "request.forwarded", + Message: "some other message", + } + _, ok := steeringEntryToTimelineEvent(entry) + if ok { + t.Error("steeringEntryToTimelineEvent returned ok=true for non-steering event; want false") + } +} + +func TestSteeringEntryToTimelineEvent_WrongMessagePrefix(t *testing.T) { + entry := proxyEventsEntry{ + Event: tokenSteeringEventName, + Message: "warn 95%", // wrong prefix + } + _, ok := steeringEntryToTimelineEvent(entry) + if ok { + t.Error("steeringEntryToTimelineEvent returned ok=true for token_steering with wrong message prefix") + } +} + +func TestSteeringEntryToTimelineEvent_CamelCaseEventName(t *testing.T) { + entry := proxyEventsEntry{ + EventNameCamel: timeoutSteeringEventName, + Message: awfTimeWarningPrefix + " 90% time used.", + } + evt, ok := steeringEntryToTimelineEvent(entry) + if !ok { + t.Fatal("expected ok=true for camelCase eventName field") + } + if evt.Status != "time" { + t.Errorf("Status = %q; want time", evt.Status) + } +} + +func TestSteeringEntryToTimelineEvent_TypeField(t *testing.T) { + entry := proxyEventsEntry{ + Type: tokenSteeringEventName, + Message: awfTokenWarningPrefix + " budget warning.", + } + evt, ok := steeringEntryToTimelineEvent(entry) + if !ok { + t.Fatal("expected ok=true for 'type' field") + } + if evt.Status != "token" { + t.Errorf("Status = %q; want token", evt.Status) + } +} + +// ─── collectSteeringTimelineEvents ─────────────────────────────────────────── + +func TestCollectSteeringTimelineEvents_EmptyDir(t *testing.T) { + dir := t.TempDir() + events, err := collectSteeringTimelineEvents(dir, false) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if len(events) != 0 { + t.Errorf("got %d events; want 0 for empty dir", len(events)) + } +} + +func TestCollectSteeringTimelineEvents_ReadsProxyEvents(t *testing.T) { + dir := t.TempDir() + logsDir := filepath.Join(dir, "sandbox", "firewall", "logs", "api-proxy-logs") + if err := os.MkdirAll(logsDir, 0700); err != nil { + t.Fatal(err) + } + eventsPath := filepath.Join(logsDir, "events.jsonl") + + lines := strings.Join([]string{ + `{"event":"token_steering","message":"[AWF TOKEN WARNING] You have used 80% of your effective token budget."}`, + `{"event_name":"timeout_steering","message":"[AWF TIME WARNING] You have used 80% of your allotted run time."}`, + `{"event":"request.forwarded"}`, + `{"event":"token_steering","message":"warn 95%"}`, + }, "\n") + if err := os.WriteFile(eventsPath, []byte(lines+"\n"), 0600); err != nil { + t.Fatal(err) + } + + events, err := collectSteeringTimelineEvents(dir, false) + if err != nil { + t.Fatalf("collectSteeringTimelineEvents: %v", err) + } + if len(events) != 2 { + t.Fatalf("got %d events; want 2 (only spec-compliant steering events)", len(events)) + } + if events[0].Kind != TimelineKindSteering { + t.Errorf("events[0].Kind = %q; want steering", events[0].Kind) + } + if events[0].Status != "token" { + t.Errorf("events[0].Status = %q; want token", events[0].Status) + } + if events[1].Status != "time" { + t.Errorf("events[1].Status = %q; want time", events[1].Status) + } +} + +func TestCollectSteeringTimelineEvents_WithTimestamps(t *testing.T) { + dir := t.TempDir() + logsDir := filepath.Join(dir, "sandbox", "firewall", "logs", "api-proxy-logs") + if err := os.MkdirAll(logsDir, 0700); err != nil { + t.Fatal(err) + } + eventsPath := filepath.Join(logsDir, "events.jsonl") + + lines := strings.Join([]string{ + `{"event":"token_steering","timestamp":"2024-01-15T10:05:00.000Z","message":"[AWF TOKEN WARNING] 80% used."}`, + `{"event":"token_steering","timestamp":"2024-01-15T10:10:00.000Z","message":"[AWF TOKEN WARNING] 90% used."}`, + }, "\n") + if err := os.WriteFile(eventsPath, []byte(lines+"\n"), 0600); err != nil { + t.Fatal(err) + } + + events, err := collectSteeringTimelineEvents(dir, false) + if err != nil { + t.Fatalf("collectSteeringTimelineEvents: %v", err) + } + if len(events) != 2 { + t.Fatalf("got %d events; want 2", len(events)) + } + if events[0].Time.IsZero() || events[1].Time.IsZero() { + t.Error("expected non-zero timestamps for events with timestamp field") + } +} + +// ─── BuildUnifiedTimeline includes steering ─────────────────────────────────── + +func TestBuildUnifiedTimeline_IncludesSteeringEvents(t *testing.T) { + dir := t.TempDir() + + // Create proxy events file with one steering entry. + logsDir := filepath.Join(dir, "sandbox", "firewall", "logs", "api-proxy-logs") + if err := os.MkdirAll(logsDir, 0700); err != nil { + t.Fatal(err) + } + eventsPath := filepath.Join(logsDir, "events.jsonl") + line := `{"event":"token_steering","message":"[AWF TOKEN WARNING] 80% of budget used."}` + if err := os.WriteFile(eventsPath, []byte(line+"\n"), 0600); err != nil { + t.Fatal(err) + } + + events, err := BuildUnifiedTimeline(dir, false) + if err != nil { + t.Fatalf("BuildUnifiedTimeline: %v", err) + } + var steeringCount int + for _, e := range events { + if e.Kind == TimelineKindSteering { + steeringCount++ + } + } + if steeringCount != 1 { + t.Errorf("got %d steering events; want 1", steeringCount) + } +} + +// ─── renderSteeringRow ──────────────────────────────────────────────────────── + +func TestRenderSteeringRow_TokenWarning(t *testing.T) { + evt := UnifiedTimelineEvent{ + Time: time.Date(2024, 1, 15, 10, 5, 0, 0, time.UTC), + Source: TimelineSourceFirewall, + Kind: TimelineKindSteering, + Status: "token", + Reason: awfTokenWarningPrefix + " You have used 80% of your effective token budget.", + } + row := renderSteeringRow(evt) + if len(row) != 5 { + t.Fatalf("row len = %d; want 5", len(row)) + } + if row[1] != "FW" { + t.Errorf("Src = %q; want FW", row[1]) + } + if !strings.Contains(row[2], "steering") { + t.Errorf("Kind = %q; want 'steering'", row[2]) + } + if !strings.Contains(row[3], "AWF TOKEN WARNING") { + t.Errorf("Detail = %q; want message text containing 'AWF TOKEN WARNING'", row[3]) + } + if row[4] != "token" { + t.Errorf("Status = %q; want token", row[4]) + } +} + +func TestRenderSteeringRow_TimeWarning(t *testing.T) { + evt := UnifiedTimelineEvent{ + Time: time.Date(2024, 1, 15, 10, 6, 0, 0, time.UTC), + Source: TimelineSourceFirewall, + Kind: TimelineKindSteering, + Status: "time", + Reason: awfTimeWarningPrefix + " You have used 80% of your allotted run time.", + } + row := renderSteeringRow(evt) + if row[4] != "time" { + t.Errorf("Status = %q; want time", row[4]) + } +} + +// ─── renderUnifiedTimeline includes steering summary ───────────────────────── + +func TestRenderUnifiedTimeline_SteeringInSummary(t *testing.T) { + now := time.Date(2024, 1, 15, 10, 0, 0, 0, time.UTC) + events := []UnifiedTimelineEvent{ + { + Time: now, Source: TimelineSourceFirewall, Kind: TimelineKindNetworkAllowed, + Host: "api.github.com:443", HTTPMethod: "CONNECT", + }, + { + Time: now.Add(1 * time.Second), Source: TimelineSourceFirewall, Kind: TimelineKindSteering, + Status: "token", Reason: awfTokenWarningPrefix + " 80% budget used.", + }, + } + out := renderUnifiedTimeline(events) + if !strings.Contains(out, "steering=1") { + t.Errorf("output missing 'steering=1' in summary; got:\n%s", out) + } + if !strings.Contains(out, "steering") { + t.Errorf("output missing 'steering' kind label; got:\n%s", out) + } +} + +// ─── renderUnifiedTimelineStream includes steering ──────────────────────────── + +func TestRenderUnifiedTimelineStream_SteeringEvent(t *testing.T) { + now := time.Date(2024, 1, 15, 10, 0, 0, 0, time.UTC) + events := []UnifiedTimelineEvent{ + {Time: now, Source: TimelineSourceAgent, Kind: TimelineKindAgentTurn, TurnIndex: 1}, + { + Time: now.Add(1 * time.Second), + Source: TimelineSourceFirewall, + Kind: TimelineKindSteering, + Status: "token", + Reason: awfTokenWarningPrefix + " 80% budget used.", + }, + } + out := renderUnifiedTimelineStream(events) + if out == "" { + t.Fatal("renderUnifiedTimelineStream returned empty string") + } + if !strings.Contains(out, "AWF TOKEN WARNING") { + t.Errorf("output missing steering message; got:\n%s", out) + } +} diff --git a/pkg/cli/token_usage.go b/pkg/cli/token_usage.go index abf835ba1fa..7c992143edc 100644 --- a/pkg/cli/token_usage.go +++ b/pkg/cli/token_usage.go @@ -599,49 +599,63 @@ func findAPIProxyEventsFile(runDir string) string { return "" } -func parseAPIProxySteeringEvents(filePath string) (int, error) { - file, err := os.Open(filepath.Clean(filePath)) - if err != nil { - return 0, err +// proxyEventsEntry is a JSONL record from api-proxy-logs/events.jsonl. +// The event name appears under one of four field names depending on the proxy version; +// the message field is present on steering events. +type proxyEventsEntry struct { + // Event name appears under one of these four keys; all are checked. + Event string `json:"event"` + Type string `json:"type"` + EventNameSnake string `json:"event_name"` + EventNameCamel string `json:"eventName"` + // Message text (present on steering events). + Message string `json:"message"` + // Optional RFC3339/RFC3339Nano timestamp (not always present). + Timestamp string `json:"timestamp"` +} + +// eventName returns the normalised event name from whichever field is populated. +func (e proxyEventsEntry) eventName() string { + for _, v := range []string{e.Event, e.Type, e.EventNameSnake, e.EventNameCamel} { + if v = strings.TrimSpace(v); v != "" { + return strings.ToLower(v) + } } - defer file.Close() + return "" +} - count := 0 - scanner := bufio.NewScanner(file) - scanner.Buffer(make([]byte, 0, 64*1024), 1024*1024) +// scanSteeringEntries reads all valid steering proxyEventsEntry records from r. +// Lines that fail the quick-keyword check or JSON decoding are silently skipped. +// The caller is responsible for the lifetime of r. +func scanSteeringEntries(r io.Reader) ([]proxyEventsEntry, error) { + var entries []proxyEventsEntry + scanner := bufio.NewScanner(r) + buf := make([]byte, maxScannerBufferSize) + scanner.Buffer(buf, maxScannerBufferSize) for scanner.Scan() { line := strings.TrimSpace(scanner.Text()) if line == "" || !containsSteeringKeyword(line) { continue } - var entry map[string]any + var entry proxyEventsEntry if err := json.Unmarshal([]byte(line), &entry); err != nil { continue } - eventName := strings.ToLower(strings.TrimSpace(coalesceString( - entry["event"], - entry["type"], - entry["event_name"], - entry["eventName"], - ))) - message := strings.TrimSpace(coalesceString(entry["message"])) - if isSteeringEvent(eventName, message) { - count++ + if isSteeringEvent(entry.eventName(), strings.TrimSpace(entry.Message)) { + entries = append(entries, entry) } } - if err := scanner.Err(); err != nil { - return 0, err - } - return count, nil + return entries, scanner.Err() } -func coalesceString(values ...any) string { - for _, value := range values { - if str, ok := value.(string); ok && strings.TrimSpace(str) != "" { - return str - } +func parseAPIProxySteeringEvents(filePath string) (int, error) { + file, err := os.Open(filepath.Clean(filePath)) + if err != nil { + return 0, err } - return "" + defer file.Close() + entries, err := scanSteeringEntries(file) + return len(entries), err } func containsSteeringKeyword(line string) bool {