[INFO] fetching crate wl-proxy 0.1.1...
[INFO] testing wl-proxy-0.1.1 against 1.94.0 for beta-1.95-1
[INFO] extracting crate wl-proxy 0.1.1 into /workspace/builds/worker-4-tc1/source
[INFO] started tweaking crates.io crate wl-proxy 0.1.1
[INFO] finished tweaking crates.io crate wl-proxy 0.1.1
[INFO] tweaked toml for crates.io crate wl-proxy 0.1.1 written to /workspace/builds/worker-4-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate wl-proxy 0.1.1 on toolchain 1.94.0
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.94.0" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wl-proxy 0.1.1 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" "+1.94.0" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded debug-fn v1.0.0
[INFO] [stderr]   Downloaded uapi-proc v0.0.5
[INFO] [stderr]   Downloaded run-on-drop v1.0.0
[INFO] [stderr]   Downloaded linearize v0.1.5
[INFO] [stderr]   Downloaded isnt v0.2.0
[INFO] [stderr]   Downloaded error_reporter v1.0.0
[INFO] [stderr]   Downloaded linearize-derive v0.2.1
[INFO] [stderr]   Downloaded uapi v0.2.13
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1.94.0" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 566ef8d14b751c833cc280c26832e8e33164c4d58576688d216364362dccb535
[INFO] running `Command { std: "docker" "start" "-a" "566ef8d14b751c833cc280c26832e8e33164c4d58576688d216364362dccb535", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "566ef8d14b751c833cc280c26832e8e33164c4d58576688d216364362dccb535", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "566ef8d14b751c833cc280c26832e8e33164c4d58576688d216364362dccb535", kill_on_drop: false }`
[INFO] [stdout] 566ef8d14b751c833cc280c26832e8e33164c4d58576688d216364362dccb535
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1.94.0" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] ebd77840f5abcb1edbf60909acd1d7e94dc71f5cd54eb7158942d6a6f8e0ee2f
[INFO] running `Command { std: "docker" "start" "-a" "ebd77840f5abcb1edbf60909acd1d7e94dc71f5cd54eb7158942d6a6f8e0ee2f", kill_on_drop: false }`
[INFO] [stderr]    Compiling syn v2.0.111
[INFO] [stderr]    Compiling siphasher v1.0.1
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling fastrand v2.3.0
[INFO] [stderr]    Compiling isnt v0.2.0
[INFO] [stderr]    Compiling linearize v0.1.5
[INFO] [stderr]    Compiling error_reporter v1.0.0
[INFO] [stderr]    Compiling run-on-drop v1.0.0
[INFO] [stderr]    Compiling debug-fn v1.0.0
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling phf_shared v0.13.1
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling phf_generator v0.13.1
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling linearize-derive v0.2.1
[INFO] [stderr]    Compiling phf_macros v0.13.1
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling phf v0.13.1
[INFO] [stderr]    Compiling wl-proxy v0.1.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 14.92s
[INFO] running `Command { std: "docker" "inspect" "ebd77840f5abcb1edbf60909acd1d7e94dc71f5cd54eb7158942d6a6f8e0ee2f", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ebd77840f5abcb1edbf60909acd1d7e94dc71f5cd54eb7158942d6a6f8e0ee2f", kill_on_drop: false }`
[INFO] [stdout] ebd77840f5abcb1edbf60909acd1d7e94dc71f5cd54eb7158942d6a6f8e0ee2f
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1.94.0" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] cb51a7b9b908816e851b63266e446cb8e84e74883a76d8e845748ee0db879115
[INFO] running `Command { std: "docker" "start" "-a" "cb51a7b9b908816e851b63266e446cb8e84e74883a76d8e845748ee0db879115", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling anstream v0.6.21
[INFO] [stderr]    Compiling jiff v0.2.16
[INFO] [stderr]    Compiling regex-automata v0.4.13
[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.1 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling env_filter v0.1.4
[INFO] [stderr]    Compiling env_logger v0.11.8
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 19.08s
[INFO] running `Command { std: "docker" "inspect" "cb51a7b9b908816e851b63266e446cb8e84e74883a76d8e845748ee0db879115", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "cb51a7b9b908816e851b63266e446cb8e84e74883a76d8e845748ee0db879115", kill_on_drop: false }`
[INFO] [stdout] cb51a7b9b908816e851b63266e446cb8e84e74883a76d8e845748ee0db879115
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=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:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+1.94.0" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] f433f55f4e58c913f09502bf327fc8013ae3e3a2c360d22c449cade24bd2d0ba
[INFO] running `Command { std: "docker" "start" "-a" "f433f55f4e58c913f09502bf327fc8013ae3e3a2c360d22c449cade24bd2d0ba", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.15s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wl_proxy-dde2fd550d1d61ad)
[INFO] [stdout] 
[INFO] [stdout] running 104 tests
[INFO] [stderr] [2810428.341] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810428.381] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810428.431] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810428.450] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810428.473] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810428.493] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810428.528] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810428.537] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#5)
[INFO] [stderr] [2810428.544] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810428.560] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810428.560] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810429.063] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.093] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.123] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.137] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.149] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.162] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.186] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810429.195] {client} server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2810429.203] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810429.228] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810429.228] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.240] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810429.243] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.245] {proxy } client#1    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2810429.253] {proxy } server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2810429.257] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810429.273] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810429.319] {server} client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810429.333] {server} client#1    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2810429.340] {server} client#1    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2810429.362] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810429.370] {server} client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810429.376] {server} client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810429.380] {server} client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810429.418] {proxy } server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2810429.423] {proxy } client#1    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2810429.437] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810429.443] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810429.450] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810429.453] {proxy } client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810429.457] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810429.462] {proxy } client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810429.484] {client} server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2810429.489] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810429.494] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810429.498] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810429.636] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.707] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.777] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.796] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.850] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.870] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.875] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.906] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.945] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810429.950] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.965] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810429.977] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810429.989] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810430.010] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-11T08:45:13Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [2810430.216] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810430.291] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-03-11T08:45:13Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.65535 message: unknown message id 65535
[INFO] [stderr] [2810431.077] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810431.110] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test endpoint::tests::dispatch_destroyed ... ok
[INFO] [stderr] [2810431.142] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::from_i64 ... ok
[INFO] [stderr] [2810431.157] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test endpoint::tests::lookup ... ok
[INFO] [stderr] [2810431.171] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::from_i32 ... ok
[INFO] [stderr] [2810431.186] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test endpoint::tests::test ... ok
[INFO] [stdout] test fixed::tests::display ... ok
[INFO] [stdout] test endpoint::tests::invalid_message ... ok
[INFO] [stdout] test client::tests::objects ... ok
[INFO] [stderr] [2810435.190] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::minima ... ok
[INFO] [stderr] [2810435.214] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::one_two ... ok
[INFO] [stderr] [2810435.249] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::test_binops ... ok
[INFO] [stderr] [2810435.261] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::test_unops ... ok
[INFO] [stderr] [2810435.278] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::to_i32_ceil ... ok
[INFO] [stderr] [2810435.293] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::to_i32_floor ... ok
[INFO] [stderr] [2810435.332] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::to_f32 ... ok
[INFO] [stderr] [2810435.345] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::to_i32_nearest ... ok
[INFO] [stderr] [2810435.364] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810435.384] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810435.411] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810435.423] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810435.435] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810435.447] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810435.478] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810435.487] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test client::tests::unset_handler ... ok
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Could not add synthetic global: the message handler is already borrowed
[INFO] [stdout] test client::tests::disconnected ... ok
[INFO] [stdout] test fixed::tests::to_i32_zero ... ok
[INFO] [stdout] test global_mapper::tests::test ... ok
[INFO] [stdout] test fixed::tests::wire ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind ... ok
[INFO] [stdout] test global_mapper::tests::test_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_default ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove ... ok
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Could not handle server global: the message handler is already borrowed
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Could not handle server global remove: the message handler is already borrowed
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Could not handle client bind: the message handler is already borrowed
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Could not remove synthetic global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_bind_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_synthetic ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_ignored ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global ... ok
[INFO] [stdout] test fixed::tests::from_ints ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_error ... ok
[INFO] [stdout] test fixed::tests::debug ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_error ... ok
[INFO] [stdout] test fixed::tests::from_f32 ... ok
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test fixed::tests::test_shiftops ... ok
[INFO] [stdout] test global_mapper::tests::test_ignore_global ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_error ... ok
[INFO] [stderr] [2026-03-11T08:45:13Z 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_try_forward_global_remove_ignored ... ok
[INFO] [stdout] test handler::tests::clone ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global_error ... ok
[INFO] [stdout] test handler::tests::borrow ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_nonexistent ... ok
[INFO] [stderr] [2810455.919] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810455.949] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810455.981] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810455.997] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810456.006] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810456.031] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810456.054] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810456.070] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810456.093] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810456.106] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2810456.118] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global ... ok
[INFO] [stderr] [2026-03-11T08:45:13Z 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] [stderr] [2810457.579] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_nonexistent ... ok
[INFO] [stderr] [2810457.610] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810457.637] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810457.646] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810457.659] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810457.671] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810457.694] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810457.702] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810457.728] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810457.747] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4294967295)
[INFO] [stderr] [2026-03-11T08:45:13Z 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] [2810458.291] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810458.316] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810458.354] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810458.355] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810458.364] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810458.365] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810458.372] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind ... ok
[INFO] [stderr] [2810458.384] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_synthetic ... ok
[INFO] [stderr] [2810458.387] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::duplicate_client_id ... ok
[INFO] [stderr] [2810458.391] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test handler::tests::replace ... ok
[INFO] [stderr] [2810458.398] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810458.409] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810458.427] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810458.433] {proxy } client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2810458.433] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810458.449] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810458.452] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810458.463] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810458.498] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810458.512] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810458.533] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810458.581] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810458.600] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810458.606] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810458.613] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810458.640] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [2810458.656] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [2810459.333] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.357] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.383] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.392] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.398] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.410] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.429] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.446] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.450] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.468] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.489] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.494] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2810459.500] {client} server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2810459.501] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.505] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.516] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.529] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2810459.539] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2810459.545] {proxy } client#1    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2810459.548] {proxy } server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2810459.548] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.551] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.557] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.575] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810459.577] {server} client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2810459.592] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810459.593] {server} client#1    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2810459.597] {server} client#1    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2810459.604] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.609] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.615] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.620] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810459.627] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.643] {proxy } server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2810459.646] {proxy } client#1    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2810459.659] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.661] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810459.671] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.676] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.680] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810459.681] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.686] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.692] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.701] {client} server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2810459.714] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.715] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810459.718] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.726] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810459.732] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2810459.736] {client} server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2810459.740] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810459.741] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stdout] test object::tests::client_object_with_server_id ... ok
[INFO] [stderr] [2810459.749] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test object::tests::duplicate_generated_client_id ... ok
[INFO] [stderr] [2810459.759] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2810459.773] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.774] {proxy } client#1    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2810459.779] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810459.779] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.784] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.826] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810459.830] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810459.846] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stdout] test object::tests::double_send ... ok
[INFO] [stderr] [2810459.852] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test object::tests::forward ... ok
[INFO] [stderr] [2810459.859] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test object::tests::get_handler ... ok
[INFO] [stderr] [2810459.861] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test object::tests::server_destroyed ... ok
[INFO] [stderr] [2810459.865] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.869] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.894] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810459.898] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810459.903] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.902] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810459.906] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.911] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.917] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.950] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810459.953] {proxy } client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810459.958] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810459.963] {proxy } client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810459.981] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810459.985] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810459.998] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [2810460.002] {client} server      <= wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [2810460.011] {client} server      <= wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [2810460.029] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [2810460.036] {proxy } client#1    -> wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [2026-03-11T08:45:13Z WARN  wl_proxy::protocol_helpers] Could not forward a wlproxy_test_non_forward.echo message: the receiver has no server id
[INFO] [stderr] [2810460.123] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [2810460.135] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810460.169] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810460.175] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810460.181] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810460.213] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810460.216] {proxy } client#1    <= wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [2810460.222] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810460.226] {proxy } client#1    <= wl_display#1.delete_id(id: 7)
[INFO] [stderr] [2810460.244] {client} server      -> wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [2810460.248] {client} server      -> wl_display#1.delete_id(id: 7)
[INFO] [stderr] [2810460.262] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [2810460.265] {client} server      <= wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [2810460.274] {client} server      <= wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [2810460.291] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [2810460.299] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2810460.304] {proxy } client#1    -> wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [2810460.307] {proxy } server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2810460.311] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [2810460.322] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810460.344] {server} client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2810460.352] {server} client#1    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2810460.355] {server} client#1    <= wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [2810460.360] {server} client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2810460.365] {server} client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810460.370] {server} client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810460.401] {proxy } server      -> wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [2810460.404] {proxy } client#1    <= wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [2810460.408] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2810460.411] {proxy } client#1    <= wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [2810460.415] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2810460.419] {proxy } client#1    <= wl_display#1.delete_id(id: 8)
[INFO] [stderr] [2810460.438] {client} server      -> wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [2810460.441] {client} server      -> wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [2810460.445] {client} server      -> wl_display#1.delete_id(id: 8)
[INFO] [stderr] [2810461.118] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.132] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.159] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.168] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.175] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.186] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.261] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.276] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.302] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.314] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.316] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.324] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.332] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.343] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.344] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.352] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.369] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.382] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.397] {client} server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [2810461.400] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.406] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.413] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.428] {proxy } client#1    -> wlproxy_test#3.send_object()
[INFO] [stderr] [2810461.432] {proxy } server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [2810461.436] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.446] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.481] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810461.492] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810461.503] {server} client#1    -> wlproxy_test#3.send_object()
[INFO] [stderr] [2810461.515] {server} client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2810461.539] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.545] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.558] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.596] {proxy } server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2810461.604] {proxy } client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2810461.610] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.613] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.617] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.622] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.641] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2810461.646] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.649] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.660] {client} server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2810461.666] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.682] {proxy } client#1    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2810461.685] {proxy } server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2810461.688] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.694] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.714] {server} client#1    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2810461.717] {server} client#1    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2810461.724] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810461.728] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.732] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.758] {proxy } server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2810461.762] {proxy } client#1    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2810461.769] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.772] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.776] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.781] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810461.799] {client} server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2810461.803] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810461.806] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810463.191] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810463.386] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810463.403] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810463.428] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810463.436] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::server_sent ... ok
[INFO] [stderr] [2810463.443] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810463.454] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810463.713] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810463.740] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810463.749] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810463.755] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810463.779] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810463.807] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810463.836] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.548] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.570] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.599] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.608] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.616] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.628] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.673] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.690] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.915] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.928] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.955] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.964] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810466.972] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810466.985] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.030] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.045] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.307] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.321] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.350] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.361] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.369] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.383] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.433] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.451] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.697] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.712] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.741] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.750] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.759] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.772] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.837] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.855] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.906] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.918] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.942] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.950] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810467.957] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.968] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810467.992] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810468.015] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810468.025] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810468.058] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810468.069] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810468.079] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810468.088] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810468.104] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810468.136] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810468.139] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810468.145] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810468.150] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810468.171] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#50)
[INFO] [stdout] test object::tests::version ... ok
[INFO] [stdout] test object::tests::state ... ok
[INFO] [stdout] test handler::tests::map ... ok
[INFO] [stdout] test object::tests::request_without_server ... ok
[INFO] [stdout] test object::tests::client_id ... ok
[INFO] [stdout] test object::tests::client ... ok
[INFO] [stdout] test object::tests::destroyed_client ... ok
[INFO] [stderr] [2810486.121] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.144] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.153] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.171] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.193] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.203] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.213] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.213] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.234] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.239] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.249] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.266] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.277] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.305] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810486.336] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810486.345] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.355] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810486.369] {proxy } client#1    <= wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [2810486.375] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810486.385] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810486.398] {client} server      -> wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [2810486.399] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810486.435] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810486.438] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810486.445] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810486.451] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810486.623] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.642] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.669] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.678] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.685] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.697] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810486.731] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810486.743] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::destructor ... ok
[INFO] [stdout] test state::tests::destroyed_readable ... ok
[INFO] [stdout] test poll::tests::many ... ok
[INFO] [stdout] test state::tests::display_error ... ok
[INFO] [stdout] test state::tests::closed_client ... ok
[INFO] [stdout] test state::tests::add_client ... ok
[INFO] [stdout] test poll::tests::test ... ok
[INFO] [stderr] [2810488.321] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810488.337] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810488.362] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810488.370] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810488.377] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810488.388] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810488.406] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2810488.414] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.437] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2810488.447] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2810488.452] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.458] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.490] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810488.499] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810488.509] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2810488.518] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2810488.534] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.541] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.546] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.550] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.585] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2810488.589] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2810488.596] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.601] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.607] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.609] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.613] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.617] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.637] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2810488.641] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.645] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.648] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.663] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2810488.670] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.686] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2810488.693] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2810488.697] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.703] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.724] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2810488.730] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2810488.735] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.740] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.745] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.749] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.810] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2810488.835] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2810488.842] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.847] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.853] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.855] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.859] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.863] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.883] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2810488.888] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.892] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.895] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810488.908] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2810488.914] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.931] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2810488.938] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2810488.942] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.948] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.969] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2810488.974] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2810488.980] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810488.985] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810488.990] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810488.994] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.021] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2810489.025] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2810489.030] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.034] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.039] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.042] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.045] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.049] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.067] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2810489.071] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.075] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.078] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.091] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2810489.098] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.114] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2810489.121] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2810489.126] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.131] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.151] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2810489.158] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2810489.163] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.169] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.173] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.177] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.205] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2810489.208] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2810489.214] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.218] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.223] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.225] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.229] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.233] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.251] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2810489.255] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.259] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.262] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.276] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2810489.284] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.300] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2810489.307] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2810489.312] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.318] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.337] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2810489.344] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2810489.349] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.355] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.359] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.363] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.389] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stdout] test state::tests::remote_destructor ... ok
[INFO] [stderr] [2810489.393] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2810489.399] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.403] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.408] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.411] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.414] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.418] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.436] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2810489.440] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.445] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.448] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.460] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2810489.468] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.484] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2810489.491] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2810489.497] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.504] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.523] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2810489.529] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2810489.535] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.541] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810489.545] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.549] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.578] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2810489.582] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2810489.587] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.591] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.597] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.599] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.602] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.606] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810489.624] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2810489.628] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810489.632] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810489.635] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810492.193] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810492.217] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810492.246] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810492.268] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810492.282] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810492.315] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810492.343] {client} server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 15, fd2: 16)
[INFO] [stderr] [2810492.362] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810492.401] {proxy } client#1    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 47, fd2: 48)
[INFO] [stderr] [2810492.423] {proxy } server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 47, fd2: 48)
[INFO] [stderr] [2810492.430] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810492.438] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810492.519] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810492.536] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810492.548] {server} client#1    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 47, fd2: 48)
[INFO] [stderr] [2810492.561] {server} client#1    <= wlproxy_test_fd_echo#4.fd(fd1: 47, fd2: 48)
[INFO] [stderr] [2810492.580] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810492.588] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2810492.594] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810492.599] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810492.650] {proxy } server      -> wlproxy_test_fd_echo#4.fd(fd1: 28, fd2: 33)
[INFO] [stderr] [2810492.669] {proxy } client#1    <= wlproxy_test_fd_echo#4.fd(fd1: 28, fd2: 33)
[INFO] [stderr] [2810492.687] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810492.699] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810492.707] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810492.710] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810492.714] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810492.719] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2810492.767] {client} server      -> wlproxy_test_fd_echo#4.fd(fd1: 28, fd2: 33)
[INFO] [stderr] [2810492.790] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810492.797] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2810492.800] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stdout] test trans::tests::array ... ok
[INFO] [stderr] [2810496.122] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::count_hops ... ok
[INFO] [stderr] [2810496.145] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test trans::tests::echo_fd ... ok
[INFO] [stderr] [2810496.173] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test trans::tests::large_message ... ok
[INFO] [stderr] [2810496.183] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test trans::tests::small_message ... ok
[INFO] [stderr] [2810496.190] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test trans::tests::not_word_size ... ok
[INFO] [stderr] [2810496.202] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810496.228] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810496.243] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810496.257] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-03-11T08:45:13Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [2810498.443] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810498.468] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810498.497] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810498.507] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810498.515] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810498.517] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810498.528] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810498.533] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810498.548] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810498.563] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810498.573] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810498.582] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810498.596] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810498.618] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-11T08:45:13Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 4 < 8
[INFO] [stderr] [2026-03-11T08:45:13Z 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] [2810500.051] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test trans::tests::fd ... ok
[INFO] [stderr] [2810500.070] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test utils::stack::tests::stack ... ok
[INFO] [stderr] [2810500.097] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test utils::stash::tests::test ... ok
[INFO] [stderr] [2810500.105] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::recursive_dispatch ... ok
[INFO] [stderr] [2810500.112] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test trans::tests::edge_header ... ok
[INFO] [stderr] [2810500.124] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test acceptor::tests::test ... FAILED
[INFO] [stderr] [2810500.154] {client} server      <= wlproxy_test#3.recv_fd(fd: 48)
[INFO] [stderr] [2810500.160] {client} server      <= wlproxy_test#3.recv_fd(fd: 48)
[INFO] [stderr] [2810500.168] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810500.165] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810500.181] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810500.206] {proxy } client#1    -> wlproxy_test#3.recv_fd(fd: 49)
[INFO] [stderr] [2810500.211] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 49)
[INFO] [stderr] [2810500.245] {proxy } client#1    -> wlproxy_test#3.recv_fd(fd: 49)
[INFO] [stderr] [2810500.249] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 49)
[INFO] [stderr] [2810500.249] {server} client#1    -> wlproxy_test#3.recv_fd(fd: 50)
[INFO] [stderr] [2810500.254] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810500.267] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810500.946] {server} client#1    -> wlproxy_test#3.recv_fd(fd: 52)
[INFO] [stderr] [2810501.006] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810501.120] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.190] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.306] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.320] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.336] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.343] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.370] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.375] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.403] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810501.416] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810501.443] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810501.452] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810501.459] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810501.471] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810501.496] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810501.519] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810501.531] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810501.577] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2810501.589] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2810501.601] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2810501.610] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.632] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.669] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.673] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.681] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.687] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2810501.710] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2810501.727] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stdout] test utils::free_list::tests::test ... ok
[INFO] [stdout] test fixed::tests::maximum - should panic ... ok
[INFO] [stdout] test fixed::tests::minimum - should panic ... ok
[INFO] [stdout] test handler::tests::multi_borrow - should panic ... ok
[INFO] [stdout] test object::tests::duplicate_server_id - should panic ... ok
[INFO] [stdout] test object::tests::invalid_server_id - should panic ... ok
[INFO] [stdout] test state::tests::acceptor ... FAILED
[INFO] [stdout] test utils::free_list::tests::release_out_of_bounds - should panic ... ok
[INFO] [stdout] test object::tests::wrong_downcast - should panic ... ok
[INFO] [stdout] test state::tests::many_events ... ok
[INFO] [stdout] test trans::tests::many_messages ... ok
[INFO] [stdout] test trans::tests::many_messages_with_fd ... 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:     0x636868a82672 - std::backtrace_rs::backtrace::libunwind::trace::hff358a60abf734fc
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x636868a82672 - std::backtrace_rs::backtrace::trace_unsynchronized::h3b121f916dd95ec6
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x636868a82672 - std::sys::backtrace::_print_fmt::hde0a62ded68798e9
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x636868a82672 - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::h93773fc827e3113d
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x636868a94bea - core::fmt::rt::Argument::fmt::h01eff69902dad97f
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x636868a94bea - core::fmt::write::hed7b5c73d82ecb7c
[INFO] [stdout]    6:     0x636868a4f936 - std::io::default_write_fmt::h2f696ff5b8bbaa4b
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x636868a4f936 - std::io::Write::write_fmt::h5e66814db8a9cfce
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x636868a60449 - std::sys::backtrace::BacktraceLock::print::h8b1d6fcc5a56d1a3
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x636868a60449 - std::panicking::default_hook::{{closure}}::h2be84df4f189ae36
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x636868a602e1 - std::panicking::default_hook::hf0ea8939246f43a9
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x636868a1f44e - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h02d35e3888986252
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   12:     0x636868a1f44e - test::test_main_with_exit_callback::{{closure}}::h939640a27d647173
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x636868a606c2 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::hc9df09ff391af3e7
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   14:     0x636868a606c2 - std::panicking::panic_with_hook::hb4bd9ac1123582a0
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x636868a60508 - std::panicking::panic_handler::{{closure}}::hde00dd15f5637fe2
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x636868a5ba99 - std::sys::backtrace::__rust_end_short_backtrace::hb72197fa777c1785
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x636868a4470d - __rustc[4425a7e20b4c8619]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x636868a9d25c - core::panicking::panic_fmt::ha59b517dd231f4da
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x636868a9c812 - core::result::unwrap_failed::hf2d1f30a3ac850fc
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x63686874822a - core::result::Result<T,E>::unwrap::hd3cd14d8e7a45bac
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x63686874822a - wl_proxy::acceptor::tests::test::h28493390aae12c29
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:9:46
[INFO] [stdout]   22:     0x6368687489d7 - wl_proxy::acceptor::tests::test::{{closure}}::h24c1754038bc5752
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:8:10
[INFO] [stdout]   23:     0x63686867b1b6 - core::ops::function::FnOnce::call_once::h94d7a8d72360deaa
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x636868a1f20b - core::ops::function::FnOnce::call_once::hddb3cd395c36bfbb
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x636868a1f20b - test::__rust_begin_short_backtrace::h0b6a7601d9750bfa
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x636868a32c1a - test::run_test_in_process::{{closure}}::h444209903f00b347
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x636868a32c1a - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hfb3ba8f46e537649
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   28:     0x636868a32c1a - std::panicking::catch_unwind::do_call::h1672a45911fcf9dc
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x636868a32c1a - std::panicking::catch_unwind::h0fadaee22787a6dd
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x636868a32c1a - std::panic::catch_unwind::hc47ad190f2c8e188
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x636868a32c1a - test::run_test_in_process::hcd7faaf934f29999
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x636868a32c1a - test::run_test::{{closure}}::hddc4550da4871867
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x636868a0d074 - test::run_test::{{closure}}::h98ae26689f13ed94
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x636868a0d074 - std::sys::backtrace::__rust_begin_short_backtrace::h3ec4d1f21ad44588
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x636868a10a12 - std::thread::lifecycle::spawn_unchecked::{{closure}}::{{closure}}::hd8bf2c73d479939f
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x636868a10a12 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h3b4248f358af2491
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   37:     0x636868a10a12 - std::panicking::catch_unwind::do_call::hda10a64f4b8daebe
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x636868a10a12 - std::panicking::catch_unwind::h659e5ee8336ec8c7
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x636868a10a12 - std::panic::catch_unwind::h9d4d66a538912c18
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x636868a10a12 - std::thread::lifecycle::spawn_unchecked::{{closure}}::h7557906bb51d79f1
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x636868a10a12 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h9e460d1d7fc83d35
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x636868a56c7f - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h61282da819d64ea9
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/alloc/src/boxed.rs:2206:9
[INFO] [stdout]   43:     0x636868a56c7f - std::sys::thread::unix::Thread::new::thread_start::h982f9ea829d1b5fb
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/thread/unix.rs:127:17
[INFO] [stdout]   44:     0x700666b1faa4 - <unknown>
[INFO] [stdout]   45:     0x700666baca64 - 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:113:49:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: StateError(CreateAcceptor(AcceptorError(XrdNotSet)))
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x636868a82672 - std::backtrace_rs::backtrace::libunwind::trace::hff358a60abf734fc
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x636868a82672 - std::backtrace_rs::backtrace::trace_unsynchronized::h3b121f916dd95ec6
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x636868a82672 - std::sys::backtrace::_print_fmt::hde0a62ded68798e9
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x636868a82672 - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::h93773fc827e3113d
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x636868a94bea - core::fmt::rt::Argument::fmt::h01eff69902dad97f
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x636868a94bea - core::fmt::write::hed7b5c73d82ecb7c
[INFO] [stdout]    6:     0x636868a4f936 - std::io::default_write_fmt::h2f696ff5b8bbaa4b
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x636868a4f936 - std::io::Write::write_fmt::h5e66814db8a9cfce
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x636868a60449 - std::sys::backtrace::BacktraceLock::print::h8b1d6fcc5a56d1a3
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x636868a60449 - std::panicking::default_hook::{{closure}}::h2be84df4f189ae36
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x636868a602e1 - std::panicking::default_hook::hf0ea8939246f43a9
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x636868a1f44e - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h02d35e3888986252
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   12:     0x636868a1f44e - test::test_main_with_exit_callback::{{closure}}::h939640a27d647173
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x636868a606c2 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::hc9df09ff391af3e7
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/alloc/src/boxed.rs:2220:9
[INFO] [stdout]   14:     0x636868a606c2 - std::panicking::panic_with_hook::hb4bd9ac1123582a0
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x636868a60508 - std::panicking::panic_handler::{{closure}}::hde00dd15f5637fe2
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x636868a5ba99 - std::sys::backtrace::__rust_end_short_backtrace::hb72197fa777c1785
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x636868a4470d - __rustc[4425a7e20b4c8619]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x636868a9d25c - core::panicking::panic_fmt::ha59b517dd231f4da
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x636868a9c812 - core::result::unwrap_failed::hf2d1f30a3ac850fc
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x63686868db8f - core::result::Result<T,E>::unwrap::h954889e1dbb9afd0
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x63686868db8f - wl_proxy::state::tests::acceptor::h59a97f5d954db10e
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:113:49
[INFO] [stdout]   22:     0x63686868e2e7 - wl_proxy::state::tests::acceptor::{{closure}}::h08570d887a5b75a5
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:98:14
[INFO] [stdout]   23:     0x636868679ca6 - core::ops::function::FnOnce::call_once::h072cd66f2678d592
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x636868a1f20b - core::ops::function::FnOnce::call_once::hddb3cd395c36bfbb
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x636868a1f20b - test::__rust_begin_short_backtrace::h0b6a7601d9750bfa
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x636868a32c1a - test::run_test_in_process::{{closure}}::h444209903f00b347
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x636868a32c1a - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::hfb3ba8f46e537649
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   28:     0x636868a32c1a - std::panicking::catch_unwind::do_call::h1672a45911fcf9dc
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x636868a32c1a - std::panicking::catch_unwind::h0fadaee22787a6dd
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x636868a32c1a - std::panic::catch_unwind::hc47ad190f2c8e188
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x636868a32c1a - test::run_test_in_process::hcd7faaf934f29999
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x636868a32c1a - test::run_test::{{closure}}::hddc4550da4871867
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x636868a0d074 - test::run_test::{{closure}}::h98ae26689f13ed94
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x636868a0d074 - std::sys::backtrace::__rust_begin_short_backtrace::h3ec4d1f21ad44588
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x636868a10a12 - std::thread::lifecycle::spawn_unchecked::{{closure}}::{{closure}}::hd8bf2c73d479939f
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x636868a10a12 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h3b4248f358af2491
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   37:     0x636868a10a12 - std::panicking::catch_unwind::do_call::hda10a64f4b8daebe
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x636868a10a12 - std::panicking::catch_unwind::h659e5ee8336ec8c7
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x636868a10a12 - std::panic::catch_unwind::h9d4d66a538912c18
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x636868a10a12 - std::thread::lifecycle::spawn_unchecked::{{closure}}::h7557906bb51d79f1
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x636868a10a12 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h9e460d1d7fc83d35
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x636868a56c7f - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h61282da819d64ea9
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/alloc/src/boxed.rs:2206:9
[INFO] [stdout]   43:     0x636868a56c7f - std::sys::thread::unix::Thread::new::thread_start::h982f9ea829d1b5fb
[INFO] [stdout]                                at /rustc/4a4ef493e3a1488c6e321570238084b38948f6db/library/std/src/sys/thread/unix.rs:127:17
[INFO] [stdout]   44:     0x700666b1faa4 - <unknown>
[INFO] [stdout]   45:     0x700666baca64 - 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. 102 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.71s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "f433f55f4e58c913f09502bf327fc8013ae3e3a2c360d22c449cade24bd2d0ba", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "f433f55f4e58c913f09502bf327fc8013ae3e3a2c360d22c449cade24bd2d0ba", kill_on_drop: false }`
[INFO] [stdout] f433f55f4e58c913f09502bf327fc8013ae3e3a2c360d22c449cade24bd2d0ba
