[INFO] fetching crate wl-proxy 0.1.1...
[INFO] testing wl-proxy-0.1.1 against beta-2026-03-05 for beta-1.95-1
[INFO] extracting crate wl-proxy 0.1.1 into /workspace/builds/worker-4-tc2/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-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate wl-proxy 0.1.1 on toolchain beta-2026-03-05
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+beta-2026-03-05" "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" "+beta-2026-03-05" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-03-05" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 0ac7934de45ddc7e04ebda1f363758c47b99a1ce0337f17e6252f34ff5fdcbe0
[INFO] running `Command { std: "docker" "start" "-a" "0ac7934de45ddc7e04ebda1f363758c47b99a1ce0337f17e6252f34ff5fdcbe0", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0ac7934de45ddc7e04ebda1f363758c47b99a1ce0337f17e6252f34ff5fdcbe0", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "0ac7934de45ddc7e04ebda1f363758c47b99a1ce0337f17e6252f34ff5fdcbe0", kill_on_drop: false }`
[INFO] [stdout] 0ac7934de45ddc7e04ebda1f363758c47b99a1ce0337f17e6252f34ff5fdcbe0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-03-05" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 4aabf451dd5b1bdfeda42475295367a5bf0a7e1eb99a99af45fac386f88d0842
[INFO] running `Command { std: "docker" "start" "-a" "4aabf451dd5b1bdfeda42475295367a5bf0a7e1eb99a99af45fac386f88d0842", 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 run-on-drop v1.0.0
[INFO] [stderr]    Compiling linearize v0.1.5
[INFO] [stderr]    Compiling error_reporter v1.0.0
[INFO] [stderr]    Compiling debug-fn v1.0.0
[INFO] [stderr]    Compiling isnt v0.2.0
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling uapi v0.2.13
[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 phf_macros v0.13.1
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling linearize-derive v0.2.1
[INFO] [stderr]    Compiling phf v0.13.1
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling wl-proxy v0.1.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 14.85s
[INFO] running `Command { std: "docker" "inspect" "4aabf451dd5b1bdfeda42475295367a5bf0a7e1eb99a99af45fac386f88d0842", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "4aabf451dd5b1bdfeda42475295367a5bf0a7e1eb99a99af45fac386f88d0842", kill_on_drop: false }`
[INFO] [stdout] 4aabf451dd5b1bdfeda42475295367a5bf0a7e1eb99a99af45fac386f88d0842
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-03-05" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 776990d4902901e9b6736b8e4b17cdab48a38b37e2f582f53dda63996ba473e9
[INFO] running `Command { std: "docker" "start" "-a" "776990d4902901e9b6736b8e4b17cdab48a38b37e2f582f53dda63996ba473e9", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling jiff v0.2.16
[INFO] [stderr]    Compiling anstream v0.6.21
[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 17.66s
[INFO] running `Command { std: "docker" "inspect" "776990d4902901e9b6736b8e4b17cdab48a38b37e2f582f53dda63996ba473e9", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "776990d4902901e9b6736b8e4b17cdab48a38b37e2f582f53dda63996ba473e9", kill_on_drop: false }`
[INFO] [stdout] 776990d4902901e9b6736b8e4b17cdab48a38b37e2f582f53dda63996ba473e9
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+beta-2026-03-05" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 578810fbf4d58dc6234c9bc06310bc69d3d732e1375736a3f7da64caa997b5eb
[INFO] running `Command { std: "docker" "start" "-a" "578810fbf4d58dc6234c9bc06310bc69d3d732e1375736a3f7da64caa997b5eb", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.10s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wl_proxy-26d70db74ecb40f7)
[INFO] [stdout] 
[INFO] [stdout] running 104 tests
[INFO] [stderr] [2849122.266] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.311] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.363] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.376] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.394] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.414] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.459] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.472] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.609] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.626] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.659] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.673] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.687] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.701] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.732] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849122.767] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849122.802] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849122.745] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#5)
[INFO] [stderr] [2849123.177] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849125.285] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.348] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.370] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849125.410] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.418] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.432] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849125.448] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849125.473] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849125.481] {client} server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2849125.489] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849125.495] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.504] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849125.510] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849125.511] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849125.522] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849125.526] {proxy } client#1    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2849125.533] {proxy } server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2849125.537] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849125.538] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.543] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849125.576] {server} client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849125.587] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849125.591] {server} client#1    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [2849125.598] {server} client#1    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2849125.619] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849125.628] {server} client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849125.634] {server} client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849125.638] {server} client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849125.677] {proxy } server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2849125.682] {proxy } client#1    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2849125.695] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849125.701] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849125.707] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849125.710] {proxy } client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849125.714] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849125.718] {proxy } client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849125.739] {client} server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [2849125.743] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849125.748] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849125.751] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849125.990] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849126.011] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849126.081] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849126.101] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849126.134] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849126.147] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849126.158] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849126.171] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849126.213] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849126.229] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849126.973] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849126.997] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test client::tests::objects ... ok
[INFO] [stderr] [2849127.387] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test endpoint::tests::dispatch_destroyed ... ok
[INFO] [stderr] [2849127.402] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::debug ... ok
[INFO] [stdout] test fixed::tests::from_i64 ... ok
[INFO] [stdout] test fixed::tests::from_ints ... ok
[INFO] [stdout] test endpoint::tests::lookup ... ok
[INFO] [stdout] test client::tests::unset_handler ... ok
[INFO] [stdout] test fixed::tests::display ... ok
[INFO] [stderr] [2849129.989] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.025] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849130.054] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.078] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.092] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849130.101] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.115] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849130.124] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.147] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849130.148] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849130.174] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849130.218] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849130.239] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.267] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-03-11T08:45:51Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [2849130.797] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849130.856] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-03-11T08:45:51Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.65535 message: unknown message id 65535
[INFO] [stdout] test fixed::tests::from_i32 ... ok
[INFO] [stdout] test fixed::tests::from_f32 ... ok
[INFO] [stdout] test fixed::tests::minima ... ok
[INFO] [stdout] test fixed::tests::one_two ... ok
[INFO] [stderr] [2026-03-11T08:45:51Z WARN  wl_proxy::global_mapper] Could not add synthetic global: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::test_binops ... ok
[INFO] [stdout] test fixed::tests::test_shiftops ... ok
[INFO] [stdout] test client::tests::disconnected ... ok
[INFO] [stdout] test endpoint::tests::test ... ok
[INFO] [stdout] test fixed::tests::to_i32_ceil ... ok
[INFO] [stderr] [2026-03-11T08:45:51Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stderr] [2026-03-11T08:45:51Z WARN  wl_proxy::global_mapper] Could not handle client bind: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::to_i32_nearest ... ok
[INFO] [stdout] test endpoint::tests::invalid_message ... ok
[INFO] [stdout] test fixed::tests::wire ... ok
[INFO] [stdout] test fixed::tests::test_unops ... ok
[INFO] [stdout] test fixed::tests::to_i32_floor ... ok
[INFO] [stdout] test global_mapper::tests::test ... ok
[INFO] [stdout] test global_mapper::tests::test_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_nonexistent ... ok
[INFO] [stderr] [2026-03-11T08:45:51Z WARN  wl_proxy::global_mapper] Could not handle server global remove: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_bind_error ... ok
[INFO] [stderr] [2026-03-11T08:45:51Z WARN  wl_proxy::global_mapper] Could not remove synthetic global: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::to_i32_zero ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_ignored ... ok
[INFO] [stdout] test fixed::tests::to_f32 ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_error ... ok
[INFO] [stderr] [2026-03-11T08:45:51Z 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:51Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stderr] [2026-03-11T08:45:51Z WARN  wl_proxy::global_mapper] Could not handle server global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_synthetic ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_nonexistent ... ok
[INFO] [stderr] [2026-03-11T08:45:51Z 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_bind_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_synthetic ... ok
[INFO] [stdout] test global_mapper::tests::test_ignore_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_ignored ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global_error ... ok
[INFO] [stdout] test handler::tests::borrow ... ok
[INFO] [stderr] [2849137.939] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849137.966] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849137.987] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849137.996] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.006] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.009] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.027] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.035] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.038] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.044] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.052] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.053] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.074] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.085] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.094] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.094] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.102] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.114] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849138.120] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849138.123] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.139] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849138.157] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849138.160] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849138.166] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849138.194] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.218] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.230] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849138.247] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849138.261] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849138.284] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849138.290] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849138.295] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849138.330] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849138.361] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849138.383] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849138.389] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849138.394] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849138.397] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849138.400] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849138.404] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849138.423] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849138.455] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.466] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849138.471] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849138.474] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849138.474] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.501] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.518] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.525] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.544] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.570] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849138.595] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4294967295)
[INFO] [stderr] [2026-03-11T08:45:51Z 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] [2849138.927] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849138.960] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849138.987] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849139.012] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849139.034] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849139.057] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849139.090] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849139.108] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849139.125] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849139.145] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849139.177] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849139.193] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849139.201] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849139.224] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849139.258] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849139.271] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849139.303] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849139.323] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2849139.329] {proxy } client#1    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2026-03-11T08:45:51Z ERROR wl_proxy::state] Could not handle client message: could not handle a wlproxy_test#3.create_dummy message: could not assign client id 4 to argument id: the client id 4 is already in use
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global ... ok
[INFO] [stdout] test handler::tests::clone ... ok
[INFO] [stdout] test handler::tests::replace ... ok
[INFO] [stdout] test handler::tests::map ... ok
[INFO] [stdout] test object::tests::destroyed_client ... ok
[INFO] [stdout] test object::tests::client_id ... ok
[INFO] [stdout] test object::tests::double_send ... ok
[INFO] [stdout] test object::tests::client_object_with_server_id ... ok
[INFO] [stdout] test global_mapper::tests::test_default ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global ... ok
[INFO] [stdout] test object::tests::client ... ok
[INFO] [stdout] test object::tests::duplicate_client_id ... ok
[INFO] [stdout] test object::tests::request_without_server ... ok
[INFO] [stderr] [2849153.138] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.141] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.175] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.175] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.198] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.212] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.213] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.215] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.215] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.222] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.224] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.225] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.239] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test poll::tests::test ... ok
[INFO] [stderr] [2849153.243] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.248] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.252] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.257] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.263] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.265] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.266] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.283] {proxy } client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2849153.292] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.301] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.330] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2849153.336] {client} server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2849153.344] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.367] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2849153.378] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2849153.377] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.383] {proxy } client#1    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2849153.386] {proxy } server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2849153.389] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.390] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.395] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.415] {server} client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [2849153.426] {server} client#1    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [2849153.437] {server} client#1    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2849153.453] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.459] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849153.462] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.465] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849153.475] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849153.484] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.497] {proxy } server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2849153.497] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849153.500] {proxy } client#1    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [2849153.514] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849153.523] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849153.528] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849153.532] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test object::tests::duplicate_generated_client_id ... ok
[INFO] [stderr] [2849153.556] {client} server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stdout] test object::tests::get_handler ... ok
[INFO] [stderr] [2849153.565] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test poll::tests::many ... ok
[INFO] [stderr] [2849153.568] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849153.584] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2849153.588] {client} server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2849153.594] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849153.613] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2849153.621] {proxy } client#1    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2849153.625] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849153.631] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.654] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.660] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849153.665] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849153.695] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849153.698] {proxy } client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849153.702] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849153.707] {proxy } client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849153.724] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849153.728] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849153.741] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [2849153.745] {client} server      <= wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [2849153.754] {client} server      <= wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [2849153.781] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [2849153.790] {proxy } client#1    -> wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [2026-03-11T08:45:52Z WARN  wl_proxy::protocol_helpers] Could not forward a wlproxy_test_non_forward.echo message: the receiver has no server id
[INFO] [stderr] [2849153.906] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [2849153.920] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849153.947] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849154.050] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849154.057] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849154.092] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849154.096] {proxy } client#1    <= wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [2849154.100] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849154.105] {proxy } client#1    <= wl_display#1.delete_id(id: 7)
[INFO] [stderr] [2849154.125] {client} server      -> wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [2849154.129] {client} server      -> wl_display#1.delete_id(id: 7)
[INFO] [stderr] [2849154.144] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [2849154.148] {client} server      <= wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [2849154.159] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.163] {client} server      <= wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [2849154.178] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.183] {proxy } client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [2849154.192] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2849154.196] {proxy } client#1    -> wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [2849154.199] {proxy } server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2849154.202] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [2849154.206] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.211] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849154.216] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.231] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.232] {server} client#1    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [2849154.242] {server} client#1    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [2849154.245] {server} client#1    <= wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [2849154.247] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.250] {server} client#1    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [2849154.255] {server} client#1    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849154.260] {server} client#1    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849154.277] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.277] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.288] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.293] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.295] {proxy } server      -> wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [2849154.299] {proxy } client#1    <= wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [2849154.304] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [2849154.306] {proxy } client#1    <= wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [2849154.311] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [2849154.316] {proxy } client#1    <= wl_display#1.delete_id(id: 8)
[INFO] [stderr] [2849154.321] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.330] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.334] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.336] {client} server      -> wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [2849154.339] {client} server      -> wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [2849154.343] {client} server      -> wl_display#1.delete_id(id: 8)
[INFO] [stderr] [2849154.344] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.347] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.356] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.384] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.394] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.396] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.398] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.402] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.407] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.407] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.408] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.414] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.419] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.430] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.438] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.444] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.445] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.453] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.457] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.461] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.473] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.484] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.494] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.501] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849154.511] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849154.531] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.553] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.564] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.585] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.594] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849154.612] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849154.654] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849154.664] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849154.669] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849154.674] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849154.682] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.695] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [2849154.703] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [2849154.708] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.720] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.741] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849154.751] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849154.770] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849154.845] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849154.855] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849154.860] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849154.865] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849154.890] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#50)
[INFO] [stderr] [2849157.950] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.043] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.180] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.561] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.627] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::version ... ok
[INFO] [stderr] [2849158.734] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.775] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.803] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.855] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.901] {client} server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [2849158.923] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.941] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.945] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.966] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.975] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849158.981] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849158.992] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849159.013] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849159.049] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849159.067] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849159.438] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::forward ... ok
[INFO] [stderr] [2849159.464] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::state ... ok
[INFO] [stderr] [2849159.489] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::count_hops ... ok
[INFO] [stderr] [2849159.504] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::server_destroyed ... ok
[INFO] [stderr] [2849159.516] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::destroyed_readable ... ok
[INFO] [stderr] [2849159.533] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::destructor ... ok
[INFO] [stderr] [2849160.846] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849160.885] {proxy } client#1    -> wlproxy_test#3.send_object()
[INFO] [stderr] [2849160.889] {proxy } server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [2849160.894] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849160.907] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849160.955] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849160.974] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849160.987] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849161.004] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.020] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.064] {server} client#1    -> wlproxy_test#3.send_object()
[INFO] [stderr] [2849161.088] {server} client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2849161.112] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849161.126] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.131] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.171] {proxy } server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2849161.188] {proxy } client#1    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2849161.197] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.200] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.206] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.211] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.236] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [2849161.250] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.254] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.276] {client} server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2849161.284] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849161.306] {proxy } client#1    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2849161.310] {proxy } server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2849161.314] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849161.322] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849161.356] {server} client#1    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [2849161.360] {server} client#1    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2849161.369] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849161.375] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.379] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.415] {proxy } server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2849161.427] {proxy } client#1    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2849161.435] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.438] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.443] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.448] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.469] {client} server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [2849161.482] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.485] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.839] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.853] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849161.870] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849161.876] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849162.477] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.500] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.530] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.549] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.559] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.575] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.587] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.592] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.619] {proxy } client#1    <= wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [2849162.620] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.629] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.641] {client} server      -> wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [2849162.643] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.655] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.681] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849162.689] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849162.716] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2849162.725] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849162.747] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2849162.767] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2849162.773] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849162.785] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849162.807] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [2849162.829] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2849162.852] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849162.858] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849162.863] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849162.866] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849162.895] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2849162.898] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2849162.915] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849162.920] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849162.925] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849162.927] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849162.930] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849162.933] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849162.955] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [2849162.958] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849162.962] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849162.965] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849162.978] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2849162.985] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849162.999] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2849163.005] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2849163.010] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.014] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.031] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [2849163.036] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2849163.040] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.045] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.049] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.053] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.067] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849163.078] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2849163.081] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2849163.082] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849163.085] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.089] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.093] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.095] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.099] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.102] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.108] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849163.116] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849163.117] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [2849163.120] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.124] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.124] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849163.126] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.136] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849163.137] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2849163.142] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.155] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2849163.161] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2849163.162] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849163.165] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.170] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.184] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849163.187] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [2849163.191] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2849163.195] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849163.196] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.200] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.204] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.207] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.230] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2849163.233] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2849163.237] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.241] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.245] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.247] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.250] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.254] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.271] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [2849163.274] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.278] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.281] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.292] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2849163.298] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.312] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2849163.318] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2849163.324] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.329] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.346] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [2849163.351] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2849163.356] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.360] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.364] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.368] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.390] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2849163.393] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2849163.398] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.402] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.406] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.408] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.411] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.414] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.429] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [2849163.432] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.436] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.438] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.449] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2849163.455] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.468] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2849163.474] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2849163.478] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.483] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.498] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [2849163.504] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2849163.509] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.513] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.517] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.521] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.543] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2849163.546] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2849163.551] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.555] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.559] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.561] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.564] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.567] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.582] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [2849163.586] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.589] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.592] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.603] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2849163.609] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.622] {proxy } client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2849163.629] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2849163.634] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.640] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.657] {server} client#1    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [2849163.662] {server} client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2849163.667] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.672] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849163.676] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.680] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.702] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2849163.705] {proxy } client#1    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2849163.710] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.713] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.718] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.720] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.723] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.726] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849163.741] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [2849163.744] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849163.748] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849163.751] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stdout] test state::tests::add_client ... ok
[INFO] [stderr] [2849164.729] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::remote_destructor ... ok
[INFO] [stderr] [2849164.754] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::server_sent ... ok
[INFO] [stderr] [2849164.768] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test state::tests::closed_client ... ok
[INFO] [stderr] [2849164.788] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test state::tests::display_error ... ok
[INFO] [stderr] [2849164.811] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849164.950] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849164.961] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849164.978] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849164.989] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849165.013] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849165.024] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849165.247] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.392] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.417] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.445] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.455] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.462] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.465] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.475] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.479] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.501] {client} server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 24, fd2: 25)
[INFO] [stderr] [2849165.508] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.510] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849165.519] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.527] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.540] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.553] {proxy } client#1    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 60, fd2: 61)
[INFO] [stderr] [2849165.566] {proxy } server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 60, fd2: 61)
[INFO] [stderr] [2849165.566] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849165.572] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849165.579] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849165.623] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.634] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.645] {server} client#1    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 60, fd2: 61)
[INFO] [stderr] [2849165.656] {server} client#1    <= wlproxy_test_fd_echo#4.fd(fd1: 60, fd2: 61)
[INFO] [stderr] [2849165.674] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2026-03-11T08:45:52Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [2849165.681] {server} client#1    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [2849165.687] {server} client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849165.691] {server} client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849165.742] {proxy } server      -> wlproxy_test_fd_echo#4.fd(fd1: 61, fd2: 65)
[INFO] [stderr] [2849165.746] {proxy } client#1    <= wlproxy_test_fd_echo#4.fd(fd1: 61, fd2: 65)
[INFO] [stderr] [2849165.763] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849165.769] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849165.776] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849165.778] {proxy } client#1    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849165.783] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849165.787] {proxy } client#1    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849165.837] {client} server      -> wlproxy_test_fd_echo#4.fd(fd1: 47, fd2: 49)
[INFO] [stderr] [2849165.859] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849165.865] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [2849165.868] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [2849165.879] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.911] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.921] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849165.933] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.946] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849165.974] {client} server      <= wlproxy_test#3.recv_fd(fd: 18)
[INFO] [stderr] [2849165.979] {client} server      <= wlproxy_test#3.recv_fd(fd: 18)
[INFO] [stderr] [2849165.988] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849166.024] {proxy } client#1    -> wlproxy_test#3.recv_fd(fd: 15)
[INFO] [stderr] [2849166.028] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 15)
[INFO] [stderr] [2849166.060] {proxy } client#1    -> wlproxy_test#3.recv_fd(fd: 15)
[INFO] [stderr] [2849166.064] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 15)
[INFO] [stderr] [2849166.068] {proxy } client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849166.078] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849166.115] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849166.125] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849166.135] {server} client#1    -> wlproxy_test#3.recv_fd(fd: 15)
[INFO] [stderr] [2849166.159] {server} client#1    -> wlproxy_test#3.recv_fd(fd: 15)
[INFO] [stderr] [2849166.164] {server} client#1    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2849166.174] {server} client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849166.193] {server} client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849166.225] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849166.236] {proxy } client#1    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849166.253] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849166.259] {proxy } client#1    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [2849166.283] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [2849166.295] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stdout] test trans::tests::array ... ok
[INFO] [stdout] test state::tests::recursive_dispatch ... ok
[INFO] [stdout] test trans::tests::large_message ... ok
[INFO] [stdout] test trans::tests::echo_fd ... ok
[INFO] [stdout] test trans::tests::fd ... ok
[INFO] [stderr] [2849169.690] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849169.713] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849169.740] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849169.756] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849169.764] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849169.783] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849169.808] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849169.874] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849169.910] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-11T08:45:52Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 4 < 8
[INFO] [stderr] [2849170.398] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849170.420] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849170.468] {proxy } client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849170.485] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849170.492] {proxy } client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849170.513] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849170.587] {server} client#1    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2849170.605] {server} client#1    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2849170.636] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-11T08:45:52Z 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] [stdout] test trans::tests::small_message ... ok
[INFO] [stdout] test trans::tests::edge_header ... ok
[INFO] [stdout] test trans::tests::not_word_size ... ok
[INFO] [stdout] test utils::free_list::tests::test ... ok
[INFO] [stdout] test utils::stash::tests::test ... ok
[INFO] [stdout] test utils::stack::tests::stack ... ok
[INFO] [stdout] test acceptor::tests::test ... FAILED
[INFO] [stdout] test fixed::tests::minimum - should panic ... ok
[INFO] [stdout] test fixed::tests::maximum - should panic ... ok
[INFO] [stdout] test handler::tests::multi_borrow - should panic ... ok
[INFO] [stdout] test object::tests::wrong_downcast - should panic ... ok
[INFO] [stdout] test state::tests::acceptor ... FAILED
[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 utils::free_list::tests::release_out_of_bounds - should panic ... ok
[INFO] [stdout] test state::tests::many_events ... ok
[INFO] [stdout] test trans::tests::many_messages_with_fd ... ok
[INFO] [stdout] test trans::tests::many_messages ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- acceptor::tests::test stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'acceptor::tests::test' (25) panicked at src/acceptor/tests.rs:9:46:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: AcceptorError(XrdNotSet)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x6060a2cecbea - std[b80a194dd3c418bb]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x6060a2cecbea - std[b80a194dd3c418bb]::backtrace_rs::backtrace::trace_unsynchronized::<std[b80a194dd3c418bb]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x6060a2cecbea - std[b80a194dd3c418bb]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x6060a2cecbea - <<std[b80a194dd3c418bb]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[10b6fa85044e1869]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x6060a2d04bba - <core[10b6fa85044e1869]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x6060a2d04bba - core[10b6fa85044e1869]::fmt::write
[INFO] [stdout]    6:     0x6060a2cf2be2 - std[b80a194dd3c418bb]::io::default_write_fmt::<alloc[dd269455e567d8e9]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x6060a2cf2be2 - <alloc[dd269455e567d8e9]::vec::Vec<u8> as std[b80a194dd3c418bb]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x6060a2ccbb3f - <std[b80a194dd3c418bb]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x6060a2ccbb3f - std[b80a194dd3c418bb]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x6060a2ce4ff9 - std[b80a194dd3c418bb]::panicking::default_hook
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x6060a2c7a4cc - <alloc[dd269455e567d8e9]::boxed::Box<dyn for<'a, 'b> core[10b6fa85044e1869]::ops::function::Fn<(&'a std[b80a194dd3c418bb]::panic::PanicHookInfo<'b>,), Output = ()> + core[10b6fa85044e1869]::marker::Sync + core[10b6fa85044e1869]::marker::Send> as core[10b6fa85044e1869]::ops::function::Fn<(&std[b80a194dd3c418bb]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x6060a2c7a4cc - test[826cbc6ef54ab466]::test_main_with_exit_callback::<test[826cbc6ef54ab466]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x6060a2ce51b2 - <alloc[dd269455e567d8e9]::boxed::Box<dyn for<'a, 'b> core[10b6fa85044e1869]::ops::function::Fn<(&'a std[b80a194dd3c418bb]::panic::PanicHookInfo<'b>,), Output = ()> + core[10b6fa85044e1869]::marker::Sync + core[10b6fa85044e1869]::marker::Send> as core[10b6fa85044e1869]::ops::function::Fn<(&std[b80a194dd3c418bb]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x6060a2ce51b2 - std[b80a194dd3c418bb]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x6060a2ccbbf8 - std[b80a194dd3c418bb]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x6060a2cc34e9 - std[b80a194dd3c418bb]::sys::backtrace::__rust_end_short_backtrace::<std[b80a194dd3c418bb]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x6060a2ccca2d - __rustc[9698a3e60dd14283]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x6060a2d0554c - core[10b6fa85044e1869]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x6060a2d05292 - core[10b6fa85044e1869]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x6060a28ce48a - core::result::Result<T,E>::unwrap::haa6ccd973b94af37
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x6060a28ce48a - wl_proxy::acceptor::tests::test::ha94a3e5ca002f68c
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:9:46
[INFO] [stdout]   22:     0x6060a28ced07 - wl_proxy::acceptor::tests::test::{{closure}}::hf51917539865c93f
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:8:10
[INFO] [stdout]   23:     0x6060a293b786 - core::ops::function::FnOnce::call_once::hd54ecfd5741b8f1e
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x6060a2c6e5ab - <fn() -> core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x6060a2c6e5ab - test[826cbc6ef54ab466]::__rust_begin_short_backtrace::<core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>, fn() -> core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x6060a2c7af9b - test[826cbc6ef54ab466]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x6060a2c7af9b - <core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   28:     0x6060a2c7af9b - std[b80a194dd3c418bb]::panicking::catch_unwind::do_call::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}>, core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x6060a2c7af9b - std[b80a194dd3c418bb]::panicking::catch_unwind::<core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>, core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x6060a2c7af9b - std[b80a194dd3c418bb]::panic::catch_unwind::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}>, core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x6060a2c7af9b - test[826cbc6ef54ab466]::run_test_in_process
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x6060a2c7af9b - test[826cbc6ef54ab466]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x6060a2c766b4 - test[826cbc6ef54ab466]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x6060a2c766b4 - std[b80a194dd3c418bb]::sys::backtrace::__rust_begin_short_backtrace::<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked::<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x6060a2c7dba2 - <core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   37:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::panicking::catch_unwind::do_call::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::panicking::catch_unwind::<(), core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::panic::catch_unwind::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked::<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x6060a2c7dba2 - <std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1} as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x6060a2cec4ff - <alloc[dd269455e567d8e9]::boxed::Box<dyn core[10b6fa85044e1869]::ops::function::FnOnce<(), Output = ()> + core[10b6fa85044e1869]::marker::Send> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x6060a2cec4ff - <std[b80a194dd3c418bb]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x7f14522e4aa4 - <unknown>
[INFO] [stdout]   45:     0x7f1452371a64 - 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:     0x6060a2cecbea - std[b80a194dd3c418bb]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x6060a2cecbea - std[b80a194dd3c418bb]::backtrace_rs::backtrace::trace_unsynchronized::<std[b80a194dd3c418bb]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x6060a2cecbea - std[b80a194dd3c418bb]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x6060a2cecbea - <<std[b80a194dd3c418bb]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[10b6fa85044e1869]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x6060a2d04bba - <core[10b6fa85044e1869]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x6060a2d04bba - core[10b6fa85044e1869]::fmt::write
[INFO] [stdout]    6:     0x6060a2cf2be2 - std[b80a194dd3c418bb]::io::default_write_fmt::<alloc[dd269455e567d8e9]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x6060a2cf2be2 - <alloc[dd269455e567d8e9]::vec::Vec<u8> as std[b80a194dd3c418bb]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x6060a2ccbb3f - <std[b80a194dd3c418bb]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x6060a2ccbb3f - std[b80a194dd3c418bb]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x6060a2ce4ff9 - std[b80a194dd3c418bb]::panicking::default_hook
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x6060a2c7a4cc - <alloc[dd269455e567d8e9]::boxed::Box<dyn for<'a, 'b> core[10b6fa85044e1869]::ops::function::Fn<(&'a std[b80a194dd3c418bb]::panic::PanicHookInfo<'b>,), Output = ()> + core[10b6fa85044e1869]::marker::Sync + core[10b6fa85044e1869]::marker::Send> as core[10b6fa85044e1869]::ops::function::Fn<(&std[b80a194dd3c418bb]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x6060a2c7a4cc - test[826cbc6ef54ab466]::test_main_with_exit_callback::<test[826cbc6ef54ab466]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x6060a2ce51b2 - <alloc[dd269455e567d8e9]::boxed::Box<dyn for<'a, 'b> core[10b6fa85044e1869]::ops::function::Fn<(&'a std[b80a194dd3c418bb]::panic::PanicHookInfo<'b>,), Output = ()> + core[10b6fa85044e1869]::marker::Sync + core[10b6fa85044e1869]::marker::Send> as core[10b6fa85044e1869]::ops::function::Fn<(&std[b80a194dd3c418bb]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x6060a2ce51b2 - std[b80a194dd3c418bb]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x6060a2ccbbf8 - std[b80a194dd3c418bb]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x6060a2cc34e9 - std[b80a194dd3c418bb]::sys::backtrace::__rust_end_short_backtrace::<std[b80a194dd3c418bb]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x6060a2ccca2d - __rustc[9698a3e60dd14283]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x6060a2d0554c - core[10b6fa85044e1869]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x6060a2d05292 - core[10b6fa85044e1869]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x6060a294d47f - core::result::Result<T,E>::unwrap::h0d9b279e29db1541
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x6060a294d47f - wl_proxy::state::tests::acceptor::h819ec067878c5b26
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:113:49
[INFO] [stdout]   22:     0x6060a294dbd7 - wl_proxy::state::tests::acceptor::{{closure}}::h0ba8d74a21bb244a
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:98:14
[INFO] [stdout]   23:     0x6060a293a676 - core::ops::function::FnOnce::call_once::h600db34ff17b068a
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x6060a2c6e5ab - <fn() -> core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x6060a2c6e5ab - test[826cbc6ef54ab466]::__rust_begin_short_backtrace::<core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>, fn() -> core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x6060a2c7af9b - test[826cbc6ef54ab466]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x6060a2c7af9b - <core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   28:     0x6060a2c7af9b - std[b80a194dd3c418bb]::panicking::catch_unwind::do_call::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}>, core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x6060a2c7af9b - std[b80a194dd3c418bb]::panicking::catch_unwind::<core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>, core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x6060a2c7af9b - std[b80a194dd3c418bb]::panic::catch_unwind::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<test[826cbc6ef54ab466]::run_test_in_process::{closure#0}>, core[10b6fa85044e1869]::result::Result<(), alloc[dd269455e567d8e9]::string::String>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x6060a2c7af9b - test[826cbc6ef54ab466]::run_test_in_process
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x6060a2c7af9b - test[826cbc6ef54ab466]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x6060a2c766b4 - test[826cbc6ef54ab466]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x6060a2c766b4 - std[b80a194dd3c418bb]::sys::backtrace::__rust_begin_short_backtrace::<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked::<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x6060a2c7dba2 - <core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/panic/unwind_safe.rs:274:9
[INFO] [stdout]   37:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::panicking::catch_unwind::do_call::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::panicking::catch_unwind::<(), core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::panic::catch_unwind::<core[10b6fa85044e1869]::panic::unwind_safe::AssertUnwindSafe<std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x6060a2c7dba2 - std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked::<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x6060a2c7dba2 - <std[b80a194dd3c418bb]::thread::lifecycle::spawn_unchecked<test[826cbc6ef54ab466]::run_test::{closure#1}, ()>::{closure#1} as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x6060a2cec4ff - <alloc[dd269455e567d8e9]::boxed::Box<dyn core[10b6fa85044e1869]::ops::function::FnOnce<(), Output = ()> + core[10b6fa85044e1869]::marker::Send> as core[10b6fa85044e1869]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x6060a2cec4ff - <std[b80a194dd3c418bb]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/ad726b5063362ec9897ef3d67452fc5606ee70fa/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x7f14522e4aa4 - <unknown>
[INFO] [stdout]   45:     0x7f1452371a64 - 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.73s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "578810fbf4d58dc6234c9bc06310bc69d3d732e1375736a3f7da64caa997b5eb", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "578810fbf4d58dc6234c9bc06310bc69d3d732e1375736a3f7da64caa997b5eb", kill_on_drop: false }`
[INFO] [stdout] 578810fbf4d58dc6234c9bc06310bc69d3d732e1375736a3f7da64caa997b5eb
