[INFO] fetching crate thoughtjack 0.5.0...
[INFO] testing thoughtjack-0.5.0 against try#dec9417b8611e34e787a3e4c37686b5131f9e5c5 for pr-154210
[INFO] extracting crate thoughtjack 0.5.0 into /workspace/builds/worker-7-tc2/source
[INFO] started tweaking crates.io crate thoughtjack 0.5.0
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate thoughtjack 0.5.0
[INFO] tweaked toml for crates.io crate thoughtjack 0.5.0 written to /workspace/builds/worker-7-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate thoughtjack 0.5.0 on toolchain dec9417b8611e34e787a3e4c37686b5131f9e5c5
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate thoughtjack 0.5.0 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] c1e60c7a6d147bcd72bccea0e5a559817c433776eff024750312c056690e95ff
[INFO] running `Command { std: "docker" "start" "-a" "c1e60c7a6d147bcd72bccea0e5a559817c433776eff024750312c056690e95ff", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "c1e60c7a6d147bcd72bccea0e5a559817c433776eff024750312c056690e95ff", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c1e60c7a6d147bcd72bccea0e5a559817c433776eff024750312c056690e95ff", kill_on_drop: false }`
[INFO] [stdout] c1e60c7a6d147bcd72bccea0e5a559817c433776eff024750312c056690e95ff
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] d8619dfbe9d39f3bb87ec170e6911fbc8e7fc4066f112dccdd05f7a0d9e1d5db
[INFO] running `Command { std: "docker" "start" "-a" "d8619dfbe9d39f3bb87ec170e6911fbc8e7fc4066f112dccdd05f7a0d9e1d5db", kill_on_drop: false }`
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling foldhash v0.2.0
[INFO] [stderr]    Compiling tracing-core v0.1.36
[INFO] [stderr]    Compiling log v0.4.29
[INFO] [stderr]    Compiling dunce v1.0.5
[INFO] [stderr]    Compiling fs_extra v1.3.0
[INFO] [stderr]    Compiling http v1.4.0
[INFO] [stderr]    Compiling zerocopy v0.8.39
[INFO] [stderr]    Compiling syn v2.0.114
[INFO] [stderr]    Compiling jobserver v0.1.34
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling errno v0.3.14
[INFO] [stderr]    Compiling socket2 v0.6.2
[INFO] [stderr]    Compiling mio v1.1.1
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling aws-lc-rs v1.15.4
[INFO] [stderr]    Compiling bitflags v2.10.0
[INFO] [stderr]    Compiling hashbrown v0.16.1
[INFO] [stderr]    Compiling signal-hook-registry v1.4.8
[INFO] [stderr]    Compiling thiserror v2.0.18
[INFO] [stderr]    Compiling serde_json v1.0.149
[INFO] [stderr]    Compiling rustls-pki-types v1.14.0
[INFO] [stderr]    Compiling cc v1.2.55
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling aho-corasick v1.1.4
[INFO] [stderr]    Compiling regex-syntax v0.8.9
[INFO] [stderr]    Compiling ahash v0.8.12
[INFO] [stderr]    Compiling rustls v0.23.36
[INFO] [stderr]    Compiling getrandom v0.4.1
[INFO] [stderr]    Compiling percent-encoding v2.3.2
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling rand_core v0.9.5
[INFO] [stderr]    Compiling sync_wrapper v1.0.2
[INFO] [stderr]    Compiling rustls-native-certs v0.8.3
[INFO] [stderr]    Compiling indexmap v2.13.0
[INFO] [stderr]    Compiling inventory v0.3.22
[INFO] [stderr]    Compiling form_urlencoded v1.2.2
[INFO] [stderr]    Compiling murmur3 v0.4.1
[INFO] [stderr]    Compiling nom v7.1.3
[INFO] [stderr]    Compiling uuid v1.21.0
[INFO] [stderr]    Compiling raw-cpuid v11.6.0
[INFO] [stderr]    Compiling better_any v0.2.1
[INFO] [stderr]    Compiling http-body v1.0.1
[INFO] [stderr]    Compiling arraydeque v0.5.1
[INFO] [stderr]    Compiling typed-arena v2.0.2
[INFO] [stderr]    Compiling http-body-util v0.1.3
[INFO] [stderr]    Compiling ryu v1.0.23
[INFO] [stderr]    Compiling annotate-snippets v0.12.12
[INFO] [stderr]    Compiling encoding_rs_io v0.1.7
[INFO] [stderr]    Compiling antlr4rust v0.5.2
[INFO] [stderr]    Compiling rand_xoshiro v0.7.0
[INFO] [stderr]    Compiling metrics-exporter-prometheus v0.18.1
[INFO] [stderr]    Compiling sketches-ddsketch v0.3.0
[INFO] [stderr]    Compiling chrono v0.4.43
[INFO] [stderr]    Compiling nohash-hasher v0.2.0
[INFO] [stderr]    Compiling iri-string v0.7.10
[INFO] [stderr]    Compiling clap_lex v1.0.0
[INFO] [stderr]    Compiling cmake v0.1.57
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling clap_builder v4.5.58
[INFO] [stderr]    Compiling thread_local v1.1.9
[INFO] [stderr]    Compiling matchit v0.8.4
[INFO] [stderr]    Compiling nu-ansi-term v0.50.3
[INFO] [stderr]    Compiling unsafe-libyaml v0.2.11
[INFO] [stderr]    Compiling dashmap v6.1.0
[INFO] [stderr]    Compiling aws-lc-sys v0.37.1
[INFO] [stderr]    Compiling libz-sys v1.1.23
[INFO] [stderr]    Compiling libgit2-sys v0.18.3+1.9.2
[INFO] [stderr]    Compiling regex-automata v0.4.14
[INFO] [stderr]    Compiling quanta v0.12.6
[INFO] [stderr]    Compiling serde_path_to_error v0.1.20
[INFO] [stderr]    Compiling humantime v2.3.0
[INFO] [stderr]    Compiling synstructure v0.13.2
[INFO] [stderr]    Compiling zerofrom-derive v0.1.6
[INFO] [stderr]    Compiling yoke-derive v0.8.1
[INFO] [stderr]    Compiling zerovec-derive v0.11.2
[INFO] [stderr]    Compiling displaydoc v0.2.5
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling tokio-macros v2.6.0
[INFO] [stderr]    Compiling tracing-attributes v0.1.31
[INFO] [stderr]    Compiling futures-macro v0.3.31
[INFO] [stderr]    Compiling tokio v1.49.0
[INFO] [stderr]    Compiling thiserror-impl v2.0.18
[INFO] [stderr]    Compiling serde_json_path_macros_internal v0.1.2
[INFO] [stderr]    Compiling thiserror-impl v1.0.69
[INFO] [stderr]    Compiling zerofrom v0.1.6
[INFO] [stderr]    Compiling clap_derive v4.5.55
[INFO] [stderr]    Compiling yoke v0.8.1
[INFO] [stderr]    Compiling regex v1.12.3
[INFO] [stderr]    Compiling zerovec v0.11.5
[INFO] [stderr]    Compiling zerotrie v0.2.3
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling futures-util v0.3.31
[INFO] [stderr]    Compiling async-trait v0.1.89
[INFO] [stderr]    Compiling thiserror v1.0.69
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling ppv-lite86 v0.2.21
[INFO] [stderr]    Compiling tinystr v0.8.2
[INFO] [stderr]    Compiling potential_utf v0.1.4
[INFO] [stderr]    Compiling icu_collections v2.1.1
[INFO] [stderr]    Compiling icu_locale_core v2.1.1
[INFO] [stderr]    Compiling axum-core v0.5.6
[INFO] [stderr]    Compiling metrics v0.24.3
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling saphyr-parser-bw v0.0.608
[INFO] [stderr]    Compiling rand v0.9.2
[INFO] [stderr]    Compiling clap v4.5.58
[INFO] [stderr]    Compiling icu_provider v2.1.1
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling metrics-util v0.20.1
[INFO] [stderr]    Compiling icu_properties v2.1.2
[INFO] [stderr]    Compiling icu_normalizer v2.1.1
[INFO] [stderr]    Compiling serde_json_path_core v0.2.2
[INFO] [stderr]    Compiling serde-saphyr v0.0.20
[INFO] [stderr]    Compiling serde_urlencoded v0.7.1
[INFO] [stderr]    Compiling tracing-serde v0.2.0
[INFO] [stderr]    Compiling serde_yaml v0.9.34+deprecated
[INFO] [stderr]    Compiling tracing-subscriber v0.3.22
[INFO] [stderr]    Compiling idna_adapter v1.2.1
[INFO] [stderr]    Compiling idna v1.1.0
[INFO] [stderr]    Compiling serde_json_path_macros v0.1.6
[INFO] [stderr]    Compiling serde_json_path v0.7.2
[INFO] [stderr]    Compiling url v2.5.8
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling cel v0.12.0
[INFO] [stderr]    Compiling h2 v0.4.13
[INFO] [stderr]    Compiling tokio-stream v0.1.18
[INFO] [stderr]    Compiling tower-http v0.6.8
[INFO] [stderr]    Compiling oatf v0.2.0
[INFO] [stderr]    Compiling hyper v1.8.1
[INFO] [stderr]    Compiling hyper-util v0.1.20
[INFO] [stderr]    Compiling git2 v0.20.4
[INFO] [stderr]    Compiling axum v0.8.8
[INFO] [stderr]    Compiling built v0.8.0
[INFO] [stderr]    Compiling thoughtjack v0.5.0 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling rustls-webpki v0.103.9
[INFO] [stderr]    Compiling tokio-rustls v0.26.4
[INFO] [stderr]    Compiling rustls-platform-verifier v0.6.2
[INFO] [stderr]    Compiling hyper-rustls v0.27.7
[INFO] [stderr]    Compiling reqwest v0.13.2
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 56s
[INFO] running `Command { std: "docker" "inspect" "d8619dfbe9d39f3bb87ec170e6911fbc8e7fc4066f112dccdd05f7a0d9e1d5db", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "d8619dfbe9d39f3bb87ec170e6911fbc8e7fc4066f112dccdd05f7a0d9e1d5db", kill_on_drop: false }`
[INFO] [stdout] d8619dfbe9d39f3bb87ec170e6911fbc8e7fc4066f112dccdd05f7a0d9e1d5db
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 396c5eef02ff303a00997e27bca369d7862c9c06c8cbab03d2633cbcff93fd1b
[INFO] running `Command { std: "docker" "start" "-a" "396c5eef02ff303a00997e27bca369d7862c9c06c8cbab03d2633cbcff93fd1b", kill_on_drop: false }`
[INFO] [stderr]    Compiling tokio v1.49.0
[INFO] [stderr]    Compiling bitflags v2.10.0
[INFO] [stderr]    Compiling raw-cpuid v11.6.0
[INFO] [stderr]    Compiling antlr4rust v0.5.2
[INFO] [stderr]    Compiling wait-timeout v0.2.1
[INFO] [stderr]    Compiling rand_xorshift v0.4.0
[INFO] [stderr]    Compiling tempfile v3.25.0
[INFO] [stderr]    Compiling git2 v0.20.4
[INFO] [stderr]    Compiling rusty-fork v0.3.1
[INFO] [stderr]    Compiling proptest v1.10.0
[INFO] [stderr]    Compiling cel v0.12.0
[INFO] [stderr]    Compiling quanta v0.12.6
[INFO] [stderr]    Compiling metrics-util v0.20.1
[INFO] [stderr]    Compiling built v0.8.0
[INFO] [stderr]    Compiling thoughtjack v0.5.0 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling tower v0.5.3
[INFO] [stderr]    Compiling tokio-rustls v0.26.4
[INFO] [stderr]    Compiling h2 v0.4.13
[INFO] [stderr]    Compiling tokio-stream v0.1.18
[INFO] [stderr]    Compiling tower-http v0.6.8
[INFO] [stderr]    Compiling oatf v0.2.0
[INFO] [stderr]    Compiling tokio-test v0.4.5
[INFO] [stderr]    Compiling hyper v1.8.1
[INFO] [stderr]    Compiling hyper-util v0.1.20
[INFO] [stderr]    Compiling hyper-rustls v0.27.7
[INFO] [stderr]    Compiling axum v0.8.8
[INFO] [stderr]    Compiling metrics-exporter-prometheus v0.18.1
[INFO] [stderr]    Compiling reqwest v0.13.2
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 1m 15s
[INFO] running `Command { std: "docker" "inspect" "396c5eef02ff303a00997e27bca369d7862c9c06c8cbab03d2633cbcff93fd1b", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "396c5eef02ff303a00997e27bca369d7862c9c06c8cbab03d2633cbcff93fd1b", kill_on_drop: false }`
[INFO] [stdout] 396c5eef02ff303a00997e27bca369d7862c9c06c8cbab03d2633cbcff93fd1b
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-7-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] c4ef456ef3711b3587bc532395febf0101910be8dd4a478994f36c30f63c5491
[INFO] running `Command { std: "docker" "start" "-a" "c4ef456ef3711b3587bc532395febf0101910be8dd4a478994f36c30f63c5491", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.46s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/thoughtjack-ad53fdcceb579893)
[INFO] [stdout] 
[INFO] [stdout] running 671 tests
[INFO] [stdout] test cli::args::tests::test_mcp_client_args_requires_command ... ok
[INFO] [stdout] test cli::args::tests::test_no_args_fails ... ok
[INFO] [stdout] test cli::args::tests::test_excessive_verbosity_clamps ... ok
[INFO] [stdout] test cli::args::tests::test_color_choices_parse ... ok
[INFO] [stdout] test cli::args::tests::test_log_format_values ... ok
[INFO] [stdout] test cli::args::tests::test_mcp_client_command_endpoint_conflict ... ok
[INFO] [stdout] test cli::args::tests::test_invalid_color_value ... ok
[INFO] [stdout] test cli::args::tests::test_scenarios_run_command ... ok
[INFO] [stdout] test cli::args::tests::test_verbose_count ... ok
[INFO] [stdout] test cli::args::tests::test_run_max_session ... ok
[INFO] [stdout] test cli::args::tests::test_color_values ... ok
[INFO] [stdout] test cli::args::tests::test_json_log_format ... ok
[INFO] [stdout] test cli::args::tests::test_quiet_flag ... ok
[INFO] [stdout] test cli::args::tests::test_help_output ... ok
[INFO] [stdout] test cli::args::tests::test_unknown_subcommand_fails ... ok
[INFO] [stdout] test cli::args::tests::test_run_grace_period ... ok
[INFO] [stdout] test cli::args::tests::test_scenarios_show_command ... ok
[INFO] [stdout] test cli::args::tests::test_run_with_config ... ok
[INFO] [stdout] test cli::args::tests::test_scenarios_list_with_category ... ok
[INFO] [stdout] test cli::args::tests::test_version_output ... ok
[INFO] [stdout] test cli::args::tests::test_scenarios_list_command ... ok
[INFO] [stdout] test cli::args::tests::test_verbose_quiet_conflict ... ok
[INFO] [stdout] test cli::args::tests::test_validate_normalize ... ok
[INFO] [stdout] test cli::args::tests::test_version_command ... ok
[INFO] [stdout] test engine::actions::tests::elicitation_without_sender_does_not_panic ... ok
[INFO] [stdout] test engine::actions::tests::all_sender_errors_logged_but_execution_completes ... ok
[INFO] [stdout] test engine::actions::tests::multiple_actions_execute_in_order ... ok
[INFO] [stdout] test engine::actions::tests::elicitation_url_mode_auto_generates_id ... ok
[INFO] [stdout] test engine::actions::tests::binding_specific_action_logged ... ok
[INFO] [stdout] test engine::generation::tests::invalid_agui_rejects ... ok
[INFO] [stdout] test engine::actions::tests::log_action_executes_without_panic ... ok
[INFO] [stdout] test engine::actions::tests::notification_with_interpolated_params ... ok
[INFO] [stdout] test engine::generation::tests::invalid_a2a_rejects ... ok
[INFO] [stdout] test engine::actions::tests::elicitation_explicit_id_from_extensions ... ok
[INFO] [stdout] test engine::actions::tests::notification_sender_error_continues_to_next_action ... ok
[INFO] [stdout] test engine::actions::tests::notification_without_sender_does_not_panic ... ok
[INFO] [stdout] test engine::actions::tests::elicitation_sender_error_continues_to_next_action ... ok
[INFO] [stdout] test engine::generation::tests::mcp_invalid_structure_rejects ... ok
[INFO] [stdout] test cli::args::tests::test_validate_command ... ok
[INFO] [stdout] test engine::generation::tests::mcp_messages_missing_role_rejects ... ok
[INFO] [stdout] test engine::generation::tests::unknown_protocol_passes ... ok
[INFO] [stdout] test engine::generation::tests::valid_agui_passes ... ok
[INFO] [stdout] test engine::generation::tests::valid_mcp_prompt_messages_passes ... ok
[INFO] [stdout] test engine::generation::tests::valid_mcp_tool_content_passes ... ok
[INFO] [stdout] test engine::generation::tests::valid_a2a_messages_passes ... ok
[INFO] [stdout] test engine::mcp_server::tests::apply_generation_replaces_generate_blocks ... ok
[INFO] [stdout] test engine::generation::tests::mcp_content_missing_type_rejects ... ok
[INFO] [stdout] test engine::mcp_server::tests::completion_returns_empty ... ok
[INFO] [stdout] test engine::generation::tests::mcp_messages_missing_content_rejects ... ok
[INFO] [stdout] test engine::generation::tests::empty_content_array_passes_mcp ... ok
[INFO] [stdout] test engine::generation::tests::valid_a2a_artifacts_passes ... ok
[INFO] [stdout] test engine::generation::tests::mcp_tool_with_output_schema_and_structured_content_passes ... ok
[INFO] [stdout] test engine::generation::tests::mcp_tool_with_output_schema_requires_structured_content ... ok
[INFO] [stdout] test engine::mcp_server::tests::default_capabilities_derives_from_state ... ok
[INFO] [stdout] test engine::mcp_server::tests::default_capabilities_includes_logging ... ok
[INFO] [stdout] test engine::mcp_server::tests::connection_reset_side_effect_returns_error ... ok
[INFO] [stdout] test engine::mcp_server::tests::default_capabilities_empty_state ... ok
[INFO] [stdout] test engine::mcp_server::tests::dispatch_response_no_responses_returns_empty_content ... ok
[INFO] [stdout] test engine::mcp_server::tests::drive_phase_completes_on_eof ... ok
[INFO] [stdout] test engine::mcp_server::tests::drive_phase_emits_events ... ok
[INFO] [stdout] test engine::mcp_server::tests::drive_phase_handles_notification_from_agent ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_015_server_info_impersonation ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_016_custom_protocol_version ... ok
[INFO] [stdout] test engine::mcp_server::tests::dispatch_response_empty_responses_returns_empty_content ... ok
[INFO] [stdout] test engine::mcp_server::tests::drive_phase_completes_on_cancel ... ok
[INFO] [stdout] test engine::mcp_server::tests::default_capabilities_includes_resource_templates ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_017_tool_icon_and_title ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_018_tool_call_is_error ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_022_elicitation_url_mode ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_019_audio_content ... ok
[INFO] [stdout] test engine::mcp_server::tests::entry_action_sender_sends_elicitation ... ok
[INFO] [stdout] test engine::mcp_server::tests::elicitation_first_match_wins ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_023_elicitation_declined ... ok
[INFO] [stdout] test engine::mcp_server::tests::elicitation_response_returns_empty_object ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_020_content_annotations ... ok
[INFO] [stdout] test engine::mcp_server::tests::elicitation_agent_declines ... ok
[INFO] [stdout] test engine::mcp_server::tests::ec_oatf_021_task_capability ... ok
[INFO] [stdout] test engine::mcp_server::tests::entry_action_sender_sends_notification ... ok
[INFO] [stdout] test engine::mcp_server::tests::extractors_refreshed_per_request ... ok
[INFO] [stdout] test engine::mcp_server::tests::find_by_field_works ... ok
[INFO] [stdout] test engine::mcp_server::tests::find_by_name_works ... ok
[INFO] [stdout] test engine::mcp_server::tests::generate_random_bytes_different_seeds_differ ... ok
[INFO] [stdout] test engine::mcp_server::tests::generate_nested_json_produces_valid_json ... ok
[INFO] [stdout] test engine::mcp_server::tests::generate_random_bytes_is_deterministic ... ok
[INFO] [stdout] test engine::mcp_server::tests::generate_nested_json_respects_depth_limit ... ok
[INFO] [stdout] test engine::mcp_server::tests::delayed_delivery_waits ... ok
[INFO] [stdout] test engine::mcp_server::tests::generate_unbounded_line_correct_length ... ok
[INFO] [stdout] test engine::mcp_server::tests::generate_unicode_stress_produces_content ... ok
[INFO] [stdout] test engine::mcp_server::tests::resources_list_returns_resources ... ok
[INFO] [stdout] test engine::mcp_server::tests::id_collision_side_effect_with_count ... ok
[INFO] [stdout] test engine::mcp_server::tests::resources_read_returns_content ... ok
[INFO] [stdout] test engine::mcp_server::tests::notification_flood_sends_before_response ... ok
[INFO] [stdout] test engine::mcp_server::tests::initialize_returns_capabilities ... ok
[INFO] [stdout] test engine::mcp_server::tests::resources_read_falls_back_to_template ... ok
[INFO] [stdout] test engine::mcp_server::tests::prompts_get_selects_response ... ok
[INFO] [stdout] test engine::mcp_server::tests::ping_returns_empty_object ... ok
[INFO] [stdout] test engine::mcp_server::tests::prompts_list_returns_prompts ... ok
[INFO] [stdout] test engine::mcp_server::tests::resources_templates_list_returns_templates ... ok
[INFO] [stdout] test engine::mcp_server::tests::sampling_returns_empty_object ... ok
[INFO] [stdout] test engine::mcp_server::tests::select_response_no_match ... ok
[INFO] [stdout] test engine::mcp_server::tests::strip_internal_fields_removes_responses ... ok
[INFO] [stdout] test engine::mcp_server::tests::subscribe_returns_success ... ok
[INFO] [stdout] test engine::mcp_server::tests::synthesize_no_provider ... ok
[INFO] [stdout] test engine::mcp_server::tests::tasks_cancel_returns_cancelled ... ok
[INFO] [stdout] test engine::mcp_server::tests::tasks_result_returns_result ... ok
[INFO] [stdout] test engine::mcp_server::tests::tools_list_returns_tools ... ok
[INFO] [stdout] test engine::mcp_server::tests::tools_call_unknown_tool_errors ... ok
[INFO] [stdout] test engine::mcp_server::tests::tasks_get_unknown_returns_error ... ok
[INFO] [stdout] test engine::mcp_server::tests::tasks_get_returns_task ... ok
[INFO] [stdout] test engine::mcp_server::tests::tools_list_includes_input_schema ... ok
[INFO] [stdout] test engine::mcp_server::tests::tasks_list_returns_all_tasks ... ok
[INFO] [stdout] test engine::mcp_server::tests::tools_call_selects_response ... ok
[INFO] [stdout] test engine::mcp_server::tests::unknown_method_returns_null ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_exact_match ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_no_variables_exact ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_multiple_variables ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_no_variables_mismatch ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_rejects_wrong_prefix ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_rejects_empty_variable ... ok
[INFO] [stdout] test engine::mcp_server::tests::unbounded_delivery_inflates_response ... ok
[INFO] [stdout] test engine::mcp_server::tests::tasks_list_empty_state ... ok
[INFO] [stdout] test engine::mcp_server::tests::uri_template_trailing_literal ... ok
[INFO] [stdout] test engine::mcp_server::tests::roots_list_returns_empty_roots ... ok
[INFO] [stdout] test engine::phase::tests::effective_state_merges_across_phases ... ok
[INFO] [stdout] test engine::phase::tests::count_threshold_exact ... ok
[INFO] [stdout] test engine::phase::tests::effective_state_chain_three_phases ... ok
[INFO] [stdout] test engine::phase::tests::advance_resets_trigger_state ... ok
[INFO] [stdout] test engine::phase::tests::effective_state_returns_value ... ok
[INFO] [stdout] test engine::phase::tests::is_terminal_on_triggerless_phase ... ok
[INFO] [stdout] test engine::phase::tests::actor_returns_correct_actor ... ok
[INFO] [stdout] test engine::phase::tests::advance_beyond_last_phase_wraps_safely ... ok
[INFO] [stdout] test engine::phase::tests::new_engine_starts_at_phase_zero ... ok
[INFO] [stdout] test engine::phase::tests::single_phase_document_is_terminal ... ok
[INFO] [stdout] test engine::phase::tests::process_event_advances_after_count ... ok
[INFO] [stdout] test engine::phase_loop::tests::drain_events_after_driver_completes ... ok
[INFO] [stdout] test engine::phase::tests::process_event_stays_on_terminal_phase ... ok
[INFO] [stdout] test engine::phase_loop::tests::await_extractors_resolves ... ok
[INFO] [stdout] test engine::phase::tests::process_event_stays_on_no_match ... ok
[INFO] [stdout] test engine::phase_loop::tests::build_interpolation_extractors_merges ... ok
[INFO] [stdout] test engine::phase_loop::tests::drain_events_stops_on_advance ... ok
[INFO] [stdout] test engine::phase_loop::tests::driver_error_propagates ... ok
[INFO] [stdout] test engine::phase_loop::tests::ec_oatf_007_no_state_phase ... ok
[INFO] [stdout] test engine::phase::tests::qualified_event_matches_trigger ... ok
[INFO] [stdout] test engine::phase_loop::tests::on_phase_advanced_called ... ok
[INFO] [stdout] test engine::phase_loop::tests::ec_oatf_008_empty_string_extractor ... ok
[INFO] [stdout] test engine::phase_loop::tests::phase_loop_advances_on_trigger ... ok
[INFO] [stdout] test engine::phase_loop::tests::multi_phase_full_lifecycle ... ok
[INFO] [stdout] test engine::phase_loop::tests::extractor_capture_local_scope ... ok
[INFO] [stdout] test engine::phase_loop::tests::extractor_capture_cross_actor ... ok
[INFO] [stdout] test engine::phase_loop::tests::phase_loop_captures_trace_entries ... ok
[INFO] [stdout] test engine::phase_loop::tests::phase_loop_terminal_phase_completes ... ok
[INFO] [stdout] test engine::phase_loop::tests::server_vs_client_extractor_source ... ok
[INFO] [stdout] test engine::trace::tests::append_increments_length ... ok
[INFO] [stdout] test engine::trace::tests::cloned_trace_shares_entries ... ok
[INFO] [stdout] test engine::trace::tests::default_trace_is_empty ... ok
[INFO] [stdout] test engine::trace::tests::new_trace_is_empty ... ok
[INFO] [stdout] test engine::trace::tests::sequence_numbers_are_monotonic ... ok
[INFO] [stdout] test engine::trace::tests::snapshot_is_independent ... ok
[INFO] [stdout] test engine::types::tests::actor_result_construction ... ok
[INFO] [stdout] test engine::types::tests::await_extractor_construction ... ok
[INFO] [stdout] test engine::types::tests::direction_display ... ok
[INFO] [stdout] test engine::types::tests::direction_equality ... ok
[INFO] [stdout] test engine::types::tests::direction_serialization ... ok
[INFO] [stdout] test engine::types::tests::phase_action_equality ... ok
[INFO] [stdout] test engine::types::tests::protocol_event_construction ... ok
[INFO] [stdout] test engine::types::tests::termination_reason_display ... ok
[INFO] [stdout] test engine::types::tests::termination_reason_serialization ... ok
[INFO] [stdout] test error::tests::test_config_error_display ... ok
[INFO] [stdout] test error::tests::test_config_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_engine_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_exit_codes ... ok
[INFO] [stdout] test error::tests::test_io_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_loader_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_orchestration_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_transport_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_usage_error_exit_code ... ok
[INFO] [stdout] test error::tests::test_validation_issue_display ... ok
[INFO] [stdout] test error::tests::test_validation_issue_warning_display ... ok
[INFO] [stdout] test engine::phase_loop::tests::phase_loop_cancellation_returns_cancelled ... ok
[INFO] [stdout] test loader::tests::detect_await_cycles_circular_detected ... ok
[INFO] [stdout] test loader::tests::detect_await_cycles_linear_ok ... ok
[INFO] [stdout] test loader::tests::detect_await_cycles_no_deps ... ok
[INFO] [stdout] test loader::tests::detect_await_cycles_self_cycle ... ok
[INFO] [stdout] test error::tests::test_verdict_error_exit_code ... ok
[INFO] [stdout] test loader::tests::load_invalid_document_returns_error ... ok
[INFO] [stdout] test loader::tests::ec_oatf_006_sdk_validation_error ... ok
[INFO] [stdout] test loader::tests::preprocess_clean_yaml_passes_through ... ok
[INFO] [stdout] test loader::tests::load_valid_multi_phase_document ... ok
[INFO] [stdout] test loader::tests::load_valid_single_phase_document ... ok
[INFO] [stdout] test loader::tests::preprocess_extracts_await_extractors ... ok
[INFO] [stdout] test loader::tests::preprocess_invalid_yaml_returns_error ... ok
[INFO] [stdout] test loader::tests::preprocess_single_actor_warns_and_ignores ... ok
[INFO] [stdout] test engine::trace::tests::concurrent_appends ... ok
[INFO] [stdout] test engine::generation::tests::proptests::prop_valid_mcp_content_passes ... ok
[INFO] [stdout] test observability::events::tests::all_event_categories_serialize_to_valid_json ... ok
[INFO] [stdout] test loader::tests::proptests::prop_empty_graph_ok ... ok
[INFO] [stdout] test observability::events::tests::emit_survives_writer_error ... ok
[INFO] [stdout] test observability::events::tests::emitter_increments_sequence ... ok
[INFO] [stdout] test observability::events::tests::emitter_writes_valid_jsonl ... ok
[INFO] [stdout] test observability::events::tests::concurrent_emit_from_multiple_threads ... ok
[INFO] [stdout] test observability::events::tests::event_serializes_with_type_tag ... ok
[INFO] [stdout] test engine::mcp_server::helpers::tests::prop_variable_substitution ... ok
[INFO] [stdout] test observability::events::tests::flush_is_idempotent_and_safe ... ok
[INFO] [stdout] test engine::generation::tests::proptests::prop_unknown_protocol_passes ... ok
[INFO] [stdout] test observability::events::tests::from_file_appends_to_existing ... ok
[INFO] [stdout] test loader::tests::proptests::prop_cycle_always_detected ... ok
[INFO] [stderr] {"sequence":0,"timestamp":"2026-04-01T02:49:55.367010754Z","type":"ServerStarted","server_name":"test-server","transport":"stdio"}
[INFO] [stdout] test observability::events::tests::from_file_creates_valid_jsonl_output ... ok
[INFO] [stdout] test observability::events::tests::test_empty_server_lifecycle_events ... ok
[INFO] [stdout] test observability::events::tests::noop_emitter_discards_all_events ... ok
[INFO] [stdout] test observability::events::tests::test_timestamp_is_utc ... ok
[INFO] [stdout] test observability::logging::tests::log_format_clone_copy_eq ... ok
[INFO] [stdout] test observability::logging::tests::log_format_default_is_human ... ok
[INFO] [stdout] test observability::logging::tests::test_invalid_log_level_fallback ... ok
[INFO] [stdout] test observability::logging::tests::test_log_format_debug ... ok
[INFO] [stdout] test observability::logging::tests::test_log_format_json_ne_human ... ok
[INFO] [stdout] test observability::logging::tests::test_multiple_verbosity_flags ... ok
[INFO] [stdout] test observability::logging::tests::test_quiet_and_verbose_conflict ... ok
[INFO] [stdout] test observability::logging::tests::test_unicode_in_log_messages ... ok
[INFO] [stdout] test observability::logging::tests::test_verbosity_saturates_at_255 ... ok
[INFO] [stdout] test observability::logging::tests::verbosity_0_is_warn ... ok
[INFO] [stdout] test observability::logging::tests::verbosity_1_is_info ... ok
[INFO] [stdout] test observability::logging::tests::verbosity_255_is_trace ... ok
[INFO] [stdout] test observability::logging::tests::verbosity_2_is_debug ... ok
[INFO] [stdout] test observability::logging::tests::verbosity_3_is_trace ... ok
[INFO] [stdout] test observability::events::tests::test_metrics_with_no_requests ... ok
[INFO] [stdout] test observability::events::tests::stderr_emitter_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::record_functions_do_not_panic_without_recorder ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_all_known_mcp_methods ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_known_a2a_method_returns_original ... ok
[INFO] [stdout] test engine::mcp_server::helpers::tests::prop_literal_self_match ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_known_agui_event_returns_original ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_known_mcp_method_returns_original ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_unknown_method_returns_unknown ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_all_known_agui_events ... ok
[INFO] [stdout] test observability::metrics::tests::sanitize_all_known_a2a_methods ... ok
[INFO] [stdout] test engine::mcp_server::helpers::tests::prop_empty_variable_rejected ... ok
[INFO] [stdout] test observability::metrics::tests::test_elicitation_and_sampling_recognized ... ok
[INFO] [stdout] test observability::metrics::tests::test_record_event_count_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::test_metrics_counter_overflow_saturates ... ok
[INFO] [stdout] test observability::logging::tests::init_logging_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::test_sanitize_empty_method ... ok
[INFO] [stdout] test observability::metrics::tests::test_record_payload_size_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::test_record_phase_transition_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::test_set_connections_active_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::test_set_current_phase_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::test_record_error_does_not_panic ... ok
[INFO] [stdout] test observability::metrics::tests::v05_record_functions_do_not_panic_without_recorder ... ok
[INFO] [stdout] test engine::trace::tests::proptests::prop_trace_seq_monotonic ... ok
[INFO] [stdout] test observability::metrics::tests::test_init_metrics_none_port ... ok
[INFO] [stdout] test observability::metrics::tests::very_long_method_returns_unknown ... ok
[INFO] [stdout] test observability::metrics::tests::test_sanitize_method_with_slash ... ok
[INFO] [stdout] test orchestration::gate::tests::all_servers_ready_opens_gate ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::actor_outcome_name ... ok
[INFO] [stdout] test orchestration::gate::tests::zero_servers_no_gate_needed ... ok
[INFO] [stdout] test orchestration::gate::tests::dropped_sender_detected ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::ec_orch_012_trace_ordering ... ok
[INFO] [stdout] test engine::trace::tests::trace_entry_fields_captured ... ok
[INFO] [stdout] test observability::events::tests::envelope_flattens_event_fields ... ok
[INFO] [stdout] test orchestration::gate::tests::subscribe_before_ready ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::ec_orch_011_high_contention_store ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::unpack_join_result_handles_success ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::orchestrate_mixed_outcomes ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::ec_orch_010_duplicate_actor_name ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::orchestrate_single_server_completes ... ok
[INFO] [stdout] test orchestration::runner::tests::a2a_client_requires_endpoint ... ok
[INFO] [stdout] test orchestration::runner::tests::build_actor_config_defaults ... ok
[INFO] [stdout] test orchestration::runner::tests::build_actor_config_header_without_colon_skipped ... ok
[INFO] [stdout] test orchestration::runner::tests::build_actor_config_maps_flags ... ok
[INFO] [stdout] test orchestration::runner::tests::build_actor_config_parses_multiple_headers ... ok
[INFO] [stdout] test orchestration::runner::tests::agui_client_requires_endpoint ... ok
[INFO] [stdout] test orchestration::runner::tests::mcp_client_requires_command_or_endpoint ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::zero_client_shutdown ... ok
[INFO] [stdout] test orchestration::runner::tests::mcp_server_stdio_runs_to_completion ... ok
[INFO] [stdout] test orchestration::runner::tests::merge_headers_appends_new ... ok
[INFO] [stdout] test orchestration::runner::tests::merge_headers_case_insensitive ... ok
[INFO] [stdout] test orchestration::runner::tests::merge_headers_empty_override_preserves_base ... ok
[INFO] [stdout] test orchestration::runner::tests::merge_headers_empty_base_uses_overrides ... ok
[INFO] [stdout] test orchestration::runner::tests::merge_headers_override_replaces_base ... ok
[INFO] [stdout] test orchestration::runner::tests::mode_env_prefix_maps_client_modes ... ok
[INFO] [stdout] test orchestration::store::tests::extractor_store_all_qualified ... ok
[INFO] [stdout] test orchestration::store::tests::extractor_store_clone_shares_data ... ok
[INFO] [stdout] test orchestration::store::tests::extractor_store_get_missing ... ok
[INFO] [stdout] test orchestration::store::tests::extractor_store_overwrite ... ok
[INFO] [stdout] test orchestration::store::tests::extractor_store_set_and_get ... ok
[INFO] [stdout] test orchestration::gate::tests::timeout_returns_error_with_server_names ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::ec_orch_016_zero_client_shutdown ... ok
[INFO] [stdout] test orchestration::runner::tests::resolve_headers_passthrough_for_server_mode ... ok
[INFO] [stdout] test orchestration::runner::tests::unsupported_mode_errors ... ok
[INFO] [stdout] test orchestration::store::tests::subscribe_notifies_on_set ... ok
[INFO] [stdout] test protocol::a2a_client::tests::auto_generate_message_id ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::ec_orch_014_zero_grace_period ... ok
[INFO] [stdout] test protocol::a2a_client::tests::build_task_message_streaming ... ok
[INFO] [stdout] test protocol::a2a_client::tests::build_with_configuration ... ok
[INFO] [stdout] test protocol::a2a_client::tests::build_with_interpolation ... ok
[INFO] [stdout] test protocol::a2a_client::tests::build_with_metadata ... ok
[INFO] [stderr] 2026-04-01T02:49:55.482511Z  WARN await_extractors: timed out, proceeding without value actor=producer extractor=never_set_key
[INFO] [stdout] test engine::mcp_server::helpers::tests::prop_no_panic_on_arbitrary ... ok
[INFO] [stdout] test engine::generation::tests::proptests::prop_mcp_no_content_fails ... ok
[INFO] [stdout] test protocol::a2a_client::tests::context_id_not_overridden ... ok
[INFO] [stdout] test protocol::a2a_client::tests::context_id_persistence ... ok
[INFO] [stdout] test protocol::a2a_client::tests::detect_artifact_update ... ok
[INFO] [stdout] test protocol::a2a_client::tests::detect_message_response ... ok
[INFO] [stdout] test protocol::a2a_client::tests::detect_missing_kind ... ok
[INFO] [stdout] test protocol::a2a_client::tests::detect_task_created ... ok
[INFO] [stdout] test protocol::a2a_client::tests::detect_unknown_kind ... ok
[INFO] [stdout] test protocol::a2a_client::tests::missing_task_message_errors ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_basic_data_event ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_consecutive_errors_tracked ... ok
[INFO] [stdout] test protocol::a2a_client::tests::detect_status_update ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_empty_data_ignored ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_incremental_chunks ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_extracts_result_field ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_malformed_json_skipped ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_sse_comment_ignored ... ok
[INFO] [stdout] test protocol::a2a_client::tests::preserve_existing_message_id ... ok
[INFO] [stdout] test orchestration::orchestrator::tests::ec_orch_002_await_extractor_timeout ... ok
[INFO] [stdout] test protocol::a2a_client::tests::parse_multiple_events_one_chunk ... ok
[INFO] [stdout] test protocol::a2a_client::tests::build_task_message_from_state ... ok
[INFO] [stdout] test orchestration::runner::tests::a2a_server_mode_recognized ... ok
[INFO] [stdout] test protocol::a2a_client::tests::status_qualifier_auth_required ... ok
[INFO] [stdout] test protocol::a2a_client::tests::status_qualifier_non_status_event ... ok
[INFO] [stdout] test protocol::a2a_client::tests::status_qualifier_rejected ... ok
[INFO] [stdout] test protocol::a2a_client::tests::status_qualifier_input_required ... ok
[INFO] [stdout] test protocol::a2a_client::tests::sync_response_kind_message ... ok
[INFO] [stdout] test protocol::a2a_client::tests::sync_response_kind_task ... ok
[INFO] [stdout] test protocol::a2a_client::tests::status_qualifier_resolution ... ok
[INFO] [stdout] test protocol::a2a_client::tests::proptests::prop_a2a_result_extraction ... ok
[INFO] [stdout] test protocol::a2a_server::tests::agent_card_endpoint ... ok
[INFO] [stdout] test loader::tests::proptests::prop_self_loop_detected ... ok
[INFO] [stdout] test loader::tests::proptests::prop_dag_no_false_positive ... ok
[INFO] [stdout] test protocol::a2a_server::tests::cancel_nonexistent_task_errors ... ok
[INFO] [stdout] test protocol::a2a_server::tests::context_id_tracking ... ok
[INFO] [stdout] test protocol::a2a_server::tests::create_and_get_task ... ok
[INFO] [stdout] test protocol::a2a_server::tests::create_driver ... ok
[INFO] [stdout] test protocol::a2a_server::tests::create_task_with_context_id ... ok
[INFO] [stdout] test protocol::a2a_server::tests::get_nonexistent_task ... ok
[INFO] [stdout] test protocol::a2a_server::tests::invalid_json_returns_parse_error ... ok
[INFO] [stdout] test protocol::a2a_server::tests::jsonrpc_error_format ... ok
[INFO] [stdout] test protocol::a2a_server::tests::jsonrpc_success_format ... ok
[INFO] [stdout] test protocol::a2a_server::tests::message_send_missing_message_returns_invalid_params ... ok
[INFO] [stdout] test protocol::a2a_server::tests::cancel_active_task ... ok
[INFO] [stdout] test protocol::a2a_server::tests::cancel_completed_task_errors ... ok
[INFO] [stdout] test protocol::a2a_server::tests::message_stream_missing_message_returns_invalid_params ... ok
[INFO] [stdout] test protocol::a2a_server::tests::message_send_returns_task ... ok
[INFO] [stdout] test protocol::a2a_server::tests::push_notification_returns_not_supported ... ok
[INFO] [stdout] test protocol::a2a_server::tests::resolve_response_type_message ... ok
[INFO] [stdout] test protocol::a2a_server::tests::resolve_task_content_no_responses ... ok
[INFO] [stdout] test protocol::a2a_server::tests::resolve_task_content_with_artifacts ... ok
[INFO] [stdout] test protocol::a2a_server::tests::resolve_task_content_with_matching_response ... ok
[INFO] [stdout] test protocol::a2a_server::tests::response_dispatch_with_interpolation ... ok
[INFO] [stdout] test protocol::a2a_server::tests::resubscribe_terminal_task_returns_unsupported ... ok
[INFO] [stdout] test protocol::a2a_server::tests::missing_method_returns_invalid_request ... ok
[INFO] [stdout] test protocol::a2a_server::tests::unknown_method_returns_error ... ok
[INFO] [stdout] test protocol::a2a_server::tests::terminal_state_detection ... ok
[INFO] [stdout] test protocol::a2a_server::tests::resolve_response_type_defaults_to_task ... ok
[INFO] [stdout] test engine::trace::tests::proptests::prop_trace_all_preserved ... ok
[INFO] [stdout] test protocol::agui::tests::accumulate_reasoning ... ok
[INFO] [stdout] test protocol::agui::tests::accumulate_reasoning_chunk ... ok
[INFO] [stdout] test protocol::agui::tests::accumulated_response_includes_tool_call_result ... ok
[INFO] [stdout] test protocol::agui::tests::accumulate_tool_call ... ok
[INFO] [stdout] test protocol::agui::tests::accumulate_text_message ... ok
[INFO] [stdout] test protocol::agui::tests::accumulate_tool_call_result ... ok
[INFO] [stdout] test protocol::agui::tests::auto_generate_ids ... ok
[INFO] [stdout] test protocol::agui::tests::build_with_template_interpolation ... ok
[INFO] [stdout] test protocol::agui::tests::ec_agui_007_out_of_order_deltas ... ok
[INFO] [stdout] test protocol::agui::tests::build_with_context_field ... ok
[INFO] [stdout] test protocol::agui::tests::ec_agui_012_unknown_event_type_full_parser ... ok
[INFO] [stdout] test protocol::agui::tests::ec_agui_013_reasoning_in_accumulated_response ... ok
[INFO] [stdout] test protocol::agui::tests::ec_agui_014_streamed_tool_call_args ... ok
[INFO] [stdout] test protocol::agui::tests::empty_messages_array_valid ... ok
[INFO] [stdout] test protocol::agui::tests::map_all_26_event_types ... ok
[INFO] [stdout] test protocol::agui::tests::missing_run_agent_input_errors ... ok
[INFO] [stdout] test protocol::agui::tests::parent_run_id_from_state ... ok
[INFO] [stdout] test protocol::agui::tests::parse_agui_canonical_custom_interrupt ... ok
[INFO] [stdout] test protocol::agui::tests::parse_agui_canonical_format ... ok
[INFO] [stdout] test protocol::agui::tests::build_from_full_state ... ok
[INFO] [stdout] test protocol::agui::tests::accumulator_reset_clears_all ... ok
[INFO] [stdout] test protocol::agui::tests::parse_basic_sse_event ... ok
[INFO] [stdout] test protocol::agui::tests::parse_consecutive_errors_counted ... ok
[INFO] [stdout] test protocol::agui::tests::parse_custom_interrupt ... ok
[INFO] [stdout] test protocol::agui::tests::parse_custom_non_interrupt ... ok
[INFO] [stdout] test protocol::agui::tests::parse_incremental_chunks ... ok
[INFO] [stdout] test protocol::agui::tests::parse_malformed_json_returns_error ... ok
[INFO] [stdout] test protocol::agui::tests::parse_multiline_data ... ok
[INFO] [stdout] test protocol::agui::tests::parse_multiple_events_in_one_chunk ... ok
[INFO] [stdout] test protocol::agui::tests::parse_sse_comment_ignored ... ok
[INFO] [stdout] test protocol::agui::tests::parse_sse_event_line_takes_precedence ... ok
[INFO] [stdout] test protocol::agui::tests::parse_data_only_event_no_type ... ok
[INFO] [stdout] test protocol::agui::tests::parse_success_resets_consecutive_errors ... ok
[INFO] [stdout] test protocol::agui::tests::parse_agui_canonical_stream ... ok
[INFO] [stdout] test protocol::agui::tests::proptests::prop_agui_event_type_mapping_stable ... ok
[INFO] [stdout] test protocol::agui::tests::run_agent_input_camel_case ... ok
[INFO] [stdout] test protocol::agui::tests::run_agent_input_parent_run_id ... ok
[INFO] [stdout] test protocol::agui::tests::run_agent_input_serialization ... ok
[INFO] [stdout] test protocol::agui::tests::run_id_from_document ... ok
[INFO] [stdout] test protocol::agui::tests::synthesize_not_yet_supported ... ok
[INFO] [stdout] test protocol::agui::tests::text_message_chunk_accumulates_content ... ok
[INFO] [stdout] test protocol::agui::tests::text_message_chunk_single_shot ... ok
[INFO] [stdout] test protocol::agui::tests::thread_id_from_document ... ok
[INFO] [stdout] test protocol::agui::tests::proptests::prop_agui_sse_chunk_independence ... ok
[INFO] [stdout] test protocol::agui::tests::tool_call_chunk_accumulates_arguments ... ok
[INFO] [stdout] test protocol::agui::tests::tool_call_end_resolves_name_from_start ... ok
[INFO] [stdout] test protocol::agui::tests::tool_call_start_without_end ... ok
[INFO] [stdout] test protocol::agui::tests::unknown_event_type_passes_through ... ok
[INFO] [stdout] test protocol::mcp_client::tests::capabilities_empty_state ... ok
[INFO] [stdout] test protocol::mcp_client::tests::capabilities_with_all ... ok
[INFO] [stdout] test protocol::mcp_client::tests::capabilities_with_elicitation ... ok
[INFO] [stdout] test protocol::mcp_client::tests::capabilities_with_roots ... ok
[INFO] [stdout] test protocol::mcp_client::tests::capabilities_with_sampling ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_error_response ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_notification ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_notification_without_params ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_response_removes_pending_entry ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_response_with_pending ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_response_with_string_id ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_response_without_pending ... ok
[INFO] [stdout] test protocol::mcp_client::tests::classify_server_request ... ok
[INFO] [stdout] test protocol::mcp_client::tests::default_sampling_response_structure ... ok
[INFO] [stdout] test protocol::mcp_client::tests::driver_bootstrap_spawns_multiplexer_and_handler ... ok
[INFO] [stdout] test protocol::mcp_client::tests::driver_forward_pending_events_drains_channels ... ok
[INFO] [stdout] test protocol::mcp_client::tests::driver_initialize_rejects_error_response_ec_mcpc_005 ... ok
[INFO] [stdout] test protocol::mcp_client::tests::driver_initialize_sends_handshake ... ok
[INFO] [stdout] test protocol::mcp_client::tests::driver_next_id_is_monotonic ... ok
[INFO] [stdout] test protocol::mcp_client::tests::elicitation_cancel_when_no_match ... ok
[INFO] [stdout] test protocol::mcp_client::tests::elicitation_cancel_when_no_responses ... ok
[INFO] [stdout] test protocol::mcp_client::tests::elicitation_static_response ... ok
[INFO] [stdout] test protocol::mcp_client::tests::elicitation_when_condition_matches ... ok
[INFO] [stdout] test protocol::mcp_client::tests::elicitation_with_extractor_interpolation ... ok
[INFO] [stdout] test protocol::agui::tests::proptests::prop_agui_custom_interrupt_detection ... ok
[INFO] [stderr] 2026-04-01T02:49:55.889492Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889635Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889688Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889729Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889759Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889792Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889834Z  WARN max session expired, cancelling all actors
[INFO] [stderr] 2026-04-01T02:49:55.889871Z  WARN max session expired, cancelling all actors
[INFO] [stdout] test orchestration::orchestrator::tests::max_session_timeout_cancels ... ok
[INFO] [stdout] test protocol::mcp_client::tests::handler_responds_to_elicitation ... ok
[INFO] [stdout] test protocol::mcp_client::tests::handler_responds_to_ping ... ok
[INFO] [stderr] 2026-04-01T02:49:55.948875Z  WARN handler error, sending error response method=sampling/createMessage error=driver error: synthesize not yet supported — GenerationProvider not available
[INFO] [stdout] test protocol::mcp_client::tests::handler_responds_to_roots_list ... ok
[INFO] [stdout] test protocol::mcp_client::tests::handler_stops_on_cancel ... ok
[INFO] [stdout] test protocol::a2a_client::tests::proptests::prop_a2a_sse_no_panic ... ok
[INFO] [stdout] test protocol::a2a_client::tests::transport_creation ... ok
[INFO] [stdout] test protocol::mcp_client::tests::handler_sampling_error_sends_error_response ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_closed_display ... ok
[INFO] [stdout] test protocol::mcp_client::tests::handler_unknown_method_returns_empty ... ok
[INFO] [stdout] test protocol::mcp_client::tests::handler_responds_to_sampling ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_routes_notification ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_routes_server_request_to_handler ... ok
[INFO] [stderr] 2026-04-01T02:49:56.029838Z  WARN received response for unknown request id id=999
[INFO] [stdout] test protocol::mcp_client::tests::handler_uses_fresh_extractors ... ok
[INFO] [stdout] test protocol::agui::tests::ec_agui_010_thread_id_persistence_across_builds ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_already_typed_action ... ok
[INFO] [stdout] test engine::phase_loop::tests::ec_oatf_014_driver_panic ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_bare_string_action ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_cancel_sets_close_reason ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_get_prompt_action ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_multi_key_object_passthrough ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_eof_sets_close_reason ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_null_action_passthrough ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_single_key_with_non_object_value ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_numeric_action_passthrough ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_subscribe_resource_action ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_read_resource_action ... ok
[INFO] [stdout] test protocol::mcp_client::tests::normalize_single_key_object_action ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_default_when_no_match ... ok
[INFO] [stdout] test protocol::mcp_client::tests::roots_empty_when_not_configured ... ok
[INFO] [stdout] test protocol::mcp_client::tests::roots_with_configured_roots ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_static_response ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_synthesize_stub_error ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_with_extractor_interpolation ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_falls_through_to_default ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::create_driver_neither_command_nor_endpoint_errors ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_when_condition_matches ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_routes_response_to_oneshot ... ok
[INFO] [stdout] test protocol::mcp_client::tests::sampling_default_when_no_responses ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_transport_error_sets_close_reason ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::http_reader_returns_none_on_sender_drop ... ok
[INFO] [stdout] test protocol::mcp_client::tests::multiplexer_unmatched_response_id_ec_mcpc_001 ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_basic_response ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::http_reader_receives_response ... ok
[INFO] [stdout] test protocol::a2a_client::tests::create_driver ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_empty_lines_no_event ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_malformed_json_returns_error ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_comments_ignored ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_multiple_events ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_notification ... ok
[INFO] [stdout] test scenarios::tests::builtin_scenarios_within_binary_size_budget ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::sse_parser_incremental_chunks ... ok
[INFO] [stdout] test scenarios::tests::category_label_titlecase ... ok
[INFO] [stdout] test scenarios::tests::find_scenario_existing ... ok
[INFO] [stdout] test scenarios::tests::find_scenario_missing ... ok
[INFO] [stdout] test scenarios::tests::category_display_lowercase ... ok
[INFO] [stdout] test scenarios::tests::all_builtin_scenarios_are_self_contained ... ok
[INFO] [stdout] test scenarios::tests::list_filter_by_category ... ok
[INFO] [stdout] test orchestration::store::tests::proptests::prop_last_writer_wins ... ok
[INFO] [stdout] test scenarios::tests::list_filter_by_category_and_tag ... ok
[INFO] [stdout] test scenarios::tests::list_filter_multi_vector ... ok
[INFO] [stdout] test protocol::agui::tests::thread_id_persistence ... ok
[INFO] [stdout] test scenarios::tests::list_filter_by_tag ... ok
[INFO] [stdout] test scenarios::tests::list_filter_protocol ... ok
[INFO] [stdout] test scenarios::tests::list_scenario_names_returns_all ... ok
[INFO] [stdout] test scenarios::tests::scenario_metadata_populated ... ok
[INFO] [stdout] test scenarios::tests::suggest_scenario_close ... ok
[INFO] [stdout] test transport::http::tests::connection_guard_cleanup_on_drop ... ok
[INFO] [stdout] test scenarios::tests::no_duplicate_scenario_names ... ok
[INFO] [stdout] test transport::http::tests::concurrent_posts_all_succeed ... ok
[INFO] [stdout] test scenarios::tests::suggest_scenario_far ... ok
[INFO] [stdout] test transport::http::tests::dns_rebinding_evil_origin_rejected ... ok
[INFO] [stdout] test protocol::a2a_client::tests::proptests::prop_a2a_sse_chunk_independence ... ok
[INFO] [stdout] test transport::http::tests::connection_tracking ... ok
[INFO] [stdout] test transport::http::tests::dns_rebinding_host_127_allowed ... ok
[INFO] [stdout] test transport::http::tests::default_connection_context_is_stdio ... ok
[INFO] [stdout] test transport::http::tests::debug_format ... ok
[INFO] [stdout] test transport::http::tests::parse_bind_addr_full ... ok
[INFO] [stdout] test transport::http::tests::parse_bind_addr_localhost ... ok
[INFO] [stdout] test transport::http::tests::post_after_cancel_rejected ... ok
[INFO] [stdout] test transport::http::tests::dns_rebinding_no_header_rejected ... ok
[INFO] [stdout] test transport::http::tests::parse_bind_addr_colon_port ... ok
[INFO] [stdout] test transport::http::tests::parse_bind_addr_port_only ... ok
[INFO] [stdout] test transport::http::tests::dns_rebinding_localhost_origin_allowed ... ok
[INFO] [stdout] test transport::http::tests::parse_bind_addr_invalid ... ok
[INFO] [stdout] test transport::http::tests::post_invalid_json_returns_400 ... ok
[INFO] [stdout] test transport::http::tests::post_empty_body_returns_400 ... ok
[INFO] [stdout] test transport::http::tests::response_handle_send_and_finalize ... ok
[INFO] [stdout] test transport::http::tests::response_handle_adapter_implements_transport ... ok
[INFO] [stdout] test transport::http::tests::post_valid_message_returns_200 ... ok
[INFO] [stdout] test transport::http::tests::sse_connection_counter_tracks ... ok
[INFO] [stdout] test transport::http::tests::sse_endpoint_returns_200 ... ok
[INFO] [stdout] test transport::http::tests::sse_stream_content_type ... ok
[INFO] [stdout] test transport::http::tests::post_oversized_body_returns_413 ... ok
[INFO] [stdout] test transport::http::tests::session_id_header_on_initialize ... ok
[INFO] [stdout] test transport::http::tests::transport_type_is_http ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_batch_request_parse ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_binary_in_string_field ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_deserialize_notification ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_deserialize_request ... ok
[INFO] [stdout] test protocol::a2a_client::tests::transport_with_headers ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_deserialize_response_with_error ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_deserialize_request_with_params ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_deserialize_response_with_null_result ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_deserialize_response_with_result ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_empty_batch_request ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_empty_json_message ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_empty_object ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_error_codes ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_error_with_data ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_invalid_json ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_missing_jsonrpc_version ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_malformed_json ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_negative_integer_request_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_non_object_json ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_accessors ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_constructor_no_params ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_constructor ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_omits_params_when_none ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_no_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_with_params_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_null_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_null_request_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_numeric_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_notification_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_request_complex_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_request_accessors ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_request_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_request_serialization_format ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_accessors ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_both_result_and_error ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_error_constructor ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_request_with_no_params ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_error_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_omits_result_when_none ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_success_constructor ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_omits_error_when_none ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_response_success_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_string_id ... ok
[INFO] [stderr] 2026-04-01T02:49:56.350928Z  WARN trace buffer full — dropping new entries max=100000
[INFO] [stdout] test transport::jsonrpc::tests::test_string_request_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_unknown_method_parse ... ok
[INFO] [stdout] test transport::jsonrpc::tests::test_very_large_request_id ... ok
[INFO] [stdout] test transport::jsonrpc::tests::proptests::prop_jsonrpc_id_preservation ... ok
[INFO] [stdout] test transport::sse::tests::default_creates_empty_parser ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::proptests::prop_mcp_sse_chunk_independence ... ok
[INFO] [stdout] test transport::sse::tests::parse_comment_ignored ... ok
[INFO] [stdout] test transport::sse::tests::parse_basic_data_event ... ok
[INFO] [stdout] test transport::sse::tests::parse_cr_lf_line_endings ... ok
[INFO] [stdout] test transport::sse::tests::parse_empty_lines_no_event ... ok
[INFO] [stdout] test transport::sse::tests::parse_event_with_type ... ok
[INFO] [stdout] test transport::sse::tests::parse_incremental_chunks ... ok
[INFO] [stdout] test transport::sse::tests::parse_multiple_events ... ok
[INFO] [stdout] test transport::sse::tests::parse_multiline_data ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::create_driver_with_endpoint_succeeds ... ok
[INFO] [stdout] test transport::sse::tests::proptests::prop_chunk_independence ... ok
[INFO] [stdout] test transport::sse::tests::buffer_overflow_returns_error ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::proptests::prop_mcp_sse_no_panic ... ok
[INFO] [stdout] test engine::trace::tests::capacity_limit_drops_entries ... ok
[INFO] [stdout] test transport::stdio::tests::connection_context_returns_stdio_context ... ok
[INFO] [stdout] test transport::sse::tests::data_overflow_returns_error ... ok
[INFO] [stdout] test transport::stdio::tests::sanitize_for_log_empty_input ... ok
[INFO] [stdout] test transport::stdio::tests::sanitize_for_log_truncates_long_input ... ok
[INFO] [stdout] test transport::stdio::tests::sanitize_for_log_replaces_control_chars ... ok
[INFO] [stdout] test transport::stdio::tests::test_stdio_config_default ... ok
[INFO] [stdout] test transport::stdio::tests::test_env_or_default ... ok
[INFO] [stdout] test transport::stdio::tests::test_stdio_context ... ok
[INFO] [stdout] test transport::stdio::tests::test_stdio_transport_type ... ok
[INFO] [stdout] test transport::stdio::tests::with_config_applies_custom_values ... ok
[INFO] [stdout] test transport::tests::test_transport_type_display ... ok
[INFO] [stdout] test transport::tests::test_constants ... ok
[INFO] [stdout] test transport::stdio::tests::test_stdio_transport_debug ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_002_all_skipped_protocol_mismatch ... ok
[INFO] [stdout] test transport::tests::test_connection_context_stdio ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_003_first_match_wins ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_004_cel_evaluator_error ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_005_all_correlation_mixed ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_007_grace_period_captures_evidence ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_008_empty_trace ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_009_protocol_filtering ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_006_any_correlation_one_match ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_020_all_correlation_enhancement ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::create_http_transport_succeeds ... ok
[INFO] [stdout] test transport::sse::tests::recovery_after_data_overflow ... ok
[INFO] [stdout] test verdict::evaluation::tests::extract_protocol_strips_client_suffix ... ok
[INFO] [stdout] test verdict::evaluation::tests::extract_protocol_passthrough_other ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_001_empty_indicators ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_013_semantic_no_engine ... ok
[INFO] [stdout] test verdict::evaluation::tests::ec_verdict_001_zero_indicators ... ok
[INFO] [stdout] test verdict::evaluation::tests::extract_protocol_strips_server_suffix ... ok
[INFO] [stdout] test verdict::evaluation::tests::merge_verdict_matched_wins ... ok
[INFO] [stdout] test verdict::evaluation::tests::filter_multi_actor_by_protocol ... ok
[INFO] [stdout] test verdict::evaluation::tests::merge_verdict_error_over_not_matched ... ok
[INFO] [stdout] test verdict::evaluation::tests::filter_single_actor_all_pass ... ok
[INFO] [stdout] test verdict::evaluation::tests::filter_empty_trace ... ok
[INFO] [stdout] test verdict::evaluation::tests::merge_verdict_skipped_over_not_matched ... ok
[INFO] [stdout] test verdict::evaluation::tests::semantic_empty_trace_skipped ... ok
[INFO] [stdout] test verdict::evaluation::tests::semantic_skipped_when_no_semantic_flag ... ok
[INFO] [stdout] test verdict::grace::tests::cli_override_takes_precedence ... ok
[INFO] [stdout] test verdict::grace::tests::default_zero_when_nothing_specified ... ok
[INFO] [stdout] test verdict::evaluation::tests::verdict_has_timestamp_and_source ... ok
[INFO] [stdout] test transport::sse::tests::recovery_after_buffer_overflow ... ok
[INFO] [stdout] test transport::jsonrpc::tests::proptests::prop_jsonrpc_method_preservation ... ok
[INFO] [stdout] test verdict::grace::tests::document_value_used_when_no_cli ... ok
[INFO] [stdout] test verdict::evaluation::tests::mixed_pattern_matched_semantic_skipped ... ok
[INFO] [stderr] 2026-04-01T02:49:56.725066Z  WARN could not parse document grace_period, using 0s duration="not-a-duration"
[INFO] [stdout] test verdict::grace::tests::duration_accessor ... ok
[INFO] [stderr] 
[INFO] [stdout] test verdict::grace::tests::humantime_formats_accepted ... ok
[INFO] [stderr]   TJ-TEST-001: Test Attack
[INFO] [stdout] test verdict::grace::tests::new_state_not_started ... ok
[INFO] [stdout] test verdict::grace::tests::expires_after_duration ... ok
[INFO] [stdout] test verdict::grace::tests::start_records_snapshot_and_time ... ok
[INFO] [stdout] test verdict::grace::tests::unparseable_document_value_falls_back_to_zero ... ok
[INFO] [stdout] test verdict::grace::tests::zero_duration_expires_immediately ... ok
[INFO] [stdout] test verdict::output::tests::attack_result_strings ... ok
[INFO] [stdout] test verdict::output::tests::build_verdict_output_includes_correlation ... ok
[INFO] [stdout] test verdict::output::tests::build_verdict_output_populates_fields ... ok
[INFO] [stdout] test verdict::output::tests::correlation_defaults_to_any ... ok
[INFO] [stdout] test verdict::output::tests::ec_verdict_011_unicode_in_evidence ... ok
[INFO] [stdout] test verdict::output::tests::ec_verdict_012_permission_denied ... ok
[INFO] [stdout] test verdict::output::tests::exit_code_error ... ok
[INFO] [stdout] test verdict::output::tests::exit_code_exploited ... ok
[INFO] [stderr] 
[INFO] [stderr]   Result: EXPLOITED
[INFO] [stderr] 
[INFO] [stderr]   Indicators:
[INFO] [stderr]     + ind-1 [matched]
[INFO] [stderr]       found malicious content
[INFO] [stderr]     o ind-2 [skipped]
[INFO] [stderr]       No inference engine configured
[INFO] [stderr] 
[INFO] [stderr]   Summary: 1 matched, 0 not matched, 0 errors, 1 skipped
[INFO] [stderr]   Correlation: any (1 match sufficient)
[INFO] [stderr] 
[INFO] [stderr]   Execution: 12 messages, 4.5s
[INFO] [stderr]     + mcp_poison: 2/2 phases
[INFO] [stderr] 
[INFO] [stderr] 
[INFO] [stderr]   (unnamed attack)
[INFO] [stderr] 
[INFO] [stderr]   Result: NOT EXPLOITED
[INFO] [stderr] 
[INFO] [stderr]   Summary: 0 matched, 0 not matched, 0 errors, 0 skipped
[INFO] [stderr] 
[INFO] [stderr]   Execution: 0 messages, 0.0s
[INFO] [stderr] 
[INFO] [stdout] test verdict::output::tests::exit_code_not_exploited ... ok
[INFO] [stdout] test verdict::output::tests::exit_code_partial ... ok
[INFO] [stdout] test verdict::output::tests::human_summary_does_not_panic ... ok
[INFO] [stderr] 
[INFO] [stdout] test verdict::output::tests::human_summary_empty_indicators ... ok
[INFO] [stdout] test verdict::grace::tests::remaining_decreases ... ok
[INFO] [stderr]   TJ-TEST-001: Test Attack
[INFO] [stderr] 
[INFO] [stderr]   Result: EXPLOITED
[INFO] [stderr] 
[INFO] [stderr]   Indicators:
[INFO] [stderr]     + ind-1 [matched]
[INFO] [stderr]       found malicious content
[INFO] [stderr]     o ind-2 [skipped]
[INFO] [stderr]       No inference engine configured
[INFO] [stderr] 
[INFO] [stderr]   Summary: 1 matched, 0 not matched, 0 errors, 1 skipped
[INFO] [stderr]   Correlation: any (1 match sufficient)
[INFO] [stderr] 
[INFO] [stderr]   Execution: 12 messages, 4.5s
[INFO] [stdout] test verdict::output::tests::indicator_result_strings ... ok
[INFO] [stdout] test verdict::output::tests::json_output_omits_correlation_when_none ... ok
[INFO] [stderr]     + mcp_poison: 2/2 phases
[INFO] [stderr] 
[INFO] [stderr] 
[INFO] [stderr]   TJ-TEST-001: Test Attack
[INFO] [stdout] test verdict::output::tests::human_summary_includes_correlation ... ok
[INFO] [stderr]   Severity: HIGH (confidence: 85)
[INFO] [stderr] 
[INFO] [stderr]   Result: EXPLOITED
[INFO] [stderr] 
[INFO] [stderr]   Indicators:
[INFO] [stderr]     + ind-1 [matched]
[INFO] [stderr]       found malicious content
[INFO] [stdout] test verdict::output::tests::json_output_includes_correlation ... ok
[INFO] [stdout] test verdict::output::tests::json_output_serializes_correctly ... ok
[INFO] [stderr]     o ind-2 [skipped]
[INFO] [stderr]       No inference engine configured
[INFO] [stderr] 
[INFO] [stdout] test verdict::output::tests::termination_status_strings ... ok
[INFO] [stdout] test verdict::output::tests::json_output_write_to_temp_file ... ok
[INFO] [stderr]   Summary: 1 matched, 0 not matched, 0 errors, 1 skipped
[INFO] [stderr]   Correlation: any (1 match sufficient)
[INFO] [stderr] 
[INFO] [stderr]   Execution: 12 messages, 4.5s
[INFO] [stderr]     + mcp_poison: 2/2 phases
[INFO] [stderr] 
[INFO] [stdout] test verdict::output::tests::human_summary_includes_severity ... ok
[INFO] [stdout] test verdict::evaluation::tests::proptests::prop_known_modes_correct ... ok
[INFO] [stdout] test protocol::mcp_client::transport::tests::create_http_transport_with_headers ... ok
[INFO] [stdout] test verdict::evaluation::tests::proptests::prop_extract_protocol_idempotent ... ok
[INFO] [stdout] test transport::sse::tests::proptests::prop_no_panic ... ok
[INFO] [stdout] test verdict::evaluation::tests::proptests::prop_unknown_passthrough ... ok
[INFO] [stdout] test transport::jsonrpc::tests::proptests::prop_jsonrpc_round_trip ... ok
[INFO] [stdout] test transport::jsonrpc::tests::proptests::prop_jsonrpc_variant_discrimination ... ok
[INFO] [stdout] test orchestration::store::tests::proptests::prop_version_monotonic ... ok
[INFO] [stdout] test transport::jsonrpc::tests::proptests::prop_jsonrpc_no_panic_on_object ... ok
[INFO] [stdout] test orchestration::store::tests::proptests::prop_qualified_key_format ... ok
[INFO] [stdout] test orchestration::store::tests::proptests::prop_no_lost_writes ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 671 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.00s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/thoughtjack-c85eedbba7102c30)
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/integration_tests.rs (/opt/rustwide/target/debug/deps/integration_tests-3a8a71b5631ad7f2)
[INFO] [stdout] 
[INFO] [stdout] running 43 tests
[INFO] [stdout] test integration::a2a_client_http::a2a_client_agent_card_timeout ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_auth_required_status ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_sync_receives_sse ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_stream_never_final ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_direct_message_response ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_send_task ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_streaming_final ... ok
[INFO] [stdout] test integration::agui_http::agui_canonical_data_only_sse ... ok
[INFO] [stdout] test integration::a2a_client_http::a2a_client_rejected_status ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_configuration_in_params ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_message_send ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_cancel_completed_task ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_unknown_method ... ok
[INFO] [stdout] test integration::mcp_client_stdio::mcp_client_init_and_tools_list ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_task_not_found ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_agent_card ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_concurrent_message_send ... ok
[INFO] [stdout] test integration::a2a_server_http::a2a_server_agent_card_rug_pull ... ok
[INFO] [stdout] test integration::agui_http::agui_happy_path_sse_stream ... ok
[INFO] [stdout] test integration::agui_http::agui_reasoning_events ... ok
[INFO] [stdout] test integration::mcp_client_stdio::mcp_client_interleaved_server_request ... ok
[INFO] [stdout] test integration::mcp_client_stdio::mcp_client_all_actions_error ... ok
[INFO] [stdout] test integration::agui_http::agui_malformed_sse_event ... ok
[INFO] [stdout] test integration::verdict_pipeline::verdict_any_one_match ... ok
[INFO] [stdout] test integration::verdict_pipeline::verdict_empty_trace ... ok
[INFO] [stdout] test integration::verdict_pipeline::verdict_grace_entries_included ... ok
[INFO] [stdout] test integration::verdict_pipeline::verdict_pattern_exploited ... ok
[INFO] [stdout] test integration::verdict_pipeline::verdict_protocol_filter ... ok
[INFO] [stdout] test integration::agui_http::agui_connection_drops_mid_stream ... ok
[INFO] [stdout] test integration::verdict_pipeline::verdict_all_mixed ... ok
[INFO] [stdout] test integration::agui_http::agui_custom_event_passthrough ... ok
[INFO] [stdout] test integration::orchestration::max_session_cancels_all ... ok
[INFO] [stdout] test integration::orchestration::two_actor_extractor_handoff ... ok
[INFO] [stdout] test integration::agui_http::agui_http_500_no_retry ... ok
[INFO] [stdout] test integration::orchestration::grace_period_on_clients_done ... ok
[INFO] [stdout] test integration::agui_http::agui_multi_run_phase ... ok
[INFO] [stdout] test integration::agui_http::agui_tool_call_streamed_args ... ok
[INFO] [stdout] test integration::orchestration::zero_grace_period ... ok
[INFO] [stdout] test integration::orchestration::client_error_counts_as_done ... ok
[INFO] [stdout] test integration::orchestration::trace_merge_ordering ... ok
[INFO] [stdout] test integration::orchestration::await_extractors_timeout ... ok
[INFO] [stdout] test integration::agui_http::agui_http_429_retry ... ok
[INFO] [stdout] test integration::mcp_client_stdio::mcp_client_server_exits ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 43 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 30.95s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests thoughtjack
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "c4ef456ef3711b3587bc532395febf0101910be8dd4a478994f36c30f63c5491", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c4ef456ef3711b3587bc532395febf0101910be8dd4a478994f36c30f63c5491", kill_on_drop: false }`
[INFO] [stdout] c4ef456ef3711b3587bc532395febf0101910be8dd4a478994f36c30f63c5491