[INFO] fetching crate turbomcp-server 2.3.6...
[INFO] testing turbomcp-server-2.3.6 against master#0d162b25edd5bf0dba9a22e83b614f1113e90474 for pr-150681
[INFO] extracting crate turbomcp-server 2.3.6 into /workspace/builds/worker-1-tc1/source
[INFO] started tweaking crates.io crate turbomcp-server 2.3.6
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate turbomcp-server 2.3.6
[INFO] tweaked toml for crates.io crate turbomcp-server 2.3.6 written to /workspace/builds/worker-1-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate turbomcp-server 2.3.6 on toolchain 0d162b25edd5bf0dba9a22e83b614f1113e90474
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0d162b25edd5bf0dba9a22e83b614f1113e90474" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate turbomcp-server 2.3.6 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" "+0d162b25edd5bf0dba9a22e83b614f1113e90474" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded rend v0.5.3
[INFO] [stderr]   Downloaded card-validate v2.4.0
[INFO] [stderr]   Downloaded garde_derive v0.22.1
[INFO] [stderr]   Downloaded config v0.15.19
[INFO] [stderr]   Downloaded axum-valid v0.24.0
[INFO] [stderr]   Downloaded referencing v0.33.0
[INFO] [stderr]   Downloaded jsonschema v0.33.0
[INFO] [stderr]   Downloaded raw-cpuid v11.6.0
[INFO] [stderr]   Downloaded ron v0.12.0
[INFO] [stderr]   Downloaded sonic-rs v0.3.17
[INFO] [stderr]   Downloaded simd-json v0.13.11
[INFO] [stderr]   Downloaded rkyv v0.8.12
[INFO] [stderr]   Downloaded faststr v0.2.32
[INFO] [stderr]   Downloaded aws-lc-rs v1.15.2
[INFO] [stderr]   Downloaded turbomcp-transport v2.3.6
[INFO] [stderr]   Downloaded turbomcp-protocol v2.3.6
[INFO] [stderr]   Downloaded governor v0.10.4
[INFO] [stderr]   Downloaded turbomcp-auth v2.3.6
[INFO] [stderr]   Downloaded async-compression v0.4.36
[INFO] [stderr]   Downloaded bon-macros v3.8.1
[INFO] [stderr]   Downloaded turbomcp-macros v2.3.6
[INFO] [stderr]   Downloaded yaml-rust2 v0.10.4
[INFO] [stderr]   Downloaded turbomcp-dpop v2.3.6
[INFO] [stderr]   Downloaded tower-sessions v0.13.0
[INFO] [stderr]   Downloaded secrecy v0.8.0
[INFO] [stderr]   Downloaded bon v3.8.1
[INFO] [stderr]   Downloaded schemars_derive v1.2.0
[INFO] [stderr]   Downloaded compression-codecs v0.4.35
[INFO] [stderr]   Downloaded zmij v1.0.4
[INFO] [stderr]   Downloaded halfbrown v0.2.5
[INFO] [stderr]   Downloaded garde v0.22.1
[INFO] [stderr]   Downloaded tower-cookies v0.10.0
[INFO] [stderr]   Downloaded tower-sessions-memory-store v0.13.0
[INFO] [stderr]   Downloaded quanta v0.12.6
[INFO] [stderr]   Downloaded tower_governor v0.8.0
[INFO] [stderr]   Downloaded openssl-probe v0.2.0
[INFO] [stderr]   Downloaded rustls-native-certs v0.8.3
[INFO] [stderr]   Downloaded value-trait v0.8.1
[INFO] [stderr]   Downloaded munge_macro v0.4.7
[INFO] [stderr]   Downloaded ptr_meta_derive v0.3.1
[INFO] [stderr]   Downloaded ptr_meta v0.3.1
[INFO] [stderr]   Downloaded rancor v0.1.1
[INFO] [stderr]   Downloaded sonic-number v0.1.0
[INFO] [stderr]   Downloaded oncemutex v0.1.1
[INFO] [stderr]   Downloaded regex-cache v0.2.1
[INFO] [stderr]   Downloaded tower-sessions-core v0.13.0
[INFO] [stderr]   Downloaded nonempty v0.7.0
[INFO] [stderr]   Downloaded forwarded-header-value v0.1.1
[INFO] [stderr]   Downloaded munge v0.4.7
[INFO] [stderr]   Downloaded rkyv_derive v0.8.12
[INFO] [stderr]   Downloaded sonic-simd v0.1.2
[INFO] [stderr]   Downloaded phonenumber v0.3.7+8.13.52
[INFO] [stderr]   Downloaded aws-lc-sys v0.35.0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:845e597a41426bbf2703be69acdb67d10b6de511142d05cba7bbe119c898b2c7" "/opt/rustwide/cargo-home/bin/cargo" "+0d162b25edd5bf0dba9a22e83b614f1113e90474" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 3ff3ddf0c2ff0f8430e28992cda2d626522236fcdbf6eec644b95fc0bbd8b4e1
[INFO] running `Command { std: "docker" "start" "-a" "3ff3ddf0c2ff0f8430e28992cda2d626522236fcdbf6eec644b95fc0bbd8b4e1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "3ff3ddf0c2ff0f8430e28992cda2d626522236fcdbf6eec644b95fc0bbd8b4e1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "3ff3ddf0c2ff0f8430e28992cda2d626522236fcdbf6eec644b95fc0bbd8b4e1", kill_on_drop: false }`
[INFO] [stdout] 3ff3ddf0c2ff0f8430e28992cda2d626522236fcdbf6eec644b95fc0bbd8b4e1
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:845e597a41426bbf2703be69acdb67d10b6de511142d05cba7bbe119c898b2c7" "/opt/rustwide/cargo-home/bin/cargo" "+0d162b25edd5bf0dba9a22e83b614f1113e90474" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] cef681fef1c903e466421ddf442eb0c396884e6aaf4641969ae65d8939cc9291
[INFO] running `Command { std: "docker" "start" "-a" "cef681fef1c903e466421ddf442eb0c396884e6aaf4641969ae65d8939cc9291", kill_on_drop: false }`
[INFO] [stderr]    Compiling serde_core v1.0.228
[INFO] [stderr]    Compiling zerocopy v0.8.31
[INFO] [stderr]    Compiling proc-macro2 v1.0.104
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling zmij v1.0.4
[INFO] [stderr]    Compiling ahash v0.8.12
[INFO] [stderr]    Compiling ref-cast v1.0.25
[INFO] [stderr]    Compiling lexical-util v1.0.7
[INFO] [stderr]    Compiling errno v0.3.14
[INFO] [stderr]    Compiling futures-channel v0.3.31
[INFO] [stderr]    Compiling simdutf8 v0.1.5
[INFO] [stderr]    Compiling futures-io v0.3.31
[INFO] [stderr]    Compiling mio v1.1.1
[INFO] [stderr]    Compiling socket2 v0.6.1
[INFO] [stderr]    Compiling serde_json v1.0.148
[INFO] [stderr]    Compiling signal-hook-registry v1.4.8
[INFO] [stderr]    Compiling crunchy v0.2.4
[INFO] [stderr]    Compiling tiny-keccak v2.0.2
[INFO] [stderr]    Compiling hashbrown v0.15.5
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling castaway v0.2.4
[INFO] [stderr]    Compiling quote v1.0.42
[INFO] [stderr]    Compiling getrandom v0.2.16
[INFO] [stderr]    Compiling sonic-number v0.1.0
[INFO] [stderr]    Compiling sonic-simd v0.1.2
[INFO] [stderr]    Compiling syn v2.0.112
[INFO] [stderr]    Compiling simd-adler32 v0.3.8
[INFO] [stderr]    Compiling bumpalo v3.19.1
[INFO] [stderr]    Compiling crossbeam-deque v0.8.6
[INFO] [stderr]    Compiling crossbeam-channel v0.5.15
[INFO] [stderr]    Compiling crossbeam-queue v0.3.12
[INFO] [stderr]    Compiling float-cmp v0.9.0
[INFO] [stderr]    Compiling arc-swap v1.8.0
[INFO] [stderr]    Compiling const-random-macro v0.1.16
[INFO] [stderr]    Compiling miniz_oxide v0.8.9
[INFO] [stderr]    Compiling erased-serde v0.4.9
[INFO] [stderr]    Compiling lexical-write-integer v1.0.6
[INFO] [stderr]    Compiling lexical-parse-integer v1.0.6
[INFO] [stderr]    Compiling tracing-core v0.1.36
[INFO] [stderr]    Compiling winnow v0.7.14
[INFO] [stderr]    Compiling num-integer v0.1.46
[INFO] [stderr]    Compiling lexical-parse-float v1.0.6
[INFO] [stderr]    Compiling const-random v0.1.18
[INFO] [stderr]    Compiling dlv-list v0.5.2
[INFO] [stderr]    Compiling num-complex v0.4.6
[INFO] [stderr]    Compiling flate2 v1.1.5
[INFO] [stderr]    Compiling bit-vec v0.8.0
[INFO] [stderr]    Compiling lexical-write-float v1.0.6
[INFO] [stderr]    Compiling borrow-or-share v0.2.4
[INFO] [stderr]    Compiling crossbeam v0.8.4
[INFO] [stderr]    Compiling form_urlencoded v1.2.2
[INFO] [stderr]    Compiling num-bigint v0.4.6
[INFO] [stderr]    Compiling num-iter v0.1.45
[INFO] [stderr]    Compiling bit-set v0.8.0
[INFO] [stderr]    Compiling hashlink v0.10.0
[INFO] [stderr]    Compiling dyn-clone v1.0.20
[INFO] [stderr]    Compiling vsimd v0.8.0
[INFO] [stderr]    Compiling outref v0.5.2
[INFO] [stderr]    Compiling arraydeque v0.5.1
[INFO] [stderr]    Compiling convert_case v0.6.0
[INFO] [stderr]    Compiling hdrhistogram v7.5.4
[INFO] [stderr]    Compiling tracing-log v0.2.0
[INFO] [stderr]    Compiling bytecount v0.6.9
[INFO] [stderr]    Compiling lexical-core v1.0.6
[INFO] [stderr]    Compiling num-cmp v0.1.0
[INFO] [stderr]    Compiling yaml-rust2 v0.10.4
[INFO] [stderr]    Compiling pathdiff v0.2.3
[INFO] [stderr]    Compiling uuid v1.19.0
[INFO] [stderr]    Compiling serde_spanned v1.0.4
[INFO] [stderr]    Compiling bitflags v2.10.0
[INFO] [stderr]    Compiling toml_datetime v0.7.5+spec-1.1.0
[INFO] [stderr]    Compiling num-rational v0.4.2
[INFO] [stderr]    Compiling num v0.4.3
[INFO] [stderr]    Compiling serde-untagged v0.1.9
[INFO] [stderr]    Compiling fraction v0.15.3
[INFO] [stderr]    Compiling uuid-simd v0.8.0
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling fancy-regex v0.16.2
[INFO] [stderr]    Compiling matchers v0.2.0
[INFO] [stderr]    Compiling toml_parser v1.0.6+spec-1.1.0
[INFO] [stderr]    Compiling toml v0.9.10+spec-1.1.0
[INFO] [stderr]    Compiling synstructure v0.13.2
[INFO] [stderr]    Compiling serde_derive_internals v0.29.1
[INFO] [stderr]    Compiling pest_generator v2.8.4
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling zerocopy-derive v0.8.31
[INFO] [stderr]    Compiling zerofrom-derive v0.1.6
[INFO] [stderr]    Compiling yoke-derive v0.8.1
[INFO] [stderr]    Compiling ref-cast-impl v1.0.25
[INFO] [stderr]    Compiling zerovec-derive v0.11.2
[INFO] [stderr]    Compiling displaydoc v0.2.5
[INFO] [stderr]    Compiling futures-macro v0.3.31
[INFO] [stderr]    Compiling tokio-macros v2.6.0
[INFO] [stderr]    Compiling tracing-attributes v0.1.31
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling async-trait v0.1.89
[INFO] [stderr]    Compiling pest_derive v2.8.4
[INFO] [stderr]    Compiling schemars_derive v1.2.0
[INFO] [stderr]    Compiling futures-util v0.3.31
[INFO] [stderr]    Compiling zerofrom v0.1.6
[INFO] [stderr]    Compiling tokio v1.48.0
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling yoke v0.8.1
[INFO] [stderr]    Compiling zerovec v0.11.5
[INFO] [stderr]    Compiling zerotrie v0.2.3
[INFO] [stderr]    Compiling thiserror v2.0.17
[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 serde v1.0.228
[INFO] [stderr]    Compiling smallvec v1.15.1
[INFO] [stderr]    Compiling faststr v0.2.32
[INFO] [stderr]    Compiling compact_str v0.7.1
[INFO] [stderr]    Compiling chrono v0.4.42
[INFO] [stderr]    Compiling schemars v1.2.0
[INFO] [stderr]    Compiling sonic-rs v0.3.17
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling icu_provider v2.1.1
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling fluent-uri v0.3.2
[INFO] [stderr]    Compiling tracing-serde v0.2.0
[INFO] [stderr]    Compiling email_address v0.2.9
[INFO] [stderr]    Compiling icu_properties v2.1.2
[INFO] [stderr]    Compiling json5 v0.4.1
[INFO] [stderr]    Compiling icu_normalizer v2.1.1
[INFO] [stderr]    Compiling ron v0.12.0
[INFO] [stderr]    Compiling tracing-subscriber v0.3.22
[INFO] [stderr]    Compiling half v2.7.1
[INFO] [stderr]    Compiling ppv-lite86 v0.2.21
[INFO] [stderr]    Compiling hashbrown v0.14.5
[INFO] [stderr]    Compiling referencing v0.33.0
[INFO] [stderr]    Compiling ciborium-ll v0.2.2
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling idna_adapter v1.2.1
[INFO] [stderr]    Compiling rand v0.9.2
[INFO] [stderr]    Compiling ciborium v0.2.2
[INFO] [stderr]    Compiling idna v1.1.0
[INFO] [stderr]    Compiling futures-executor v0.3.31
[INFO] [stderr]    Compiling halfbrown v0.2.5
[INFO] [stderr]    Compiling dashmap v6.1.0
[INFO] [stderr]    Compiling futures v0.3.31
[INFO] [stderr]    Compiling value-trait v0.8.1
[INFO] [stderr]    Compiling ordered-multimap v0.7.3
[INFO] [stderr]    Compiling url v2.5.7
[INFO] [stderr]    Compiling jsonschema v0.33.0
[INFO] [stderr]    Compiling simd-json v0.13.11
[INFO] [stderr]    Compiling rust-ini v0.21.3
[INFO] [stderr]    Compiling config v0.15.19
[INFO] [stderr]    Compiling tokio-util v0.7.17
[INFO] [stderr]    Compiling turbomcp-protocol v2.3.6
[INFO] [stderr]    Compiling tower v0.5.2
[INFO] [stderr]    Compiling turbomcp-transport v2.3.6
[INFO] [stderr]    Compiling turbomcp-macros v2.3.6
[INFO] [stderr]    Compiling turbomcp-server v2.3.6 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 37s
[INFO] running `Command { std: "docker" "inspect" "cef681fef1c903e466421ddf442eb0c396884e6aaf4641969ae65d8939cc9291", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "cef681fef1c903e466421ddf442eb0c396884e6aaf4641969ae65d8939cc9291", kill_on_drop: false }`
[INFO] [stdout] cef681fef1c903e466421ddf442eb0c396884e6aaf4641969ae65d8939cc9291
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:845e597a41426bbf2703be69acdb67d10b6de511142d05cba7bbe119c898b2c7" "/opt/rustwide/cargo-home/bin/cargo" "+0d162b25edd5bf0dba9a22e83b614f1113e90474" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 62e6f62d176e7b80704da5a9aa873bafc694a2404553ae49f6a57c0b34c97797
[INFO] running `Command { std: "docker" "start" "-a" "62e6f62d176e7b80704da5a9aa873bafc694a2404553ae49f6a57c0b34c97797", kill_on_drop: false }`
[INFO] [stderr]    Compiling bitflags v2.10.0
[INFO] [stderr]    Compiling bit-vec v0.8.0
[INFO] [stderr]    Compiling crossbeam-deque v0.8.6
[INFO] [stderr]    Compiling rustix v1.1.3
[INFO] [stderr]    Compiling crossbeam v0.8.4
[INFO] [stderr]    Compiling rayon-core v1.13.0
[INFO] [stderr]    Compiling anstyle v1.0.13
[INFO] [stderr]    Compiling clap_lex v0.7.6
[INFO] [stderr]    Compiling wait-timeout v0.2.1
[INFO] [stderr]    Compiling tinytemplate v1.2.1
[INFO] [stderr]    Compiling plotters v0.3.7
[INFO] [stderr]    Compiling criterion-plot v0.6.0
[INFO] [stderr]    Compiling rand_xorshift v0.4.0
[INFO] [stderr]    Compiling turbomcp-protocol v2.3.6
[INFO] [stderr]    Compiling ron v0.12.0
[INFO] [stderr]    Compiling bit-set v0.8.0
[INFO] [stderr]    Compiling clap_builder v4.5.53
[INFO] [stderr]    Compiling fancy-regex v0.16.2
[INFO] [stderr]    Compiling rayon v1.11.0
[INFO] [stderr]    Compiling jsonschema v0.33.0
[INFO] [stderr]    Compiling config v0.15.19
[INFO] [stderr]    Compiling tempfile v3.24.0
[INFO] [stderr]    Compiling rusty-fork v0.3.1
[INFO] [stderr]    Compiling proptest v1.9.0
[INFO] [stderr]    Compiling clap v4.5.53
[INFO] [stderr]    Compiling criterion v0.7.0
[INFO] [stderr]    Compiling turbomcp-transport v2.3.6
[INFO] [stderr]    Compiling turbomcp-macros v2.3.6
[INFO] [stderr]    Compiling turbomcp-server v2.3.6 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 1m 01s
[INFO] running `Command { std: "docker" "inspect" "62e6f62d176e7b80704da5a9aa873bafc694a2404553ae49f6a57c0b34c97797", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "62e6f62d176e7b80704da5a9aa873bafc694a2404553ae49f6a57c0b34c97797", kill_on_drop: false }`
[INFO] [stdout] 62e6f62d176e7b80704da5a9aa873bafc694a2404553ae49f6a57c0b34c97797
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:845e597a41426bbf2703be69acdb67d10b6de511142d05cba7bbe119c898b2c7" "/opt/rustwide/cargo-home/bin/cargo" "+0d162b25edd5bf0dba9a22e83b614f1113e90474" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 6c49f85da73e81893f0149d8f613bf7bb45f0e8bcc47845ec217c46dd76aaaaf
[INFO] running `Command { std: "docker" "start" "-a" "6c49f85da73e81893f0149d8f613bf7bb45f0e8bcc47845ec217c46dd76aaaaf", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.51s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/turbomcp_server-9ad9231b9b4d177c)
[INFO] [stdout] 
[INFO] [stdout] running 192 tests
[INFO] [stdout] test capabilities::tests::test_adapter_implements_trait ... ok
[INFO] [stdout] test capabilities::tests::test_adapter_creation ... ok
[INFO] [stdout] test capabilities::tests::test_adapter_is_send_sync ... ok
[INFO] [stdout] test config::inline_tests::test_default_config ... ok
[INFO] [stdout] test capabilities::tests::test_adapter_clone ... ok
[INFO] [stdout] test config::tests::test_builder_bind_address ... ok
[INFO] [stdout] test config::tests::test_builder_description ... ok
[INFO] [stdout] test config::tests::test_builder_log_level ... ok
[INFO] [stdout] test config::tests::test_builder_partial_configuration ... ok
[INFO] [stdout] test config::tests::test_builder_port ... ok
[INFO] [stdout] test config::tests::test_builder_method_chaining ... ok
[INFO] [stdout] test config::tests::test_builder_name ... ok
[INFO] [stdout] test config::tests::test_builder_rate_limiting ... ok
[INFO] [stdout] test config::tests::test_builder_request_timeout ... ok
[INFO] [stdout] test config::tests::test_builder_tls ... ok
[INFO] [stdout] test config::tests::test_builder_version ... ok
[INFO] [stdout] test config::inline_tests::test_config_builder ... ok
[INFO] [stdout] test config::tests::test_config_debug_formatting ... ok
[INFO] [stdout] test config::tests::test_configuration_builder_default ... ok
[INFO] [stdout] test config::tests::test_empty_string_configurations ... ok
[INFO] [stdout] test config::tests::test_configuration_compatibility ... ok
[INFO] [stdout] test config::tests::test_extreme_timeout_values ... ok
[INFO] [stdout] test config::tests::test_config_clone ... ok
[INFO] [stdout] test config::tests::test_configuration_builder_new ... ok
[INFO] [stdout] test config::tests::test_development_config ... ok
[INFO] [stdout] test config::tests::test_production_like_config ... ok
[INFO] [stdout] test config::tests::test_server_config_json_roundtrip ... ok
[INFO] [stdout] test config::tests::test_server_config_serialization ... ok
[INFO] [stdout] test config::tests::test_timeout_config_default ... ok
[INFO] [stdout] test config::tests::test_tls_config_creation ... ok
[INFO] [stdout] test config::tests::test_tls_config_serialization ... ok
[INFO] [stdout] test config::tests::test_unicode_string_configurations ... ok
[INFO] [stdout] test config::tests::test_rate_limiting_config_default ... ok
[INFO] [stdout] test config::tests::test_logging_config_default ... ok
[INFO] [stdout] test config::tests::test_server_config_default ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_api_surface ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_cloning ... ok
[INFO] [stdout] test elicitation::tests::test_coordinator_creation ... ok
[INFO] [stdout] test config::tests::test_large_additional_fields ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_with_config ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_concurrent_access ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_creation ... ok
[INFO] [stdout] test error::tests::test_error_context_creation ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_default ... ok
[INFO] [stdout] test config::inline_tests::proptest_tests::test_config_port_roundtrip ... ok
[INFO] [stdout] test config::tests::test_builder_reuse ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_send_sync ... ok
[INFO] [stdout] test config::tests::test_extreme_port_values ... ok
[INFO] [stdout] test config::tests::test_extreme_rate_limiting_values ... ok
[INFO] [stdout] test error::tests::test_error_context_builder_pattern ... ok
[INFO] [stdout] test error::tests::test_all_error_variants_coverage ... ok
[INFO] [stdout] test error::tests::test_error_context_clone ... ok
[INFO] [stdout] test error::tests::test_error_context_debug_formatting ... ok
[INFO] [stdout] test error::tests::test_server_error_display ... ok
[INFO] [stdout] test error::tests::test_server_error_fatal ... ok
[INFO] [stdout] test error::tests::test_server_error_from_serde_error ... ok
[INFO] [stdout] test error::tests::test_server_error_retryable ... ok
[INFO] [stdout] test elicitation::tests::test_shared_coordinator_type_compatibility ... ok
[INFO] [stdout] test error::tests::test_server_result_type ... ok
[INFO] [stdout] test error_sanitization::tests::test_display_mode_default ... ok
[INFO] [stdout] test error_sanitization::tests::test_generic_error_message ... ok
[INFO] [stdout] test error::tests::test_error_recovery_enum ... ok
[INFO] [stdout] test error::tests::test_server_error_codes ... ok
[INFO] [stdout] test error::tests::test_server_error_constructors ... ok
[INFO] [stdout] test error::tests::test_server_error_from_io_error ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitized_error_development_mode ... ok
[INFO] [stdout] test elicitation::tests::test_coordinator_response_handling ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_urls ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_email_addresses ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_connection_strings ... ok
[INFO] [stdout] test lifecycle::tests::test_add_health_check ... ok
[INFO] [stdout] test lifecycle::tests::test_empty_health_checks_list ... ok
[INFO] [stdout] test lifecycle::tests::test_concurrent_health_access ... ok
[INFO] [stdout] test lifecycle::tests::test_health_check_clone ... ok
[INFO] [stdout] test lifecycle::tests::test_concurrent_state_access ... ok
[INFO] [stdout] test lifecycle::tests::test_health_check_creation ... ok
[INFO] [stdout] test lifecycle::tests::test_health_check_debug ... ok
[INFO] [stdout] test lifecycle::tests::test_health_check_with_different_string_types ... ok
[INFO] [stdout] test lifecycle::tests::test_health_status_clone ... ok
[INFO] [stdout] test lifecycle::tests::test_health_status_debug ... ok
[INFO] [stdout] test lifecycle::tests::test_health_status_creation ... ok
[INFO] [stdout] test lifecycle::tests::test_lifecycle_debug ... ok
[INFO] [stdout] test lifecycle::tests::test_multiple_health_checks_same_name ... ok
[INFO] [stdout] test lifecycle::tests::test_multiple_shutdown_subscribers ... ok
[INFO] [stdout] test lifecycle::tests::test_realistic_server_lifecycle_scenario ... ok
[INFO] [stdout] test lifecycle::tests::test_server_lifecycle_creation ... ok
[INFO] [stdout] test lifecycle::tests::test_server_lifecycle_default ... ok
[INFO] [stdout] test lifecycle::tests::test_server_shutdown ... ok
[INFO] [stdout] test lifecycle::tests::test_server_start ... ok
[INFO] [stdout] test lifecycle::tests::test_add_health_check_updates_timestamp ... ok
[INFO] [stdout] test lifecycle::tests::test_server_state_debug ... ok
[INFO] [stdout] test lifecycle::tests::test_server_state_equality ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_secrets ... ok
[INFO] [stdout] test lifecycle::tests::test_health_check_timestamps ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_ipv4_addresses ... ok
[INFO] [stdout] test lifecycle::tests::test_server_state_transitions ... ok
[INFO] [stdout] test lifecycle::tests::test_shutdown_signal ... ok
[INFO] [stdout] test lifecycle::tests::test_update_health_status_unhealthy ... ok
[INFO] [stdout] test metrics::tests::test_connection_metrics ... ok
[INFO] [stdout] test metrics::tests::test_custom_metrics ... ok
[INFO] [stdout] test lifecycle::tests::test_shutdown_signal_receiver_drop ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_ipv6_addresses ... ok
[INFO] [stdout] test metrics::tests::test_calculated_metrics ... ok
[INFO] [stdout] test metrics::tests::test_error_rate_calculation ... ok
[INFO] [stdout] test metrics::tests::test_error_tracking ... ok
[INFO] [stdout] test metrics::tests::test_server_metrics_creation ... ok
[INFO] [stdout] test metrics::tests::test_record_request_lifecycle ... ok
[INFO] [stdout] test metrics::tests::test_server_metrics_default ... ok
[INFO] [stdout] test metrics::tests::test_resource_metrics ... ok
[INFO] [stdout] test observability::tests::test_observability_config_defaults ... ok
[INFO] [stdout] test metrics::tests::test_response_time_histogram ... ok
[INFO] [stdout] test observability::tests::test_observability_config_builder ... ok
[INFO] [stdout] test observability::tests::test_global_observability ... ok
[INFO] [stdout] test metrics::tests::test_tool_call_metrics ... ok
[INFO] [stdout] test registry::tests::test_handler_metadata_clone ... ok
[INFO] [stdout] test observability::tests::test_performance_monitor ... ok
[INFO] [stdout] test lifecycle::tests::test_update_health_status ... ok
[INFO] [stdout] test observability::tests::test_security_audit_logger ... ok
[INFO] [stdout] test registry::tests::test_handler_metadata_creation ... ok
[INFO] [stdout] test observability::tests::test_observability_initialization_enables_logging ... ok
[INFO] [stdout] test registry::tests::test_handler_metadata_debug ... ok
[INFO] [stdout] test registry::tests::test_handler_metadata_version_patterns ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.737497Z","level":"INFO","fields":{"message":"TurboMCP observability initialized successfully","service_name":"regression-test","service_version":"2.3.6","security_auditing":true,"performance_monitoring":true},"target":"turbomcp_server::observability","filename":"src/observability.rs","line_number":166,"threadId":"ThreadId(127)"}
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.737603Z","level":"INFO","fields":{"message":"Test log message to stderr"},"target":"turbomcp_server::observability::tests","filename":"src/observability.rs","line_number":625,"threadId":"ThreadId(127)"}
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.737638Z","level":"INFO","fields":{"message":"Shutting down TurboMCP observability"},"target":"turbomcp_server::observability","filename":"src/observability.rs","line_number":190,"threadId":"ThreadId(127)"}
[INFO] [stdout] test registry::tests::test_handler_metadata_default ... ok
[INFO] [stdout] test registry::tests::test_registry_collections_empty ... ok
[INFO] [stdout] test registry::tests::test_handler_metadata_optional_fields ... ok
[INFO] [stdout] test registry::tests::test_handler_registry_debug ... ok
[INFO] [stdout] test registry::tests::test_registry_config_boundaries ... ok
[INFO] [stdout] test registry::tests::test_registry_config_clone ... ok
[INFO] [stdout] test registry::tests::test_registry_config_debug ... ok
[INFO] [stdout] test registry::tests::test_registry_config_custom ... ok
[INFO] [stdout] test registry::tests::test_registry_config_default ... ok
[INFO] [stdout] test registry::tests::test_registry_config_event_listeners_management ... ok
[INFO] [stdout] test registry::tests::test_registry_debug_with_empty_collections ... ok
[INFO] [stdout] test registry::tests::test_handler_registry_creation ... ok
[INFO] [stdout] test registry::tests::test_registry_event_clone ... ok
[INFO] [stdout] test registry::tests::test_registry_event_handler_updated ... ok
[INFO] [stdout] test registry::tests::test_registry_event_debug ... ok
[INFO] [stdout] test registry::tests::test_registry_event_handler_unregistered ... ok
[INFO] [stdout] test registry::tests::test_registry_event_handler_registered ... ok
[INFO] [stdout] test registry::tests::test_registry_creation_consistency ... ok
[INFO] [stdout] test registry::tests::test_registry_event_timestamp_ordering ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.749777Z","level":"INFO","fields":{"message":"Registered resource handler: stdio://test_resource"},"target":"turbomcp_server::registry","filename":"src/registry.rs","line_number":365,"threadId":"ThreadId(160)"}
[INFO] [stdout] test routing::tests::test_request_router_debug ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.750048Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(165)"}
[INFO] [stdout] test routing::tests::test_request_router_new ... ok
[INFO] [stdout] test routing::tests::test_request_router_with_config ... ok
[INFO] [stdout] test registry::tests::test_resource_registration_lookup_by_uri ... ok
[INFO] [stdout] test routing::tests::test_route_empty_method ... ok
[INFO] [stdout] test routing::tests::test_route_metadata_clone ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.754492Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(167)"}
[INFO] [stdout] test routing::tests::test_route_metadata_custom ... ok
[INFO] [stdout] test routing::tests::test_route_metadata_debug ... ok
[INFO] [stdout] test routing::tests::test_route_metadata_default ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.756953Z","level":"DEBUG","fields":{"message":"Client protocol version supported, using it","client_version":"2024-11-05"},"target":"turbomcp_server::routing::handlers::initialize","filename":"src/routing/handlers/initialize.rs","line_number":41,"threadId":"ThreadId(166)"}
[INFO] [stdout] test routing::tests::test_custom_route_integration ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.757212Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(167)"}
[INFO] [stdout] test registry::tests::test_registry_event_types ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.759862Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(173)"}
[INFO] [stdout] test routing::tests::test_route_method_not_found ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.760099Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(173)"}
[INFO] [stdout] test routing::tests::test_route_initialize_request ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.760384Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(173)"}
[INFO] [stdout] test routing::tests::test_route_logging_and_sampling ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.760889Z","level":"INFO","fields":{"message":"🔍 [ServerError::error_code] Returning code: -32603 for variant: Discriminant(12)"},"target":"turbomcp_server::error","filename":"src/error.rs","line_number":346,"threadId":"ThreadId(176)"}
[INFO] [stdout] test routing::tests::test_route_tools_list_request ... ok
[INFO] [stdout] test routing::tests::test_router_add_route ... ok
[INFO] [stdout] test routing::tests::test_router_config_clone ... ok
[INFO] [stdout] test routing::tests::test_route_resource_methods ... ok
[INFO] [stdout] test routing::tests::test_router_config_custom ... ok
[INFO] [stdout] test routing::tests::test_router_config_debug ... ok
[INFO] [stdout] test routing::tests::test_router_config_default ... ok
[INFO] [stdout] test routing::tests::test_simple_route_handler ... ok
[INFO] [stdout] test routing::tests::test_route_with_validation_disabled ... ok
[INFO] [stdout] test routing::tests::test_route_very_long_method ... ok
[INFO] [stdout] test routing::tests::test_router_different_configurations ... ok
[INFO] [stdout] test runtime::tests::test_stdio_dispatcher_clean_shutdown ... ok
[INFO] [stdout] test runtime::tests::test_stdio_dispatcher_creation ... ok
[INFO] [stdout] test runtime::tests::test_stdio_message_types ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.765947Z","level":"WARN","fields":{"message":"🔒 SECURITY NOTICE: Binding to all interfaces (0.0.0.0)\n\n⚠️  Binding to 0.0.0.0 exposes your server on ALL network interfaces.\n\nSecurity Checklist:\n✓ Is authentication enabled? (recommended for 0.0.0.0)\n✓ Is this behind a reverse proxy? (nginx, traefik, cloudflare)\n✓ Is firewall configured? (only allow intended sources)\n✓ Is TLS/HTTPS enabled? (required for production)\n\nBest Practices:\n- Production: Bind to specific interface (10.0.1.5:8080)\n- Development: Bind to localhost (127.0.0.1:8080)\n- Cloud: Use reverse proxy for TLS termination\n\nCurrent binding: \"\\\"0.0.0.0:8080\\\"\"\n\nSee: OWASP Top 10 - Broken Access Control (A01:2021)\nSee: CWE-284 - Improper Access Control"},"target":"turbomcp_server::security_checks","filename":"src/security_checks.rs","line_number":102,"threadId":"ThreadId(191)"}
[INFO] [stdout] test security_checks::tests::test_all_interfaces_warning ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.766364Z","level":"WARN","fields":{"message":"🔒 SECURITY NOTICE: Binding to all interfaces (0.0.0.0)\n\n⚠️  Binding to 0.0.0.0 exposes your server on ALL network interfaces.\n\nSecurity Checklist:\n✓ Is authentication enabled? (recommended for 0.0.0.0)\n✓ Is this behind a reverse proxy? (nginx, traefik, cloudflare)\n✓ Is firewall configured? (only allow intended sources)\n✓ Is TLS/HTTPS enabled? (required for production)\n\nBest Practices:\n- Production: Bind to specific interface (10.0.1.5:8080)\n- Development: Bind to localhost (127.0.0.1:8080)\n- Cloud: Use reverse proxy for TLS termination\n\nCurrent binding: \"\\\"[::]:8080\\\"\"\n\nSee: OWASP Top 10 - Broken Access Control (A01:2021)\nSee: CWE-284 - Improper Access Control"},"target":"turbomcp_server::security_checks","filename":"src/security_checks.rs","line_number":102,"threadId":"ThreadId(192)"}
[INFO] [stdout] test security_checks::tests::test_ipv6_all_interfaces ... ok
[INFO] [stdout] test security_checks::tests::test_localhost_binding_no_warning ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.768061Z","level":"DEBUG","fields":{"message":"Starting tool execution with timeout","tool_name":"long_running","execution_id":"bd6a6885-dc97-4311-ad0f-1c3ffa17de31","timeout_seconds":3},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":115,"span":{"tool_name":"long_running","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"long_running","name":"execute_with_timeout"},{"tool_name":"long_running","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(194)"}
[INFO] [stdout] test config::inline_tests::proptest_tests::test_config_name_preservation ... ok
[INFO] [stdout] test timeout::tests::test_per_tool_timeout_override ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.771549Z","level":"DEBUG","fields":{"message":"Starting tool execution with timeout","tool_name":"test_tool","execution_id":"48819006-e3cf-4196-b94f-ca36130327ce","timeout_seconds":3},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":115,"span":{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"test_tool","name":"execute_with_timeout"},{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(196)"}
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.771720Z","level":"WARN","fields":{"message":"Tool execution failed with server error","tool_name":"test_tool","execution_id":"48819006-e3cf-4196-b94f-ca36130327ce","elapsed_ms":"0","error":"Handler error: custom error"},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":175,"span":{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"test_tool","name":"execute_with_timeout"},{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(196)"}
[INFO] [stdout] test timeout::tests::test_server_error_propagation ... ok
[INFO] [stdout] test runtime::tests::test_pending_requests_cleanup ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.772673Z","level":"DEBUG","fields":{"message":"Starting tool execution with timeout","tool_name":"test_tool","execution_id":"69a96993-0134-4484-a48d-a52762ee7c5f","timeout_seconds":3},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":115,"span":{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"test_tool","name":"execute_with_timeout"},{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(197)"}
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.773432Z","level":"DEBUG","fields":{"message":"Starting tool execution with timeout","tool_name":"fast_tool","execution_id":"4d7ed013-99dc-4545-a8b5-7e35b5557d59","timeout_seconds":1},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":115,"span":{"tool_name":"fast_tool","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"fast_tool","name":"execute_with_timeout"},{"tool_name":"fast_tool","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(198)"}
[INFO] [stdout] test lifecycle::tests::test_server_state_clone_copy ... ok
[INFO] [stdout] test timeout::tests::test_active_executions_tracking ... ok
[INFO] [stdout] test registry::tests::test_registry_collections_thread_safety ... ok
[INFO] [stdout] test elicitation::tests::test_coordinator_stats ... ok
[INFO] [stdout] test runtime::tests::test_joinset_task_tracking ... ok
[INFO] [stdout] test routing::tests::test_simple_route_handler_handle ... ok
[INFO] [stdout] test error_sanitization::tests::test_no_false_positives ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitized_error_production_mode ... ok
[INFO] [stdout] test runtime::tests::test_joinset_with_timeout ... ok
[INFO] [stdout] test config::inline_tests::proptest_tests::test_rate_limiting_config ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:18.874384Z","level":"DEBUG","fields":{"message":"Tool execution completed successfully","tool_name":"test_tool","execution_id":"69a96993-0134-4484-a48d-a52762ee7c5f","elapsed_ms":"101"},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":166,"span":{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"test_tool","name":"execute_with_timeout"},{"tool_name":"test_tool","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(197)"}
[INFO] [stdout] test timeout::tests::test_successful_tool_execution ... ok
[INFO] [stdout] test error_sanitization::tests::test_full_sanitization ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_windows_paths ... ok
[INFO] [stdout] test error_sanitization::tests::test_sanitize_unix_paths ... ok
[INFO] [stdout] test elicitation::tests::test_coordinator_timeout ... ok
[INFO] [stderr] {"timestamp":"2026-01-07T23:33:19.777104Z","level":"ERROR","fields":{"message":"🔒 SECURITY AUDIT: Tool execution timed out","tool_name":"fast_tool","execution_id":"4d7ed013-99dc-4545-a8b5-7e35b5557d59","timeout_seconds":1,"elapsed_ms":"1003","event_type":"TIMEOUT_EVENT","security_concern":"potential_dos_indicator"},"target":"turbomcp_server::timeout","filename":"src/timeout.rs","line_number":198,"span":{"tool_name":"fast_tool","name":"execute_with_timeout_and_cancellation"},"spans":[{"tool_name":"fast_tool","name":"execute_with_timeout"},{"tool_name":"fast_tool","name":"execute_with_timeout_and_cancellation"}],"threadId":"ThreadId(198)"}
[INFO] [stdout] test timeout::tests::test_tool_timeout ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 192 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.10s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/turbomcp_server-f24c9387fb4a530c)
[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/http_headers_test.rs (/opt/rustwide/target/debug/deps/http_headers_test-9c09b06d9fa6bc18)
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test test_header_case_insensitivity ... ok
[INFO] [stdout] test test_context_header_methods ... ok
[INFO] [stderr]      Running tests/server_tests.rs (/opt/rustwide/target/debug/deps/server_tests-56ce3c7e70d794c4)
[INFO] [stdout] test test_http_headers_extracted ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 18 tests
[INFO] [stdout] test test_server_builder_empty_configuration ... ok
[INFO] [stdout] test test_server_builder_partial_configuration ... ok
[INFO] [stdout] test test_server_builder_with_none_description ... ok
[INFO] [stdout] test test_server_builder_configuration_methods ... ok
[INFO] [stdout] test test_server_creation_with_rate_limiting_disabled ... ok
[INFO] [stdout] test test_server_arc_reference_sharing ... ok
[INFO] [stdout] test test_server_accessors ... ok
[INFO] [stdout] test test_server_with_minimal_config ... ok
[INFO] [stdout] test test_server_with_unicode_config ... ok
[INFO] [stdout] test test_server_debug_implementation ... ok
[INFO] [stdout] test test_server_builder_default ... ok
[INFO] [stdout] test test_server_creation_default ... ok
[INFO] [stdout] test test_server_builder_overwrites ... ok
[INFO] [stdout] test test_server_resource_cleanup ... ok
[INFO] [stdout] test test_server_config_edge_cases ... ok
[INFO] [stdout] test test_server_config_very_long_strings ... ok
[INFO] [stdout] test test_server_builder_stress ... ok
[INFO] [stdout] test test_server_builder_method_chaining ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 18 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.09s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/stdio_lifecycle_test.rs (/opt/rustwide/target/debug/deps/stdio_lifecycle_test-7c57c74e058c371a)
[INFO] [stdout] 
[INFO] [stdout] running 9 tests
[INFO] [stdout] test test_stdio_shutdown_signal ... ok
[INFO] [stdout] test test_pending_request_cleanup_on_timeout ... ok
[INFO] [stdout] test test_rapid_task_spawn_and_join ... ok
[INFO] [stdout] test test_joinset_multiple_tasks ... ok
[INFO] [stdout] test test_stdio_dispatcher_concurrent_usage ... ok
[INFO] [stdout] test test_stdio_shutdown_on_channel_close ... ok
[INFO] [stdout] test test_joinset_timeout_and_abort ... ok
[INFO] [stdout] test test_task_error_handling ... ok
[INFO] [stdout] test test_graceful_shutdown_with_fallback ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 9 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.29s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/tasks_integration_tests.rs (/opt/rustwide/target/debug/deps/tasks_integration_tests-02e23b27de9c3b49)
[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/test_helpers.rs (/opt/rustwide/target/debug/deps/test_helpers-e36079263c4628c0)
[INFO] [stdout] 
[INFO] [stdout] running 4 tests
[INFO] [stdout] test tests::test_helper_creates_server ... ok
[INFO] [stdout] test tests::test_helper_creates_versioned_builder ... ok
[INFO] [stdout] test tests::test_helper_creates_named_builder ... ok
[INFO] [stdout] test tests::test_helper_creates_builder ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 4 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/timeout_integration_tests.rs (/opt/rustwide/target/debug/deps/timeout_integration_tests-8e1ee538367fca7b)
[INFO] [stdout] 
[INFO] [stdout] running 14 tests
[INFO] [stdout] test test_operation_error_propagation ... ok
[INFO] [stdout] test test_timeout_error_conversion_to_server_error ... ok
[INFO] [stdout] test test_cancellation_error_conversion_to_server_error ... ok
[INFO] [stdout] test test_cancel_all_executions ... ok
[INFO] [stdout] test test_timeout_vs_cancellation_priority ... ok
[INFO] [stdout] test test_context_integration_with_cancellation_token ... ok
[INFO] [stdout] test test_cancellation_token_creation_and_return ... ok
[INFO] [stdout] test test_timeout_manager_basic_execution ... ok
[INFO] [stdout] test test_external_cancellation_token ... ok
[INFO] [stdout] test test_timeout_manager_drop_cleanup ... ok
[INFO] [stdout] test test_active_executions_monitoring ... ok
[INFO] [stdout] test test_concurrent_timeout_operations ... ok
[INFO] [stdout] test test_timeout_manager_timeout_exceeded ... ok
[INFO] [stdout] test test_high_load_timeout_management ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 14 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.51s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/websocket_config_test.rs (/opt/rustwide/target/debug/deps/websocket_config_test-58ed588f5d048602)
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests turbomcp_server
[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] [stdout] 
[INFO] [stdout] running 47 tests
[INFO] [stdout] test src/capabilities.rs - capabilities::ServerToClientAdapter::new (line 84) - compile ... ok
[INFO] [stdout] test src/elicitation.rs - elicitation::ElicitationBridge (line 668) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::ElicitationCoordinator (line 58) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::ElicitationPriority (line 192) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::ElicitationStats (line 533) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::ElicitationTransport (line 608) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::IncomingElicitationResponse (line 249) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::OutgoingElicitation (line 153) ... ignored
[INFO] [stdout] test src/config.rs - config::ServerConfig::from_file_with_prefix (line 280) - compile ... ok
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization (line 21) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::DisplayMode (line 61) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::SanitizedError (line 120) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::SanitizedError<E>::development (line 192) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::SanitizedError<E>::inner (line 221) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::SanitizedError<E>::into_inner (line 206) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::SanitizedError<E>::new (line 162) ... ignored
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::SanitizedError<E>::production (line 177) ... ignored
[INFO] [stdout] test src/handler_validation.rs - handler_validation (line 33) ... ignored
[INFO] [stdout] test src/elicitation.rs - elicitation::SharedElicitationCoordinator (line 726) - compile ... ok
[INFO] [stdout] test src/config.rs - config::ConfigurationBuilder::protocol_version (line 460) ... ok
[INFO] [stdout] test src/config.rs - config::ConfigurationBuilder::supported_protocol_versions (line 480) ... ok
[INFO] [stdout] test src/config.rs - config::ConfigurationBuilder::allow_protocol_fallback (line 500) ... ok
[INFO] [stdout] test src/config.rs - config::ServerConfig::from_file (line 228) - compile ... ok
[INFO] [stdout] test src/handlers/utils.rs - handlers::utils::tool (line 31) - compile ... ok
[INFO] [stdout] test src/routing/handlers/completion.rs - routing::handlers::completion::handle (line 22) ... ignored
[INFO] [stdout] test src/routing/handlers/elicitation.rs - routing::handlers::elicitation::handle (line 20) ... ignored
[INFO] [stdout] test src/routing/handlers/logging.rs - routing::handlers::logging::handle_set_level (line 21) ... ignored
[INFO] [stdout] test src/routing/handlers/resources.rs - routing::handlers::resources::handle_list_templates (line 114) ... ignored
[INFO] [stdout] test src/routing/mod.rs - routing::RequestRouter::create_context (line 251) ... ignored
[INFO] [stdout] test src/runtime.rs - runtime::TransportDispatcher (line 445) ... ignored
[INFO] [stdout] test src/runtime.rs - runtime::run_transport_bidirectional (line 743) ... ignored
[INFO] [stdout] test src/security_checks.rs - security_checks::check_binding_security (line 26) ... ignored
[INFO] [stdout] test src/security_checks.rs - security_checks::check_binding_security (line 77) ... ignored
[INFO] [stdout] test src/server/core.rs - server::core::McpServer::shutdown_handle (line 443) - compile ... ok
[INFO] [stdout] test src/server/core.rs - server::core::McpServer::shutdown_handle (line 465) - compile ... ok
[INFO] [stdout] test src/lib.rs - (line 63) - compile ... ok
[INFO] [stdout] test src/lib.rs - (line 22) - compile ... ok
[INFO] [stdout] test src/registry.rs - registry::HandlerRegistry::new (line 174) ... ok
[INFO] [stdout] test src/server/builder.rs - server::builder::ServerBuilder::protocol_version_config (line 127) ... ok
[INFO] [stdout] test src/server/core.rs - server::core::McpServer (line 116) - compile ... ok
[INFO] [stdout] test src/config.rs - config::ServerConfig::builder (line 328) ... ok
[INFO] [stdout] test src/config.rs - config::ProtocolVersionConfig (line 20) ... ok
[INFO] [stdout] test src/config.rs - config::ConfigurationBuilder::protocol_version_config (line 519) ... ok
[INFO] [stdout] test src/registry.rs - registry (line 39) ... ok
[INFO] [stdout] test src/registry.rs - registry (line 29) ... ok
[INFO] [stdout] test src/error_sanitization.rs - error_sanitization::sanitize_error_message (line 261) ... ok
[INFO] [stdout] test src/observability.rs - observability (line 15) - compile ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 22 passed; 0 failed; 25 ignored; 0 measured; 0 filtered out; finished in 0.36s
[INFO] [stdout] 
[INFO] [stdout] all doctests ran in 3.36s; merged doctests compilation took 2.94s
[INFO] running `Command { std: "docker" "inspect" "6c49f85da73e81893f0149d8f613bf7bb45f0e8bcc47845ec217c46dd76aaaaf", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "6c49f85da73e81893f0149d8f613bf7bb45f0e8bcc47845ec217c46dd76aaaaf", kill_on_drop: false }`
[INFO] [stdout] 6c49f85da73e81893f0149d8f613bf7bb45f0e8bcc47845ec217c46dd76aaaaf