[INFO] fetching crate h3x 0.1.0...
[INFO] testing h3x-0.1.0 against try#dec9417b8611e34e787a3e4c37686b5131f9e5c5 for pr-154210-1
[INFO] extracting crate h3x 0.1.0 into /workspace/builds/worker-3-tc2/source
[INFO] started tweaking crates.io crate h3x 0.1.0
[INFO] finished tweaking crates.io crate h3x 0.1.0
[INFO] tweaked toml for crates.io crate h3x 0.1.0 written to /workspace/builds/worker-3-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate h3x 0.1.0 on toolchain dec9417b8611e34e787a3e4c37686b5131f9e5c5
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate h3x 0.1.0 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 58d92692e8f7f8d2d7ba73024600440677090448b2f06340bad28808c0aeae2f
[INFO] running `Command { std: "docker" "start" "-a" "58d92692e8f7f8d2d7ba73024600440677090448b2f06340bad28808c0aeae2f", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "58d92692e8f7f8d2d7ba73024600440677090448b2f06340bad28808c0aeae2f", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "58d92692e8f7f8d2d7ba73024600440677090448b2f06340bad28808c0aeae2f", kill_on_drop: false }`
[INFO] [stdout] 58d92692e8f7f8d2d7ba73024600440677090448b2f06340bad28808c0aeae2f
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 67380e5e45468dbca5dbd5484ffbd84d08d608178b94e8a00ae2c162750b3d8d
[INFO] running `Command { std: "docker" "start" "-a" "67380e5e45468dbca5dbd5484ffbd84d08d608178b94e8a00ae2c162750b3d8d", kill_on_drop: false }`
[INFO] [stderr]    Compiling syn v2.0.111
[INFO] [stderr]    Compiling libc v0.2.178
[INFO] [stderr]    Compiling unicode-segmentation v1.12.0
[INFO] [stderr]    Compiling futures-channel v0.3.31
[INFO] [stderr]    Compiling proc-macro-error-attr2 v2.0.0
[INFO] [stderr]    Compiling rustls v0.23.35
[INFO] [stderr]    Compiling netlink-packet-core v0.8.1
[INFO] [stderr]    Compiling rustls-webpki v0.103.8
[INFO] [stderr]    Compiling memoffset v0.9.1
[INFO] [stderr]    Compiling zmij v1.0.2
[INFO] [stderr]    Compiling mac-addr v0.3.0
[INFO] [stderr]    Compiling nom v8.0.0
[INFO] [stderr]    Compiling nom v7.1.3
[INFO] [stderr]    Compiling hex v0.4.3
[INFO] [stderr]    Compiling time v0.3.44
[INFO] [stderr]    Compiling nix v0.29.0
[INFO] [stderr]    Compiling nix v0.30.1
[INFO] [stderr]    Compiling android-build v0.1.3
[INFO] [stderr]    Compiling oid-registry v0.8.1
[INFO] [stderr]    Compiling num-bigint v0.4.6
[INFO] [stderr]    Compiling data-encoding v2.9.0
[INFO] [stderr]    Compiling httlib-huffman v0.3.4
[INFO] [stderr]    Compiling serde_json v1.0.148
[INFO] [stderr]    Compiling matchit v0.9.1
[INFO] [stderr]    Compiling netwatcher v0.4.0
[INFO] [stderr]    Compiling convert_case v0.10.0
[INFO] [stderr]    Compiling socket2 v0.6.1
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling mio v1.1.1
[INFO] [stderr]    Compiling netlink-sys v0.8.7
[INFO] [stderr]    Compiling netlink-packet-route v0.25.1
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling getrandom v0.2.16
[INFO] [stderr]    Compiling rand_core v0.9.3
[INFO] [stderr]    Compiling rusticata-macros v4.1.0
[INFO] [stderr]    Compiling dashmap v6.1.0
[INFO] [stderr]    Compiling ring v0.17.14
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling rand v0.9.2
[INFO] [stderr]    Compiling darling_core v0.21.3
[INFO] [stderr]    Compiling darling_core v0.20.11
[INFO] [stderr]    Compiling darling_core v0.23.0
[INFO] [stderr]    Compiling proc-macro-error2 v2.0.1
[INFO] [stderr]    Compiling synstructure v0.13.2
[INFO] [stderr]    Compiling prettyplease v0.2.37
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[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 derive_more-impl v2.1.1
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling getset v0.1.6
[INFO] [stderr]    Compiling enum_dispatch v0.3.13
[INFO] [stderr]    Compiling asn1-rs-impl v0.2.0
[INFO] [stderr]    Compiling displaydoc v0.2.5
[INFO] [stderr]    Compiling asn1-rs-derive v0.6.0
[INFO] [stderr]    Compiling snafu-derive v0.8.9
[INFO] [stderr]    Compiling futures-util v0.3.31
[INFO] [stderr]    Compiling tokio v1.48.0
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling netdev v0.39.0
[INFO] [stderr]    Compiling darling_macro v0.23.0
[INFO] [stderr]    Compiling asn1-rs v0.7.1
[INFO] [stderr]    Compiling darling v0.23.0
[INFO] [stderr]    Compiling darling_macro v0.20.11
[INFO] [stderr]    Compiling qmacro v0.4.0
[INFO] [stderr]    Compiling darling_macro v0.21.3
[INFO] [stderr]    Compiling darling v0.20.11
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling derive_builder_core v0.20.2
[INFO] [stderr]    Compiling darling v0.21.3
[INFO] [stderr]    Compiling serde_with_macros v3.16.1
[INFO] [stderr]    Compiling bon-macros v3.8.1
[INFO] [stderr]    Compiling snafu v0.8.9
[INFO] [stderr]    Compiling derive_builder_macro v0.20.2
[INFO] [stderr]    Compiling serde_with v3.16.1
[INFO] [stderr]    Compiling derive_builder v0.20.2
[INFO] [stderr]    Compiling der-parser v10.0.0
[INFO] [stderr]    Compiling derive_more v2.1.1
[INFO] [stderr]    Compiling x509-parser v0.18.0
[INFO] [stderr]    Compiling futures-executor v0.3.31
[INFO] [stderr]    Compiling futures v0.3.31
[INFO] [stderr]    Compiling bon v3.8.1
[INFO] [stderr]    Compiling qbase v0.4.0
[INFO] [stderr]    Compiling qudp v0.4.0
[INFO] [stderr]    Compiling tokio-util v0.7.17
[INFO] [stderr]    Compiling qevent v0.4.0
[INFO] [stderr]    Compiling qunreliable v0.4.0
[INFO] [stderr]    Compiling qrecovery v0.4.0
[INFO] [stderr]    Compiling qcongestion v0.4.0
[INFO] [stderr]    Compiling qinterface v0.4.0
[INFO] [stderr]    Compiling qconnection v0.4.0
[INFO] [stderr]    Compiling gm-quic v0.4.0
[INFO] [stderr]    Compiling h3x v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 1m 24s
[INFO] running `Command { std: "docker" "inspect" "67380e5e45468dbca5dbd5484ffbd84d08d608178b94e8a00ae2c162750b3d8d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "67380e5e45468dbca5dbd5484ffbd84d08d608178b94e8a00ae2c162750b3d8d", kill_on_drop: false }`
[INFO] [stdout] 67380e5e45468dbca5dbd5484ffbd84d08d608178b94e8a00ae2c162750b3d8d
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 814cb7efa320e3ec51c20dc272f0e9005062555861a6f7ac5f534c3866e565b3
[INFO] running `Command { std: "docker" "start" "-a" "814cb7efa320e3ec51c20dc272f0e9005062555861a6f7ac5f534c3866e565b3", kill_on_drop: false }`
[INFO] [stderr]    Compiling rustls v0.23.35
[INFO] [stderr]    Compiling tokio v1.48.0
[INFO] [stderr]    Compiling tracing v0.1.44
[INFO] [stderr]    Compiling rustls-webpki v0.103.8
[INFO] [stderr]    Compiling tracing-subscriber v0.3.22
[INFO] [stderr]    Compiling qbase v0.4.0
[INFO] [stderr]    Compiling qudp v0.4.0
[INFO] [stderr]    Compiling tokio-util v0.7.17
[INFO] [stderr]    Compiling qevent v0.4.0
[INFO] [stderr]    Compiling qunreliable v0.4.0
[INFO] [stderr]    Compiling qcongestion v0.4.0
[INFO] [stderr]    Compiling qrecovery v0.4.0
[INFO] [stderr]    Compiling qinterface v0.4.0
[INFO] [stderr]    Compiling qconnection v0.4.0
[INFO] [stderr]    Compiling gm-quic v0.4.0
[INFO] [stderr]    Compiling h3x v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 52.80s
[INFO] running `Command { std: "docker" "inspect" "814cb7efa320e3ec51c20dc272f0e9005062555861a6f7ac5f534c3866e565b3", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "814cb7efa320e3ec51c20dc272f0e9005062555861a6f7ac5f534c3866e565b3", kill_on_drop: false }`
[INFO] [stdout] 814cb7efa320e3ec51c20dc272f0e9005062555861a6f7ac5f534c3866e565b3
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+dec9417b8611e34e787a3e4c37686b5131f9e5c5" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] b4558b4b485326f27c5cda2b117ef2373da21b353891a700844242d6fd2417a6
[INFO] running `Command { std: "docker" "start" "-a" "b4558b4b485326f27c5cda2b117ef2373da21b353891a700844242d6fd2417a6", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.36s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/h3x-c1056fb88ea22084)
[INFO] [stdout] 
[INFO] [stdout] running 24 tests
[INFO] [stdout] test frame::tests::incomplete_payload ... ok
[INFO] [stdout] test frame::tests::encode_and_decode ... ok
[INFO] [stdout] test frame::tests::new_frame ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_empty_value ... ok
[INFO] [stdout] test frame::tests::test_data_frames ... ok
[INFO] [stdout] test frame::tests::incomplete_length ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_exact_match ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_name_match_only ... ok
[INFO] [stdout] test frame::tests::incomplete_type ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_no_match ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_name_not_existing ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_value_case_sensitive ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_value_empty ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_value_existing ... ok
[INFO] [stdout] test qpack::r#static::tests::test_static_table_entries ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_value_match_only ... ok
[INFO] [stdout] test qpack::r#static::tests::test_static_table_length ... ok
[INFO] [stdout] test quic::test::pair ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_value_not_existing ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_multiple_entries_same_name ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_name_case_sensitive ... ok
[INFO] [stdout] test qpack::r#static::tests::test_find_name_existing ... ok
[INFO] [stdout] 2026-04-10T08:05:25.313760Z  INFO h3x::qpack::tests: Sent encoder stream type
[INFO] [stdout] 2026-04-10T08:05:25.316373Z  INFO h3x::qpack::tests: Sent decoder stream type
[INFO] [stdout] 2026-04-10T08:05:25.316761Z DEBUG h3x::quic::test: MockStreamWriter send 2 bytes bytes=b"\x014" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.316849Z DEBUG h3x::quic::test: MockStreamWriter send 6 bytes bytes=b"\0\0\xd4\xd7p\x91" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.316899Z DEBUG h3x::quic::test: MockStreamWriter send 17 bytes bytes=b"\x9d\x9f+\xc8ZN\xbd\x03\x8dy\x8bU%H\xd7\xa8\xa9" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.316955Z DEBUG h3x::quic::test: MockStreamWriter send 2 bytes bytes=b"q\x8a" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.317106Z DEBUG h3x::quic::test: MockStreamWriter send 10 bytes bytes=b"`u\x99\x8e\xe1b\xda\xe88\xe4" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.317167Z DEBUG h3x::quic::test: MockStreamWriter send 3 bytes bytes=b"\x7fP\x8d" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.318366Z DEBUG h3x::quic::test: MockStreamWriter send 13 bytes bytes=b"\x98\xb5\x16\x94\x8db[e\x0c\x01vW\x07" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.317301Z DEBUG interface: Bind interface successfully bind_uri=inet://[::1]:0/?alloc_port_id=1
[INFO] [stdout] 2026-04-10T08:05:25.318994Z  INFO h3x::qpack::tests: Header frame sent
[INFO] [stdout] 2026-04-10T08:05:25.319179Z DEBUG h3x::quic::test: MockStreamWriter send 3 bytes bytes=b"\xdd\0\r" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.319484Z DEBUG h3x::quic::test: MockStreamWriter send 13 bytes bytes=b"Hello, World!" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.319559Z  INFO h3x::qpack::tests: Data frame sent
[INFO] [stdout] 2026-04-10T08:05:25.319633Z DEBUG h3x::quic::test: MockStreamReader received 2 bytes bytes=b"\x014" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.320442Z DEBUG h3x::quic::test: MockStreamReader received 6 bytes bytes=b"\0\0\xd4\xd7p\x91" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.321053Z DEBUG h3x::quic::test: MockStreamReader received 17 bytes bytes=b"\x9d\x9f+\xc8ZN\xbd\x03\x8dy\x8bU%H\xd7\xa8\xa9" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.321697Z DEBUG h3x::quic::test: MockStreamReader received 2 bytes bytes=b"q\x8a" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.322245Z DEBUG h3x::quic::test: MockStreamReader received 10 bytes bytes=b"`u\x99\x8e\xe1b\xda\xe88\xe4" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.322812Z DEBUG h3x::quic::test: MockStreamReader received 3 bytes bytes=b"\x7fP\x8d" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.323367Z DEBUG h3x::quic::test: MockStreamReader received 13 bytes bytes=b"\x98\xb5\x16\x94\x8db[e\x0c\x01vW\x07" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.325398Z DEBUG h3x::quic::test: MockStreamReader received 3 bytes bytes=b"\xdd\0\r" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.326217Z  INFO h3x::qpack::tests: Decoded field section field_section=FieldSection { pseudo_headers: Some(Request { method: Some(POST), scheme: Some("https"), authority: Some(h3x.demo.lab.genmeta.net), path: Some(/api/v1/upload) }), header_map: {"user-agent": "genemta-curl/0.3.0", "accept": "*/*"} }
[INFO] [stdout] 2026-04-10T08:05:25.326874Z  INFO h3x::qpack::tests: Got data frame, reading
[INFO] [stdout] 2026-04-10T08:05:25.327482Z DEBUG h3x::quic::test: MockStreamReader received 13 bytes bytes=b"Hello, World!" stream_id=0
[INFO] [stdout] 2026-04-10T08:05:25.328113Z  INFO h3x::qpack::tests: Read data frame
[INFO] [stdout] test qpack::tests::r#static ... ok
[INFO] [stdout] 2026-04-10T08:05:25.330662Z  INFO test: Listening on [::1]:58978
[INFO] [stdout] 2026-04-10T08:05:25.331629Z DEBUG rustls::webpki::anchors: add_parsable_certificates processed 1 valid and 0 invalid certs
[INFO] [stdout] 2026-04-10T08:05:25.332337Z DEBUG rustls::webpki::anchors: add_parsable_certificates processed 1 valid and 0 invalid certs
[INFO] [stdout] 2026-04-10T08:05:25.333477Z DEBUG client_fallback:execute_request: h3x::pool: (Re)trying to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.334057Z DEBUG client_fallback:execute_request: h3x::pool: Acquired connection lock, try to initial connection
[INFO] [stdout] 2026-04-10T08:05:25.334633Z DEBUG client_fallback:execute_request: h3x::pool: Trying to connect to localhost:58978
[INFO] [stdout] 2026-04-10T08:05:25.335252Z DEBUG client_fallback:execute_request: h3x::client: Connecting to localhost:58978 via gm_quic
[INFO] [stdout] 2026-04-10T08:05:25.335897Z DEBUG client_fallback:execute_request: gm_quic::client: Connecting to localhost:58978
[INFO] [stdout] 2026-04-10T08:05:25.336629Z DEBUG client_echo:execute_request: h3x::pool: (Re)trying to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.337417Z DEBUG client_health:execute_request: h3x::pool: (Re)trying to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.338725Z DEBUG client_fallback:execute_request: h3x::client: DNS lookup for localhost:58978 returned about 2 addresses
[INFO] [stdout] 2026-04-10T08:05:25.343635Z DEBUG client_fallback:execute_request: interface: Bind interface successfully bind_uri=inet://[::]:0/?alloc_port_id=2
[INFO] [stdout] 2026-04-10T08:05:25.346402Z DEBUG client_fallback:execute_request: interface: Bind interface successfully bind_uri=inet://0.0.0.0:0/?alloc_port_id=3
[INFO] [stdout] 2026-04-10T08:05:25.347411Z DEBUG client_fallback:execute_request: rustls::client::hs: No cached session for DnsName("localhost")
[INFO] [stdout] 2026-04-10T08:05:25.347803Z DEBUG client_fallback:execute_request: rustls::client::hs: Not resuming any session
[INFO] [stdout] 2026-04-10T08:05:25.348712Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: Starting a new connection
[INFO] [stdout] 2026-04-10T08:05:25.350598Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: Add new path pathway=Direct([::]:46943)---Direct([::1]:58978) link=[::]:46943<->[::1]:58978 is_probed=false is_initial_path=true
[INFO] [stdout] 2026-04-10T08:05:25.351217Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: Add new path pathway=Direct(0.0.0.0:35819)---Direct(127.0.0.1:58978) link=0.0.0.0:35819<->127.0.0.1:58978 is_probed=false is_initial_path=false
[INFO] [stdout] 2026-04-10T08:05:25.351662Z DEBUG client_fallback:execute_request: h3x::pool: QUIC connection established, try to upgrade to H3
[INFO] [stdout] 2026-04-10T08:05:25.358310Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: quic: Starting a new connection
[INFO] [stdout] 2026-04-10T08:05:25.360687Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: quic: Add new path pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 is_probed=true is_initial_path=true
[INFO] [stdout] 2026-04-10T08:05:25.363167Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: rustls::server::hs: decided upon suite TLS13_AES_256_GCM_SHA384
[INFO] [stdout] 2026-04-10T08:05:25.364955Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: rustls::server::hs: Chosen ALPN protocol ProtocolName(6833)
[INFO] [stdout] 2026-04-10T08:05:25.366554Z  INFO try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: qconnection::tls: client_name=None
[INFO] [stdout] 2026-04-10T08:05:25.369302Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: rustls::client::hs: Using ciphersuite TLS13_AES_256_GCM_SHA384
[INFO] [stdout] 2026-04-10T08:05:25.371993Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: rustls::client::tls13: Not resuming
[INFO] [stdout] 2026-04-10T08:05:25.373804Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: rustls::client::tls13: TLS1.3 encrypted extensions: ServerExtensions { server_name_ack: (), selected_protocol: SingleProtocolName(ProtocolName(6833)), transport_parameters: 080240640404801000000704801000000104800075300e010a0504801000000604801000000008571c3083ff688319090240640f08e54b8040ec4f8330, unknown_extensions: {}, .. }
[INFO] [stdout] 2026-04-10T08:05:25.374607Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: rustls::client::hs: ALPN protocol is Some(b"h3")
[INFO] [stdout] 2026-04-10T08:05:25.376123Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: TLS handshake finished
[INFO] [stdout] 2026-04-10T08:05:25.376836Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: 0-RTT is not enabled, or not accepted by the server.
[INFO] [stdout] 2026-04-10T08:05:25.379026Z DEBUG client_fallback:execute_request: h3x::pool: H3 connection established, verifying peer identity
[INFO] [stdout] 2026-04-10T08:05:25.379647Z DEBUG client_fallback:execute_request: h3x::pool: Initialed new connection, gogogo
[INFO] [stdout] 2026-04-10T08:05:25.380153Z DEBUG client_fallback:execute_request: h3x::pool: (Re)trying to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.380682Z DEBUG client_fallback:execute_request: h3x::client: Connected authority=localhost:58978
[INFO] [stdout] 2026-04-10T08:05:25.381738Z DEBUG client_echo:execute_request: h3x::pool: Entry updated, try to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.382282Z DEBUG client_echo:execute_request: h3x::pool: (Re)trying to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.382788Z DEBUG client_echo:execute_request: h3x::client: Connected authority=localhost:58978
[INFO] [stdout] 2026-04-10T08:05:25.387423Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: quic: TLS handshake finished
[INFO] [stdout] 2026-04-10T08:05:25.388064Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319"}:connection{role=server odcid=571c3083ff688319}: quic: 0-RTT is enabled and accepted by the server.
[INFO] [stdout] 2026-04-10T08:05:25.389258Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319" server_name="localhost"}: quic_listeners: Accepted incoming connection
[INFO] [stdout] 2026-04-10T08:05:25.390122Z DEBUG client_health:execute_request: h3x::pool: Entry updated, try to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.390620Z DEBUG client_health:execute_request: h3x::pool: (Re)trying to reuse connection
[INFO] [stdout] 2026-04-10T08:05:25.391154Z DEBUG client_health:execute_request: h3x::client: Connected authority=localhost:58978
[INFO] [stdout] 2026-04-10T08:05:25.392777Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: Back off initial RTT 37ms
[INFO] [stdout] 2026-04-10T08:05:25.393435Z DEBUG server:handle_connection: h3x::server: Accepted new QUIC connection
[INFO] [stdout] 2026-04-10T08:05:25.394109Z DEBUG server:handle_connection: h3x::server: Accepted new H3 connection
[INFO] [stdout] 2026-04-10T08:05:25.395261Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319" server_name="localhost"}:connection{role=server odcid=571c3083ff688319}: quic: Connection state changed new_state=Handshaked
[INFO] [stdout] 2026-04-10T08:05:25.397608Z DEBUG server:handle_connection{server_name="localhost"}: h3x::server: Accepted incoming request stream
[INFO] [stdout] 2026-04-10T08:05:25.398312Z DEBUG server:handle_connection{server_name="localhost"}: h3x::server: Accepted incoming request stream
[INFO] [stdout] 2026-04-10T08:05:25.398984Z DEBUG server:handle_connection{server_name="localhost"}:handle_request{stream_id=0}: h3x::server: Resolving incoming request
[INFO] [stdout] 2026-04-10T08:05:25.399585Z DEBUG server:handle_connection{server_name="localhost"}:handle_request{stream_id=4}: h3x::server: Resolving incoming request
[INFO] [stdout] 2026-04-10T08:05:25.400498Z DEBUG server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}: h3x::server: Resolved new request
[INFO] [stdout] 2026-04-10T08:05:25.402405Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echo service called
[INFO] [stdout] 2026-04-10T08:05:25.403033Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(891 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.404006Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.404607Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.405079Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(839 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.405878Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(324 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.406365Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.406611Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.407468Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.408263Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(265 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.408957Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(898 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.409665Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.410350Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.410943Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(860 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.411522Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(303 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.416129Z DEBUG client_fallback:execute_request:connection{role=client odcid=571c3083ff688319}: quic: Connection state changed new_state=Handshaked
[INFO] [stdout] 2026-04-10T08:05:25.417494Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.418226Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(1169 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.418459Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=4 method="POST" uri="https://localhost:58978/echo"}:echo_service: h3x::quic::gm_quic::tests: Echoing back request body part(171 bytes)
[INFO] [stdout] 2026-04-10T08:05:25.419235Z DEBUG server:handle_connection{server_name="localhost"}:handle_request{stream_id=0 method="GET" uri="https://localhost:58978/not_found"}: h3x::server: Resolved new request
[INFO] [stdout] 2026-04-10T08:05:25.419978Z DEBUG server:handle_connection{server_name="localhost"}: h3x::server: Accepted incoming request stream
[INFO] [stdout] 2026-04-10T08:05:25.421240Z DEBUG server:handle_connection{server_name="localhost"}:handle_request{stream_id=8}: h3x::server: Resolving incoming request
[INFO] [stdout] 2026-04-10T08:05:25.421722Z DEBUG server:handle_connection{server_name="localhost"}:handle_request{stream_id=8 method="GET" uri="https://localhost:58978/health"}: h3x::server: Resolved new request
[INFO] [stdout] 2026-04-10T08:05:25.422976Z  INFO server:handle_connection{server_name="localhost"}:handle_request{stream_id=8 method="GET" uri="https://localhost:58978/health"}:health_service: h3x::quic::gm_quic::tests: Health service called
[INFO] [stdout] 2026-04-10T08:05:25.426390Z  INFO client_echo: h3x::quic::gm_quic::tests: Request sent
[INFO] [stdout] 2026-04-10T08:05:25.426603Z  INFO client_echo: h3x::quic::gm_quic::tests: Response received
[INFO] [stdout] 2026-04-10T08:05:25.429341Z  INFO client_health: h3x::quic::gm_quic::tests: Request sent
[INFO] [stdout] 2026-04-10T08:05:25.429712Z  INFO client_fallback: h3x::quic::gm_quic::tests: Request sent
[INFO] [stdout] 2026-04-10T08:05:25.433397Z DEBUG try_accept_connection{bind_uri=inet://[::1]:0/?alloc_port_id=1 pathway=Direct([::1]:58978)---Direct([::1]:46943) link=[::1]:58978<->[::1]:46943 odcid="571c3083ff688319" server_name="localhost"}:connection{role=server odcid=571c3083ff688319}: quic: Connection state changed new_state=ApplicationClose(AppError { error_code: VarInt(256), reason: "H3_NO_ERROR (0x100)" })
[INFO] [stdout] test quic::gm_quic::tests::simpl_server ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 24 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.13s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests h3x
[INFO] [stdout] 
[INFO] [stdout] running 16 tests
[INFO] [stdout] test src/connection/settings.rs - connection::settings::Setting (line 22) ... ignored
[INFO] [stdout] test src/connection/stream.rs - connection::stream::UnidirectionalStream (line 26) ... ignored
[INFO] [stdout] test src/qpack/decoder.rs - qpack::decoder::DecoderInstruction::InsertCountIncrement (line 490) ... ignored
[INFO] [stdout] test src/qpack/decoder.rs - qpack::decoder::DecoderInstruction::SectionAcknowledgment (line 476) ... ignored
[INFO] [stdout] test src/qpack/decoder.rs - qpack::decoder::DecoderInstruction::StreamCancellation (line 483) ... ignored
[INFO] [stdout] test src/qpack/encoder.rs - qpack::encoder::EncoderInstruction::Duplicate (line 475) ... ignored
[INFO] [stdout] test src/qpack/encoder.rs - qpack::encoder::EncoderInstruction::InsertWithLiteralName (line 457) ... ignored
[INFO] [stdout] test src/qpack/encoder.rs - qpack::encoder::EncoderInstruction::InsertWithNameReference (line 441) ... ignored
[INFO] [stdout] test src/qpack/encoder.rs - qpack::encoder::EncoderInstruction::SetDynamicTableCapacity (line 434) ... ignored
[INFO] [stdout] test src/qpack/field_section.rs - qpack::field_section::EncodedFieldSectionPrefix (line 32) ... ignored
[INFO] [stdout] test src/qpack/field_section.rs - qpack::field_section::FieldLineRepresentation::IndexedFieldLine (line 138) ... ignored
[INFO] [stdout] test src/qpack/field_section.rs - qpack::field_section::FieldLineRepresentation::IndexedFieldLineWithPostBaseIndex (line 145) ... ignored
[INFO] [stdout] test src/qpack/field_section.rs - qpack::field_section::FieldLineRepresentation::LiteralFieldLineWithLiteralName (line 197) ... ignored
[INFO] [stdout] test src/qpack/field_section.rs - qpack::field_section::FieldLineRepresentation::LiteralFieldLineWithNameReference (line 152) ... ignored
[INFO] [stdout] test src/qpack/field_section.rs - qpack::field_section::FieldLineRepresentation::LiteralFieldLineWithPostBaseNameReference (line 181) ... ignored
[INFO] [stdout] test src/../README.md - (line 17) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 15 ignored; 0 measured; 0 filtered out; finished in 0.63s
[INFO] [stdout] 
[INFO] [stdout] all doctests ran in 0.76s; merged doctests compilation took 0.13s
[INFO] running `Command { std: "docker" "inspect" "b4558b4b485326f27c5cda2b117ef2373da21b353891a700844242d6fd2417a6", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "b4558b4b485326f27c5cda2b117ef2373da21b353891a700844242d6fd2417a6", kill_on_drop: false }`
[INFO] [stdout] b4558b4b485326f27c5cda2b117ef2373da21b353891a700844242d6fd2417a6