Write the coder turn down, and close its thread on every path

1fb228a72d9f · AtlantisPleb · · parent 06a9c88d4204

Write the coder turn down, and close its thread on every path

A coder session never called `POST /api/v1/threads/{id}/events`. It opened a
thread, ran its turns, and revoked, so the server's only terminal act was a
cancellation: 31 of the 50 most recent threads on one account read
`error_code: cancelled` with "The thread was cancelled before it reported.",
over runs that had printed a correct answer and exited 0 (#106).

The turn now records itself as it happens, in the vocabulary `--resume` reads
and `docs/2026-08-24-coder-account-integration-audit.md` fixes: `turn.user`
before the first model call, `turn.reasoning` whole, one `tool.ran` per call
carrying its arguments and result, and `turn.assistant` with the turn's usage
and call count.

The half that keeps it honest is the failure. A refused proxy, a stream that
broke, an exhausted step budget, and an interrupted session each record
`turn.failed` and never a `turn.assistant` — a record saying every session
succeeded would be exactly as wrong as one saying every session was cancelled.
Recording is best effort, because a transcript the server will not take is no
reason to throw away an answer a reader is waiting on, but a refused append is
kept in `record_failures` and reported rather than swallowed.

`close()` was called from one place — the headless path. The interactive
session and every delegated child relied on the `Drop` impl, which spawns a
`DELETE` onto whatever runtime is still up and may never be polled; the audit
in #89 found two threads still open from long-dead sessions, and a thread left
open holds its grant's remaining budget. It is now awaited on the interactive,
plain, and delegated paths (#107). `run_tui` awaits its actor with a bound
instead of aborting it, and the actor revokes on its way out.

And the spend it returns is read. The one caller dropped it, so the CLI printed
its own client-side accumulation and nothing could notice the two diverging.
`spend_line` reports the server's figure and names the gap when there is one.

What this does not do: a thread's own `report` and `error_code` still read as
cancelled. `Threads.finish/2` — the only thing that writes a real report and
leaves `error_code` empty — has no HTTP route and no caller outside tests, so
`DELETE` → `Threads.cancel/2` is the only terminal act a client can perform.
The transcript is now right; the thread's summary fields need a server route.

Refs #106, #107, #89.

Deploy story

What this commit did to the running system — joined from the forge receipt chain, the part a commit page elsewhere cannot show.

Not deployed through the forge lane

No push, promotion, build, or deploy receipt references this commit (receipts are scanned over a bounded recent window). Changes shipped by full node replacement carry their proof in the release gate receipt instead.

Changed files

  • modified crates/openagents-cli/src/cli.rs
  • modified crates/openagents-cli/src/delegate.rs
  • modified crates/openagents-cli/src/interactive.rs
  • modified crates/openagents-cli/src/resume.rs
  • modified crates/openagents-cli/src/runtime.rs
  • modified crates/openagents-cli/tests/delegate_test.rs
  • modified crates/openagents-cli/tests/runtime_test.rs

Diff

7 files changed, +1125 -45

crates/openagents-cli/src/cli.rs modified +12 -2

@@ -4386,8 +4386,18 @@ async fn run_headless_coder(

4386 4386
    if runtime.last_usage.reported() {
4387 4387
        println!("Usage: {}", runtime.last_usage.line());
4388 4388
    }
4389
    if let Err(error) = revoked {
4390
        eprintln!("oa: the thread was not revoked: {error}");
4389
    // The revocation reply carries the grant's own spend, and dropping it is
4390
    // how the CLI came to print a client-side count nothing could check.
4391
    match revoked {
4392
        Ok(spent) => {
4393
            if let Some(line) = runtime.spend_line(spent) {
4394
                println!("{line}");
4395
            }
4396
        }
4397
        Err(error) => eprintln!("oa: the thread was not revoked: {error}"),
4398
    }
4399
    for failure in &runtime.record_failures {
4400
        eprintln!("oa: {failure}");
4391 4401
    }
4392 4402
4393 4403
    if let Some(path) = coder.export.as_deref() {
crates/openagents-cli/src/delegate.rs modified +41 -14

@@ -519,23 +519,50 @@ async fn run_proxy_child(

519 519
520 520
    let id = task.id;
521 521
    let sink = events.clone();
522
    let turn = runtime.execute_turn(&task.prompt, move |chunk| {
523
        let _ = sink.send(ChildEvent::Output {
522
523
    let outcome = {
524
        let turn = runtime.execute_turn(&task.prompt, move |chunk| {
525
            let _ = sink.send(ChildEvent::Output {
526
                id,
527
                text: chunk.to_string(),
528
            });
529
        });
530
531
        tokio::select! {
532
            biased;
533
            _ = cancel.changed() => Err("stopped before finishing".to_string()),
534
            answered = turn => answered.map_err(|error| error.to_string()),
535
        }
536
    };
537
538
    // A cancelled child drops its turn mid-flight, so the turn's own failure
539
    // path never runs and the transcript would simply stop. Say what happened
540
    // before the thread is revoked, so a stopped child is not left looking
541
    // like one that finished quietly.
542
    if let Err(why) = &outcome {
543
        runtime.note_interruption(why).await;
544
    }
545
    // Awaited, on every path. A child used to leave its thread to the `Drop`
546
    // impl, which spawns a best-effort DELETE the process may never poll — and
547
    // a thread left open holds its grant's remaining budget. The failure is
548
    // reported to the parent's event stream rather than to a screen this child
549
    // does not own.
550
    if let Err(error) = runtime.close().await {
551
        let _ = events.send(ChildEvent::Activity {
524 552
            id,
525
            text: chunk.to_string(),
553
            text: format!("the thread was not revoked: {error}"),
526 554
        });
527
    });
555
    }
556
    for failure in &runtime.record_failures {
557
        let _ = events.send(ChildEvent::Activity {
558
            id,
559
            text: failure.clone(),
560
        });
561
    }
528 562
529
    tokio::select! {
530
        biased;
531
        _ = cancel.changed() => Err(ChildFailure {
532
            why: "stopped before finishing".to_string(),
533
            pid: None,
534
        }),
535
        answered = turn => match answered {
536
            Ok(text) => Ok(ChildAnswer { text, pid: None }),
537
            Err(error) => Err(ChildFailure { why: error.to_string(), pid: None }),
538
        },
563
    match outcome {
564
        Ok(text) => Ok(ChildAnswer { text, pid: None }),
565
        Err(why) => Err(ChildFailure { why, pid: None }),
539 566
    }
540 567
}
541 568
crates/openagents-cli/src/interactive.rs modified +61 -6

@@ -143,6 +143,12 @@ pub enum TurnEvent {

143 143
/// How often the streaming bullet flips.
144 144
const PULSE: Duration = Duration::from_millis(400);
145 145
146
/// How long the exit waits for the session to revoke its thread.
147
///
148
/// Long enough for a `DELETE` on a working connection, short enough that a
149
/// reader who has quit does not sit looking at a finished screen.
150
const THREAD_REVOCATION_GRACE: Duration = Duration::from_secs(15);
151
146 152
/// The diff inspector's state.
147 153
struct DiffView {
148 154
    files: Vec<FileDiff>,

@@ -858,7 +864,31 @@ where

858 864
    }
859 865
}
860 866
867
/// Revoke a session's thread and say what it cost, and what went unrecorded.
868
///
869
/// The lines land on stdout rather than in a screen because both callers reach
870
/// here after their screen is gone. Silence when the session held no thread:
871
/// the local lane has nothing to revoke and nothing was billed.
872
pub async fn close_and_report(session: &mut CoderRuntimeSession) {
873
    match session.close().await {
874
        Ok(spent) => {
875
            if let Some(line) = session.spend_line(spent) {
876
                println!("{line}");
877
            }
878
        }
879
        Err(error) => eprintln!("oa: the thread was not revoked: {error}"),
880
    }
881
    for failure in &session.record_failures {
882
        eprintln!("oa: {failure}");
883
    }
884
}
885
861 886
/// Own the session and do what the app asks for.
887
///
888
/// Returns once the app has dropped its control channel, having revoked the
889
/// session's thread on the way out. The caller awaits that rather than
890
/// aborting the task: an aborted actor drops its session, and the `Drop` impl
891
/// only spawns a revocation that the exiting process may never poll.
862 892
pub async fn runtime_actor(
863 893
    mut session: CoderRuntimeSession,
864 894
    mut control: UnboundedReceiver<Control>,

@@ -887,7 +917,7 @@ pub async fn runtime_actor(

887 917
                    Err(error) => TurnEvent::Failed(error.to_string()),
888 918
                };
889 919
                if events.send(event).is_err() {
890
                    return;
920
                    break;
891 921
                }
892 922
            }
893 923
            Control::Diff(arguments) => {

@@ -896,7 +926,7 @@ pub async fn runtime_actor(

896 926
                    Err(why) => TurnEvent::Notice(why),
897 927
                };
898 928
                if events.send(event).is_err() {
899
                    return;
929
                    break;
900 930
                }
901 931
            }
902 932
            Control::ForeignResume(selection) => {

@@ -932,7 +962,7 @@ pub async fn runtime_actor(

932 962
                        control: session,
933 963
                    });
934 964
                    if opened.is_err() {
935
                        return;
965
                        break;
936 966
                    }
937 967
                    // Forwarded from a task of its own so this actor stays
938 968
                    // able to answer while the program runs.

@@ -952,6 +982,9 @@ pub async fn runtime_actor(

952 982
            },
953 983
        }
954 984
    }
985
    // The app has gone. Revoke the thread here, awaited, rather than leaving
986
    // it to `Drop` in an aborted task.
987
    close_and_report(&mut session).await;
955 988
}
956 989
957 990
/// Collect the diff `/diff` asked for.

@@ -1137,7 +1170,23 @@ pub async fn run_tui(

1137 1170
        .await
1138 1171
    };
1139 1172
1140
    runtime.abort();
1173
    // `run_loop` has taken the control sender with it, so the actor's receiver
1174
    // is closed and the actor is on its way out with a revocation to make.
1175
    // Awaited rather than aborted: aborting drops the session inside a dead
1176
    // task, where the `Drop` impl can only spawn a DELETE this process may
1177
    // exit before polling. Bounded, because a turn still streaming would
1178
    // otherwise hold the exit for as long as the model wants — and in that
1179
    // case `Drop`'s best effort is what is left, which is what it is for.
1180
    if tokio::time::timeout(THREAD_REVOCATION_GRACE, runtime)
1181
        .await
1182
        .is_err()
1183
    {
1184
        eprintln!(
1185
            "oa: the session was still working after {}s, so its thread was left to the \
1186
             best-effort revocation.",
1187
            THREAD_REVOCATION_GRACE.as_secs()
1188
        );
1189
    }
1141 1190
    result?;
1142 1191
1143 1192
    if let Some(path) = args.export {

@@ -1206,7 +1255,7 @@ async fn run_without_a_terminal(

1206 1255
    // streamed, which is how the offline paths still say something.
1207 1256
    let streamed = std::sync::Arc::new(std::sync::atomic::AtomicBool::new(false));
1208 1257
    let saw = std::sync::Arc::clone(&streamed);
1209
    let answer = session
1258
    let answered = session
1210 1259
        .execute_turn(&prompt, move |chunk| {
1211 1260
            use std::io::Write;
1212 1261
            saw.store(true, std::sync::atomic::Ordering::Relaxed);

@@ -1214,7 +1263,13 @@ async fn run_without_a_terminal(

1214 1263
            let _ = std::io::stdout().flush();
1215 1264
        })
1216 1265
        .await
1217
        .map_err(|e| e.to_string())?;
1266
        .map_err(|e| e.to_string());
1267
    // Awaited, and awaited whether the turn worked or not. This path used to
1268
    // return on the failure and leave the revocation to `Drop`, which spawns a
1269
    // best-effort DELETE that may never be polled before the process exits —
1270
    // and a thread left open holds its grant's remaining budget.
1271
    close_and_report(&mut session).await;
1272
    let answer = answered?;
1218 1273
    if !streamed.load(std::sync::atomic::Ordering::Relaxed) {
1219 1274
        print!("{answer}");
1220 1275
    }
crates/openagents-cli/src/resume.rs modified +9 -5

@@ -29,11 +29,15 @@

29 29
//!
30 30
//! ## What a Rust-opened thread replays to
31 31
//!
32
//! [`crate::runtime`] records `thread.opened` and no turn events, so a thread
33
//! this CLI opened replays to an empty conversation while one `openagents
34
//! coder` opened replays to its transcript. That is the record, not a parse
35
//! failure, and the caller says how many messages came back rather than
36
//! implying a transcript that is not there.
32
//! Its own conversation. [`crate::runtime`] records `turn.user`, `tool.ran`
33
//! and `turn.assistant` as a turn runs, which is the vocabulary below, so a
34
//! thread this CLI opened resumes the same way one `openagents coder` opened
35
//! does. It did not always: the runtime recorded nothing at all, every thread
36
//! held one `thread.opened` and no more, and `--resume` on one replayed zero
37
//! messages. A thread from before that fix still replays to an empty
38
//! conversation — that is the record, not a parse failure, and the caller says
39
//! how many messages came back rather than implying a transcript that is not
40
//! there.
37 41
38 42
use crate::runtime::ChatMessage;
39 43
use serde::Deserialize;
crates/openagents-cli/src/runtime.rs modified +291 -16

@@ -19,6 +19,26 @@

19 19
//! request with the sentence `Completed autonomous reasoning turn (offline
20 20
//! fallback).` and exit 0. Neither comes back.
21 21
//!
22
//! ## A turn writes itself down before the thread is revoked
23
//!
24
//! The thread lane records what it did to `POST /api/v1/threads/{id}/events`
25
//! as it happens — `turn.user`, `turn.reasoning`, `tool.ran`, `turn.assistant`
26
//! — which is the vocabulary [`crate::resume`] replays and the one
27
//! `docs/2026-08-24-coder-account-integration-audit.md` fixes. It used to
28
//! record nothing at all, so every session reached `DELETE` with a transcript
29
//! holding one `thread.opened` and nothing else, and the account's history
30
//! read as a wall of cancellations over runs that had answered correctly.
31
//!
32
//! A turn that did not answer records [`ThreadRecord::failed`] instead, and
33
//! never an answer: the point of writing the turn down is that the record
34
//! matches what happened, which it does not if a refused proxy, a broken
35
//! stream, an interrupted session, or an exhausted step budget lands in the
36
//! transcript looking like an answer.
37
//!
38
//! Recording is best effort and does not fail a turn that worked: a transcript
39
//! that could not be written is kept in [`CoderRuntimeSession::record_failures`]
40
//! and reported, rather than swallowed or allowed to throw away an answer.
41
//!
22 42
//! ## Model ids are the server's, not this file's
23 43
//!
24 44
//! The deployment publishes its catalog at `GET /api/v1/models` and refuses

@@ -57,6 +77,12 @@ pub const OLLAMA_HOST: &str = "http://127.0.0.1:11434";

57 77
/// A backstop against a model that loops, not a budget.
58 78
const MAX_TOOL_STEPS: usize = 30;
59 79
80
/// How many transcript events one append may carry.
81
///
82
/// The server's own cap (`OpenAgents.Threads.maximum_event_batch/0`). A longer
83
/// list is split into several appends rather than refused as one.
84
const MAX_EVENT_BATCH: usize = 100;
85
60 86
/// The tier names a reader may type, and the catalog id each one opens on.
61 87
///
62 88
/// A tier is the unit `--lane` deals in: `flash` is the fast lane whatever

@@ -233,6 +259,85 @@ pub struct InferenceGrant {

233 259
    pub model: String,
234 260
}
235 261
262
/// One event on a thread's transcript, in the vocabulary `--resume` replays.
263
///
264
/// The words are the ones the server's own readers know: `turn.user`,
265
/// `turn.reasoning`, `tool.ran` and `turn.assistant` are what
266
/// [`crate::resume::replay_wire`] rebuilds a conversation from and what the
267
/// WEKA export cuts model calls at. `turn.failed` is deliberately outside that
268
/// set — a turn that did not answer has no answer to replay, and a reader that
269
/// does not know the word skips it rather than feeding a failure back to a
270
/// model as though the model had said it.
271
#[derive(Debug, Clone, PartialEq, Serialize)]
272
pub struct ThreadRecord {
273
    pub event_type: String,
274
    pub payload: serde_json::Value,
275
}
276
277
impl ThreadRecord {
278
    fn new(event_type: &str, payload: serde_json::Value) -> Self {
279
        Self {
280
            event_type: event_type.to_string(),
281
            payload,
282
        }
283
    }
284
285
    /// What the reader asked.
286
    pub fn user(text: &str) -> Self {
287
        Self::new("turn.user", serde_json::json!({ "text": text }))
288
    }
289
290
    /// What the model thought before it answered, recorded whole.
291
    pub fn reasoning(text: &str) -> Self {
292
        Self::new("turn.reasoning", serde_json::json!({ "text": text }))
293
    }
294
295
    /// One call with its arguments and its result: one fact, one event.
296
    ///
297
    /// `arguments` is the raw JSON string the wire carried, not a re-encoding
298
    /// of it, because that is what goes back to a model on replay.
299
    pub fn tool_ran(call_id: &str, tool: &str, arguments: &str, output: &str) -> Self {
300
        Self::new(
301
            "tool.ran",
302
            serde_json::json!({
303
                "call_id": call_id,
304
                "tool": tool,
305
                "arguments": arguments,
306
                "output": output,
307
            }),
308
        )
309
    }
310
311
    /// The answer, with what the turn spent reaching it.
312
    pub fn assistant(text: &str, usage: TurnUsage, calls: usize) -> Self {
313
        Self::new(
314
            "turn.assistant",
315
            serde_json::json!({
316
                "text": text,
317
                "usage": usage,
318
                "calls": calls,
319
            }),
320
        )
321
    }
322
323
    /// A turn that produced no answer, and the sentence saying why.
324
    ///
325
    /// This is the half of the record that keeps it honest. A session that
326
    /// failed must not read afterwards as one that succeeded, so every exit
327
    /// from a turn that is not the model's own answer writes one of these and
328
    /// no `turn.assistant`.
329
    pub fn failed(why: &str, usage: TurnUsage, calls: usize) -> Self {
330
        Self::new(
331
            "turn.failed",
332
            serde_json::json!({
333
                "error": why,
334
                "usage": usage,
335
                "calls": calls,
336
            }),
337
        )
338
    }
339
}
340
236 341
#[derive(Debug, Clone, Serialize, Deserialize)]
237 342
pub struct ChatMessage {
238 343
    pub role: String,

@@ -259,6 +364,22 @@ pub struct CoderRuntimeSession {

259 364
    pub last_model: Option<String>,
260 365
    /// What the last turn spent, summed over its steps.
261 366
    pub last_usage: TurnUsage,
367
    /// How many tools the last turn ran, counted as they were recorded.
368
    pub last_calls: usize,
369
    /// What every turn this session ran has spent, summed.
370
    ///
371
    /// The figure to hold a server-reported grant spend against: `last_usage`
372
    /// is one turn, and a session that ran four of them and compared the
373
    /// fourth against the grant's total would report a divergence on every
374
    /// multi-turn session and call it a mismatch.
375
    pub session_usage: TurnUsage,
376
    /// Transcript appends this session could not make, in the order they failed.
377
    ///
378
    /// Recording is best effort — a thread the server would not take an event
379
    /// for is not a reason to throw away an answer the reader is waiting on —
380
    /// but a silent best effort is how the record came to disagree with the
381
    /// session in the first place. The failure is kept here and reported.
382
    pub record_failures: Vec<String>,
262 383
    /// The reasoning the last turn emitted, if the model emits any.
263 384
    ///
264 385
    /// Kept off the content callback deliberately: `delta.reasoning` and

@@ -302,6 +423,9 @@ impl CoderRuntimeSession {

302 423
            last_grant: None,
303 424
            last_model: None,
304 425
            last_usage: TurnUsage::default(),
426
            last_calls: 0,
427
            session_usage: TurnUsage::default(),
428
            record_failures: Vec::new(),
305 429
            last_reasoning: String::new(),
306 430
            reasoning: None,
307 431
            repository: None,

@@ -677,6 +801,91 @@ impl CoderRuntimeSession {

677 801
        }))
678 802
    }
679 803
804
    /// What the server billed this session against what this process counted.
805
    ///
806
    /// `close` hands back the grant's own `spent`, and the caller used to drop
807
    /// it, so the CLI printed its client-side accumulation and nothing could
808
    /// ever notice the two disagreeing. This is the line that notices: the
809
    /// server's figure, and a second sentence naming the gap when there is one.
810
    ///
811
    /// `None` when the server reported no spend — the local lane, or a session
812
    /// that never opened a thread — because there is nothing to reconcile.
813
    pub fn spend_line(&self, reported: Option<TurnUsage>) -> Option<String> {
814
        let reported = reported?;
815
        let counted = self.session_usage.total_tokens;
816
        let billed = reported.total_tokens;
817
        let line = format!("Billed by the server: {billed} tokens");
818
        if billed == counted {
819
            return Some(line);
820
        }
821
        Some(format!(
822
            "{line} — this session counted {counted}, a difference of {}. \
823
             The server's figure is the one the account is charged against.",
824
            billed.abs_diff(counted)
825
        ))
826
    }
827
828
    // ───────────────────────────────────────────────────────── the transcript
829
830
    /// The thread this session holds, while it holds one.
831
    pub fn thread(&self) -> Option<&str> {
832
        self.thread_id.as_deref()
833
    }
834
835
    /// Append events to this session's thread transcript.
836
    ///
837
    /// `POST /api/v1/threads/{id}/events`, batched: one round trip lands the
838
    /// whole list in order or none of it, capped at the server's own batch
839
    /// maximum so a long step is split rather than refused whole. A session
840
    /// holding no thread — the local lane, or one already revoked — writes
841
    /// nothing and answers `Ok(false)`, because nowhere to write is not a
842
    /// failure to write.
843
    pub async fn record(&self, events: &[ThreadRecord]) -> Result<bool, Failure> {
844
        let Some(thread_id) = &self.thread_id else {
845
            return Ok(false);
846
        };
847
        if events.is_empty() {
848
            return Ok(false);
849
        }
850
        let url = format!("{}/threads/{thread_id}/events", self.api_base);
851
        for batch in events.chunks(MAX_EVENT_BATCH) {
852
            let mut request = self
853
                .http
854
                .post(&url)
855
                .timeout(Duration::from_secs(30))
856
                .json(&serde_json::json!({ "events": batch }));
857
            if let Some(token) = &self.user_token {
858
                request = request.bearer_auth(token);
859
            }
860
            let resp = request.send().await.map_err(|error| -> Failure {
861
                format!("{url} could not be reached: {error}").into()
862
            })?;
863
            if !resp.status().is_success() {
864
                let status = resp.status();
865
                let body = resp.text().await.unwrap_or_default();
866
                return Err(format!(
867
                    "{url} refused the transcript append: {status} {}",
868
                    snippet(&body)
869
                )
870
                .into());
871
            }
872
        }
873
        Ok(true)
874
    }
875
876
    /// Record, keeping a refusal rather than failing the turn over it.
877
    pub async fn note(&mut self, events: Vec<ThreadRecord>) {
878
        if let Err(error) = self.record(&events).await {
879
            let kinds = events
880
                .iter()
881
                .map(|event| event.event_type.as_str())
882
                .collect::<Vec<_>>()
883
                .join(", ");
884
            self.record_failures
885
                .push(format!("{kinds} were not recorded: {error}"));
886
        }
887
    }
888
680 889
    // ─────────────────────────────────────────────────────────── the turn
681 890
682 891
    pub async fn execute_turn<F>(

@@ -706,17 +915,22 @@ impl CoderRuntimeSession {

706 915
        });
707 916
708 917
        self.last_usage = TurnUsage::default();
918
        self.last_calls = 0;
709 919
        self.last_reasoning.clear();
710 920
711
        if self.lane.is_local() {
921
        let answered = if self.lane.is_local() {
712 922
            self.run_local_turn(&tool_defs, chunk_callback).await
713 923
        } else {
714
            self.run_thread_turn(&tool_defs, chunk_callback).await
715
        }
924
            self.run_thread_turn(prompt, &tool_defs, chunk_callback)
925
                .await
926
        };
927
        self.session_usage.add(self.last_usage);
928
        answered
716 929
    }
717 930
718 931
    async fn run_thread_turn<F>(
719 932
        &mut self,
933
        prompt: &str,
720 934
        tool_defs: &[ToolDefinition],
721 935
        mut chunk_callback: F,
722 936
    ) -> Result<String, Failure>

@@ -741,6 +955,10 @@ impl CoderRuntimeSession {

741 955
        };
742 956
        self.last_model = Some(grant.model.clone());
743 957
958
        // The transcript opens with what was asked, before a model is reached,
959
        // so a turn that dies mid-step still leaves the question behind.
960
        self.note(vec![ThreadRecord::user(prompt)]).await;
961
744 962
        let mut final_answer = String::new();
745 963
        // False means the step budget ran out with every step still calling
746 964
        // tools, which is not an answer and must not be returned as one.

@@ -785,15 +1003,16 @@ impl CoderRuntimeSession {

785 1003
                Ok(r) => {
786 1004
                    let status = r.status();
787 1005
                    let body = r.text().await.unwrap_or_default();
788
                    return Err(format!(
1006
                    let why = format!(
789 1007
                        "{} refused the turn: {status} {}",
790 1008
                        grant.proxy_url,
791 1009
                        snippet(&body)
792
                    )
793
                    .into());
1010
                    );
1011
                    return Err(self.record_failure(why).await);
794 1012
                }
795 1013
                Err(error) => {
796
                    return Err(format!("{} could not be reached: {error}", grant.proxy_url).into())
1014
                    let why = format!("{} could not be reached: {error}", grant.proxy_url);
1015
                    return Err(self.record_failure(why).await);
797 1016
                }
798 1017
            };
799 1018

@@ -804,11 +1023,16 @@ impl CoderRuntimeSession {

804 1023
                let event = match event {
805 1024
                    Ok(event) => event,
806 1025
                    Err(error) => {
807
                        return Err(format!(
1026
                        let why = format!(
808 1027
                            "the reply from {} stopped mid-stream: {error}",
809 1028
                            grant.proxy_url
810
                        )
811
                        .into())
1029
                        );
1030
                        // What streamed before the break is part of what
1031
                        // happened and is kept, but the turn still records as
1032
                        // failed: an incomplete answer is not an answer.
1033
                        self.last_usage.add(step.usage);
1034
                        self.last_reasoning.push_str(&step.reasoning);
1035
                        return Err(self.record_failure(why).await);
812 1036
                    }
813 1037
                };
814 1038
                if event.data == "[DONE]" {

@@ -823,6 +1047,14 @@ impl CoderRuntimeSession {

823 1047
            self.last_usage.add(step.usage);
824 1048
            self.last_reasoning.push_str(&step.reasoning);
825 1049
1050
            // The working comes before whatever it led to, in the order it
1051
            // happened. Recorded whole: it is the largest part of what a
1052
            // session produces and a transcript without it is a summary.
1053
            if !step.reasoning.trim().is_empty() {
1054
                let thought = ThreadRecord::reasoning(&step.reasoning);
1055
                self.note(vec![thought]).await;
1056
            }
1057
826 1058
            if step.tool_calls.is_empty() {
827 1059
                final_answer = step.content;
828 1060
                // The answer joins the transcript. `run_tools` records an

@@ -842,24 +1074,55 @@ impl CoderRuntimeSession {

842 1074
                    tool_calls: None,
843 1075
                    tool_call_id: None,
844 1076
                });
1077
                let said = ThreadRecord::assistant(&final_answer, self.last_usage, self.last_calls);
1078
                self.note(vec![said]).await;
845 1079
                answered = true;
846 1080
                break;
847 1081
            }
848
            self.run_tools(step).await;
1082
            let ran = self.run_tools(step).await;
1083
            self.last_calls += ran.len();
1084
            self.note(ran).await;
849 1085
        }
850 1086
851 1087
        if !answered {
852
            return Err(format!(
1088
            let why = format!(
853 1089
                "the turn used all {MAX_TOOL_STEPS} tool steps without producing an answer; \
854 1090
                 nothing was returned rather than an empty answer that reads as success"
855
            )
856
            .into());
1091
            );
1092
            return Err(self.record_failure(why).await);
857 1093
        }
858 1094
        Ok(final_answer)
859 1095
    }
860 1096
1097
    /// Write a turn's failure to the transcript, then hand back the failure.
1098
    ///
1099
    /// Every exit from a turn that is not the model's own answer goes through
1100
    /// here, so the record cannot say a session succeeded where it did not.
1101
    async fn record_failure(&mut self, why: String) -> Failure {
1102
        let (usage, calls) = (self.last_usage, self.last_calls);
1103
        self.note(vec![ThreadRecord::failed(&why, usage, calls)])
1104
            .await;
1105
        why.into()
1106
    }
1107
1108
    /// Record that this session stopped before the turn in flight answered.
1109
    ///
1110
    /// A dropped turn future never reaches [`Self::record_failure`] — a
1111
    /// cancelled child, a session quit mid-turn — so the caller that dropped
1112
    /// it says so here. Without this an interruption leaves a transcript that
1113
    /// simply stops, which a later reader has no way to tell from a turn that
1114
    /// finished quietly.
1115
    pub async fn note_interruption(&mut self, why: &str) {
1116
        let (usage, calls) = (self.last_usage, self.last_calls);
1117
        self.note(vec![ThreadRecord::failed(why, usage, calls)])
1118
            .await;
1119
    }
1120
861 1121
    /// Record the assistant's tool calls, run them, and put the results back.
862
    async fn run_tools(&mut self, step: StepAccumulator) {
1122
    ///
1123
    /// Hands back one `tool.ran` per call for the transcript: the call and its
1124
    /// result are one fact, and the caller has both only once the tool has run.
1125
    async fn run_tools(&mut self, step: StepAccumulator) -> Vec<ThreadRecord> {
863 1126
        let recorded: Vec<serde_json::Value> = step
864 1127
            .tool_calls
865 1128
            .values()

@@ -883,6 +1146,7 @@ impl CoderRuntimeSession {

883 1146
            tool_call_id: None,
884 1147
        });
885 1148
1149
        let mut ran = Vec::new();
886 1150
        for (id, name, args_str) in step.tool_calls.into_values() {
887 1151
            let arguments: serde_json::Value =
888 1152
                serde_json::from_str(&args_str).unwrap_or(serde_json::json!({}));

@@ -892,6 +1156,12 @@ impl CoderRuntimeSession {

892 1156
                arguments,
893 1157
            };
894 1158
            let result = self.tools.execute_tool(&call).await;
1159
            ran.push(ThreadRecord::tool_ran(
1160
                &id,
1161
                &name,
1162
                &args_str,
1163
                &result.output,
1164
            ));
895 1165
            self.messages.push(ChatMessage {
896 1166
                role: "tool".to_string(),
897 1167
                content: Some(result.output),

@@ -899,6 +1169,7 @@ impl CoderRuntimeSession {

899 1169
                tool_call_id: Some(id),
900 1170
            });
901 1171
        }
1172
        ran
902 1173
    }
903 1174
904 1175
    // ────────────────────────────────────────────────────── the local lane

@@ -1087,7 +1358,11 @@ impl CoderRuntimeSession {

1087 1358
                answered = true;
1088 1359
                break;
1089 1360
            }
1090
            self.run_tools(step).await;
1361
            // The local lane holds no thread of its own, so `note` writes
1362
            // nothing; it is called anyway so a local session that resumed
1363
            // somebody's thread records against it like any other.
1364
            let ran = self.run_tools(step).await;
1365
            self.note(ran).await;
1091 1366
        }
1092 1367
1093 1368
        if !answered {
crates/openagents-cli/tests/delegate_test.rs modified +174

@@ -333,3 +333,177 @@ fn an_unknown_lane_is_not_silently_ox_alpha() {

333 333
    assert!(!ChildLane::known("gemni"));
334 334
    assert!(!ChildLane::known(""));
335 335
}
336
337
// ──────────────────────────────────────────────────── the child's own thread
338
//
339
// A delegated child opens a thread of its own and used to leave revoking it to
340
// the `Drop` impl, which spawns a best-effort `DELETE` onto whatever runtime is
341
// still up. The audit in #89 found two threads still open from long-dead
342
// sessions; a thread left open holds its grant's remaining budget (issue #107).
343
344
/// How long the stub holds a revocation open.
345
///
346
/// Long enough to tell an awaited `close()` from the `Drop` impl's spawned
347
/// best effort, which returns at once and leaves its request in flight.
348
const REVOCATION_HELD: Duration = Duration::from_millis(600);
349
350
/// A stand-in for the account API and the proxy, which records what it took.
351
struct ProxyStub {
352
    origin: String,
353
    requests: std::sync::Arc<std::sync::Mutex<Vec<String>>>,
354
}
355
356
impl ProxyStub {
357
    fn request_lines(&self) -> Vec<String> {
358
        self.requests
359
            .lock()
360
            .unwrap()
361
            .iter()
362
            .map(|request| request.lines().next().unwrap_or_default().to_string())
363
            .collect()
364
    }
365
}
366
367
/// Answers a thread open, transcript appends, a revocation, and one turn.
368
async fn proxy_stub() -> ProxyStub {
369
    use tokio::io::{AsyncReadExt, AsyncWriteExt};
370
371
    let listener = tokio::net::TcpListener::bind("127.0.0.1:0").await.unwrap();
372
    let port = listener.local_addr().unwrap().port();
373
    let origin = format!("http://127.0.0.1:{port}");
374
    let requests = std::sync::Arc::new(std::sync::Mutex::new(Vec::new()));
375
376
    let seen = std::sync::Arc::clone(&requests);
377
    let grant_url = format!("{origin}/proxy");
378
    tokio::spawn(async move {
379
        loop {
380
            let Ok((mut socket, _)) = listener.accept().await else {
381
                return;
382
            };
383
            let mut request = Vec::new();
384
            let mut buffer = [0u8; 4096];
385
            loop {
386
                let Ok(read) = socket.read(&mut buffer).await else {
387
                    break;
388
                };
389
                if read == 0 {
390
                    break;
391
                }
392
                request.extend_from_slice(&buffer[..read]);
393
                let text = String::from_utf8_lossy(&request);
394
                if let Some(end) = text.find("\r\n\r\n") {
395
                    let length = text
396
                        .lines()
397
                        .find_map(|line| {
398
                            line.strip_prefix("content-length: ")
399
                                .or_else(|| line.strip_prefix("Content-Length: "))
400
                        })
401
                        .and_then(|value| value.trim().parse::<usize>().ok())
402
                        .unwrap_or(0);
403
                    if request.len() >= end + 4 + length {
404
                        break;
405
                    }
406
                }
407
            }
408
            let request = String::from_utf8_lossy(&request).to_string();
409
            let line = request.lines().next().unwrap_or_default().to_string();
410
            seen.lock().unwrap().push(request);
411
412
            let (status, content_type, body) = if line.starts_with("POST")
413
                && line.contains("/events")
414
            {
415
                (
416
                    201,
417
                    "application/json",
418
                    r#"{"events":[{"id":1}]}"#.to_string(),
419
                )
420
            } else if line.starts_with("POST /api/v1/threads") {
421
                (
422
                    200,
423
                    "application/json",
424
                    format!(
425
                        r#"{{"thread":{{"id":"th_child"}},"grant":{{"token":"tok","url":"{grant_url}","model":"ox-alpha"}}}}"#
426
                    ),
427
                )
428
            } else if line.starts_with("DELETE /api/v1/threads/") {
429
                // Held open, so an awaited revocation is measurably slower
430
                // than a spawned one. See the test below.
431
                tokio::time::sleep(REVOCATION_HELD).await;
432
                (
433
                    200,
434
                    "application/json",
435
                    r#"{"grant":{"status":"revoked","spent":{"calls":1,"total_tokens":12}}}"#
436
                        .to_string(),
437
                )
438
            } else {
439
                let frame =
440
                    serde_json::json!({"choices":[{"delta":{"content":"the child answered"}}]});
441
                let stream = format!("data: {frame}\n\ndata: [DONE]\n\n");
442
                let head = "HTTP/1.1 200 OK\r\ncontent-type: text/event-stream\r\nconnection: close\r\n\r\n";
443
                let _ = socket.write_all(head.as_bytes()).await;
444
                let _ = socket.write_all(stream.as_bytes()).await;
445
                let _ = socket.flush().await;
446
                continue;
447
            };
448
449
            let head = format!(
450
                "HTTP/1.1 {status} X\r\ncontent-type: {content_type}\r\ncontent-length: {}\r\nconnection: close\r\n\r\n",
451
                body.len()
452
            );
453
            let _ = socket.write_all(head.as_bytes()).await;
454
            let _ = socket.write_all(body.as_bytes()).await;
455
            let _ = socket.flush().await;
456
        }
457
    });
458
459
    ProxyStub { origin, requests }
460
}
461
462
/// A child on the proxy revokes its own thread, awaited, and writes its turn
463
/// down on the way.
464
///
465
/// A child used to leave the revocation to the `Drop` impl, which spawns a
466
/// `DELETE` onto whatever runtime is still up and may never be polled. Timed
467
/// rather than merely observed: the stub holds the revocation open, so a child
468
/// that finishes faster than that did not wait for it.
469
#[tokio::test]
470
async fn a_delegated_child_revokes_its_own_thread() {
471
    let _guard = exclusive();
472
    let stub = proxy_stub().await;
473
    std::env::set_var("OPENAGENTS_API_BASE", format!("{}/api/v1", stub.origin));
474
475
    let supervisor = DelegationSupervisor::new(1, "ox-alpha", Some("oat_test".to_string()))
476
        .with_isolation(Isolation::None)
477
        .in_directory(Some(std::env::temp_dir()));
478
    let (results, _events) = run(&supervisor, "say something", None).await;
479
480
    std::env::remove_var("OPENAGENTS_API_BASE");
481
482
    assert_eq!(results.len(), 1);
483
    assert!(
484
        results[0].success,
485
        "the child failed: {}",
486
        results[0].output
487
    );
488
489
    let lines = stub.request_lines();
490
    assert!(
491
        lines
492
            .iter()
493
            .any(|line| line.starts_with("DELETE /api/v1/threads/th_child")),
494
        "the child left its thread open: {lines:?}"
495
    );
496
    assert!(
497
        lines
498
            .iter()
499
            .any(|line| line.starts_with("POST") && line.contains("/events")),
500
        "the child recorded nothing of what it did: {lines:?}"
501
    );
502
    assert!(
503
        results[0].duration_ms >= REVOCATION_HELD.as_millis(),
504
        "the child finished in {}ms with the revocation held open for {}ms, so it was \
505
         spawned and abandoned rather than awaited",
506
        results[0].duration_ms,
507
        REVOCATION_HELD.as_millis()
508
    );
509
}
crates/openagents-cli/tests/runtime_test.rs modified +537 -2

@@ -32,6 +32,9 @@ enum Reply {

32 32
    Sse(Vec<String>, Option<(usize, Duration)>),
33 33
    /// Newline-delimited JSON, the shape Ollama streams.
34 34
    Ndjson(Vec<String>, Option<(usize, Duration)>),
35
    /// A body sent after a pause. What tells a call that was awaited from one
36
    /// that was spawned and hoped for: only the first waits.
37
    Delayed(Duration, u16, &'static str, String),
35 38
}
36 39
37 40
/// A server that records what it was asked and answers from a script.

@@ -82,7 +85,15 @@ where

82 85
                    return;
83 86
                };
84 87
                seen.lock().unwrap().push(request.clone());
85
                match handler(&request, &origin) {
88
                let reply = match handler(&request, &origin) {
89
                    Reply::Delayed(pause, status, content_type, body) => {
90
                        tokio::time::sleep(pause).await;
91
                        Reply::Body(status, content_type, body)
92
                    }
93
                    other => other,
94
                };
95
                match reply {
96
                    Reply::Delayed(..) => unreachable!("already unwrapped"),
86 97
                    Reply::Body(status, content_type, body) => {
87 98
                        let head = format!(
88 99
                            "HTTP/1.1 {status} X\r\ncontent-type: {content_type}\r\n\

@@ -368,10 +379,12 @@ async fn a_second_turn_reuses_the_first_turns_thread() {

368 379
    session.execute_turn("one", |_| {}).await.unwrap();
369 380
    session.execute_turn("two", |_| {}).await.unwrap();
370 381
382
    // The open, not the appends: `POST /threads/{id}/events` shares the prefix
383
    // and a turn now writes several of those.
371 384
    let opens = stub
372 385
        .request_lines()
373 386
        .iter()
374
        .filter(|line| line.starts_with("POST /api/v1/threads"))
387
        .filter(|line| line.starts_with("POST /api/v1/threads ") && !line.contains("/events"))
375 388
        .count();
376 389
    assert_eq!(opens, 1, "each turn opened its own thread");
377 390
}

@@ -929,3 +942,525 @@ async fn the_second_turn_carries_what_the_first_turn_answered() {

929 942
        bodies[1]
930 943
    );
931 944
}
945
946
// ────────────────────────────────────────────────────────────── the record
947
//
948
// A session used to reach `DELETE` having recorded nothing at all, so the
949
// server's only terminal act was a cancellation and 31 of the 50 most recent
950
// threads on one account read `error_code: cancelled` over runs that had
951
// answered correctly (issue #106). These prove the turn writes itself down
952
// first, and — the half that matters more — that a turn which did *not* answer
953
// writes down that it did not.
954
955
/// The `event_type` of every transcript event the stub was posted, in order.
956
fn recorded(stub: &Stub) -> Vec<serde_json::Value> {
957
    stub.requests()
958
        .iter()
959
        .filter(|request| {
960
            request
961
                .lines()
962
                .next()
963
                .is_some_and(|line| line.starts_with("POST") && line.contains("/events"))
964
        })
965
        .filter_map(|request| {
966
            request
967
                .split_once("\r\n\r\n")
968
                .map(|(_, body)| body.to_string())
969
        })
970
        .filter_map(|body| serde_json::from_str::<serde_json::Value>(&body).ok())
971
        .flat_map(|body| {
972
            body.get("events")
973
                .and_then(|events| events.as_array())
974
                .cloned()
975
                .unwrap_or_default()
976
        })
977
        .collect()
978
}
979
980
fn kinds(events: &[serde_json::Value]) -> Vec<String> {
981
    events
982
        .iter()
983
        .map(|event| event["event_type"].as_str().unwrap_or("?").to_string())
984
        .collect()
985
}
986
987
/// The 201 the record route answers an append with.
988
fn appended() -> Reply {
989
    Reply::Body(
990
        201,
991
        "application/json",
992
        r#"{"events":[{"id":7}],"thread":{"id":"th_test","event_count":7}}"#.to_string(),
993
    )
994
}
995
996
fn revoked(total_tokens: u64) -> Reply {
997
    Reply::Body(
998
        200,
999
        "application/json",
1000
        format!(
1001
            r#"{{"grant":{{"status":"revoked","spent":{{"calls":1,"total_tokens":{total_tokens}}}}},
1002
                "thread":{{"id":"th_test","status":"cancelled"}}}}"#
1003
        ),
1004
    )
1005
}
1006
1007
/// A stub that answers a thread open, transcript appends, a revocation, and a
1008
/// two-step turn: reasoning and a `shell` call, then the answer.
1009
fn recording_stub() -> Stub {
1010
    start(|request, origin| {
1011
        let line = request.lines().next().unwrap_or_default().to_string();
1012
        if line.starts_with("POST") && line.contains("/events") {
1013
            return appended();
1014
        }
1015
        if line.starts_with("POST /api/v1/threads") {
1016
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
1017
        }
1018
        if line.starts_with("DELETE /api/v1/threads/") {
1019
            return revoked(116);
1020
        }
1021
        // The second call carries the tool result back, which is how a
1022
        // stateless stub tells the steps of one turn apart.
1023
        if request.contains(r#""role":"tool""#) {
1024
            return Reply::Sse(
1025
                vec![
1026
                    frame(serde_json::json!({"choices":[{"delta":{"content":"It said hello."}}]})),
1027
                    frame(serde_json::json!({
1028
                        "choices": [],
1029
                        "usage": {"prompt_tokens": 99, "completion_tokens": 17, "total_tokens": 116}
1030
                    })),
1031
                ],
1032
                None,
1033
            );
1034
        }
1035
        Reply::Sse(
1036
            vec![
1037
                frame(serde_json::json!({"choices":[{"delta":{"reasoning":"I should look."}}]})),
1038
                frame(serde_json::json!({"choices":[{"delta":{"tool_calls":[{
1039
                    "index": 0,
1040
                    "id": "call_a",
1041
                    "function": {"name": "shell", "arguments": "{\"command\":\"echo hello\"}"}
1042
                }]}}]})),
1043
            ],
1044
            None,
1045
        )
1046
    })
1047
}
1048
1049
/// A turn that answered is written to the transcript, in order, before the
1050
/// thread is revoked.
1051
#[tokio::test]
1052
async fn a_finished_turn_is_written_down_before_the_thread_is_revoked() {
1053
    let stub = recording_stub();
1054
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1055
    let answer = session
1056
        .execute_turn("what does echo hello print?", |_| {})
1057
        .await
1058
        .expect("the turn failed");
1059
    assert_eq!(answer, "It said hello.");
1060
    session.close().await.expect("the revocation failed");
1061
1062
    let events = recorded(&stub);
1063
    assert_eq!(
1064
        kinds(&events),
1065
        vec!["turn.user", "turn.reasoning", "tool.ran", "turn.assistant"],
1066
        "the transcript is not the session: {:?}",
1067
        kinds(&events)
1068
    );
1069
1070
    assert_eq!(events[0]["payload"]["text"], "what does echo hello print?");
1071
    assert_eq!(events[1]["payload"]["text"], "I should look.");
1072
1073
    let ran = &events[2]["payload"];
1074
    assert_eq!(ran["call_id"], "call_a");
1075
    assert_eq!(ran["tool"], "shell");
1076
    assert_eq!(
1077
        ran["arguments"], r#"{"command":"echo hello"}"#,
1078
        "the arguments are the wire's own string, which is what replays"
1079
    );
1080
    assert!(
1081
        ran["output"].as_str().unwrap_or_default().contains("hello"),
1082
        "the tool ran but its result was not recorded: {ran}"
1083
    );
1084
1085
    let said = &events[3]["payload"];
1086
    assert_eq!(said["text"], "It said hello.");
1087
    assert_eq!(said["usage"]["total_tokens"], 116);
1088
    assert_eq!(said["calls"], 1);
1089
1090
    // Nothing claims a failure, because there was none.
1091
    assert!(
1092
        !kinds(&events).contains(&"turn.failed".to_string()),
1093
        "a turn that answered recorded a failure"
1094
    );
1095
1096
    // And every append landed before the revocation. A record written after
1097
    // the thread is terminal is refused by the server and is not a record.
1098
    let lines = stub.request_lines();
1099
    let revocation = lines
1100
        .iter()
1101
        .position(|line| line.starts_with("DELETE"))
1102
        .expect("no revocation was sent");
1103
    let last_append = lines
1104
        .iter()
1105
        .rposition(|line| line.starts_with("POST") && line.contains("/events"))
1106
        .expect("nothing was appended");
1107
    assert!(
1108
        last_append < revocation,
1109
        "an append landed after the revocation: {lines:?}"
1110
    );
1111
}
1112
1113
/// What a recorded turn replays to on the next `--resume`.
1114
///
1115
/// This is the thing #106 unblocked: with only `thread.opened` on the thread,
1116
/// `oa coder --resume` on a thread this CLI had opened replayed nothing. The
1117
/// recorded events go through the real `replay_wire`, so a change to either
1118
/// side of that contract fails here.
1119
#[tokio::test]
1120
async fn a_recorded_turn_replays_into_the_conversation_it_came_from() {
1121
    let stub = recording_stub();
1122
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1123
    session
1124
        .execute_turn("what does echo hello print?", |_| {})
1125
        .await
1126
        .expect("the turn failed");
1127
    session.close().await.expect("the revocation failed");
1128
1129
    // Exactly what `GET /api/v1/threads/{id}/events` would hand back.
1130
    let transcript: Vec<openagents_cli::resume::ThreadEvent> = recorded(&stub)
1131
        .into_iter()
1132
        .enumerate()
1133
        .map(|(index, event)| openagents_cli::resume::ThreadEvent {
1134
            id: index as i64 + 1,
1135
            event_type: event["event_type"].as_str().unwrap_or_default().to_string(),
1136
            payload: event["payload"].clone(),
1137
        })
1138
        .collect();
1139
1140
    let replayed = openagents_cli::resume::replay_wire(&transcript);
1141
    let shape: Vec<&str> = replayed.iter().map(|m| m.role.as_str()).collect();
1142
    assert_eq!(
1143
        shape,
1144
        vec!["user", "assistant", "tool", "assistant"],
1145
        "the recorded turn does not rebuild the conversation it came from"
1146
    );
1147
    assert_eq!(
1148
        replayed[0].content.as_deref(),
1149
        Some("what does echo hello print?")
1150
    );
1151
    assert_eq!(
1152
        replayed[1].tool_calls.as_ref().unwrap()[0]["function"]["name"],
1153
        "shell"
1154
    );
1155
    assert_eq!(replayed[2].tool_call_id.as_deref(), Some("call_a"));
1156
    assert_eq!(replayed[3].content.as_deref(), Some("It said hello."));
1157
}
1158
1159
/// A turn the proxy refused records the refusal, and records no answer.
1160
///
1161
/// The mirror of the bug being fixed: a record that says every session
1162
/// succeeded is exactly as wrong as one that says every session was cancelled.
1163
#[tokio::test]
1164
async fn a_refused_turn_records_the_failure_and_never_an_answer() {
1165
    let stub = start(|request, origin| {
1166
        let line = request.lines().next().unwrap_or_default().to_string();
1167
        if line.starts_with("POST") && line.contains("/events") {
1168
            return appended();
1169
        }
1170
        if line.starts_with("POST /api/v1/threads") {
1171
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
1172
        }
1173
        if line.starts_with("DELETE /api/v1/threads/") {
1174
            return revoked(0);
1175
        }
1176
        Reply::Body(
1177
            402,
1178
            "application/json",
1179
            r#"{"code":"credit_exhausted","message":"nothing left"}"#.to_string(),
1180
        )
1181
    });
1182
1183
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1184
    let failure = session
1185
        .execute_turn("do something", |_| {})
1186
        .await
1187
        .expect_err("a refused proxy returned success");
1188
    session.close().await.expect("the revocation failed");
1189
1190
    let events = recorded(&stub);
1191
    assert_eq!(
1192
        kinds(&events),
1193
        vec!["turn.user", "turn.failed"],
1194
        "a refused turn did not write down that it failed: {:?}",
1195
        kinds(&events)
1196
    );
1197
    let why = events[1]["payload"]["error"].as_str().unwrap_or_default();
1198
    assert!(
1199
        why.contains("402") && why.contains("credit_exhausted"),
1200
        "the recorded failure does not say what refused it: {why}"
1201
    );
1202
    assert!(
1203
        failure.to_string().contains("402"),
1204
        "the caller was told something else: {failure}"
1205
    );
1206
}
1207
1208
/// A turn that spends its whole step budget records that, rather than an
1209
/// answer it never produced.
1210
#[tokio::test]
1211
async fn a_turn_that_runs_out_of_steps_records_the_failure() {
1212
    let stub = start(|request, origin| {
1213
        let line = request.lines().next().unwrap_or_default().to_string();
1214
        if line.starts_with("POST") && line.contains("/events") {
1215
            return appended();
1216
        }
1217
        if line.starts_with("POST /api/v1/threads") {
1218
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
1219
        }
1220
        if line.starts_with("DELETE /api/v1/threads/") {
1221
            return revoked(0);
1222
        }
1223
        // Never answers. Always asks for another tool.
1224
        Reply::Sse(
1225
            vec![frame(
1226
                serde_json::json!({"choices":[{"delta":{"tool_calls":[{
1227
                    "index": 0,
1228
                    "id": "call_loop",
1229
                    "function": {"name": "shell", "arguments": "{\"command\":\"true\"}"}
1230
                }]}}]}),
1231
            )],
1232
            None,
1233
        )
1234
    });
1235
1236
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1237
    let failure = session
1238
        .execute_turn("loop forever", |_| {})
1239
        .await
1240
        .expect_err("a turn with no answer returned one");
1241
1242
    let events = recorded(&stub);
1243
    let kinds = kinds(&events);
1244
    assert_eq!(kinds.first().map(String::as_str), Some("turn.user"));
1245
    assert_eq!(
1246
        kinds.last().map(String::as_str),
1247
        Some("turn.failed"),
1248
        "the exhausted budget was not written down: {kinds:?}"
1249
    );
1250
    assert!(
1251
        !kinds.contains(&"turn.assistant".to_string()),
1252
        "a turn that never answered recorded an answer: {kinds:?}"
1253
    );
1254
    let last = events.last().expect("an event");
1255
    assert!(
1256
        last["payload"]["error"]
1257
            .as_str()
1258
            .unwrap_or_default()
1259
            .contains("tool steps"),
1260
        "the recorded failure does not name the budget: {last}"
1261
    );
1262
    // The count is the calls it actually made, not a zero.
1263
    assert_eq!(last["payload"]["calls"], 30);
1264
    assert!(failure.to_string().contains("tool steps"));
1265
}
1266
1267
/// A session interrupted mid-turn says so, because its turn never got to.
1268
#[tokio::test]
1269
async fn an_interrupted_session_records_the_interruption() {
1270
    let stub = recording_stub();
1271
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1272
    session
1273
        .execute_turn("what does echo hello print?", |_| {})
1274
        .await
1275
        .expect("the turn failed");
1276
    session.note_interruption("stopped before finishing").await;
1277
1278
    let kinds = kinds(&recorded(&stub));
1279
    assert_eq!(
1280
        kinds.last().map(String::as_str),
1281
        Some("turn.failed"),
1282
        "the interruption left no trace: {kinds:?}"
1283
    );
1284
}
1285
1286
/// A transcript the server will not take does not cost the reader their answer
1287
/// — and is not swallowed either.
1288
#[tokio::test]
1289
async fn a_refused_append_is_reported_and_does_not_lose_the_answer() {
1290
    let stub = start(|request, origin| {
1291
        let line = request.lines().next().unwrap_or_default().to_string();
1292
        if line.starts_with("POST") && line.contains("/events") {
1293
            return Reply::Body(
1294
                422,
1295
                "application/json",
1296
                r#"{"code":"event_invalid","message":"no"}"#.to_string(),
1297
            );
1298
        }
1299
        if line.starts_with("POST /api/v1/threads") {
1300
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
1301
        }
1302
        Reply::Sse(
1303
            vec![frame(
1304
                serde_json::json!({"choices":[{"delta":{"content":"PONG"}}]}),
1305
            )],
1306
            None,
1307
        )
1308
    });
1309
1310
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1311
    let answer = session
1312
        .execute_turn("say pong", |_| {})
1313
        .await
1314
        .expect("a refused append threw away a turn that worked");
1315
    assert_eq!(answer, "PONG");
1316
    assert!(
1317
        session
1318
            .record_failures
1319
            .iter()
1320
            .any(|failure| failure.contains("turn.assistant") && failure.contains("422")),
1321
        "the refused append was swallowed: {:?}",
1322
        session.record_failures
1323
    );
1324
}
1325
1326
/// The revocation's `spent` is read rather than dropped, and a divergence from
1327
/// what this process counted is named rather than left for nobody to notice.
1328
#[tokio::test]
1329
async fn the_grant_spend_is_reported_and_a_divergence_is_named() {
1330
    let stub = start(|request, origin| {
1331
        let line = request.lines().next().unwrap_or_default().to_string();
1332
        if line.starts_with("POST") && line.contains("/events") {
1333
            return appended();
1334
        }
1335
        if line.starts_with("POST /api/v1/threads") {
1336
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
1337
        }
1338
        if line.starts_with("DELETE /api/v1/threads/") {
1339
            return revoked(500);
1340
        }
1341
        Reply::Sse(
1342
            vec![
1343
                frame(serde_json::json!({"choices":[{"delta":{"content":"PONG"}}]})),
1344
                frame(serde_json::json!({
1345
                    "choices": [],
1346
                    "usage": {"prompt_tokens": 99, "completion_tokens": 17, "total_tokens": 116}
1347
                })),
1348
            ],
1349
            None,
1350
        )
1351
    });
1352
1353
    let mut session = session(Lane::OxAlpha, stub.base.clone());
1354
    session.execute_turn("say pong", |_| {}).await.unwrap();
1355
    assert_eq!(session.session_usage.total_tokens, 116);
1356
1357
    let spent = session.close().await.expect("the revocation failed");
1358
    let line = session
1359
        .spend_line(spent)
1360
        .expect("the server reported a spend and nothing said so");
1361
    assert!(line.contains("500"), "{line}");
1362
    assert!(line.contains("116"), "{line}");
1363
    assert!(line.contains("384"), "the divergence was not named: {line}");
1364
1365
    // And an agreeing figure is reported without crying mismatch.
1366
    let agreed = session
1367
        .spend_line(Some(TurnUsage {
1368
            prompt_tokens: 0,
1369
            completion_tokens: 0,
1370
            total_tokens: 116,
1371
        }))
1372
        .expect("a reported spend");
1373
    assert_eq!(agreed, "Billed by the server: 116 tokens");
1374
}
1375
1376
/// The interactive session revokes its thread when the screen goes, awaited.
1377
///
1378
/// `run_tui` used to `abort()` this actor, which drops the session inside a
1379
/// dead task where the `Drop` impl can only spawn a `DELETE` the exiting
1380
/// process may never poll (issue #107). Here the app's control channel is
1381
/// dropped, exactly as leaving the screen drops it.
1382
///
1383
/// Proved with a clock, because "the stub eventually saw a DELETE" is also
1384
/// what the racing `Drop` does on a runtime that stays up. The stub holds the
1385
/// revocation open for `HELD`, so only an actor that *awaits* the close takes
1386
/// that long to return; a spawned best effort returns immediately and leaves
1387
/// the request in flight.
1388
#[tokio::test]
1389
async fn the_interactive_actor_awaits_its_revocation_when_the_app_goes() {
1390
    /// Long enough to separate an awaited call from a spawned one, short
1391
    /// enough not to slow the suite.
1392
    const HELD: Duration = Duration::from_millis(600);
1393
1394
    let stub = start(|request, origin| {
1395
        let line = request.lines().next().unwrap_or_default().to_string();
1396
        if line.starts_with("POST") && line.contains("/events") {
1397
            return appended();
1398
        }
1399
        if line.starts_with("POST /api/v1/threads") {
1400
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
1401
        }
1402
        if line.starts_with("DELETE /api/v1/threads/") {
1403
            return Reply::Delayed(
1404
                HELD,
1405
                200,
1406
                "application/json",
1407
                r#"{"grant":{"status":"revoked","spent":{"calls":1,"total_tokens":116}}}"#
1408
                    .to_string(),
1409
            );
1410
        }
1411
        Reply::Sse(
1412
            vec![frame(
1413
                serde_json::json!({"choices":[{"delta":{"content":"ok"}}]}),
1414
            )],
1415
            None,
1416
        )
1417
    });
1418
    let session = session(Lane::OxAlpha, stub.base.clone());
1419
1420
    let (control_tx, control_rx) = tokio::sync::mpsc::unbounded_channel();
1421
    let (event_tx, mut event_rx) = tokio::sync::mpsc::unbounded_channel();
1422
    let actor = tokio::spawn(openagents_cli::interactive::runtime_actor(
1423
        session, control_rx, event_tx,
1424
    ));
1425
1426
    control_tx
1427
        .send(openagents_cli::interactive::Control::Prompt(
1428
            "say ok".to_string(),
1429
        ))
1430
        .unwrap();
1431
    // Wait for the turn to settle before the app goes, so what is timed below
1432
    // is the exit and not the turn.
1433
    loop {
1434
        match event_rx.recv().await.expect("the actor stopped early") {
1435
            openagents_cli::interactive::TurnEvent::Done(_) => break,
1436
            openagents_cli::interactive::TurnEvent::Failed(why) => panic!("the turn failed: {why}"),
1437
            _ => {}
1438
        }
1439
    }
1440
1441
    drop(control_tx);
1442
    let left = Instant::now();
1443
    tokio::time::timeout(Duration::from_secs(10), actor)
1444
        .await
1445
        .expect("the actor never returned, so nothing was awaited")
1446
        .expect("the actor panicked");
1447
    let took = left.elapsed();
1448
1449
    let lines = stub.request_lines();
1450
    assert!(
1451
        lines
1452
            .iter()
1453
            .any(|line| line.starts_with("DELETE /api/v1/threads/th_test")),
1454
        "the interactive session left its thread open: {lines:?}"
1455
    );
1456
    assert!(
1457
        took >= HELD,
1458
        "the actor returned after {took:?} with the revocation still held open for {HELD:?}, \
1459
         so it was spawned and abandoned rather than awaited"
1460
    );
1461
    // And it wrote the turn down on the way, like every other path.
1462
    assert!(
1463
        kinds(&recorded(&stub)).contains(&"turn.assistant".to_string()),
1464
        "the interactive session recorded no answer"
1465
    );
1466
}

This page updates live while a promote is in flight · changelog