[INFO] fetching crate links_blocking 0.2.12... [INFO] testing links_blocking-0.2.12 against try#b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b for pr-145330-1 [INFO] extracting crate links_blocking 0.2.12 into /workspace/builds/worker-0-tc2/source [INFO] started tweaking crates.io crate links_blocking 0.2.12 [INFO] finished tweaking crates.io crate links_blocking 0.2.12 [INFO] tweaked toml for crates.io crate links_blocking 0.2.12 written to /workspace/builds/worker-0-tc2/source/Cargo.toml [INFO] validating manifest of crates.io crate links_blocking 0.2.12 on toolchain b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }` [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "generate-lockfile" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] [stderr] Updating crates.io index [INFO] [stderr] Locking 151 packages to latest compatible versions [INFO] [stderr] Adding criterion v0.5.1 (available: v0.7.0) [INFO] [stderr] Adding rand v0.8.5 (available: v0.9.2) [INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }` [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }` [INFO] [stdout] 203b4044b083750153dbc953ddd7d3d7c0a33b5bcbcefe1a49fb439f58fe4291 [INFO] running `Command { std: "docker" "start" "-a" "203b4044b083750153dbc953ddd7d3d7c0a33b5bcbcefe1a49fb439f58fe4291", kill_on_drop: false }` [INFO] running `Command { std: "docker" "inspect" "203b4044b083750153dbc953ddd7d3d7c0a33b5bcbcefe1a49fb439f58fe4291", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "203b4044b083750153dbc953ddd7d3d7c0a33b5bcbcefe1a49fb439f58fe4291", kill_on_drop: false }` [INFO] [stdout] 203b4044b083750153dbc953ddd7d3d7c0a33b5bcbcefe1a49fb439f58fe4291 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "build" "--frozen" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] bd4a3dfba65442249cc71e553eda15ea9864982df06e9031775396d06a989983 [INFO] running `Command { std: "docker" "start" "-a" "bd4a3dfba65442249cc71e553eda15ea9864982df06e9031775396d06a989983", kill_on_drop: false }` [INFO] [stderr] Compiling links_core v0.2.12 [INFO] [stderr] Compiling byteserde v0.6.2 [INFO] [stderr] Compiling links_blocking v0.2.12 (/opt/rustwide/workdir) [INFO] [stderr] Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.98s [INFO] running `Command { std: "docker" "inspect" "bd4a3dfba65442249cc71e553eda15ea9864982df06e9031775396d06a989983", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "bd4a3dfba65442249cc71e553eda15ea9864982df06e9031775396d06a989983", kill_on_drop: false }` [INFO] [stdout] bd4a3dfba65442249cc71e553eda15ea9864982df06e9031775396d06a989983 [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }` [INFO] [stdout] 94dd52c14c7071d463f336e93a360b1cb33bf63991b6d61951c04d38d4f0a22f [INFO] running `Command { std: "docker" "start" "-a" "94dd52c14c7071d463f336e93a360b1cb33bf63991b6d61951c04d38d4f0a22f", kill_on_drop: false }` [INFO] [stderr] Compiling regex-automata v0.4.11 [INFO] [stderr] Compiling anstyle-query v1.1.4 [INFO] [stderr] Compiling quote v1.0.41 [INFO] [stderr] Compiling futures-util v0.3.31 [INFO] [stderr] Compiling serde_json v1.0.145 [INFO] [stderr] Compiling num-format v0.4.4 [INFO] [stderr] Compiling colored v2.2.0 [INFO] [stderr] Compiling tokio v1.47.1 [INFO] [stderr] Compiling anstream v0.6.20 [INFO] [stderr] Compiling syn v2.0.106 [INFO] [stderr] Compiling regex v1.11.3 [INFO] [stderr] Compiling futures-executor v0.3.31 [INFO] [stderr] Compiling env_filter v0.1.3 [INFO] [stderr] Compiling env_logger v0.11.8 [INFO] [stderr] Compiling futures v0.3.31 [INFO] [stderr] Compiling serde_derive v1.0.228 [INFO] [stderr] Compiling byteserde_derive v0.6.2 [INFO] [stderr] Compiling serde v1.0.228 [INFO] [stderr] Compiling byteserde_types v0.6.2 [INFO] [stderr] Compiling ciborium v0.2.2 [INFO] [stderr] Compiling tinytemplate v1.2.1 [INFO] [stderr] Compiling links_core v0.2.12 [INFO] [stderr] Compiling criterion v0.5.1 [INFO] [stderr] Compiling links_blocking v0.2.12 (/opt/rustwide/workdir) [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 21.38s [INFO] running `Command { std: "docker" "inspect" "94dd52c14c7071d463f336e93a360b1cb33bf63991b6d61951c04d38d4f0a22f", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "94dd52c14c7071d463f336e93a360b1cb33bf63991b6d61951c04d38d4f0a22f", kill_on_drop: false }` [INFO] [stdout] 94dd52c14c7071d463f336e93a360b1cb33bf63991b6d61951c04d38d4f0a22f [INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+b6ae10aa7319b7ebb6c7b3331dd71a9d6c9c5b4b" "test" "--frozen", kill_on_drop: false }` [INFO] [stdout] 56940a25b8bce9f16e9e9c31884a4c05aa147db473807bda67b0e0a29a3081b3 [INFO] running `Command { std: "docker" "start" "-a" "56940a25b8bce9f16e9e9c31884a4c05aa147db473807bda67b0e0a29a3081b3", kill_on_drop: false }` [INFO] [stderr] Finished `test` profile [unoptimized + debuginfo] target(s) in 0.16s [INFO] [stderr] Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/links_blocking-c20650947e160111) [INFO] [stdout] [INFO] [stderr] 2025-10-02T03:08:36.155452535Z INFO (connect::svc::test::test_svc_not_connected) links_blocking::connect::svc::test svc: Svc, RoundRobinPool> [INFO] [stdout] running 6 tests [INFO] [stdout] test connect::svc::test::test_svc_not_connected ... ok [INFO] [stderr] 2025-10-02T03:08:36.155868205Z INFO (connect::svc::test::test_svc_clt_connected) links_blocking::connect::svc::test svc: Svc, RoundRobinPool> [INFO] [stderr] 2025-10-02T03:08:36.155998655Z INFO (core::framer::test::test_reader ) links_blocking::core::framer::test send_frame: [INFO] [stderr] 0000: 04 c2 ae fe 3e c0 8e 4d 99 b6 ed ac c4 f6 87 9c | . Â ® þ > À . M . ¶ í ¬ Ä ö . . [INFO] [stderr] 0001: 59 5b 0d fb 07 30 ff b1 b9 4e 4f 94 99 04 d4 0f | Y [ . û . 0 ÿ ± ¹ N O . . . Ô . [INFO] [stderr] 0002: 9c a7 80 e4 4f 1a 3f cc ed d4 de fd 55 28 31 ae | . § . ä O . ? Ì í Ô Þ ý U ( 1 ® [INFO] [stderr] 0003: 57 06 ba 28 a6 01 5d 0f c9 6d 93 0d 44 31 c3 b6 | W . º ( ¦ . ] . É m . . D 1 Ã ¶ [INFO] [stderr] 0004: 63 32 2e 28 eb 11 85 8d db e9 90 de 65 19 89 ea | c 2 . ( ë . . . Û é . Þ e . . ê [INFO] [stderr] 0005: 7f d0 8a f6 45 61 3f e9 0f 6a c7 80 2a 4a 40 80 | . Ð . ö E a ? é . j Ç . * J @ . [INFO] [stderr] 0006: 2f e1 8f de 4d c5 27 d0 01 b1 1f 34 2f 4c 1f 5c | / á . Þ M Å ' Ð . ± . 4 / L . \ [INFO] [stderr] 0007: 6b 09 50 0b 8d 29 14 71 f3 cb bc 75 ce 6b 51 97 | k . P . . ) . q ó Ë ¼ u Î k Q . [INFO] [stderr] [INFO] [stderr] 2025-10-02T03:08:36.157055135Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test svc: Svc, RoundRobinPool> [INFO] [stderr] 2025-10-02T03:08:36.160319605Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test clt: Clt127.0.0.1:23283), CltTestMessenger, 128> [INFO] [stderr] 2025-10-02T03:08:36.160909365Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test #0, clt: Clt127.0.0.1:48771), CltTestMessenger, 128> [INFO] [stderr] 2025-10-02T03:08:36.161433265Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::svc Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46280) Accepted [INFO] [stderr] 2025-10-02T03:08:36.161560485Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test #1, clt: Clt127.0.0.1:48771), CltTestMessenger, 128> [INFO] [stderr] 2025-10-02T03:08:36.161650215Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::svc Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46290) Accepted [INFO] [stderr] 2025-10-02T03:08:36.161779225Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test #2, clt: Clt127.0.0.1:48771), CltTestMessenger, 128> [INFO] [stderr] 2025-10-02T03:08:36.161891935Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:46298->127.0.0.1:48771), addr: connected, peer: connected, fd: 19 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.161995625Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:46298->127.0.0.1:48771), addr: connected, peer: connected, fd: 18 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.162097635Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test clt_pool_err: Custom { kind: OutOfMemory, error: "RoundRobinPool at max capacity: 2, element: Clt127.0.0.1:48771), CltTestMessenger, 128> will be dropped" } [INFO] [stderr] 2025-10-02T03:08:36.162215745Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::svc Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46298) Accepted [INFO] [stderr] 2025-10-02T03:08:36.162317705Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46298), addr: connected, peer: disconnected, fd: 19 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.162421295Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46298), addr: connected, peer: disconnected, fd: 18 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.162615045Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test svc_pool_err: Custom { kind: OutOfMemory, error: "RoundRobinPool at max capacity: 2, element: Clt will be dropped" } [INFO] [stderr] 2025-10-02T03:08:36.162766955Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test #3, clt: Clt127.0.0.1:48771), CltTestMessenger, 128> [INFO] [stderr] 2025-10-02T03:08:36.162862575Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:46302->127.0.0.1:48771), addr: connected, peer: connected, fd: 19 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.162986235Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:46302->127.0.0.1:48771), addr: connected, peer: connected, fd: 18 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.163097375Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test clt_pool_err: Custom { kind: OutOfMemory, error: "RoundRobinPool at max capacity: 2, element: Clt127.0.0.1:48771), CltTestMessenger, 128> will be dropped" } [INFO] [stderr] 2025-10-02T03:08:36.163205115Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::svc Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46302) Accepted [INFO] [stderr] 2025-10-02T03:08:36.163302255Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46302), addr: connected, peer: disconnected, fd: 19 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.163402905Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46302), addr: connected, peer: disconnected, fd: 18 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.163503155Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test svc_pool_err: Custom { kind: OutOfMemory, error: "RoundRobinPool at max capacity: 2, element: Clt will be dropped" } [INFO] [stderr] 2025-10-02T03:08:36.163605105Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test clt_pool: RoundRobinPool127.0.0.1:48771), CltTestMessenger, 128>,Clt127.0.0.1:48771), CltTestMessenger, 128>]> [INFO] [stderr] 2025-10-02T03:08:36.163730505Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test svc_pool: RoundRobinPool,Clt]> [INFO] [stderr] 2025-10-02T03:08:36.164000625Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test clt_msg: Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.164126795Z INFO (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::connect::pool::test svc_msg: Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.164250495Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:46280->127.0.0.1:48771), addr: connected, peer: connected, fd: 8 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.164355545Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:46280->127.0.0.1:48771), addr: connected, peer: connected, fd: 7 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.164466015Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:46290->127.0.0.1:48771), addr: connected, peer: connected, fd: 15 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.164597845Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:46290->127.0.0.1:48771), addr: connected, peer: connected, fd: 14 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.164732505Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46280), addr: connected, peer: disconnected, fd: 13 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.164841035Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46280), addr: connected, peer: disconnected, fd: 12 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.165554255Z DEBUG (connect::clt::test::test_clt_not_connected ) links_blocking::connect::clt Initiator(unittest@pending->127.0.0.1:3482) connection failed. e: Os { code: 111, kind: ConnectionRefused, message: "Connection refused" } [INFO] [stderr] 2025-10-02T03:08:36.161319955Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236) Accepted [INFO] [stderr] 2025-10-02T03:08:36.167446635Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test svc: Svc, RoundRobinPool]>> [INFO] [stderr] 2025-10-02T03:08:36.167184905Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46290), addr: connected, peer: disconnected, fd: 17 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.167802735Z DEBUG (connect::pool::test::test_svcpool_cltpool_connected) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:48771<-127.0.0.1:46290), addr: connected, peer: disconnected, fd: 16 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.167900615Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test --------- PRE SPLIT --------- [INFO] [stderr] 2025-10-02T03:08:36.168353715Z INFO (connect::svc::test::test_svc_clt_connected ) links_core::callbacks::logger LoggerCallback::on_sent Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283) Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.168755675Z INFO (connect::svc::test::test_svc_clt_connected ) links_core::callbacks::logger LoggerCallback::on_recv Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236) Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stdout] test connect::pool::test::test_svcpool_cltpool_connected ... ok [INFO] [stderr] 2025-10-02T03:08:36.169116185Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test --------- SVC SPLIT POOL --------- [INFO] [stderr] 2025-10-02T03:08:36.169368065Z INFO (connect::svc::test::test_svc_clt_connected ) links_core::callbacks::logger LoggerCallback::on_sent Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283) Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.169707275Z INFO (connect::svc::test::test_svc_clt_connected ) links_core::callbacks::logger LoggerCallback::on_recv Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236) Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.169929385Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test --------- CLT SPLIT DIRECT --------- [INFO] [stderr] 2025-10-02T03:08:36.170094205Z INFO (connect::svc::test::test_svc_clt_connected ) links_core::callbacks::logger LoggerCallback::on_sent Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283) Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.170311815Z INFO (connect::svc::test::test_svc_clt_connected ) links_core::callbacks::logger LoggerCallback::on_recv Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236) Dbg(CltTestMsgDebug { ty: ConstCharAscii<49>('1'), text: StringAsciiFixed<127, 32, true>(" Hello Frm Client Msg") }) [INFO] [stderr] 2025-10-02T03:08:36.170504475Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test --------- CLT DROP RANDOM HALF --------- [INFO] [stderr] 2025-10-02T03:08:36.170622305Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test dropping clt_recv [INFO] [stderr] 2025-10-02T03:08:36.170758005Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283), addr: connected, peer: connected, fd: 6 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.171036055Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283), addr: connected, peer: connected, fd: 5 }::shutdown how: Write, reason: write_frame error [INFO] [stderr] 2025-10-02T03:08:36.171400875Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test clt_send err: Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283) FrameWriter::write_frame caused by: [Broken pipe (os error 32)] [INFO] [stderr] 2025-10-02T03:08:36.171661095Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test --------- SVC RECV/SEND SHOULD FAIL CLT DROPS HALF --------- [INFO] [stderr] 2025-10-02T03:08:36.172778005Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236), addr: connected, peer: disconnected, fd: 4 }::shutdown how: Write, reason: read_frame EOF [INFO] [stderr] 2025-10-02T03:08:36.173074075Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::pool recver: CltRecver is dead and will be dropped, connection reset by peer. recvers: RoundRobinPool [INFO] [stderr] 2025-10-02T03:08:36.173515995Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236), addr: connected, peer: disconnected, fd: 4 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.175312905Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test pool_recver opt: None [INFO] [stderr] 2025-10-02T03:08:36.176051065Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236), addr: connected, peer: disconnected, fd: 11 }::shutdown while disconnected how: Write, reason: write_frame error [INFO] [stderr] 2025-10-02T03:08:36.176940115Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236), addr: connected, peer: disconnected, fd: 11 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.177417275Z INFO (connect::svc::test::test_svc_clt_connected ) links_blocking::connect::svc::test pool_sender err: sender: CltSender is dead and will be dropped, senders: RoundRobinPool. error: (Acceptor(unittest@127.0.0.1:23283<-127.0.0.1:49236) FrameWriter::write_frame caused by: [Broken pipe (os error 32)]) [INFO] [stderr] 2025-10-02T03:08:36.179929845Z DEBUG (connect::svc::test::test_svc_clt_connected ) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:49236->127.0.0.1:23283), addr: connected, peer: disconnected, fd: 5 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.178897955Z DEBUG (connect::clt::test::test_clt_not_connected ) links_blocking::connect::clt Initiator(unittest@pending->127.0.0.1:3482) connection failed. e: Os { code: 111, kind: ConnectionRefused, message: "Connection refused" } [INFO] [stdout] test connect::svc::test::test_svc_clt_connected ... ok [INFO] [stderr] 2025-10-02T03:08:36.191128115Z DEBUG (connect::clt::test::test_clt_not_connected ) links_blocking::connect::clt Initiator(unittest@pending->127.0.0.1:3482) connection failed. e: Os { code: 111, kind: ConnectionRefused, message: "Connection refused" } [INFO] [stdout] test connect::clt::test::test_clt_not_connected ... ok [INFO] [stderr] 2025-10-02T03:08:36.205440324Z DEBUG (connect::clt::test::test_clt_not_connected ) links_blocking::connect::clt Initiator(unittest@pending->127.0.0.1:3482) connection failed. e: Os { code: 111, kind: ConnectionRefused, message: "Connection refused" } [INFO] [stderr] 2025-10-02T03:08:36.205687884Z INFO (connect::clt::test::test_clt_not_connected ) links_blocking::connect::clt::test res: Err(Custom { kind: TimedOut, error: "Initiator { name: \"unittest\", local: None, peer: 127.0.0.1:3482 } connect timeout: 50ms" }) [INFO] [stderr] 2025-10-02T03:08:36.263058093Z INFO (Thread-Svc ) links_blocking::core::framer::test svc: reader: FrameReader> { Acceptor(unittest@127.0.0.1:55495<-127.0.0.1:34790), addr: connected, peer: connected, fd: 5 } [INFO] [stderr] 2025-10-02T03:08:36.263108963Z INFO (core::framer::test::test_reader ) links_blocking::core::framer::test clt: FrameWriter { Initiator(unittest@127.0.0.1:34790->127.0.0.1:55495), addr: connected, peer: connected, fd: 3 } [INFO] [stderr] 2025-10-02T03:08:36.272194263Z INFO (Thread-Svc ) links_blocking::core::messenger::test Acceptor(unittest@127.0.0.1:23202<-127.0.0.1:33676) MessageSender connected [INFO] [stderr] 2025-10-02T03:08:36.272177523Z INFO (core::messenger::test::test_messenger ) links_blocking::core::messenger::test Initiator(unittest@127.0.0.1:33676->127.0.0.1:23202) MessageSender connected [INFO] [stderr] 2025-10-02T03:08:36.622301267Z INFO (core::framer::test::test_reader ) links_blocking::core::framer::test dropping clt_reader [INFO] [stderr] 2025-10-02T03:08:36.622595667Z DEBUG (core::framer::test::test_reader ) links_blocking::core::framer FrameReader> { Initiator(unittest@127.0.0.1:34790->127.0.0.1:55495), addr: connected, peer: connected, fd: 4 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.622783287Z DEBUG (core::framer::test::test_reader ) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:34790->127.0.0.1:55495), addr: connected, peer: connected, fd: 3 }::shutdown how: Write, reason: write_frame error [INFO] [stderr] 2025-10-02T03:08:36.622966587Z INFO (core::framer::test::test_reader ) links_blocking::core::framer::test clt_writer.write_frame() err: Initiator(unittest@127.0.0.1:34790->127.0.0.1:55495) FrameWriter::write_frame caused by: [Broken pipe (os error 32)] [INFO] [stderr] 2025-10-02T03:08:36.763523145Z DEBUG (Thread-Svc ) links_blocking::core::framer FrameReader> { Acceptor(unittest@127.0.0.1:55495<-127.0.0.1:34790), addr: connected, peer: disconnected, fd: 5 }::shutdown how: Write, reason: read_frame EOF [INFO] [stderr] 2025-10-02T03:08:36.763740455Z INFO (Thread-Svc ) links_blocking::core::framer::test svc: read_frame is None, client closed connection [INFO] [stderr] 2025-10-02T03:08:36.763850535Z DEBUG (Thread-Svc ) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:55495<-127.0.0.1:34790), addr: connected, peer: disconnected, fd: 10 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.765439705Z DEBUG (Thread-Svc ) links_blocking::core::framer FrameReader> { Acceptor(unittest@127.0.0.1:55495<-127.0.0.1:34790), addr: connected, peer: disconnected, fd: 5 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:36.765925445Z INFO (core::framer::test::test_reader ) links_blocking::core::framer::test frame_send_count: 100,000, frame_recv_count: 100,000 [INFO] [stderr] 2025-10-02T03:08:36.766005694Z INFO (core::framer::test::test_reader ) links_blocking::core::framer::test per send elapsed: 3.589µs, total elapsed: 358.989104ms [INFO] [stderr] 2025-10-02T03:08:36.766080745Z DEBUG (core::framer::test::test_reader ) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:34790->127.0.0.1:55495), addr: connected, peer: disconnected, fd: 3 }::shutdown while disconnected how: Both, reason: drop [INFO] [stdout] test core::framer::test::test_reader ... ok [INFO] [stderr] 2025-10-02T03:08:39.384433619Z INFO (core::messenger::test::test_messenger ) links_blocking::core::messenger::test dropping clt_sender [INFO] [stdout] test core::messenger::test::test_messenger ... ok [INFO] [stderr] 2025-10-02T03:08:39.384619259Z DEBUG (Thread-Svc ) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:23202<-127.0.0.1:33676), addr: connected, peer: disconnected, fd: 12 }::shutdown how: Write, reason: read_frame EOF [INFO] [stdout] [INFO] [stderr] 2025-10-02T03:08:39.384759319Z INFO (Thread-Svc ) links_blocking::core::messenger::test Acceptor { name: "unittest", local: 127.0.0.1:23202, peer: Some(127.0.0.1:33676) } MessageRecver Connection Closed by Client [INFO] [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.23s [INFO] [stderr] 2025-10-02T03:08:39.384873589Z DEBUG (Thread-Svc ) links_blocking::core::framer FrameWriter { Acceptor(unittest@127.0.0.1:23202<-127.0.0.1:33676), addr: connected, peer: disconnected, fd: 7 }::shutdown while disconnected how: Both, reason: drop [INFO] [stdout] [INFO] [stderr] 2025-10-02T03:08:39.385000369Z DEBUG (Thread-Svc ) links_blocking::core::framer FrameReader { Acceptor(unittest@127.0.0.1:23202<-127.0.0.1:33676), addr: connected, peer: disconnected, fd: 12 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:39.385244769Z DEBUG (core::messenger::test::test_messenger ) links_blocking::core::framer FrameWriter { Initiator(unittest@127.0.0.1:33676->127.0.0.1:23202), addr: connected, peer: disconnected, fd: 8 }::shutdown how: Both, reason: drop [INFO] [stderr] 2025-10-02T03:08:39.385359139Z DEBUG (core::messenger::test::test_messenger ) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:33676->127.0.0.1:23202), addr: connected, peer: disconnected, fd: 11 }::shutdown while disconnected how: Write, reason: read_frame EOF [INFO] [stderr] 2025-10-02T03:08:39.385465309Z INFO (core::messenger::test::test_messenger ) links_blocking::core::messenger::test clt_recver.recv(): None [INFO] [stderr] 2025-10-02T03:08:39.385535409Z INFO (core::messenger::test::test_messenger ) links_blocking::core::messenger::test clt_msg_sent_count: 100,000, clt_msg_recv_count: 100,000 [INFO] [stderr] 2025-10-02T03:08:39.385605079Z INFO (core::messenger::test::test_messenger ) links_blocking::core::messenger::test svc_msg_sent_count: 100,000, svc_msg_recv_count: 100,000 [INFO] [stderr] 2025-10-02T03:08:39.385672209Z INFO (core::messenger::test::test_messenger ) links_blocking::core::messenger::test per round trip elapsed: 31.119µs, total elapsed: 3.111968436s [INFO] [stderr] 2025-10-02T03:08:39.385742459Z DEBUG (core::messenger::test::test_messenger ) links_blocking::core::framer FrameReader { Initiator(unittest@127.0.0.1:33676->127.0.0.1:23202), addr: connected, peer: disconnected, fd: 11 }::shutdown while disconnected how: Both, reason: drop [INFO] [stderr] Doc-tests links_blocking [INFO] [stdout] [INFO] [stdout] running 6 tests [INFO] [stdout] test src/connect/pool.rs - connect::pool::CltsPool (line 19) - compile ... ok [INFO] [stdout] test src/core/messenger.rs - core::messenger (line 8) - compile ... ok [INFO] [stdout] test src/connect/pool.rs - connect::pool::PoolCltAcceptor (line 375) - compile ... ok [INFO] [stdout] test src/connect/pool.rs - connect::pool::CltRecversPool (line 156) ... ok [INFO] [stdout] test src/core/framer.rs - core::framer (line 8) ... ok [INFO] [stdout] test src/connect/pool.rs - connect::pool::CltSendersPool (line 268) ... ok [INFO] [stdout] [INFO] [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.29s [INFO] [stdout] [INFO] running `Command { std: "docker" "inspect" "56940a25b8bce9f16e9e9c31884a4c05aa147db473807bda67b0e0a29a3081b3", kill_on_drop: false }` [INFO] running `Command { std: "docker" "rm" "-f" "56940a25b8bce9f16e9e9c31884a4c05aa147db473807bda67b0e0a29a3081b3", kill_on_drop: false }` [INFO] [stdout] 56940a25b8bce9f16e9e9c31884a4c05aa147db473807bda67b0e0a29a3081b3