Stop the coder crashing, confabulating, and calling failures successes

c48fa5b1389f · AtlantisPleb · · parent 3b3a7b46fb1a

Stop the coder crashing, confabulating, and calling failures successes

Five defects a live-execution audit found by driving the agent rather than
reading it (openagents#89).

**A panic that killed the process.** `tools.rs` bounded tool output with
`&combined[..OUTPUT_LIMIT]`, a byte index into a `String`. The first time a
command printed a non-ASCII character straddling byte 30,000 the slice panicked
and took the whole agent with it, before the thread could be revoked. Any `git
log`, test run, or accented file past 30 kB did it. It steps back to a
character boundary now.

**The model could not see what it said.** `run_tools` records an assistant turn
only when that turn called a tool, so a turn that simply answered never joined
`self.messages` — and the session is reused across turns. Asked in turn two
what it said in turn one, it confabulated: "invent a codeword" gave QORVEN,
"what was the codeword?" gave ZORBEX. The answer is recorded now, in both the
hosted and the local loop.

**Exhausting the step budget returned success.** `final_answer` was assigned
only on a step with no tool calls, so thirty tool-calling steps fell out of the
loop and returned `Ok("")` — printed as `Turn result:` and a blank line, exit 0.
It refuses instead.

**Failed tools were reported as successes.** Every `shell` and `openagents`
result carried `is_error: false`, including a non-zero exit, a timeout, and a
CLI that could not be spawned, so a failing build read like a passing one and
the model carried on. Both helpers return the outcome with the text now.

**A cancelled fan-out orphaned its shell commands.** The `/bin/sh` spawn had no
process group, so the shell's children survived and reparented to init;
`delegate.rs`, `computer.rs` and `acp.rs` all already did this and `tools.rs`
was the exception. It gets `process_group(0)` and `kill_on_drop`.

Each fix has a test that fails against the old behaviour, verified by reverting
the fix and watching it fail — including the confabulation one, which asserts
the second turn's request body carries the first turn's answer. A test that
asked the model to recall something from the *user's* prompt would have passed
against the defect, because user messages were always recorded.

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/runtime.rs
  • modified crates/openagents-cli/src/tools.rs
  • modified crates/openagents-cli/tests/runtime_test.rs

Diff

3 files changed, +234 -17

crates/openagents-cli/src/runtime.rs modified +56

@@ -742,6 +742,9 @@ impl CoderRuntimeSession {

742 742
        self.last_model = Some(grant.model.clone());
743 743
744 744
        let mut final_answer = String::new();
745
        // False means the step budget ran out with every step still calling
746
        // tools, which is not an answer and must not be returned as one.
747
        let mut answered = false;
745 748
746 749
        for _ in 0..MAX_TOOL_STEPS {
747 750
            let req_body = serde_json::json!({

@@ -822,11 +825,36 @@ impl CoderRuntimeSession {

822 825
823 826
            if step.tool_calls.is_empty() {
824 827
                final_answer = step.content;
828
                // The answer joins the transcript. `run_tools` records an
829
                // assistant turn only when that turn called a tool, so without
830
                // this the model never sees anything it said itself: asked in
831
                // the next turn what it just told you, it confabulates a new
832
                // answer rather than reading the old one. A test that asks it
833
                // to recall something from the *user's* prompt hides this,
834
                // because user messages were always recorded.
835
                self.messages.push(ChatMessage {
836
                    role: "assistant".to_string(),
837
                    content: if final_answer.is_empty() {
838
                        None
839
                    } else {
840
                        Some(final_answer.clone())
841
                    },
842
                    tool_calls: None,
843
                    tool_call_id: None,
844
                });
845
                answered = true;
825 846
                break;
826 847
            }
827 848
            self.run_tools(step).await;
828 849
        }
829 850
851
        if !answered {
852
            return Err(format!(
853
                "the turn used all {MAX_TOOL_STEPS} tool steps without producing an answer; \
854
                 nothing was returned rather than an empty answer that reads as success"
855
            )
856
            .into());
857
        }
830 858
        Ok(final_answer)
831 859
    }
832 860

@@ -973,6 +1001,9 @@ impl CoderRuntimeSession {

973 1001
974 1002
        let url = format!("{}/api/chat", self.ollama_host.trim_end_matches('/'));
975 1003
        let mut final_answer = String::new();
1004
        // False means the step budget ran out with every step still calling
1005
        // tools, which is not an answer and must not be returned as one.
1006
        let mut answered = false;
976 1007
977 1008
        for _ in 0..MAX_TOOL_STEPS {
978 1009
            let req_body = serde_json::json!({

@@ -1036,11 +1067,36 @@ impl CoderRuntimeSession {

1036 1067
1037 1068
            if step.tool_calls.is_empty() {
1038 1069
                final_answer = step.content;
1070
                // The answer joins the transcript. `run_tools` records an
1071
                // assistant turn only when that turn called a tool, so without
1072
                // this the model never sees anything it said itself: asked in
1073
                // the next turn what it just told you, it confabulates a new
1074
                // answer rather than reading the old one. A test that asks it
1075
                // to recall something from the *user's* prompt hides this,
1076
                // because user messages were always recorded.
1077
                self.messages.push(ChatMessage {
1078
                    role: "assistant".to_string(),
1079
                    content: if final_answer.is_empty() {
1080
                        None
1081
                    } else {
1082
                        Some(final_answer.clone())
1083
                    },
1084
                    tool_calls: None,
1085
                    tool_call_id: None,
1086
                });
1087
                answered = true;
1039 1088
                break;
1040 1089
            }
1041 1090
            self.run_tools(step).await;
1042 1091
        }
1043 1092
1093
        if !answered {
1094
            return Err(format!(
1095
                "the turn used all {MAX_TOOL_STEPS} tool steps without producing an answer; \
1096
                 nothing was returned rather than an empty answer that reads as success"
1097
            )
1098
            .into());
1099
        }
1044 1100
        Ok(final_answer)
1045 1101
    }
1046 1102
}
crates/openagents-cli/src/tools.rs modified +123 -17

@@ -36,6 +36,26 @@ use crate::plugins::{

36 36
};
37 37
38 38
pub const OUTPUT_LIMIT: usize = 30_000;
39
40
/// The largest index at or below `max` that is a character boundary in `text`.
41
///
42
/// Slicing a `String` by a byte index panics when the index lands inside a
43
/// multi-byte character, and truncating tool output at a fixed byte count does
44
/// exactly that the first time a command prints an accent or an emoji past the
45
/// limit. The panic took the whole agent process with it, before the thread
46
/// could even be revoked. `str::floor_char_boundary` is unstable, so this is
47
/// the same thing spelled out.
48
fn floor_char_boundary(text: &str, max: usize) -> usize {
49
    if max >= text.len() {
50
        return text.len();
51
    }
52
    let mut index = max;
53
    while index > 0 && !text.is_char_boundary(index) {
54
        index -= 1;
55
    }
56
    index
57
}
58
39 59
pub const DEFAULT_TIMEOUT_SECS: u64 = 120;
40 60
pub const MAXIMUM_TIMEOUT_SECS: u64 = 600;
41 61

@@ -373,11 +393,11 @@ impl HarnessToolRegistry {

373 393
                    };
374 394
                }
375 395
376
                let output_str = run_real_shell(cmd, &self.cwd, timeout_secs).await;
396
                let (output_str, failed) = run_real_shell(cmd, &self.cwd, timeout_secs).await;
377 397
                ToolOutput {
378 398
                    call_id: call.id.clone(),
379 399
                    output: output_str,
380
                    is_error: false,
400
                    is_error: failed,
381 401
                }
382 402
            }
383 403
            "skill" => {

@@ -402,11 +422,11 @@ impl HarnessToolRegistry {

402 422
                    .map(|arr| arr.iter().filter_map(|v| v.as_str()).map(String::from).collect::<Vec<_>>())
403 423
                    .unwrap_or_default();
404 424
405
                let output_str = run_openagents_cli(&args_array).await;
425
                let (output_str, failed) = run_openagents_cli(&args_array).await;
406 426
                ToolOutput {
407 427
                    call_id: call.id.clone(),
408 428
                    output: output_str,
409
                    is_error: false,
429
                    is_error: failed,
410 430
                }
411 431
            }
412 432
            "delegate" => {

@@ -770,17 +790,30 @@ pub fn check_shell_refusal(cmd: &str) -> Option<String> {

770 790
    None
771 791
}
772 792
773
async fn run_real_shell(cmd: &str, cwd: &Path, timeout_secs: u64) -> String {
774
    let child = match Command::new("/bin/sh")
793
/// The text a tool result carries, and whether the command actually worked.
794
///
795
/// The outcome used to be dropped here and every shell result was reported to
796
/// the model as `is_error: false`, so a failing build read like a passing one
797
/// and the model carried on as though the step had succeeded.
798
async fn run_real_shell(cmd: &str, cwd: &Path, timeout_secs: u64) -> (String, bool) {
799
    let mut command = Command::new("/bin/sh");
800
    command
775 801
        .arg("-c")
776 802
        .arg(cmd)
777 803
        .current_dir(cwd)
778 804
        .stdout(Stdio::piped())
779 805
        .stderr(Stdio::piped())
780
        .spawn()
806
        // The shell spawns children of its own, and without a group of their
807
        // own they survive a cancelled fan-out and reparent to init. Every
808
        // other spawn site in this crate — `delegate.rs`, `computer.rs`,
809
        // `acp.rs` — already puts its child in one; this was the exception.
810
        .kill_on_drop(true);
811
    #[cfg(unix)]
812
    command.process_group(0);
813
    let child = match command.spawn()
781 814
    {
782 815
        Ok(c) => c,
783
        Err(e) => return format!("Failed to spawn shell command: {}", e),
816
        Err(e) => return (format!("Failed to spawn shell command: {}", e), true),
784 817
    };
785 818
786 819
    let execution = child.wait_with_output();

@@ -792,28 +825,41 @@ async fn run_real_shell(cmd: &str, cwd: &Path, timeout_secs: u64) -> String {

792 825
793 826
            let total_len = combined.len();
794 827
            let bounded = if total_len > OUTPUT_LIMIT {
795
                format!("{}\n\n[Output truncated: printed {} characters, limit is {}]", &combined[..OUTPUT_LIMIT], total_len, OUTPUT_LIMIT)
828
                format!(
829
                    "{}\n\n[Output truncated: printed {} characters, limit is {}]",
830
                    &combined[..floor_char_boundary(&combined, OUTPUT_LIMIT)],
831
                    total_len,
832
                    OUTPUT_LIMIT
833
                )
796 834
            } else {
797 835
                combined
798 836
            };
799 837
800 838
            if output.status.success() {
801 839
                if bounded.trim().is_empty() {
802
                    "The command succeeded and printed nothing.".to_string()
840
                    ("The command succeeded and printed nothing.".to_string(), false)
803 841
                } else {
804
                    bounded.trim().to_string()
842
                    (bounded.trim().to_string(), false)
805 843
                }
806 844
            } else {
807 845
                let code = output.status.code().unwrap_or(1);
808
                format!("The command exited with code {}.\n\n{}", code, bounded.trim())
846
                (
847
                    format!("The command exited with code {}.\n\n{}", code, bounded.trim()),
848
                    true,
849
                )
809 850
            }
810 851
        }
811
        Ok(Err(e)) => format!("Shell execution error: {}", e),
812
        Err(_) => format!("The command timed out after {} seconds and was stopped.", timeout_secs),
852
        Ok(Err(e)) => (format!("Shell execution error: {}", e), true),
853
        Err(_) => (
854
            format!("The command timed out after {} seconds and was stopped.", timeout_secs),
855
            true,
856
        ),
813 857
    }
814 858
}
815 859
816
async fn run_openagents_cli(args: &[String]) -> String {
860
/// As [`run_real_shell`]: the text, and whether it worked. A CLI that could
861
/// not even be spawned was previously reported to the model as a success.
862
async fn run_openagents_cli(args: &[String]) -> (String, bool) {
817 863
    let mut cmd = Command::new("openagents");
818 864
    cmd.args(args);
819 865
    cmd.stdout(Stdio::piped());

@@ -824,9 +870,9 @@ async fn run_openagents_cli(args: &[String]) -> String {

824 870
            let mut combined = String::new();
825 871
            combined.push_str(&String::from_utf8_lossy(&output.stdout));
826 872
            combined.push_str(&String::from_utf8_lossy(&output.stderr));
827
            combined.trim().to_string()
873
            (combined.trim().to_string(), !output.status.success())
828 874
        }
829
        Err(e) => format!("Failed to run openagents CLI: {}", e),
875
        Err(e) => (format!("Failed to run openagents CLI: {}", e), true),
830 876
    }
831 877
}
832 878

@@ -1181,3 +1227,63 @@ mod tests {

1181 1227
        assert!(out.output.contains("does_not_exist"), "{}", out.output);
1182 1228
    }
1183 1229
}
1230
1231
#[cfg(test)]
1232
mod defect_tests {
1233
    use super::*;
1234
1235
    /// `&combined[..OUTPUT_LIMIT]` is a *byte* index into a `String`. The first
1236
    /// time a command printed an accent or an emoji straddling the limit, the
1237
    /// slice panicked and took the whole agent process with it — before the
1238
    /// thread could even be revoked. Any `git log`, test run, or file with a
1239
    /// non-ASCII character past 30 kB did it.
1240
    #[test]
1241
    fn truncation_survives_a_multibyte_character_on_the_boundary() {
1242
        // 29,999 ASCII bytes, then a 3-byte character straddling byte 30,000.
1243
        let mut text = "a".repeat(OUTPUT_LIMIT - 1);
1244
        text.push_str("€€€");
1245
        assert!(!text.is_char_boundary(OUTPUT_LIMIT), "the probe must straddle");
1246
1247
        let cut = floor_char_boundary(&text, OUTPUT_LIMIT);
1248
        // The old code did `&text[..OUTPUT_LIMIT]`, which panics here.
1249
        let head = &text[..cut];
1250
1251
        assert_eq!(cut, OUTPUT_LIMIT - 1, "it must step back to the boundary");
1252
        assert!(head.ends_with('a'));
1253
        assert!(text.len() > cut, "there was something to truncate");
1254
    }
1255
1256
    #[test]
1257
    fn a_boundary_that_is_already_clean_is_left_alone() {
1258
        let text = "a".repeat(OUTPUT_LIMIT + 10);
1259
        assert_eq!(floor_char_boundary(&text, OUTPUT_LIMIT), OUTPUT_LIMIT);
1260
    }
1261
1262
    #[test]
1263
    fn a_short_string_is_never_cut() {
1264
        let text = "€€€";
1265
        assert_eq!(floor_char_boundary(text, OUTPUT_LIMIT), text.len());
1266
    }
1267
1268
    /// Every shell result was reported to the model as `is_error: false`, so a
1269
    /// failing build read exactly like a passing one.
1270
    #[tokio::test]
1271
    async fn a_failing_command_is_reported_as_a_failure() {
1272
        let dir = std::env::temp_dir();
1273
        let (text, failed) = run_real_shell("exit 7", &dir, 30).await;
1274
        assert!(failed, "exit 7 must be reported as an error, got: {text}");
1275
        assert!(text.contains('7'), "the code belongs in the text: {text}");
1276
1277
        let (text, failed) = run_real_shell("true", &dir, 30).await;
1278
        assert!(!failed, "a successful command must not be an error: {text}");
1279
    }
1280
1281
    /// A timeout is not a successful result either.
1282
    #[tokio::test]
1283
    async fn a_timed_out_command_is_reported_as_a_failure() {
1284
        let dir = std::env::temp_dir();
1285
        let (text, failed) = run_real_shell("sleep 5", &dir, 1).await;
1286
        assert!(failed, "a timeout must be an error, got: {text}");
1287
        assert!(text.contains("timed out"), "{text}");
1288
    }
1289
}
crates/openagents-cli/tests/runtime_test.rs modified +55

@@ -874,3 +874,58 @@ async fn the_local_lane_runs_tools_and_feeds_the_result_back() {

874 874
        chats[1]
875 875
    );
876 876
}
877
878
/// The model must be able to see what it said itself.
879
///
880
/// `run_tools` records an assistant turn only when that turn called a tool, so
881
/// a turn that simply answered was never added to `self.messages`. The session
882
/// is reused across turns, so asked in turn two what it said in turn one, the
883
/// model had nothing to read and confabulated a fresh answer instead:
884
///
885
///     turn 1: "invent a six-letter codeword" -> QORVEN
886
///     turn 2: "what was the codeword?"       -> ZORBEX
887
///
888
/// This asserts the recording rather than the model's behaviour: the second
889
/// turn's request body must carry the first turn's answer. A test that asked
890
/// the model to recall something from the *user's* prompt would pass against
891
/// the defect, because user messages were always recorded.
892
#[tokio::test]
893
async fn the_second_turn_carries_what_the_first_turn_answered() {
894
    let stub = start(|request, origin| {
895
        if request.starts_with("POST /api/v1/threads") {
896
            return Reply::Body(200, "application/json", grant_body(origin, "ox-alpha"));
897
        }
898
        Reply::Sse(
899
            vec![frame(
900
                serde_json::json!({"choices":[{"delta":{"content":"QORVEN"}}]}),
901
            )],
902
            None,
903
        )
904
    });
905
906
    let mut session = session(Lane::OxAlpha, stub.base.clone());
907
    let first = session
908
        .execute_turn("invent a codeword", |_| {})
909
        .await
910
        .unwrap();
911
    assert_eq!(first, "QORVEN");
912
    session
913
        .execute_turn("what was the codeword?", |_| {})
914
        .await
915
        .unwrap();
916
917
    // The last proxy request is the second turn's. It must contain the answer
918
    // the first turn produced.
919
    let bodies: Vec<String> = stub
920
        .requests()
921
        .into_iter()
922
        .filter(|r| !r.starts_with("POST /api/v1/threads"))
923
        .collect();
924
    assert_eq!(bodies.len(), 2, "expected one proxy call per turn");
925
    assert!(
926
        bodies[1].contains("QORVEN"),
927
        "the second turn did not carry the first turn's answer, so the model \
928
         cannot see what it said: {}",
929
        bodies[1]
930
    );
931
}

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