diff --git a/sdk/event_templates.py b/sdk/event_templates.py index d693ce52..3f1abe4e 100644 --- a/sdk/event_templates.py +++ b/sdk/event_templates.py @@ -5,7 +5,7 @@ | { seq: number; type: "reasoning"; text: string } | { seq: number; type: "started"; provider: string; model: string } | { seq: number; type: "model_call_started"; provider: string; model: string } - | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number } + | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number; retried?: boolean } | { seq: number; type: "tool_call"; name: string; input: Record } | { seq: number; type: "tool_call_started"; name: string; input: Record } | { seq: number; type: "tool_rejected"; name: string; reason: "budget" | "duplicate" | string; input: Record; message: string } @@ -28,7 +28,7 @@ | { seq: number; type: "reasoning"; text: string } | { seq: number; type: "started"; provider: string; model: string } | { seq: number; type: "model_call_started"; provider: string; model: string } - | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number } + | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number; retried?: boolean } | { seq: number; type: "tool_call"; name: string; input: Record } | { seq: number; type: "tool_call_started"; name: string; input: Record } | { seq: number; type: "tool_rejected"; name: string; reason: "budget" | "duplicate" | string; input: Record; message: string } diff --git a/sdk/ts/harness.ts b/sdk/ts/harness.ts index b46674e8..fafddb13 100644 --- a/sdk/ts/harness.ts +++ b/sdk/ts/harness.ts @@ -29,7 +29,7 @@ export type Event = | { seq: number; type: "reasoning"; text: string } | { seq: number; type: "started"; provider: string; model: string } | { seq: number; type: "model_call_started"; provider: string; model: string } - | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number } + | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number; retried?: boolean } | { seq: number; type: "tool_call"; name: string; input: Record } | { seq: number; type: "tool_call_started"; name: string; input: Record } | { seq: number; type: "tool_rejected"; name: string; reason: "budget" | "duplicate" | string; input: Record; message: string } diff --git a/sdk/ts/remote.ts b/sdk/ts/remote.ts index cbefa804..d2e85b6c 100644 --- a/sdk/ts/remote.ts +++ b/sdk/ts/remote.ts @@ -25,7 +25,7 @@ export type Event = | { seq: number; type: "reasoning"; text: string } | { seq: number; type: "started"; provider: string; model: string } | { seq: number; type: "model_call_started"; provider: string; model: string } - | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number } + | { seq: number; type: "model_call_finished"; provider: string; model: string; ok: boolean; ms: number; retried?: boolean } | { seq: number; type: "tool_call"; name: string; input: Record } | { seq: number; type: "tool_call_started"; name: string; input: Record } | { seq: number; type: "tool_rejected"; name: string; reason: "budget" | "duplicate" | string; input: Record; message: string } diff --git a/src/agent_request.zig b/src/agent_request.zig index 38342357..7c90e8fd 100644 --- a/src/agent_request.zig +++ b/src/agent_request.zig @@ -216,6 +216,8 @@ pub fn request(self: *Agent, tools_in: ?[]const u8) !std.json.ObjectMap { const max_openai404_retries: usize = 2; var gw_retry = policy.GatewayRetryState{}; // #gateway-artifact state (agent_gateway_retry.zig) @import("cache_ttl.zig").begin(self); // #1320: before request_started moves + var call: @import("model_call.zig").Call = .{}; // #1665: pairs every started attempt + errdefer call.fail(self, false); rebuild: while (true) { if (@import("agent_async_tools.zig").started(self)) return error.AsyncToolStreamFailed; const live = self.usesLiveTransport(); @@ -241,7 +243,7 @@ pub fn request(self: *Agent, tools_in: ?[]const u8) !std.json.ObjectMap { const t0: Io.Timestamp = .now(self.io, .awake); self.request_started = t0; self.first_token_traced = false; - if (main_mod.json_mode and !self.sub) self.emit(.{ .type = "model_call_started", .provider = self.provider.id, .model = self.provider.model }); + call.start(self); // HTTP calls are flaky: a kept-alive connection the server closed // (HttpConnectionClosing), a reset, a truncated TLS read. Retry a // few times with a fresh connection; on persistent failure surface @@ -424,7 +426,7 @@ pub fn request(self: *Agent, tools_in: ?[]const u8) !std.json.ObjectMap { continue :rebuild; } if (self.tracer) |tr| tr.api(self.label, self.sub, self.provider.model, ms, body.len, resp_body.len, self.last_context_tokens, self.last_cache_read, false); - if (main_mod.json_mode and !self.sub) self.emit(.{ .type = "model_call_finished", .provider = self.provider.id, .model = self.provider.model, .ok = true, .ms = ms }); + call.finish(self, ms); try @import("agent_model_loop.zig").checkResponse(self, obj); return obj; }, @@ -513,7 +515,7 @@ pub fn request(self: *Agent, tools_in: ?[]const u8) !std.json.ObjectMap { if (recoverBehavioralOverflow(self, root, &context_retried)) continue; // #414: silent overflow / upstream truncation → trim + retry if (!self.compaction_request) self.compact_transport_failures = 0; if (self.tracer) |tr| tr.api(self.label, self.sub, self.provider.model, ms, body.len, resp_body.len, self.last_context_tokens, self.last_cache_read, false); - if (main_mod.json_mode and !self.sub) self.emit(.{ .type = "model_call_finished", .provider = self.provider.id, .model = self.provider.model, .ok = true, .ms = ms }); + call.finish(self, ms); try @import("agent_model_loop.zig").checkResponse(self, root); return root; } @@ -587,7 +589,7 @@ pub fn request(self: *Agent, tools_in: ?[]const u8) !std.json.ObjectMap { if (recoverBehavioralOverflow(self, root, &context_retried)) continue; // #414: same, on the non-streamed body if (!self.compaction_request) self.compact_transport_failures = 0; if (self.tracer) |tr| tr.api(self.label, self.sub, self.provider.model, ms, body.len, resp_body.len, self.last_context_tokens, self.last_cache_read, false); - if (main_mod.json_mode and !self.sub) self.emit(.{ .type = "model_call_finished", .provider = self.provider.id, .model = self.provider.model, .ok = true, .ms = ms }); + call.finish(self, ms); try @import("agent_model_loop.zig").checkResponse(self, root); return root; } diff --git a/src/main.zig b/src/main.zig index c77ae41a..9abf7250 100644 --- a/src/main.zig +++ b/src/main.zig @@ -573,7 +573,7 @@ test { // ── Unit tests (`zig build test`): pull in tests from imported modu _ = .{ @import("compact_status.zig"), @import("compact_mix.zig") }; // compact status + GRAFF_COMPACT_MIX mixture arm _ = .{ @import("agent_clef_compact.zig"), @import("agent_clef_compact_tests.zig"), @import("agent_clef_archive.zig") }; // gateway /v1/compact client (Clef pruning) + archive mode _ = @import("agent_compact_recover.zig"); // compaction last-resort recovery (split for the ceiling) - _ = @import("agent_request_search_tests.zig"); + _ = .{ @import("agent_request_search_tests.zig"), @import("model_call.zig") }; // #1665: model-call event pairing _ = @import("agent_ws_steer.zig"); _ = @import("agent_ws_signal.zig"); _ = .{ @import("agent_ws_prewarm.zig"), @import("agent_ws_headers.zig") }; diff --git a/src/model_call.zig b/src/model_call.zig new file mode 100644 index 00000000..fa7720a1 --- /dev/null +++ b/src/model_call.zig @@ -0,0 +1,67 @@ +//! #1665: JSON model-call lifecycle. Every `model_call_started` pairs with one +//! `model_call_finished`. A request rebuilt before its response (a WebSocket +//! reanchor, a stream reconnect, a steer, a recovered overflow) closes the +//! attempt with ok=false and retried=true before the next one starts; an +//! attempt that ends the request with an error closes with ok=false. + +const main_mod = @import("main.zig"); +const Agent = @import("agent.zig").Agent; + +pub const Call = struct { + open: bool = false, + + fn on(self: *Agent) bool { + return main_mod.json_mode and !self.sub; + } + + pub fn start(c: *Call, self: *Agent) void { + if (!on(self)) return; + if (c.open) c.fail(self, true); + self.emit(.{ .type = "model_call_started", .provider = self.provider.id, .model = self.provider.model }); + c.open = true; + } + + pub fn finish(c: *Call, self: *Agent, ms: i64) void { + if (!c.open) return; + c.open = false; + self.emit(.{ .type = "model_call_finished", .provider = self.provider.id, .model = self.provider.model, .ok = true, .ms = ms }); + } + + /// The attempt ended without a usable response. `retried`: the request + /// goes out again as a new attempt. + pub fn fail(c: *Call, self: *Agent, retried: bool) void { + if (!c.open) return; + c.open = false; + const ms: i64 = if (self.request_started) |t0| t0.untilNow(self.io, .awake).toMilliseconds() else 0; + self.emit(.{ .type = "model_call_finished", .provider = self.provider.id, .model = self.provider.model, .ok = false, .ms = ms, .retried = retried }); + } +}; + +test "every started model call pairs with one finished event" { + const std = @import("std"); + var arena_state = std.heap.ArenaAllocator.init(std.testing.allocator); + defer arena_state.deinit(); + var agent = try @import("agent_request_body_responses.zig").testAgentFor(arena_state.allocator(), "codex", .responses, "gpt-5"); + var buf: [4096]u8 = undefined; + var w: std.Io.Writer = .fixed(&buf); + agent.out = &w; + const was_json = main_mod.json_mode; + main_mod.json_mode = true; + defer main_mod.json_mode = was_json; + + var call: Call = .{}; + call.start(&agent); // first attempt + call.start(&agent); // rebuilt after a reanchor: closes the first + call.finish(&agent, 12); + call.finish(&agent, 12); // already closed: no second event + call.start(&agent); + call.fail(&agent, false); // the request ended with an error + call.fail(&agent, false); + + const out = w.buffered(); + try std.testing.expectEqual(@as(usize, 3), std.mem.count(u8, out, "\"model_call_started\"")); + try std.testing.expectEqual(@as(usize, 3), std.mem.count(u8, out, "\"model_call_finished\"")); + try std.testing.expectEqual(@as(usize, 1), std.mem.count(u8, out, "\"retried\":true")); + try std.testing.expectEqual(@as(usize, 1), std.mem.count(u8, out, "\"retried\":false")); + try std.testing.expectEqual(@as(usize, 1), std.mem.count(u8, out, "\"ok\":true")); +} diff --git a/src/schema_protocol.zig b/src/schema_protocol.zig index f5d37177..b530af7a 100644 --- a/src/schema_protocol.zig +++ b/src/schema_protocol.zig @@ -45,7 +45,7 @@ pub const json = \\ {"type": "reasoning", "text": "reasoning/thinking delta (GUI shows a collapsible Thinking block)"}, \\ {"type": "started", "provider": "provider", "model": "model"}, \\ {"type": "model_call_started", "provider": "provider", "model": "model"}, - \\ {"type": "model_call_finished", "provider": "provider", "model": "model", "ok": true, "ms": 0}, + \\ {"type": "model_call_finished", "provider": "provider", "model": "model", "ok": true, "ms": 0, "retried": "present only when ok is false: true when the request goes out again as a new attempt (pairs every model_call_started)"}, \\ {"type": "tool_call", "name": "tool", "input": {}, "id": "sa-… when a correlated tool call is available; pairs with tool_result/agent_usage"}, \\ {"type": "tool_call_started", "name": "tool", "input": {}}, \\ {"type": "tool_rejected", "name": "tool", "reason": "budget|duplicate", "input": {}, "message": "..."},