[INFO] fetching crate wl-proxy 0.1.0...
[INFO] testing wl-proxy-0.1.0 against beta-2026-01-20 for beta-1.94-1
[INFO] extracting crate wl-proxy 0.1.0 into /workspace/builds/worker-0-tc2/source
[INFO] started tweaking crates.io crate wl-proxy 0.1.0
[INFO] finished tweaking crates.io crate wl-proxy 0.1.0
[INFO] tweaked toml for crates.io crate wl-proxy 0.1.0 written to /workspace/builds/worker-0-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate wl-proxy 0.1.0 on toolchain beta-2026-01-20
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+beta-2026-01-20" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wl-proxy 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" "+beta-2026-01-20" "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:98afbf2d16093dec2546ff8915fddc74e65664aa03fc460b3712b1c2c54a33e4" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-01-20" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] ad299f1256a6e4ccd9b3a1b307dda93826f3051ef89a5c52803a1fea4b0ad218
[INFO] running `Command { std: "docker" "start" "-a" "ad299f1256a6e4ccd9b3a1b307dda93826f3051ef89a5c52803a1fea4b0ad218", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "ad299f1256a6e4ccd9b3a1b307dda93826f3051ef89a5c52803a1fea4b0ad218", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ad299f1256a6e4ccd9b3a1b307dda93826f3051ef89a5c52803a1fea4b0ad218", kill_on_drop: false }`
[INFO] [stdout] ad299f1256a6e4ccd9b3a1b307dda93826f3051ef89a5c52803a1fea4b0ad218
[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=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-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:98afbf2d16093dec2546ff8915fddc74e65664aa03fc460b3712b1c2c54a33e4" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-01-20" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 3b3529690686c6c6067577b9cd98359a0c53f193225059e98048ca18dde4b7da
[INFO] running `Command { std: "docker" "start" "-a" "3b3529690686c6c6067577b9cd98359a0c53f193225059e98048ca18dde4b7da", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.178
[INFO] [stderr]    Compiling find-msvc-tools v0.1.5
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling phf_shared v0.13.1
[INFO] [stderr]    Compiling linearize v0.1.5
[INFO] [stderr]    Compiling debug-fn v1.0.0
[INFO] [stderr]    Compiling isnt v0.2.0
[INFO] [stderr]    Compiling run-on-drop v1.0.0
[INFO] [stderr]    Compiling error_reporter v1.0.0
[INFO] [stderr]    Compiling syn v2.0.111
[INFO] [stderr]    Compiling cc v1.2.49
[INFO] [stderr]    Compiling phf_generator v0.13.1
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling phf_macros v0.13.1
[INFO] [stderr]    Compiling linearize-derive v0.2.1
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling phf v0.13.1
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling wl-proxy v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 14.18s
[INFO] running `Command { std: "docker" "inspect" "3b3529690686c6c6067577b9cd98359a0c53f193225059e98048ca18dde4b7da", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "3b3529690686c6c6067577b9cd98359a0c53f193225059e98048ca18dde4b7da", kill_on_drop: false }`
[INFO] [stdout] 3b3529690686c6c6067577b9cd98359a0c53f193225059e98048ca18dde4b7da
[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=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-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:98afbf2d16093dec2546ff8915fddc74e65664aa03fc460b3712b1c2c54a33e4" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-01-20" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] f2a5164b0067b8d3118ce58845e1ce5ae2b3e2e8c18e7b172154199f21fc4cf1
[INFO] running `Command { std: "docker" "start" "-a" "f2a5164b0067b8d3118ce58845e1ce5ae2b3e2e8c18e7b172154199f21fc4cf1", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling jiff v0.2.16
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling wl-proxy v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling env_logger v0.11.8
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 15.50s
[INFO] running `Command { std: "docker" "inspect" "f2a5164b0067b8d3118ce58845e1ce5ae2b3e2e8c18e7b172154199f21fc4cf1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "f2a5164b0067b8d3118ce58845e1ce5ae2b3e2e8c18e7b172154199f21fc4cf1", kill_on_drop: false }`
[INFO] [stdout] f2a5164b0067b8d3118ce58845e1ce5ae2b3e2e8c18e7b172154199f21fc4cf1
[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=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-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:98afbf2d16093dec2546ff8915fddc74e65664aa03fc460b3712b1c2c54a33e4" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-01-20" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 50ab8718928a70f0caaaedc3ac4378ec196a20c18a432a5fdd9904c9edfce7a6
[INFO] running `Command { std: "docker" "start" "-a" "50ab8718928a70f0caaaedc3ac4378ec196a20c18a432a5fdd9904c9edfce7a6", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.47s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wl_proxy-b3e187eab71b87a5)
[INFO] [stdout] 
[INFO] [stdout] running 103 tests
[INFO] [stderr] [1272915.970] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272915.970] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.001] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.004] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.041] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.041] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.051] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.053] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.073] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.074] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.089] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.089] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.122] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.65535 message: unknown message id 65535
[INFO] [stderr] [1272916.368] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.399] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.705] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.735] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.764] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.780] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.801] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.814] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272916.862] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272916.878] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272917.636] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272917.836] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272917.877] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272917.930] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272917.974] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272918.147] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272918.205] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272918.247] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272918.281] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#5)
[INFO] [stderr] [1272918.312] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272918.361] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272918.446] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272918.711] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test client::tests::objects ... ok
[INFO] [stderr] [1272918.819] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test client::tests::unset_handler ... ok
[INFO] [stderr] [1272919.329] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test endpoint::tests::invalid_message ... ok
[INFO] [stderr] [1272919.435] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::display ... ok
[INFO] [stderr] [1272919.499] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::from_f32 ... ok
[INFO] [stderr] [1272919.583] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::debug ... ok
[INFO] [stderr] [1272919.648] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test endpoint::tests::dispatch_destroyed ... ok
[INFO] [stderr] [1272919.728] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272919.762] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272919.785] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272919.796] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272919.817] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272919.820] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272919.697] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272919.830] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272919.843] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272919.886] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272919.906] {client} server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1272919.914] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1272919.960] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272919.989] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272920.028] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272920.063] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [1272920.193] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272920.256] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272920.292] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272920.333] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272920.336] {proxy } client#1    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1272920.400] {proxy } server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1272920.483] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1272920.536] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stdout] test fixed::tests::from_i64 ... ok
[INFO] [stderr] [1272920.663] {server} client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test fixed::tests::test_binops ... ok
[INFO] [stderr] [1272920.693] {server} client#1    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stdout] test fixed::tests::test_unops ... ok
[INFO] [stderr] [1272920.704] {server} client#1    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stdout] test fixed::tests::from_i32 ... ok
[INFO] [stderr] [1272920.731] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test fixed::tests::to_f32 ... ok
[INFO] [stderr] [1272920.742] {server} client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stdout] test fixed::tests::test_shiftops ... ok
[INFO] [stderr] [1272920.750] {server} client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272920.756] {server} client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272921.004] {proxy } server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1272921.012] {proxy } client#1    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1272921.032] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272921.039] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272921.450] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272921.465] {proxy } client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272921.471] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272921.477] {proxy } client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272921.702] {client} server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1272921.719] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272921.725] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272921.729] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stdout] test client::tests::disconnected ... ok
[INFO] [stdout] test fixed::tests::from_ints ... ok
[INFO] [stdout] test fixed::tests::to_i32_ceil ... ok
[INFO] [stdout] test fixed::tests::one_two ... ok
[INFO] [stdout] test endpoint::tests::test ... ok
[INFO] [stdout] test global_mapper::tests::test ... ok
[INFO] [stdout] test fixed::tests::to_i32_floor ... ok
[INFO] [stdout] test global_mapper::tests::test_default ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Could not handle server global: the message handler is already borrowed
[INFO] [stdout] test endpoint::tests::lookup ... ok
[INFO] [stdout] test fixed::tests::to_i32_nearest ... ok
[INFO] [stdout] test fixed::tests::minima ... ok
[INFO] [stdout] test fixed::tests::wire ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Could not handle server global remove: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::to_i32_zero ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_error ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Could not handle client bind: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_ignored ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Could not add synthetic global: the message handler is already borrowed
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stdout] test global_mapper::tests::test_ignore_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_error ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Could not remove synthetic global: the message handler is already borrowed
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test global_mapper::tests::test_forward_bind_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_synthetic ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_ignored ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind ... ok
[INFO] [stdout] test handler::tests::clone ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_nonexistent ... ok
[INFO] [stderr] [1272929.220] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272929.225] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272929.295] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test handler::tests::map ... ok
[INFO] [stdout] test handler::tests::borrow ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_synthetic ... ok
[INFO] [stderr] [1272929.475] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global_error ... ok
[INFO] [stderr] [1272929.557] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272929.711] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test handler::tests::replace ... ok
[INFO] [stderr] [1272929.867] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272929.875] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272929.918] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272929.941] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272929.975] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272930.019] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272930.061] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272930.081] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272930.103] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272930.130] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272930.137] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272930.146] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272930.170] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272930.173] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272930.187] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272930.192] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272930.199] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272930.225] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272930.234] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272930.246] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272930.269] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272930.280] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272930.307] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272930.323] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272930.330] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272930.335] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272930.371] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272930.382] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272930.400] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272930.406] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272930.413] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272930.417] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272930.421] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272930.426] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272930.466] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272930.479] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272930.484] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272930.487] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stdout] test object::tests::client_id ... ok
[INFO] [stderr] [1272930.965] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.025] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.108] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.125] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.149] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.176] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.191] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.242] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.328] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.372] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::double_send ... ok
[INFO] [stderr] [1272931.404] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.407] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272931.415] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.423] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.427] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.436] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.450] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.457] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.465] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272931.468] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.477] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272931.482] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272931.487] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.498] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4294967295)
[INFO] [stderr] [1272931.503] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.552] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.560] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272931.567] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.576] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.580] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272931.591] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272931.591] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272931.637] {proxy } client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.sync message: could not assign client id 4294967295 to argument callback: the id 4294967295 is too large to be a client id
[INFO] [stderr] [1272931.638] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272931.690] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272931.695] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272931.701] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272931.746] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272931.777] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [1272931.794] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [1272931.904] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.147] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.170] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.271] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.301] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.334] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.338] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.348] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.358] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.362] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.377] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.396] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.418] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.430] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.443] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.471] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272932.485] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272932.513] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272932.519] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind ... ok
[INFO] [stderr] [1272932.558] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test object::tests::duplicate_generated_client_id ... ok
[INFO] [stderr] [1272932.577] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test object::tests::client_object_with_server_id ... ok
[INFO] [stderr] [1272932.583] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test object::tests::request_without_server ... ok
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not handle a wlproxy_test#3.create_dummy message: could not assign client id 4 to argument id: the client id 4 is already in use
[INFO] [stdout] test object::tests::client ... ok
[INFO] [stderr] [1272932.718] {server} client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1272933.578] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272933.611] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_error ... ok
[INFO] [stdout] test object::tests::destroyed_client ... ok
[INFO] [stderr] [1272934.677] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272934.759] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272934.829] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272934.908] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272934.965] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272935.016] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272935.096] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272935.129] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272935.154] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272935.175] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272935.233] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#50)
[INFO] [stdout] test object::tests::duplicate_client_id ... ok
[INFO] [stderr] [1272944.860] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272944.869] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272944.891] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272944.939] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272944.952] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272944.963] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272944.983] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.097] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.221] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.294] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.322] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.327] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.340] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.351] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.356] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.363] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.379] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.407] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.494] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.493] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.509] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.542] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.702] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.765] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.821] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.859] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272945.889] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.918] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272945.955] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1272945.976] {client} server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1272945.997] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272946.231] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272946.252] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272946.283] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272946.293] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272946.302] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272946.316] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272946.699] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272946.755] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272946.776] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::version ... ok
[INFO] [stderr] [1272946.800] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::get_handler ... ok
[INFO] [stderr] [1272946.882] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272946.953] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272946.988] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.007] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272947.028] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272947.048] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.088] {client} server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [1272947.133] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272947.151] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.178] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.205] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272947.233] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.241] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272947.257] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.321] {proxy } client#1    -> wlproxy_test#3.send_object()
[INFO] [stderr] [1272947.400] {proxy } server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [1272947.403] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1272947.423] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1272947.444] {proxy } client#1    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1272947.449] {proxy } server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1272947.453] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272947.462] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272947.507] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272947.509] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272947.548] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272947.565] {server} client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1272947.579] {server} client#1    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1272947.583] {server} client#1    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1272947.592] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272947.599] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272947.615] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272947.654] {proxy } server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1272947.654] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272947.667] {proxy } client#1    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1272947.687] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272947.697] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272947.704] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272947.710] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272947.739] {client} server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1272947.755] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272947.759] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272947.777] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1272947.790] {client} server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1272947.796] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1272947.819] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1272947.833] {proxy } client#1    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1272947.838] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1272947.846] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272947.872] {server} client#1    -> wlproxy_test#3.send_object()
[INFO] [stderr] [1272947.887] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272947.905] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272947.912] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272947.951] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272947.961] {proxy } client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272947.967] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272947.971] {server} client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1272947.973] {proxy } client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272947.996] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272947.997] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272948.000] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272948.008] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272948.014] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272948.022] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [1272948.027] {client} server      <= wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [1272948.039] {client} server      <= wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [1272948.063] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [1272948.071] {proxy } client#1    -> wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [1272948.120] {proxy } server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1272948.134] {proxy } client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1272948.143] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2026-01-28T11:46:53Z WARN  wl_proxy::protocol_helpers] Could not forward a wlproxy_test_non_forward.echo message: the receiver has no server id
[INFO] [stderr] [1272948.177] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272948.190] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272948.196] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272948.224] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1272948.223] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [1272948.253] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272948.268] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272948.272] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272948.287] {client} server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1272948.320] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272948.326] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272948.339] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272948.345] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272948.387] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272948.393] {proxy } client#1    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1272948.398] {proxy } server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1272948.402] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272948.410] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272948.434] {proxy } client#1    <= wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [1272948.462] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272948.495] {proxy } client#1    <= wl_display#1.delete_id(id: 7)
[INFO] [stderr] [1272948.516] {server} client#1    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1272948.720] {client} server      -> wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [1272948.727] {client} server      -> wl_display#1.delete_id(id: 7)
[INFO] [stderr] [1272948.747] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [1272948.752] {client} server      <= wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [1272948.762] {client} server      <= wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [1272948.786] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [1272948.795] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1272948.800] {proxy } client#1    -> wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [1272948.803] {proxy } server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1272948.807] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [1272948.818] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1272948.877] {server} client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1272948.886] {server} client#1    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1272948.905] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272948.917] {server} client#1    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1272948.922] {server} client#1    <= wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [1272948.928] {server} client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1272948.935] {server} client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272948.941] {server} client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272948.961] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272948.981] {proxy } server      -> wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [1272948.985] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272948.995] {proxy } client#1    <= wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [1272949.001] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1272949.005] {proxy } client#1    <= wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [1272949.010] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1272949.016] {proxy } client#1    <= wl_display#1.delete_id(id: 8)
[INFO] [stderr] [1272949.043] {client} server      -> wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [1272949.057] {client} server      -> wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [1272949.062] {client} server      -> wl_display#1.delete_id(id: 8)
[INFO] [stderr] [1272949.098] {proxy } server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1272949.122] {proxy } client#1    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1272949.157] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272949.178] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272949.200] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272949.221] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272949.264] {client} server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1272949.303] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272949.328] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272950.580] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272950.616] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272950.649] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272950.660] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272950.668] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272950.682] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test poll::tests::many ... ok
[INFO] [stdout] test object::tests::state ... ok
[INFO] [stdout] test object::tests::server_destroyed ... ok
[INFO] [stdout] test poll::tests::test ... ok
[INFO] [stdout] test object::tests::forward ... ok
[INFO] [stdout] test object::tests::server_sent ... ok
[INFO] [stdout] test state::tests::add_client ... ok
[INFO] [stdout] test state::tests::destroyed_readable ... ok
[INFO] [stderr] [1272953.874] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272954.317] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272954.851] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272954.898] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272954.915] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272954.950] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272954.959] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272954.967] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272954.979] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272955.007] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1272955.017] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.039] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1272955.044] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272955.050] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1272955.057] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.063] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.062] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272955.096] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1272955.111] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1272955.129] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272955.139] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.147] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272955.152] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272955.205] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1272955.211] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1272955.223] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272955.230] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272955.238] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272955.240] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272955.245] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272955.250] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272955.276] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1272955.366] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272955.442] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272955.470] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272955.556] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1272955.635] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.721] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1272955.773] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1272955.804] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.858] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272955.938] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1272956.004] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1272956.037] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272956.092] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272956.248] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272956.297] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272956.916] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272957.197] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272957.489] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272957.589] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1272957.598] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1272957.615] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.621] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.650] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272957.653] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272957.658] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272957.662] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272957.678] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272957.693] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272957.694] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1272957.698] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.703] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272957.723] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272957.732] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272957.707] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272957.740] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272957.752] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1272957.753] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272957.761] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272957.782] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1272957.790] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1272957.791] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272957.795] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272957.801] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272957.802] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272957.834] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272957.855] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1272957.857] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272957.863] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1272957.870] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272957.871] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.877] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272957.882] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272957.887] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272957.894] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272957.904] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272957.914] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1272957.922] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.918] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1272957.949] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.954] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.959] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272957.960] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272957.962] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272957.963] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272957.968] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272957.972] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272957.978] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.984] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272957.993] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1272957.997] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.002] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.005] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.006] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272958.011] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.020] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1272958.027] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.045] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1272958.052] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1272958.058] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.064] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.093] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1272958.100] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1272958.106] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.112] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.118] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.121] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.152] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1272958.157] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1272958.162] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.167] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.173] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.175] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.179] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.191] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.212] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1272958.217] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.222] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.225] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.265] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1272958.273] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.291] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1272958.299] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1272958.304] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.310] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.355] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1272958.364] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1272958.370] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.376] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.381] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.385] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.417] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1272958.421] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1272958.427] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.432] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.438] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.440] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.444] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.449] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.467] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1272958.472] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.477] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.480] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.494] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1272958.501] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.519] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1272958.550] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1272958.557] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.564] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.587] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1272958.594] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1272958.600] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.614] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272958.620] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.624] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.653] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1272958.657] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1272958.663] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.668] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.673] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.675] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.679] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.683] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272958.700] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1272958.704] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272958.708] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272958.711] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stdout] test state::tests::destructor ... ok
[INFO] [stdout] test state::tests::remote_destructor ... ok
[INFO] [stdout] test state::tests::count_hops ... ok
[INFO] [stdout] test trans::tests::array ... ok
[INFO] [stdout] test state::tests::recursive_dispatch ... ok
[INFO] [stderr] [1272960.578] {client} server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 10, fd2: 12)
[INFO] [stderr] [1272960.784] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272960.975] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272961.157] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272961.397] {proxy } client#1    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 49, fd2: 50)
[INFO] [stderr] [1272961.631] {proxy } server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 49, fd2: 50)
[INFO] [stderr] [1272961.820] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272962.041] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272962.275] {server} client#1    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 61, fd2: 62)
[INFO] [stderr] [1272962.401] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272962.426] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272962.455] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272962.464] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272962.477] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272962.489] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272962.512] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272962.520] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272962.567] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stdout] test trans::tests::large_message ... ok
[INFO] [stderr] [1272963.458] {server} client#1    <= wlproxy_test_fd_echo#4.fd(fd1: 61, fd2: 62)
[INFO] [stderr] [1272963.505] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272963.518] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272963.570] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272963.581] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272963.823] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272963.893] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272963.967] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272963.991] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272964.111] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 9 that is not a multiple of 4
[INFO] [stderr] [1272964.809] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272964.831] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1272965.064] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test trans::tests::not_word_size ... ok
[INFO] [stderr] [1272965.547] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272965.697] {proxy } server      -> wlproxy_test_fd_echo#4.fd(fd1: 61, fd2: 62)
[INFO] [stderr] [1272965.763] {proxy } client#1    <= wlproxy_test_fd_echo#4.fd(fd1: 61, fd2: 62)
[INFO] [stderr] [1272965.801] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272965.826] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272965.836] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272965.845] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272965.848] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272965.853] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272965.857] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272965.899] {client} server      -> wlproxy_test_fd_echo#4.fd(fd1: 69, fd2: 71)
[INFO] [stderr] [1272965.905] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272965.936] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272965.952] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272965.987] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.002] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.025] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272966.081] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.097] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.139] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.166] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.206] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.225] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2026-01-28T11:46:53Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 4 < 8
[INFO] [stderr] [1272966.235] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.252] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.288] {client} server      <= wlproxy_test#3.recv_fd(fd: 85)
[INFO] [stderr] [1272966.294] {client} server      <= wlproxy_test#3.recv_fd(fd: 85)
[INFO] [stderr] [1272966.303] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272966.356] {proxy } client#1    -> wlproxy_test#3.recv_fd(fd: 58)
[INFO] [stderr] [1272966.362] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 58)
[INFO] [stderr] [1272966.395] {proxy } client#1    -> wlproxy_test#3.recv_fd(fd: 58)
[INFO] [stderr] [1272966.399] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 58)
[INFO] [stderr] [1272966.404] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272966.418] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272966.041] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.471] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.493] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.502] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.519] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.553] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.586] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272966.456] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272966.644] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272966.674] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1272966.681] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1272966.716] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272966.783] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272966.980] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1272967.042] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272967.083] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1272967.122] {server} client#1    -> wlproxy_test#3.recv_fd(fd: 65)
[INFO] [stderr] [1272967.181] {server} client#1    -> wlproxy_test#3.recv_fd(fd: 65)
[INFO] [stderr] [1272967.560] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272967.637] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272967.684] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272967.814] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272967.865] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1272967.914] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272967.961] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272967.986] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272968.047] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272968.087] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272968.140] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272968.434] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272968.943] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272969.157] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1272969.210] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1272969.382] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test trans::tests::small_message ... ok
[INFO] [stdout] test trans::tests::fd ... ok
[INFO] [stdout] test trans::tests::echo_fd ... ok
[INFO] [stdout] test trans::tests::edge_header ... ok
[INFO] [stdout] test state::tests::closed_client ... ok
[INFO] [stdout] test acceptor::tests::test ... FAILED
[INFO] [stdout] test utils::stack::tests::stack ... ok
[INFO] [stdout] test utils::free_list::tests::test ... ok
[INFO] [stdout] test utils::stash::tests::test ... ok
[INFO] [stdout] test fixed::tests::maximum - should panic ... ok
[INFO] [stdout] test fixed::tests::minimum - should panic ... ok
[INFO] [stdout] test object::tests::duplicate_server_id - should panic ... ok
[INFO] [stdout] test handler::tests::multi_borrow - should panic ... ok
[INFO] [stdout] test state::tests::acceptor ... FAILED
[INFO] [stdout] test object::tests::invalid_server_id - should panic ... ok
[INFO] [stdout] test object::tests::wrong_downcast - should panic ... ok
[INFO] [stdout] test utils::free_list::tests::release_out_of_bounds - should panic ... ok
[INFO] [stdout] test state::tests::many_events ... ok
[INFO] [stdout] test trans::tests::many_messages_with_fd ... ok
[INFO] [stdout] test trans::tests::many_messages ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- acceptor::tests::test stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'acceptor::tests::test' (25) panicked at src/acceptor/tests.rs:9:46:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: AcceptorError(XrdNotSet)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x59fc19780642 - std::backtrace_rs::backtrace::libunwind::trace::hf0bd46b30bc61685
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x59fc19780642 - std::backtrace_rs::backtrace::trace_unsynchronized::h1d1fbb72ad89d7b7
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x59fc19780642 - std::sys::backtrace::_print_fmt::he38b6f68ca847f47
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x59fc19780642 - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::hb7e843cde1bc81a3
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x59fc19792bba - core::fmt::rt::Argument::fmt::hc1dd77ac64f2688c
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x59fc19792bba - core::fmt::write::h952c506e2dbe9cff
[INFO] [stdout]    6:     0x59fc1974db46 - std::io::default_write_fmt::hd23bd8145c03a23a
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x59fc1974db46 - std::io::Write::write_fmt::hdd3314a2bd8a34bd
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x59fc1975e419 - std::sys::backtrace::BacktraceLock::print::h1079b82381c2c252
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x59fc1975e419 - std::panicking::default_hook::{{closure}}::h85cb76b8462c00f2
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x59fc1975e2b1 - std::panicking::default_hook::h0134d220cc034c02
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x59fc1971bc9e - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::hb2e68dca3970e3ca
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   12:     0x59fc1971bc9e - test::test_main_with_exit_callback::{{closure}}::ha7ec2063a2565ec3
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x59fc1975e692 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::haebee478d0f56cf4
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   14:     0x59fc1975e692 - std::panicking::panic_with_hook::h8119b6db1fef734f
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x59fc1975e4d8 - std::panicking::panic_handler::{{closure}}::h24f5360b91482c0e
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x59fc19759a69 - std::sys::backtrace::__rust_end_short_backtrace::h4e60c5cbd1bd0108
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x59fc197426dd - __rustc[e4c6931bd8050421]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x59fc1979b22c - core::panicking::panic_fmt::hb1614a3ff6840071
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x59fc1979a7e2 - core::result::unwrap_failed::h7d4c34940aded59c
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x59fc193105aa - core::result::Result<T,E>::unwrap::he21855e8afa8c185
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x59fc193105aa - wl_proxy::acceptor::tests::test::h99fb66e4c0750e98
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:9:46
[INFO] [stdout]   22:     0x59fc19310e27 - wl_proxy::acceptor::tests::test::{{closure}}::h84987505a91871a9
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:8:10
[INFO] [stdout]   23:     0x59fc1936eab6 - core::ops::function::FnOnce::call_once::h207de1e0e9005747
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x59fc1971ba9b - core::ops::function::FnOnce::call_once::hefaf63600cd43d2a
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x59fc1971ba9b - test::__rust_begin_short_backtrace::he30322a73a0e9ea6
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x59fc1972f46a - test::run_test_in_process::{{closure}}::hdea3ab8d0243ef36
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x59fc1972f46a - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h66d192f42498ffce
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   28:     0x59fc1972f46a - std::panicking::catch_unwind::do_call::h822e18e8d3a6bb65
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x59fc1972f46a - std::panicking::catch_unwind::h54b1de7ceab578bf
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x59fc1972f46a - std::panic::catch_unwind::h60c29b7a9d0246b1
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x59fc1972f46a - test::run_test_in_process::h6099b5f871379b13
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x59fc1972f46a - test::run_test::{{closure}}::h926ce0a38281a4c8
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x59fc197098c4 - test::run_test::{{closure}}::h508de21a9afc7140
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x59fc197098c4 - std::sys::backtrace::__rust_begin_short_backtrace::h6e2f5c39ca00735a
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x59fc1970d182 - std::thread::lifecycle::spawn_unchecked::{{closure}}::{{closure}}::h133e44f0e5802c14
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x59fc1970d182 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h4718c1285283955c
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   37:     0x59fc1970d182 - std::panicking::catch_unwind::do_call::h0bba3937b4892238
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x59fc1970d182 - std::panicking::catch_unwind::h5b31cab5fb8c5d7f
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x59fc1970d182 - std::panic::catch_unwind::hb2fa05d52ed0124e
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x59fc1970d182 - std::thread::lifecycle::spawn_unchecked::{{closure}}::hf401cf5ff501bd29
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x59fc1970d182 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h160022e94ce3b0bb
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x59fc19754c4f - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hf234e0d1d1d272ba
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/alloc/src/boxed.rs:2206:9
[INFO] [stdout]   43:     0x59fc19754c4f - std::sys::thread::unix::Thread::new::thread_start::h106a295241840d3b
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/thread/unix.rs:127:17
[INFO] [stdout]   44:     0x7fb399cd8aa4 - <unknown>
[INFO] [stdout]   45:     0x7fb399d65a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- state::tests::acceptor stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'state::tests::acceptor' (137) panicked at src/state/tests.rs:107:49:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: StateError(CreateAcceptor(AcceptorError(XrdNotSet)))
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x59fc19780642 - std::backtrace_rs::backtrace::libunwind::trace::hf0bd46b30bc61685
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x59fc19780642 - std::backtrace_rs::backtrace::trace_unsynchronized::h1d1fbb72ad89d7b7
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x59fc19780642 - std::sys::backtrace::_print_fmt::he38b6f68ca847f47
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x59fc19780642 - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::hb7e843cde1bc81a3
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x59fc19792bba - core::fmt::rt::Argument::fmt::hc1dd77ac64f2688c
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x59fc19792bba - core::fmt::write::h952c506e2dbe9cff
[INFO] [stdout]    6:     0x59fc1974db46 - std::io::default_write_fmt::hd23bd8145c03a23a
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x59fc1974db46 - std::io::Write::write_fmt::hdd3314a2bd8a34bd
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x59fc1975e419 - std::sys::backtrace::BacktraceLock::print::h1079b82381c2c252
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x59fc1975e419 - std::panicking::default_hook::{{closure}}::h85cb76b8462c00f2
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x59fc1975e2b1 - std::panicking::default_hook::h0134d220cc034c02
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x59fc1971bc9e - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::hb2e68dca3970e3ca
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   12:     0x59fc1971bc9e - test::test_main_with_exit_callback::{{closure}}::ha7ec2063a2565ec3
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x59fc1975e692 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::haebee478d0f56cf4
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   14:     0x59fc1975e692 - std::panicking::panic_with_hook::h8119b6db1fef734f
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x59fc1975e4d8 - std::panicking::panic_handler::{{closure}}::h24f5360b91482c0e
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x59fc19759a69 - std::sys::backtrace::__rust_end_short_backtrace::h4e60c5cbd1bd0108
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x59fc197426dd - __rustc[e4c6931bd8050421]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x59fc1979b22c - core::panicking::panic_fmt::hb1614a3ff6840071
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x59fc1979a7e2 - core::result::unwrap_failed::h7d4c34940aded59c
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x59fc1937f18f - core::result::Result<T,E>::unwrap::hdbd45eb6226d11d5
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x59fc1937f18f - wl_proxy::state::tests::acceptor::ha45fa10c4cca4c43
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:107:49
[INFO] [stdout]   22:     0x59fc1937f7d7 - wl_proxy::state::tests::acceptor::{{closure}}::hdde46a8cdcf52b2e
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:92:14
[INFO] [stdout]   23:     0x59fc193700b6 - core::ops::function::FnOnce::call_once::hae2e7821fbd3c8bc
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x59fc1971ba9b - core::ops::function::FnOnce::call_once::hefaf63600cd43d2a
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x59fc1971ba9b - test::__rust_begin_short_backtrace::he30322a73a0e9ea6
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x59fc1972f46a - test::run_test_in_process::{{closure}}::hdea3ab8d0243ef36
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x59fc1972f46a - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h66d192f42498ffce
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   28:     0x59fc1972f46a - std::panicking::catch_unwind::do_call::h822e18e8d3a6bb65
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x59fc1972f46a - std::panicking::catch_unwind::h54b1de7ceab578bf
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x59fc1972f46a - std::panic::catch_unwind::h60c29b7a9d0246b1
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x59fc1972f46a - test::run_test_in_process::h6099b5f871379b13
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x59fc1972f46a - test::run_test::{{closure}}::h926ce0a38281a4c8
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x59fc197098c4 - test::run_test::{{closure}}::h508de21a9afc7140
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x59fc197098c4 - std::sys::backtrace::__rust_begin_short_backtrace::h6e2f5c39ca00735a
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x59fc1970d182 - std::thread::lifecycle::spawn_unchecked::{{closure}}::{{closure}}::h133e44f0e5802c14
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x59fc1970d182 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h4718c1285283955c
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   37:     0x59fc1970d182 - std::panicking::catch_unwind::do_call::h0bba3937b4892238
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x59fc1970d182 - std::panicking::catch_unwind::h5b31cab5fb8c5d7f
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x59fc1970d182 - std::panic::catch_unwind::hb2fa05d52ed0124e
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x59fc1970d182 - std::thread::lifecycle::spawn_unchecked::{{closure}}::hf401cf5ff501bd29
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x59fc1970d182 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h160022e94ce3b0bb
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x59fc19754c4f - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hf234e0d1d1d272ba
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/alloc/src/boxed.rs:2206:9
[INFO] [stdout]   43:     0x59fc19754c4f - std::sys::thread::unix::Thread::new::thread_start::h106a295241840d3b
[INFO] [stdout]                                at /rustc/9b1f8ff42d110b0ca138116745be921df5dc97e7/library/std/src/sys/thread/unix.rs:127:17
[INFO] [stdout]   44:     0x7fb399cd8aa4 - <unknown>
[INFO] [stdout]   45:     0x7fb399d65a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     acceptor::tests::test
[INFO] [stdout]     state::tests::acceptor
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 101 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.42s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "50ab8718928a70f0caaaedc3ac4378ec196a20c18a432a5fdd9904c9edfce7a6", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "50ab8718928a70f0caaaedc3ac4378ec196a20c18a432a5fdd9904c9edfce7a6", kill_on_drop: false }`
[INFO] [stdout] 50ab8718928a70f0caaaedc3ac4378ec196a20c18a432a5fdd9904c9edfce7a6
