[INFO] cloning repository https://github.com/bn-l/devlogger
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/bn-l/devlogger" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fbn-l%2Fdevlogger", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fbn-l%2Fdevlogger'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] b14c0a81043a20bcbb16c819687957bc8e3c0af8
[INFO] testing bn-l/devlogger against master#f9988fefd3add01f414f52b414308e7872622fee for pr-155114
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fbn-l%2Fdevlogger" "/workspace/builds/worker-3-tc1/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-3-tc1/source'...
[INFO] [stderr] done.
[INFO] started tweaking git repo https://github.com/bn-l/devlogger
[INFO] finished tweaking git repo https://github.com/bn-l/devlogger
[INFO] tweaked toml for git repo https://github.com/bn-l/devlogger written to /workspace/builds/worker-3-tc1/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/bn-l/devlogger on toolchain f9988fefd3add01f414f52b414308e7872622fee
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+f9988fefd3add01f414f52b414308e7872622fee" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate git repo https://github.com/bn-l/devlogger 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" "+f9988fefd3add01f414f52b414308e7872622fee" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded tracing-serde v0.2.0
[INFO] [stderr]   Downloaded quote v1.0.45
[INFO] [stderr]   Downloaded once_cell v1.21.4
[INFO] [stderr]   Downloaded tokio-macros v2.7.0
[INFO] [stderr]   Downloaded ref-cast-impl v1.0.25
[INFO] [stderr]   Downloaded dyn-clone v1.0.20
[INFO] [stderr]   Downloaded wasm-bindgen-macro v0.2.118
[INFO] [stderr]   Downloaded matchers v0.2.0
[INFO] [stderr]   Downloaded ref-cast v1.0.25
[INFO] [stderr]   Downloaded wasm-bindgen-shared v0.2.118
[INFO] [stderr]   Downloaded windows-collections v0.3.2
[INFO] [stderr]   Downloaded itoa v1.0.18
[INFO] [stderr]   Downloaded serde_derive_internals v0.29.1
[INFO] [stderr]   Downloaded signal-hook-registry v1.4.8
[INFO] [stderr]   Downloaded schemars_derive v1.2.1
[INFO] [stderr]   Downloaded pin-project-lite v0.2.17
[INFO] [stderr]   Downloaded windows-threading v0.2.1
[INFO] [stderr]   Downloaded cfg_aliases v0.2.1
[INFO] [stderr]   Downloaded indenter v0.3.4
[INFO] [stderr]   Downloaded is_terminal_polyfill v1.70.2
[INFO] [stderr]   Downloaded fastrand v2.4.1
[INFO] [stderr]   Downloaded semver v1.0.28
[INFO] [stderr]   Downloaded clap_lex v1.1.0
[INFO] [stderr]   Downloaded colorchoice v1.0.5
[INFO] [stderr]   Downloaded fs2 v0.4.3
[INFO] [stderr]   Downloaded darling_macro v0.23.0
[INFO] [stderr]   Downloaded windows-numerics v0.3.1
[INFO] [stderr]   Downloaded tempfile v3.27.0
[INFO] [stderr]   Downloaded anstyle-wincon v3.0.11
[INFO] [stderr]   Downloaded tracing-error v0.2.1
[INFO] [stderr]   Downloaded color-spantrace v0.3.0
[INFO] [stderr]   Downloaded utf8parse v0.2.2
[INFO] [stderr]   Downloaded once_cell_polyfill v1.70.2
[INFO] [stderr]   Downloaded strsim v0.11.1
[INFO] [stderr]   Downloaded anstyle-query v1.1.5
[INFO] [stderr]   Downloaded bitflags v2.11.1
[INFO] [stderr]   Downloaded indoc v2.0.7
[INFO] [stderr]   Downloaded rmcp-macros v1.4.0
[INFO] [stderr]   Downloaded pastey v0.2.1
[INFO] [stderr]   Downloaded rustc-demangle v0.1.27
[INFO] [stderr]   Downloaded anstream v1.0.0
[INFO] [stderr]   Downloaded darling v0.23.0
[INFO] [stderr]   Downloaded anstyle v1.0.14
[INFO] [stderr]   Downloaded anstyle-parse v1.0.0
[INFO] [stderr]   Downloaded getrandom v0.4.2
[INFO] [stderr]   Downloaded clap_derive v4.6.1
[INFO] [stderr]   Downloaded r-efi v6.0.0
[INFO] [stderr]   Downloaded wasm-bindgen-macro-support v0.2.118
[INFO] [stderr]   Downloaded owo-colors v4.3.0
[INFO] [stderr]   Downloaded wasm-bindgen v0.2.118
[INFO] [stderr]   Downloaded addr2line v0.25.1
[INFO] [stderr]   Downloaded eyre v0.6.12
[INFO] [stderr]   Downloaded windows-future v0.3.2
[INFO] [stderr]   Downloaded futures v0.3.32
[INFO] [stderr]   Downloaded clap v4.6.1
[INFO] [stderr]   Downloaded mio v1.2.0
[INFO] [stderr]   Downloaded indexmap v2.14.0
[INFO] [stderr]   Downloaded darling_core v0.23.0
[INFO] [stderr]   Downloaded schemars v1.2.1
[INFO] [stderr]   Downloaded backtrace v0.3.76
[INFO] [stderr]   Downloaded js-sys v0.3.95
[INFO] [stderr]   Downloaded cc v1.2.60
[INFO] [stderr]   Downloaded hashbrown v0.17.0
[INFO] [stderr]   Downloaded tracing-subscriber v0.3.23
[INFO] [stderr]   Downloaded process-wrap v9.1.0
[INFO] [stderr]   Downloaded clap_builder v4.6.0
[INFO] [stderr]   Downloaded chrono v0.4.44
[INFO] [stderr]   Downloaded unicode-width v0.2.2
[INFO] [stderr]   Downloaded gimli v0.32.3
[INFO] [stderr]   Downloaded rmcp v1.4.0
[INFO] [stderr]   Downloaded object v0.37.3
[INFO] [stderr]   Downloaded nix v0.31.2
[INFO] [stderr]   Downloaded regex-syntax v0.8.10
[INFO] [stderr]   Downloaded color-eyre v0.6.5
[INFO] [stderr]   Downloaded libc v0.2.185
[INFO] [stderr]   Downloaded tokio v1.52.0
[INFO] [stderr]   Downloaded windows v0.62.2
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/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" "+f9988fefd3add01f414f52b414308e7872622fee" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 29fca7b20255bcbedecb08830c30278b96cc3143566ca3a633b47c0b6211d12e
[INFO] running `Command { std: "docker" "start" "-a" "29fca7b20255bcbedecb08830c30278b96cc3143566ca3a633b47c0b6211d12e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "29fca7b20255bcbedecb08830c30278b96cc3143566ca3a633b47c0b6211d12e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "29fca7b20255bcbedecb08830c30278b96cc3143566ca3a633b47c0b6211d12e", kill_on_drop: false }`
[INFO] [stdout] 29fca7b20255bcbedecb08830c30278b96cc3143566ca3a633b47c0b6211d12e
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/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" "+f9988fefd3add01f414f52b414308e7872622fee" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] adb354ec3bb8c262e00de2f54ab67872bd998c8f2ffe3a8811476f7ab9ac81b5
[INFO] running `Command { std: "docker" "start" "-a" "adb354ec3bb8c262e00de2f54ab67872bd998c8f2ffe3a8811476f7ab9ac81b5", kill_on_drop: false }`
[INFO] [stderr]    Compiling proc-macro2 v1.0.106
[INFO] [stderr]    Compiling unicode-ident v1.0.24
[INFO] [stderr]    Compiling quote v1.0.45
[INFO] [stderr]    Compiling libc v0.2.185
[INFO] [stderr]    Compiling pin-project-lite v0.2.17
[INFO] [stderr]    Compiling memchr v2.8.0
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling zmij v1.0.21
[INFO] [stderr]    Compiling once_cell v1.21.4
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling itoa v1.0.18
[INFO] [stderr]    Compiling cfg-if v1.0.4
[INFO] [stderr]    Compiling futures-core v0.3.32
[INFO] [stderr]    Compiling serde_json v1.0.149
[INFO] [stderr]    Compiling futures-sink v0.3.32
[INFO] [stderr]    Compiling strsim v0.11.1
[INFO] [stderr]    Compiling regex-syntax v0.8.10
[INFO] [stderr]    Compiling autocfg v1.5.0
[INFO] [stderr]    Compiling tracing-core v0.1.36
[INFO] [stderr]    Compiling ident_case v1.0.1
[INFO] [stderr]    Compiling cfg_aliases v0.2.1
[INFO] [stderr]    Compiling futures-channel v0.3.32
[INFO] [stderr]    Compiling lazy_static v1.5.0
[INFO] [stderr]    Compiling futures-task v0.3.32
[INFO] [stderr]    Compiling bytes v1.11.1
[INFO] [stderr]    Compiling log v0.4.29
[INFO] [stderr]    Compiling futures-io v0.3.32
[INFO] [stderr]    Compiling slab v0.4.12
[INFO] [stderr]    Compiling sharded-slab v0.1.7
[INFO] [stderr]    Compiling nix v0.31.2
[INFO] [stderr]    Compiling thread_local v1.1.9
[INFO] [stderr]    Compiling smallvec v1.15.1
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling nu-ansi-term v0.50.3
[INFO] [stderr]    Compiling object v0.37.3
[INFO] [stderr]    Compiling utf8parse v0.2.2
[INFO] [stderr]    Compiling owo-colors v4.3.0
[INFO] [stderr]    Compiling ref-cast v1.0.25
[INFO] [stderr]    Compiling anstyle-parse v1.0.0
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling iana-time-zone v0.1.65
[INFO] [stderr]    Compiling adler2 v2.0.1
[INFO] [stderr]    Compiling is_terminal_polyfill v1.70.2
[INFO] [stderr]    Compiling bitflags v2.11.1
[INFO] [stderr]    Compiling anstyle-query v1.1.5
[INFO] [stderr]    Compiling thiserror v2.0.18
[INFO] [stderr]    Compiling colorchoice v1.0.5
[INFO] [stderr]    Compiling hashbrown v0.17.0
[INFO] [stderr]    Compiling color-spantrace v0.3.0
[INFO] [stderr]    Compiling anstyle v1.0.14
[INFO] [stderr]    Compiling gimli v0.32.3
[INFO] [stderr]    Compiling eyre v0.6.12
[INFO] [stderr]    Compiling equivalent v1.0.2
[INFO] [stderr]    Compiling miniz_oxide v0.8.9
[INFO] [stderr]    Compiling syn v2.0.117
[INFO] [stderr]    Compiling anstream v1.0.0
[INFO] [stderr]    Compiling indenter v0.3.4
[INFO] [stderr]    Compiling rustc-demangle v0.1.27
[INFO] [stderr]    Compiling rmcp v1.4.0
[INFO] [stderr]    Compiling dyn-clone v1.0.20
[INFO] [stderr]    Compiling heck v0.5.0
[INFO] [stderr]    Compiling indexmap v2.14.0
[INFO] [stderr]    Compiling clap_lex v1.1.0
[INFO] [stderr]    Compiling regex-automata v0.4.14
[INFO] [stderr]    Compiling base64 v0.22.1
[INFO] [stderr]    Compiling pastey v0.2.1
[INFO] [stderr]    Compiling unicode-width v0.2.2
[INFO] [stderr]    Compiling indoc v2.0.7
[INFO] [stderr]    Compiling errno v0.3.14
[INFO] [stderr]    Compiling mio v1.2.0
[INFO] [stderr]    Compiling signal-hook-registry v1.4.8
[INFO] [stderr]    Compiling clap_builder v4.6.0
[INFO] [stderr]    Compiling fs2 v0.4.3
[INFO] [stderr]    Compiling addr2line v0.25.1
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling darling_core v0.23.0
[INFO] [stderr]    Compiling serde_derive_internals v0.29.1
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling tracing-attributes v0.1.31
[INFO] [stderr]    Compiling tokio-macros v2.7.0
[INFO] [stderr]    Compiling futures-macro v0.3.32
[INFO] [stderr]    Compiling ref-cast-impl v1.0.25
[INFO] [stderr]    Compiling thiserror-impl v2.0.18
[INFO] [stderr]    Compiling schemars_derive v1.2.1
[INFO] [stderr]    Compiling async-trait v0.1.89
[INFO] [stderr]    Compiling clap_derive v4.6.1
[INFO] [stderr]    Compiling futures-util v0.3.32
[INFO] [stderr]    Compiling tokio v1.52.0
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling backtrace v0.3.76
[INFO] [stderr]    Compiling clap v4.6.1
[INFO] [stderr]    Compiling darling_macro v0.23.0
[INFO] [stderr]    Compiling darling v0.23.0
[INFO] [stderr]    Compiling rmcp-macros v1.4.0
[INFO] [stderr]    Compiling tracing-serde v0.2.0
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling tracing-subscriber v0.3.23
[INFO] [stderr]    Compiling futures-executor v0.3.32
[INFO] [stderr]    Compiling schemars v1.2.1
[INFO] [stderr]    Compiling futures v0.3.32
[INFO] [stderr]    Compiling tracing-error v0.2.1
[INFO] [stderr]    Compiling color-eyre v0.6.5
[INFO] [stderr]    Compiling tokio-util v0.7.18
[INFO] [stderr]    Compiling tokio-stream v0.1.18
[INFO] [stderr]    Compiling process-wrap v9.1.0
[INFO] [stderr]    Compiling devlogger v1.3.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 58.65s
[INFO] running `Command { std: "docker" "inspect" "adb354ec3bb8c262e00de2f54ab67872bd998c8f2ffe3a8811476f7ab9ac81b5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "adb354ec3bb8c262e00de2f54ab67872bd998c8f2ffe3a8811476f7ab9ac81b5", kill_on_drop: false }`
[INFO] [stdout] adb354ec3bb8c262e00de2f54ab67872bd998c8f2ffe3a8811476f7ab9ac81b5
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/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" "+f9988fefd3add01f414f52b414308e7872622fee" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] c6625ff08c0600441f9ec6714e5eb953a4ad64ecd802ebddb347ca3f8bbbb5b7
[INFO] running `Command { std: "docker" "start" "-a" "c6625ff08c0600441f9ec6714e5eb953a4ad64ecd802ebddb347ca3f8bbbb5b7", kill_on_drop: false }`
[INFO] [stderr]    Compiling bitflags v2.11.1
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling getrandom v0.4.2
[INFO] [stderr]    Compiling linux-raw-sys v0.12.1
[INFO] [stderr]    Compiling fastrand v2.4.1
[INFO] [stderr]    Compiling nix v0.31.2
[INFO] [stderr]    Compiling process-wrap v9.1.0
[INFO] [stderr]    Compiling rmcp v1.4.0
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling devlogger v1.3.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 35.69s
[INFO] running `Command { std: "docker" "inspect" "c6625ff08c0600441f9ec6714e5eb953a4ad64ecd802ebddb347ca3f8bbbb5b7", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c6625ff08c0600441f9ec6714e5eb953a4ad64ecd802ebddb347ca3f8bbbb5b7", kill_on_drop: false }`
[INFO] [stdout] c6625ff08c0600441f9ec6714e5eb953a4ad64ecd802ebddb347ca3f8bbbb5b7
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/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" "+f9988fefd3add01f414f52b414308e7872622fee" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] c8cbdb6f96ac6b6124a1632353a9946b8e21801134c580e3a4a9c25012ac97ca
[INFO] running `Command { std: "docker" "start" "-a" "c8cbdb6f96ac6b6124a1632353a9946b8e21801134c580e3a4a9c25012ac97ca", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.31s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/devlogger-4a9a59957d829f55)
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/devlogger-41feb2a08b55b3e3)
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/bin/devlogger-mcp.rs (/opt/rustwide/target/debug/deps/devlogger_mcp-e323c6c8fdb48fd8)
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stderr]      Running tests/cli_tests.rs (/opt/rustwide/target/debug/deps/cli_tests-da801951a25b71d4)
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 37 tests
[INFO] [stdout] test cli_tests::global_file_flag::file_flag_defaults_to_none ... ok
[INFO] [stdout] test cli_tests::global_file_flag::long_flag_is_also_global ... ok
[INFO] [stdout] test cli_tests::global_file_flag::long_flag_before_subcommand ... ok
[INFO] [stdout] test cli_tests::global_file_flag::short_flag_after_subcommand_with_positional ... ok
[INFO] [stdout] test cli_tests::global_file_flag::short_flag_before_subcommand ... ok
[INFO] [stdout] test cli_tests::global_file_flag::short_flag_after_subcommand ... ok
[INFO] [stdout] test cli_tests::help_and_version::version_flag_exits_with_version_error ... ok
[INFO] [stdout] test cli_tests::help_and_version::unknown_subcommand_is_error ... ok
[INFO] [stdout] test cli_tests::list_parse::list_with_section_arg ... ok
[INFO] [stdout] test cli_tests::help_and_version::help_flag_exits_with_help_error ... ok
[INFO] [stdout] test cli_tests::list_parse::list_without_args_parses_as_list_all ... ok
[INFO] [stdout] test cli_tests::move_parse::move_with_four_args_is_error ... ok
[INFO] [stdout] test cli_tests::move_parse::move_accepts_date_as_id ... ok
[INFO] [stdout] test cli_tests::list_parse::list_with_two_args_is_error ... ok
[INFO] [stdout] test cli_tests::move_parse::move_with_one_arg_is_error ... ok
[INFO] [stdout] test cli_tests::move_parse::move_with_two_args_is_error ... ok
[INFO] [stdout] test cli_tests::new_parse::new_preserves_entry_whitespace_inside_quotes ... ok
[INFO] [stdout] test cli_tests::help_and_version::no_subcommand_is_error ... ok
[INFO] [stdout] test cli_tests::move_parse::move_with_three_args_is_from_id_to ... ok
[INFO] [stdout] test cli_tests::new_parse::new_with_zero_args_is_error ... ok
[INFO] [stdout] test cli_tests::new_parse::new_with_two_args_is_section_and_entry ... ok
[INFO] [stdout] test cli_tests::read_parse::read_with_section_and_count ... ok
[INFO] [stdout] test cli_tests::sections_parse::sections_accepts_global_file_flag ... ok
[INFO] [stdout] test cli_tests::sections_parse::sections_rejects_positional_arg ... ok
[INFO] [stdout] test cli_tests::update_parse::update_accepts_date_as_id ... ok
[INFO] [stdout] test cli_tests::sections_parse::sections_parses_without_args ... ok
[INFO] [stdout] test cli_tests::update_parse::update_with_four_args_is_error ... ok
[INFO] [stdout] test cli_tests::move_parse::move_with_zero_args_is_error ... ok
[INFO] [stdout] test cli_tests::new_parse::new_with_one_arg_is_error ... ok
[INFO] [stdout] test cli_tests::update_parse::update_with_one_arg_is_error ... ok
[INFO] [stdout] test cli_tests::update_parse::update_with_three_args_is_section_id_entry ... ok
[INFO] [stdout] test cli_tests::read_parse::read_with_no_args_is_error ... ok
[INFO] [stdout] test cli_tests::new_parse::new_with_three_args_is_error ... ok
[INFO] [stdout] test cli_tests::update_parse::update_with_zero_args_is_error ... ok
[INFO] [stderr]      Running tests/integration.rs (/opt/rustwide/target/debug/deps/integration-59994f70b534b355)
[INFO] [stdout] test cli_tests::read_parse::read_with_three_args_is_error ... ok
[INFO] [stdout] test cli_tests::read_parse::read_with_section_arg ... ok
[INFO] [stdout] test cli_tests::update_parse::update_with_two_args_is_error ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 37 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.02s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 133 tests
[INFO] [stdout] test integration::edge_cases::list_on_file_with_only_prose_returns_empty_output ... ok
[INFO] [stdout] test integration::duplicate_numbers::update_by_exact_date_targets_correct_entry_even_with_duplicate_numbers ... ok
[INFO] [stdout] test integration::concurrency::section_gets_its_own_lockfile ... ok
[INFO] [stdout] test integration::edge_cases::f_flag_accepts_relative_path ... ok
[INFO] [stdout] test integration::edge_cases::long_entry_text_at_limit_is_accepted ... ok
[INFO] [stdout] test integration::duplicate_numbers::list_still_works_on_file_with_duplicate_numbers ... ok
[INFO] [stdout] test integration::edge_cases::empty_entry_text_is_accepted ... ok
[INFO] [stdout] test integration::edge_cases::no_trailing_newline_preserved_on_update ... ok
[INFO] [stdout] test integration::edge_cases::read_whole_file_dumps_bytes_verbatim_including_prose ... ok
[INFO] [stdout] test integration::edge_cases::read_n_on_prose_only_file_returns_empty ... ok
[INFO] [stdout] test integration::edge_cases::read_n_skips_prose_and_returns_only_entry_lines ... ok
[INFO] [stdout] test integration::edge_cases::whitespace_only_entry_text_is_accepted_and_preserved ... ok
[INFO] [stdout] test integration::concurrency::parallel_writers_to_different_sections_do_not_corrupt_each_other ... ok
[INFO] [stdout] test integration::edge_cases::update_to_identical_text_is_a_noop_in_content_but_succeeds ... ok
[INFO] [stdout] test integration::concurrency::ten_parallel_new_on_a_different_section_also_safe ... ok
[INFO] [stdout] test integration::entry_text::new_accepts_entry_exactly_at_length_limit ... ok
[INFO] [stdout] test integration::entry_text::new_accepts_tab_in_entry ... ok
[INFO] [stdout] test integration::concurrency::twenty_parallel_new_produces_twenty_unique_numbered_entries ... ok
[INFO] [stdout] test integration::entry_text::new_accepts_unicode_entry ... ok
[INFO] [stdout] test integration::edge_cases::updating_last_entry_works_correctly ... ok
[INFO] [stdout] test integration::edge_cases::updating_first_entry_works_correctly ... ok
[INFO] [stdout] test integration::concurrency::concurrent_updates_do_not_lose_writes ... ok
[INFO] [stdout] test integration::duplicate_numbers::update_by_date_prefix_errors_when_multiple_entries_match ... ok
[INFO] [stdout] test integration::edge_cases::update_errors_when_no_entries_exist_even_if_file_present ... ok
[INFO] [stdout] test integration::entry_text::new_rejects_entry_with_crlf ... ok
[INFO] [stdout] test integration::entry_text::new_rejects_entry_with_carriage_return ... ok
[INFO] [stdout] test integration::error_messages::consecutive_hyphens_section_name_error ... ok
[INFO] [stdout] test integration::entry_text::update_rejects_entry_exceeding_length_limit ... ok
[INFO] [stdout] test integration::file_layout::creates_parents_when_devlog_dir_missing ... ok
[INFO] [stdout] test integration::file_layout::devlog_folder_is_named_uppercase_devlog ... ok
[INFO] [stdout] test integration::file_layout::file_ends_with_newline ... ok
[INFO] [stdout] test integration::file_layout::no_temp_file_left_behind_after_update ... ok
[INFO] [stdout] test integration::entry_text::new_rejects_entry_with_newline ... ok
[INFO] [stdout] test integration::duplicate_numbers::update_by_ambiguous_number_errors_with_guidance ... ok
[INFO] [stdout] test integration::file_layout::section_file_matches_section_name_convention ... ok
[INFO] [stdout] test integration::help_output::binary_runs_correctly_after_help_invocations ... ok
[INFO] [stdout] test integration::help_output::help_exits_zero_and_lists_all_subcommands ... ok
[INFO] [stdout] test integration::help_output::no_args_shows_error_and_nonzero_exit ... ok
[INFO] [stdout] test integration::help_output::help_works_in_empty_directory ... ok
[INFO] [stdout] test integration::file_layout::section_devlog_nests_section_subdirectory ... ok
[INFO] [stdout] test integration::help_output::short_help_flag_works_too ... ok
[INFO] [stdout] test integration::help_output::version_exits_zero_and_has_nonempty_output ... ok
[INFO] [stdout] test integration::help_output::subcommand_help_describes_subcommand ... ok
[INFO] [stdout] test integration::line_endings::crlf_file_preserved_after_update ... ok
[INFO] [stdout] test integration::line_endings::crlf_preserved_across_prose_in_update ... ok
[INFO] [stdout] test integration::entry_text::new_rejects_arbitrary_control_char ... ok
[INFO] [stdout] test integration::line_endings::crlf_file_preserved_after_new ... ok
[INFO] [stdout] test integration::line_endings::fresh_file_uses_lf_by_default ... ok
[INFO] [stdout] test integration::line_endings::lf_file_stays_lf_after_new ... ok
[INFO] [stdout] test integration::line_endings::list_reads_crlf_file_correctly ... ok
[INFO] [stdout] test integration::line_endings::lf_file_stays_lf_after_update ... ok
[INFO] [stdout] test integration::list_flow::list_all_rows_fit_in_80_columns_including_prefix ... ok
[INFO] [stdout] test integration::list_flow::list_elided_count_is_accurate ... ok
[INFO] [stdout] test integration::list_flow::list_output_shape_matches_canonical_entry_line ... ok
[INFO] [stdout] test integration::list_flow::list_does_not_truncate_short_entries ... ok
[INFO] [stdout] test integration::list_flow::list_all_prefixes_each_line_with_section_name ... ok
[INFO] [stdout] test integration::entry_text::update_rejects_entry_with_newline ... ok
[INFO] [stdout] test integration::list_flow::list_sections_are_independent ... ok
[INFO] [stdout] test integration::duplicate_numbers::update_by_ambiguous_number_does_not_mutate_file ... ok
[INFO] [stdout] test integration::list_flow::list_truncates_by_display_width_for_wide_glyphs ... ok
[INFO] [stdout] test integration::entry_text::update_rejects_entry_with_carriage_return ... ok
[INFO] [stdout] test integration::list_flow::list_shows_entries_in_order ... ok
[INFO] [stdout] test integration::move_flow::move_appends_newer_entry_to_end_of_dest ... ok
[INFO] [stdout] test integration::move_flow::move_by_exact_date_resolves_target ... ok
[INFO] [stdout] test integration::list_flow::list_with_no_args_on_empty_project_prints_nothing ... ok
[INFO] [stdout] test integration::move_flow::move_preserves_prose_in_both_files ... ok
[INFO] [stdout] test integration::move_flow::move_renumbers_source_after_removal ... ok
[INFO] [stdout] test integration::list_flow::list_truncates_long_entries_to_80_chars_with_suffix ... ok
[INFO] [stdout] test integration::error_messages::numeric_section_name_error_mentions_the_bad_char ... ok
[INFO] [stdout] test integration::move_flow::move_slots_entry_in_middle_by_date ... ok
[INFO] [stdout] test integration::move_flow::move_to_new_section_creates_it ... ok
[INFO] [stdout] test integration::new_flow::each_entry_on_its_own_line ... ok
[INFO] [stdout] test integration::error_messages::leading_hyphen_section_name_error ... ok
[INFO] [stdout] test integration::new_flow::entry_text_with_pipes_survives_round_trip ... ok
[INFO] [stdout] test integration::new_flow::entry_text_with_colons_survives_round_trip ... ok
[INFO] [stdout] test integration::error_messages::parse_error_on_read_also_surfaces ... ok
[INFO] [stdout] test integration::new_flow::new_appends_rather_than_overwriting ... ok
[INFO] [stdout] test integration::new_flow::first_entry_numbered_one ... ok
[INFO] [stdout] test integration::new_flow::first_new_creates_devlog_directory_and_file ... ok
[INFO] [stdout] test integration::new_flow::new_without_dash_f_uses_cwd ... ok
[INFO] [stdout] test integration::new_flow::section_new_creates_section_subdir ... ok
[INFO] [stdout] test integration::error_messages::trailing_hyphen_section_name_error ... ok
[INFO] [stdout] test integration::new_flow::section_numbering_is_independent ... ok
[INFO] [stdout] test integration::new_flow::sequential_numbering ... ok
[INFO] [stdout] test integration::numbering::new_after_large_existing_number_continues_correctly ... ok
[INFO] [stdout] test integration::numbering::first_entry_in_empty_file_gets_number_one ... ok
[INFO] [stdout] test integration::numbering::next_new_continues_past_hand_edited_gap ... ok
[INFO] [stdout] test integration::entry_text::new_rejects_entry_exceeding_length_limit ... ok
[INFO] [stdout] test integration::numbering::update_preserves_number_even_for_hand_edited_non_sequential_file ... ok
[INFO] [stdout] test integration::numbering::update_does_not_shift_subsequent_numbers ... ok
[INFO] [stdout] test integration::numbering::numbering_is_per_section ... ok
[INFO] [stdout] test integration::read_flow::read_last_n_returns_tail ... ok
[INFO] [stdout] test integration::read_flow::read_full_file ... ok
[INFO] [stdout] test integration::read_flow::read_n_larger_than_count_returns_all ... ok
[INFO] [stdout] test integration::read_flow::read_last_two ... ok
[INFO] [stdout] test integration::read_flow::read_section_last_n ... ok
[INFO] [stdout] test integration::read_flow::read_section_full ... ok
[INFO] [stdout] test integration::read_flow::read_without_section_is_error ... ok
[INFO] [stdout] test integration::section_flow::hyphenated_section_names_work ... ok
[INFO] [stdout] test integration::read_flow::read_zero_returns_empty ... ok
[INFO] [stdout] test integration::section_flow::section_creates_expected_path ... ok
[INFO] [stdout] test integration::section_flow::multiple_sections_are_isolated ... ok
[INFO] [stdout] test integration::error_messages::parse_error_does_not_dump_file_contents_via_cli ... ok
[INFO] [stdout] test integration::sections_flow::sections_lists_multiple_real_sections ... ok
[INFO] [stdout] test integration::sections_flow::sections_on_empty_project_prints_nothing ... ok
[INFO] [stdout] test integration::sections_flow::sections_prints_created_sections_alphabetically ... ok
[INFO] [stdout] test integration::sections_flow::sections_reflects_added_sections_across_invocations ... ok
[INFO] [stdout] test integration::update_flow::update_by_date_prefix_when_unique ... ok
[INFO] [stdout] test integration::update_flow::update_by_exact_date ... ok
[INFO] [stdout] test integration::update_flow::update_by_number_replaces_text ... ok
[INFO] [stdout] test integration::error_messages::read_fails_on_invalid_n_format ... ok
[INFO] [stdout] test integration::move_flow::move_unknown_id_errors ... ok
[INFO] [stdout] test integration::new_flow::new_fails_on_invalid_section_name ... ok
[INFO] [stdout] test integration::error_messages::parse_error_is_single_line_with_path_and_line_number ... ok
[INFO] [stdout] test integration::error_messages::uppercase_section_name_error ... ok
[INFO] [stdout] test integration::update_flow::update_preserves_prose_between_entries ... ok
[INFO] [stdout] test integration::update_flow::update_preserves_other_entries ... ok
[INFO] [stdout] test integration::update_flow::update_section_entry ... ok
[INFO] [stdout] test integration::update_flow::update_preserves_entry_number_and_date ... ok
[INFO] [stdout] test integration::move_flow::move_rejects_invalid_dest_section ... ok
[INFO] [stdout] test integration::move_flow::move_same_section_errors ... ok
[INFO] [stdout] test integration::list_flow::list_missing_section_errors ... ok
[INFO] [stdout] test integration::list_flow::list_section_on_missing_file_errors ... ok
[INFO] [stdout] test integration::new_flow::new_reports_exhaustion_instead_of_overflowing_u32_max ... ok
[INFO] [stdout] test integration::list_flow::list_rejects_invalid_section_name ... ok
[INFO] [stdout] test integration::read_flow::read_missing_file_errors ... ok
[INFO] [stdout] test integration::update_flow::update_missing_file_errors ... ok
[INFO] [stdout] test integration::move_flow::move_missing_source_errors ... ok
[INFO] [stdout] test integration::sections_flow::sections_ignores_stray_directories ... ok
[INFO] [stdout] test integration::update_flow::update_invalid_id_errors ... ok
[INFO] [stdout] test integration::update_flow::update_rejects_invalid_section_name ... ok
[INFO] [stdout] test integration::update_flow::update_nonexistent_number_errors ... ok
[INFO] [stdout] test integration::section_flow::section_name_validation_errors_on_every_command ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 133 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 11.77s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/mcp.rs (/opt/rustwide/target/debug/deps/mcp-9c521f9f13176197)
[INFO] [stdout] 
[INFO] [stdout] running 170 tests
[INFO] [stdout] test mcp::args_schema::list_args_schema_has_no_required_fields ... ok
[INFO] [stdout] test mcp::args_schema::new_args_schema_has_required_section_and_text ... ok
[INFO] [stdout] test mcp::args_schema::arg_descriptions_travel_from_doc_comments_to_schema ... ok
[INFO] [stdout] test mcp::args_schema::update_args_schema_requires_section_id_and_text ... ok
[INFO] [stdout] test mcp::args_schema::move_args_schema_requires_from_section_id_and_to_section ... ok
[INFO] [stdout] test mcp::args_schema::sections_args_schema_has_no_required_fields ... ok
[INFO] [stdout] test mcp::base_dir::default_base_accessor_returns_configured_path ... ok
[INFO] [stdout] test mcp::base_dir::empty_string_base_dir_falls_back_to_default ... ok
[INFO] [stdout] test mcp::base_dir::list_reads_from_override_base_dir ... ok
[INFO] [stdout] test mcp::args_schema::read_args_schema_requires_only_section ... ok
[INFO] [stdout] test mcp::base_dir::new_honours_base_dir_override ... ok
[INFO] [stdout] test mcp::convert_roundtrip::entries_to_json_preserves_input_order ... ok
[INFO] [stdout] test mcp::convert_roundtrip::entry_json_serializes_to_expected_json_shape ... ok
[INFO] [stdout] test mcp::convert_roundtrip::entry_json_has_number_date_text_and_line ... ok
[INFO] [stderr] 2026-05-04T12:29:34.846146Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.847240Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::convert_roundtrip::section_entries_json_serializes_as_object_with_section_and_entries ... ok
[INFO] [stderr] 2026-05-04T12:29:34.851785Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.854969Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.854969Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.859814Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::convert_roundtrip::owned_entry_into_entry_json_works ... ok
[INFO] [stderr] 2026-05-04T12:29:34.863041Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::base_dir::new_writes_to_default_base_when_override_omitted ... ok
[INFO] [stdout] test mcp::base_dir::sections_honours_override_base_dir ... ok
[INFO] [stderr] 2026-05-04T12:29:34.876592Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.878432Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.890020Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.890557Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.892025Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::concurrency::parallel_mixed_sections_do_not_interfere ... ok
[INFO] [stderr] 2026-05-04T12:29:34.895094Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.897636Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:34.908661Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::concurrency::parallel_new_calls_produce_unique_contiguous_numbers ... ok
[INFO] [stderr] 2026-05-04T12:29:34.927349Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.353696Z  WARN rmcp::service: response error id=1 error=ErrorData { code: ErrorCode(-32602), message: "failed to deserialize parameters: missing field `text`", data: None }
[INFO] [stdout] test mcp::e2e_all_tools_errors::list_invalid_section_name_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::missing_required_argument_surfaces_as_protocol_error ... ok
[INFO] [stderr] 2026-05-04T12:29:35.359648Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::new_with_digits_in_section_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::new_with_empty_section_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::move_missing_source_section_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.365120Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.366217Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.367541Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.367908Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::list_missing_section_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::move_invalid_dest_section_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.378738Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.379649Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::new_with_newline_in_text_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.390089Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::invalid_base_dir_override_read_is_tool_error ... ok
[INFO] [stderr] 2026-05-04T12:29:35.400874Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::new_with_oversized_text_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::new_with_control_character_in_text_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::new_with_uppercase_section_is_tool_error_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::move_to_same_section_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.410127Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.410239Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::read_missing_section_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.412659Z  WARN rmcp::service: response error id=1 error=ErrorData { code: ErrorCode(-32602), message: "tool not found", data: None }
[INFO] [stderr] 2026-05-04T12:29:35.414484Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::unknown_tool_name_surfaces_as_protocol_error ... ok
[INFO] [stderr] 2026-05-04T12:29:35.416574Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.416657Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.419754Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::update_missing_section_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.451060Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.870348Z  WARN rmcp::service: response error id=1 error=ErrorData { code: ErrorCode(-32602), message: "failed to deserialize parameters: invalid type: integer `42`, expected a string", data: None }
[INFO] [stdout] test mcp::e2e_all_tools_errors::update_rejects_multiline_replacement_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::wrong_argument_type_is_rejected_at_protocol_layer ... ok
[INFO] [stdout] test mcp::e2e_all_tools_errors::update_with_oversized_text_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.876383Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_errors::update_unknown_id_is_tool_error_over_wire ... ok
[INFO] [stderr] 2026-05-04T12:29:35.883617Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_binary_cli::help_flag_prints_usage_and_exits_zero ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_list_with_section_over_wire_returns_ordered_entries ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_move_over_wire_relocates_entry_and_preserves_date ... ok
[INFO] [stdout] test mcp::e2e_binary_cli::short_help_flag_works ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_list_without_section_over_wire_groups_by_section ... ok
[INFO] [stdout] test mcp::e2e_binary_cli::unknown_flag_exits_nonzero ... ok
[INFO] [stdout] test mcp::e2e_binary_cli::version_flag_prints_crate_version ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_new_over_wire_writes_and_returns_confirmation ... ok
[INFO] [stderr] 2026-05-04T12:29:35.900704Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.903224Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_new_via_wire_with_explicit_base_dir_argument ... ok
[INFO] [stderr] 2026-05-04T12:29:35.909940Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.910934Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.911130Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:35.918013Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_base_dir::empty_string_base_dir_falls_back_to_default_over_wire ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_update_over_wire_preserves_number_and_date ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_read_full_over_wire_returns_exact_file_bytes ... ok
[INFO] [stderr] 2026-05-04T12:29:35.932045Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_base_dir::list_override_reads_from_override_directory ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_read_last_n_over_wire_returns_entry_lines_only ... ok
[INFO] [stdout] test mcp::e2e_all_tools_happy::devlog_sections_over_wire_round_trips_alphabetical ... ok
[INFO] [stderr] 2026-05-04T12:29:35.954064Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_base_dir::new_override_routes_write_to_override_directory ... ok
[INFO] [stderr] 2026-05-04T12:29:35.970686Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_base_dir::sections_override_reflects_override_layout ... ok
[INFO] [stderr] 2026-05-04T12:29:36.410730Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_handshake::initialize_completes_and_reports_crate_identity ... ok
[INFO] [stdout] test mcp::e2e_handshake::initialize_completes_within_ten_seconds ... ok
[INFO] [stdout] test mcp::e2e_binary_cli::dir_flag_is_respected_by_server ... ok
[INFO] [stderr] 2026-05-04T12:29:36.420742Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.421794Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.481333Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_inprocess_duplex::inprocess_tool_error_surfaces_as_wire_error ... ok
[INFO] [stderr] 2026-05-04T12:29:36.484414Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_large_payload::long_section_name_writes_and_reads_back ... ok
[INFO] [stdout] test mcp::e2e_handshake::server_instructions_are_non_empty_and_mention_every_tool ... ok
[INFO] [stdout] test mcp::e2e_handshake::tools_list_exposes_the_full_devlog_surface ... ok
[INFO] [stdout] test mcp::e2e_concurrency::concurrent_mixed_tool_calls_do_not_cross_contaminate ... ok
[INFO] [stdout] test mcp::e2e_base_dir::read_and_update_honour_override_base_dir ... ok
[INFO] [stdout] test mcp::e2e_inprocess_duplex::inprocess_handshake_and_tools_list_match_subprocess ... ok
[INFO] [stderr] 2026-05-04T12:29:36.493090Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.493278Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.500044Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.525221Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_inprocess_duplex::inprocess_full_tool_round_trip ... ok
[INFO] [stderr] 2026-05-04T12:29:36.529142Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.530604Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:36.630448Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_concurrency::many_concurrent_new_calls_share_one_stdio_pipe ... ok
[INFO] [stderr] 2026-05-04T12:29:36.653695Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_large_payload::multibyte_unicode_text_round_trips_intact ... ok
[INFO] [stdout] test mcp::e2e_lifecycle::client_cancel_terminates_the_server_cleanly ... ok
[INFO] [stdout] test mcp::e2e_large_payload::single_max_length_entry_text_round_trips_intact ... ok
[INFO] [stdout] test mcp::e2e_inprocess_duplex::inprocess_two_clients_with_separate_base_dirs_do_not_cross_contaminate ... ok
[INFO] [stderr] 2026-05-04T12:29:36.992456Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_lifecycle::initialize_and_list_tools_is_fast ... ok
[INFO] [stderr] 2026-05-04T12:29:36.996457Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:37.010238Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_logging::log_file_contains_tool_completion_records ... ok
[INFO] [stderr] 2026-05-04T12:29:37.015141Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stderr] 2026-05-04T12:29:37.015710Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_lifecycle::server_survives_error_call_followed_by_valid_call ... ok
[INFO] [stderr] 2026-05-04T12:29:37.064794Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_lifecycle::server_handles_rapid_sequential_calls_without_stalling ... ok
[INFO] [stderr] 2026-05-04T12:29:37.127278Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_logging::log_file_does_not_contain_entry_text ... ok
[INFO] [stderr] 2026-05-04T12:29:37.146364Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_lifecycle::stdin_close_after_tool_call_exits_cleanly ... ok
[INFO] [stderr] 2026-05-04T12:29:37.156718Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_logging::log_file_is_created_at_devlogger_log_dir ... ok
[INFO] [stderr] 2026-05-04T12:29:37.171855Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_lifecycle::session_survives_sustained_tool_call_volume ... ok
[INFO] [stdout] test mcp::e2e_logging::concurrent_tool_calls_produce_intact_log_lines ... ok
[INFO] [stdout] test mcp::e2e_logging::server_does_not_crash_when_home_is_unset ... ok
[INFO] [stdout] test mcp::e2e_stdout_cleanliness::server_exits_cleanly_when_stdin_closes ... ok
[INFO] [stdout] test mcp::e2e_logging::stdout_stays_clean_when_log_dir_is_unwritable ... ok
[INFO] [stdout] test mcp::e2e_logging::server_does_not_crash_when_log_dir_is_unwritable ... ok
[INFO] [stderr] 2026-05-04T12:29:37.504593Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_schemas::devlog_list_schema_has_no_required_fields ... ok
[INFO] [stdout] test mcp::e2e_timing::workaround_has_not_outlived_its_welcome ... ok
[INFO] [stdout] test mcp::errors::consecutive_hyphens_section_is_tool_error ... ok
[INFO] [stdout] test mcp::errors::digits_in_section_name_rejected ... ok
[INFO] [stdout] test mcp::errors::empty_section_name_is_tool_error_not_protocol ... ok
[INFO] [stdout] test mcp::errors::entry_text_with_cr_rejected ... ok
[INFO] [stdout] test mcp::errors::entry_text_with_null_rejected ... ok
[INFO] [stdout] test mcp::errors::leading_hyphen_section_is_tool_error ... ok
[INFO] [stdout] test mcp::errors::list_missing_section_is_tool_error_not_protocol ... ok
[INFO] [stdout] test mcp::e2e_schemas::devlog_new_schema_required_section_and_text ... ok
[INFO] [stdout] test mcp::e2e_schemas::devlog_move_schema_requires_from_section_id_to_section ... ok
[INFO] [stdout] test mcp::errors::trailing_hyphen_section_is_tool_error ... ok
[INFO] [stdout] test mcp::errors::tab_in_entry_text_is_allowed ... ok
[INFO] [stdout] test mcp::errors::read_missing_file_is_tool_error_not_protocol ... ok
[INFO] [stdout] test mcp::errors::underscore_in_section_name_rejected ... ok
[INFO] [stdout] test mcp::errors::update_missing_file_is_tool_error_not_protocol ... ok
[INFO] [stdout] test mcp::registration::default_base_is_exposed_on_the_server ... ok
[INFO] [stdout] test mcp::registration::server_info_advertises_tools_capability ... ok
[INFO] [stdout] test mcp::registration::server_info_reports_crate_name_and_version ... ok
[INFO] [stdout] test mcp::registration::server_info_has_instructions_mentioning_each_tool ... ok
[INFO] [stdout] test mcp::result_shape::list_single_section_structured_is_array_of_entries ... ok
[INFO] [stdout] test mcp::result_shape::new_result_has_both_text_and_structured ... ok
[INFO] [stdout] test mcp::result_shape::list_all_sections_structured_is_grouped ... ok
[INFO] [stdout] test mcp::result_shape::tool_errors_flip_is_error_and_still_carry_content ... ok
[INFO] [stdout] test mcp::result_shape::sections_structured_is_array_of_strings ... ok
[INFO] [stdout] test mcp::tool_list::list_missing_section_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_list::list_rejects_invalid_section_name ... ok
[INFO] [stdout] test mcp::result_shape::update_result_carries_full_entry_fields ... ok
[INFO] [stdout] test mcp::tool_list::list_single_section_returns_entries_in_order ... ok
[INFO] [stdout] test mcp::tool_list::list_with_section_text_matches_entries ... ok
[INFO] [stdout] test mcp::tool_list::list_without_section_and_no_sections_returns_empty_array ... ok
[INFO] [stdout] test mcp::tool_list::list_without_section_text_uses_bracket_prefix ... ok
[INFO] [stdout] test mcp::tool_list::list_without_section_groups_by_section_alphabetically ... ok
[INFO] [stdout] test mcp::tool_move::move_entry_appends_to_dest_when_newer_than_all_existing ... ok
[INFO] [stdout] test mcp::e2e_lifecycle::two_independent_server_processes_do_not_share_state ... ok
[INFO] [stdout] test mcp::tool_move::move_entry_inserts_in_middle_renumbering_trailing_entries ... ok
[INFO] [stdout] test mcp::result_shape::read_structured_wraps_contents_in_object ... ok
[INFO] [stdout] test mcp::e2e_schemas::devlog_read_schema_requires_only_section ... ok
[INFO] [stdout] test mcp::tool_move::move_entry_prepends_to_dest_when_older_than_all_existing ... ok
[INFO] [stdout] test mcp::tool_move::move_entry_by_exact_date_resolves_correctly ... ok
[INFO] [stdout] test mcp::tool_move::move_entry_renumbers_source_without_holes ... ok
[INFO] [stdout] test mcp::tool_move::move_missing_source_section_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_move::move_rejects_invalid_section_name_as_tool_error ... ok
[INFO] [stdout] test mcp::tool_move::move_entry_to_new_section_creates_it ... ok
[INFO] [stdout] test mcp::tool_move::move_preserves_prose_in_both_sections ... ok
[INFO] [stdout] test mcp::tool_move::move_preserves_original_date_on_moved_entry ... ok
[INFO] [stdout] test mcp::tool_move::move_unknown_id_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_move::move_to_same_section_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_increments_number_on_successive_calls ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_rejects_multiline_text_as_tool_error ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_rejects_invalid_section_as_tool_error ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_creates_file_and_returns_success_message ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_structured_content_has_number_date_and_message_only ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_writes_the_entry_to_disk ... ok
[INFO] [stdout] test mcp::tool_read::read_missing_section_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_read::read_invalid_section_name_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_read::read_entire_file_returns_full_contents ... ok
[INFO] [stdout] test mcp::e2e_schemas::devlog_sections_schema_has_only_optional_base_dir ... ok
[INFO] [stdout] test mcp::tool_sections::sections_empty_base_returns_empty_array ... ok
[INFO] [stdout] test mcp::tool_sections::sections_ignores_invalidly_named_directories ... ok
[INFO] [stdout] test mcp::tool_sections::sections_text_is_one_name_per_line ... ok
[INFO] [stdout] test mcp::tool_sections::sections_returns_sorted_unique_names ... ok
[INFO] [stdout] test mcp::tool_read::read_last_n_returns_only_entry_lines ... ok
[INFO] [stdout] test mcp::tool_update::update_by_date_prefix_when_unique ... ok
[INFO] [stdout] test mcp::tool_update::update_missing_section_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_update::update_by_number_replaces_text_and_preserves_id_and_date ... ok
[INFO] [stdout] test mcp::tool_read::read_n_larger_than_total_returns_all_entries ... ok
[INFO] [stdout] test mcp::tool_update::update_rejects_multiline_replacement ... ok
[INFO] [stdout] test mcp::tool_update::update_preserves_number_and_date_exactly ... ok
[INFO] [stdout] test mcp::tool_sections::sections_ignores_section_dirs_without_a_devlog_file ... ok
[INFO] [stdout] test mcp::tool_update::update_unknown_id_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_new::new_entry_creates_independent_sections ... ok
[INFO] [stdout] test mcp::tool_update::update_unknown_number_is_tool_error ... ok
[INFO] [stdout] test mcp::tool_update::update_by_exact_date_targets_the_matching_entry ... ok
[INFO] [stdout] test mcp::e2e_schemas::every_schema_declares_type_object ... ok
[INFO] [stdout] test mcp::e2e_schemas::every_tool_has_non_empty_description ... ok
[INFO] [stdout] test mcp::e2e_stdout_cleanliness::default_startup_has_no_banner_on_stderr ... ok
[INFO] [stdout] test mcp::e2e_stdout_cleanliness::every_line_on_stdout_is_a_valid_jsonrpc_frame_even_with_rust_log_trace ... ok
[INFO] [stdout] test mcp::e2e_timing::every_tool_call_completes_in_milliseconds ... ok
[INFO] [stderr] 2026-05-04T12:29:38.020573Z  WARN devlogger::mcp::claude_code_race_workaround: applying claude-code initialize-race workaround — delete src/mcp/claude_code_race_workaround.rs when upstream is fixed delay_ms=500 review_by="2026-07-20" upstream="anthropics/claude-code#50095, #43299, #40207"
[INFO] [stdout] test mcp::e2e_timing::initialize_and_tools_list_complete_in_milliseconds ... ok
[INFO] [stdout] test mcp::e2e_stdout_cleanliness::startup_log_goes_to_stderr_not_stdout_when_enabled ... ok
[INFO] [stdout] test mcp::e2e_large_payload::many_entries_round_trip_over_wire ... ok
[INFO] [stdout] test mcp::e2e_handshake::repeated_initialize_cycles_leave_no_leftover_state ... ok
[INFO] [stdout] test mcp::e2e_schemas::devlog_update_schema_requires_section_id_text has been running for over 60 seconds
[ERROR] error running command: no output for 300 seconds
[INFO] running `Command { std: "docker" "inspect" "c8cbdb6f96ac6b6124a1632353a9946b8e21801134c580e3a4a9c25012ac97ca", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c8cbdb6f96ac6b6124a1632353a9946b8e21801134c580e3a4a9c25012ac97ca", kill_on_drop: false }`
[INFO] [stdout] c8cbdb6f96ac6b6124a1632353a9946b8e21801134c580e3a4a9c25012ac97ca