[INFO] fetching crate wl-proxy 0.1.2...
[INFO] testing wl-proxy-0.1.2 against master#562dee4820c458d823175268e41601d4c060588a for pr-154210-1
[INFO] extracting crate wl-proxy 0.1.2 into /workspace/builds/worker-4-tc1/source
[INFO] started tweaking crates.io crate wl-proxy 0.1.2
[INFO] finished tweaking crates.io crate wl-proxy 0.1.2
[INFO] tweaked toml for crates.io crate wl-proxy 0.1.2 written to /workspace/builds/worker-4-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate wl-proxy 0.1.2 on toolchain 562dee4820c458d823175268e41601d4c060588a
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wl-proxy 0.1.2 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" "+562dee4820c458d823175268e41601d4c060588a" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded isnt v0.2.0
[INFO] [stderr]   Downloaded run-on-drop v1.0.0
[INFO] [stderr]   Downloaded uapi-proc v0.0.5
[INFO] [stderr]   Downloaded uapi v0.2.13
[INFO] [stderr]   Downloaded debug-fn v1.0.0
[INFO] [stderr]   Downloaded error_reporter v1.0.0
[INFO] [stderr]   Downloaded linearize v0.1.5
[INFO] [stderr]   Downloaded linearize-derive v0.2.1
[INFO] [stderr]   Downloaded jiff-static v0.2.16
[INFO] [stderr]   Downloaded jiff v0.2.16
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 9f2089f7460acb28431f071b9e01b2335f92b73f00de020fae4968f411613eb9
[INFO] running `Command { std: "docker" "start" "-a" "9f2089f7460acb28431f071b9e01b2335f92b73f00de020fae4968f411613eb9", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "9f2089f7460acb28431f071b9e01b2335f92b73f00de020fae4968f411613eb9", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "9f2089f7460acb28431f071b9e01b2335f92b73f00de020fae4968f411613eb9", kill_on_drop: false }`
[INFO] [stdout] 9f2089f7460acb28431f071b9e01b2335f92b73f00de020fae4968f411613eb9
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] cd3234eb55e1ab321b3a278e8d87df653febbb692ebc2af42d3a222a91678c26
[INFO] running `Command { std: "docker" "start" "-a" "cd3234eb55e1ab321b3a278e8d87df653febbb692ebc2af42d3a222a91678c26", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling fastrand v2.3.0
[INFO] [stderr]    Compiling phf_shared v0.13.1
[INFO] [stderr]    Compiling linearize v0.1.5
[INFO] [stderr]    Compiling debug-fn v1.0.0
[INFO] [stderr]    Compiling error_reporter v1.0.0
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling run-on-drop v1.0.0
[INFO] [stderr]    Compiling isnt v0.2.0
[INFO] [stderr]    Compiling syn v2.0.111
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling phf_generator v0.13.1
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling regex v1.12.2
[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 uapi-proc v0.0.5
[INFO] [stderr]    Compiling phf v0.13.1
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling wl-proxy v0.1.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 13.34s
[INFO] running `Command { std: "docker" "inspect" "cd3234eb55e1ab321b3a278e8d87df653febbb692ebc2af42d3a222a91678c26", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "cd3234eb55e1ab321b3a278e8d87df653febbb692ebc2af42d3a222a91678c26", kill_on_drop: false }`
[INFO] [stdout] cd3234eb55e1ab321b3a278e8d87df653febbb692ebc2af42d3a222a91678c26
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 093129558cdd3fa883f0503aa4664ffe46b138b1c7a97cfdead92090a18229e7
[INFO] running `Command { std: "docker" "start" "-a" "093129558cdd3fa883f0503aa4664ffe46b138b1c7a97cfdead92090a18229e7", 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 env_filter v0.1.4
[INFO] [stderr]    Compiling env_logger v0.11.8
[INFO] [stderr]    Compiling wl-proxy v0.1.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 13.28s
[INFO] running `Command { std: "docker" "inspect" "093129558cdd3fa883f0503aa4664ffe46b138b1c7a97cfdead92090a18229e7", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "093129558cdd3fa883f0503aa4664ffe46b138b1c7a97cfdead92090a18229e7", kill_on_drop: false }`
[INFO] [stdout] 093129558cdd3fa883f0503aa4664ffe46b138b1c7a97cfdead92090a18229e7
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] c35ce28124fee5fa8fc72f1b1657749e933957e7ccaaaec1dce791c4d64a3d4a
[INFO] running `Command { std: "docker" "start" "-a" "c35ce28124fee5fa8fc72f1b1657749e933957e7ccaaaec1dce791c4d64a3d4a", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.08s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wl_proxy-c279e5984628a866)
[INFO] [stdout] 
[INFO] [stderr] [ 287391.401] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] running 111 tests
[INFO] [stderr] [ 287391.692] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287391.924] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.013] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.012] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.024] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.041] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.042] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.042] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.061] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.082] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.097] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.097] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.100] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.111] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.111] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.130] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.136] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.143] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.143] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287392.164] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.165] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.179] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.187] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287392.200] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#5)
[INFO] [stderr] [ 287392.224] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287392.251] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.261] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-04-10T11:02:20Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stdout] test fixed::tests::debug ... ok
[INFO] [stderr] [ 287392.660] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test fixed::tests::from_f32 ... ok
[INFO] [stderr] [ 287392.686] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::display ... ok
[INFO] [stderr] [ 287392.808] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::from_i64 ... ok
[INFO] [stderr] [ 287392.827] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::from_ints ... ok
[INFO] [stderr] [ 287392.879] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test endpoint::tests::dispatch_destroyed ... ok
[INFO] [stderr] [ 287392.901] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.932] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.946] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287392.959] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.981] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287392.761] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test client::tests::objects ... ok
[INFO] [stdout] test fixed::tests::minima ... ok
[INFO] [stderr] [ 287393.267] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::test_binops ... ok
[INFO] [stderr] [ 287393.310] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287393.327] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287393.341] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287393.355] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287393.392] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287393.402] {client} server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [ 287393.411] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287393.458] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287393.474] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287393.480] {proxy } client#2    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [ 287393.489] {proxy } server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [ 287393.498] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287393.507] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287393.625] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287393.734] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287393.768] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287393.783] {server} client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287393.804] {server} client#2    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [ 287393.812] {server} client#2    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [ 287393.835] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287393.842] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287393.877] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287393.878] {server} client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287393.895] {server} client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287393.900] {server} client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287393.935] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287393.944] {proxy } server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [ 287393.950] {proxy } client#2    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [ 287393.967] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287393.990] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287393.999] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287394.001] {proxy } client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287394.006] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287394.012] {proxy } client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287394.038] {client} server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [ 287394.040] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287394.054] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287394.060] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287394.064] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287394.099] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287394.167] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287394.211] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2026-04-10T11:02:20Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.65535 message: unknown message id 65535
[INFO] [stderr] [ 287394.445] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test client::tests::unset_handler ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Could not handle client bind: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::one_two ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test fixed::tests::test_unops ... ok
[INFO] [stdout] test client::tests::disconnected ... ok
[INFO] [stdout] test endpoint::tests::test ... ok
[INFO] [stdout] test fixed::tests::to_i32_floor ... ok
[INFO] [stdout] test fixed::tests::to_i32_nearest ... ok
[INFO] [stdout] test fixed::tests::to_i32_ceil ... ok
[INFO] [stdout] test endpoint::tests::lookup ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Could not handle server global: the message handler is already borrowed
[INFO] [stdout] test endpoint::tests::invalid_message ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Could not add synthetic global: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::from_i32 ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z 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 ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Could not remove synthetic global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_bind_nonexistent ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stdout] test global_mapper::tests::test_forward_bind_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_synthetic ... ok
[INFO] [stdout] test fixed::tests::wire ... ok
[INFO] [stdout] test fixed::tests::test_shiftops ... ok
[INFO] [stderr] [ 287404.328] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_forward_global_error ... ok
[INFO] [stderr] [ 287404.347] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_default ... ok
[INFO] [stderr] [ 287404.378] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove ... ok
[INFO] [stderr] [ 287404.390] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_add_synthetic_global_error ... ok
[INFO] [stderr] [ 287404.399] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::to_i32_zero ... ok
[INFO] [stderr] [ 287404.431] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test fixed::tests::to_f32 ... ok
[INFO] [stderr] [ 287404.753] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_nonexistent ... ok
[INFO] [stderr] [ 287404.761] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global_error ... ok
[INFO] [stderr] [ 287404.774] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global ... ok
[INFO] [stderr] [ 287404.775] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global_error ... ok
[INFO] [stderr] [ 287404.809] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global ... ok
[INFO] [stderr] [ 287404.814] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global ... ok
[INFO] [stderr] [ 287404.828] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_error ... ok
[INFO] [stderr] [ 287404.829] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove ... ok
[INFO] [stderr] [ 287404.837] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_ignored ... ok
[INFO] [stderr] [ 287404.844] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_ignore_global ... ok
[INFO] [stderr] [ 287404.850] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_error ... ok
[INFO] [stderr] [ 287404.861] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_ignored ... ok
[INFO] [stderr] [ 287404.880] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global ... ok
[INFO] [stderr] [ 287404.889] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global_error ... ok
[INFO] [stderr] [ 287404.897] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_nonexistent ... ok
[INFO] [stderr] [ 287404.904] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4294967295)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_error ... ok
[INFO] [stderr] [ 287404.921] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test global_mapper::tests::test_forward_bind ... ok
[INFO] [stderr] [ 287404.942] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind ... ok
[INFO] [stderr] [ 287404.947] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test handler::tests::borrow ... ok
[INFO] [stderr] [ 287404.953] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test handler::tests::map ... ok
[INFO] [stderr] [ 287405.003] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test handler::tests::replace ... ok
[INFO] [stderr] [ 287405.016] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::client ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z 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] [stdout] test global_mapper::tests::test_try_forward_bind_synthetic ... ok
[INFO] [stderr] [ 287405.028] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test object::tests::client_object_with_server_id ... ok
[INFO] [stderr] [ 287405.040] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test object::tests::double_send ... ok
[INFO] [stderr] [ 287405.059] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_nonexistent ... ok
[INFO] [stderr] [ 287405.067] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test handler::tests::clone ... ok
[INFO] [stderr] [ 287405.073] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test object::tests::destroyed_client ... ok
[INFO] [stderr] [ 287405.077] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test object::tests::duplicate_client_id ... ok
[INFO] [stderr] [ 287405.141] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test object::tests::request_without_server ... ok
[INFO] [stderr] [ 287405.146] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test object::tests::duplicate_generated_client_id ... ok
[INFO] [stderr] [ 287405.165] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stdout] test object::tests::get_handler ... ok
[INFO] [stderr] [ 287405.171] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test object::tests::server_destroyed ... ok
[INFO] [stderr] [ 287405.177] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test poll::tests::edge_trigger ... ok
[INFO] [stderr] [ 287405.179] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_error ... ok
[INFO] [stderr] [ 287405.183] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287405.187] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287405.207] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287405.211] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287405.215] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287405.218] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287405.296] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287405.310] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287405.341] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287405.351] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287405.359] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287405.373] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287405.472] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287405.486] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stderr] [ 287406.377] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287406.399] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287406.451] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287406.463] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287406.472] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287406.487] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287406.519] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [ 287406.525] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test poll::tests::many ... ok
[INFO] [stderr] [ 287406.548] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test poll::tests::test ... ok
[INFO] [stderr] [ 287406.570] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test object::tests::client_id ... ok
[INFO] [stderr] [ 287406.576] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stdout] test object::tests::forward ... ok
[INFO] [stderr] [2026-04-10T11:02:20Z 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 state::tests::destroyed_readable ... ok
[INFO] [stderr] [ 287407.084] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::destructor ... ok
[INFO] [stderr] [ 287407.107] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::state ... ok
[INFO] [stderr] [ 287407.136] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287407.153] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287407.180] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::closed_client ... ok
[INFO] [stderr] [ 287407.195] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287407.234] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287407.265] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287407.279] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287407.494] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287407.511] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287407.524] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test object::tests::version ... ok
[INFO] [stderr] [ 287407.535] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test state::tests::remote_destructor ... ok
[INFO] [stderr] [ 287407.551] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test state::tests::add_client ... ok
[INFO] [stderr] [ 287407.790] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::recursive_dispatch ... ok
[INFO] [stderr] [ 287407.804] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::count_hops ... ok
[INFO] [stderr] [ 287407.831] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287407.840] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287407.848] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::suspend2 ... ok
[INFO] [stderr] [ 287407.861] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::suspend1 ... ok
[INFO] [stderr] [ 287407.887] {proxy } client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stdout] test state::tests::suspend3 ... ok
[INFO] [stderr] [ 287407.975] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::display_error ... ok
[INFO] [stderr] [ 287407.989] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287408.017] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287408.026] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287408.033] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287408.046] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287408.082] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287408.091] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287408.110] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287408.114] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287408.120] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287408.126] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287408.128] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287408.145] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287408.147] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [ 287408.154] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [ 287408.156] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287408.176] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287408.187] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287408.200] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287408.232] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287408.236] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287408.241] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287408.247] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287408.268] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#50)
[INFO] [stderr] [ 287408.646] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287408.690] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287408.739] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287408.759] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287408.776] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287408.795] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287409.127] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287409.155] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287409.184] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287409.203] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287409.220] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287409.233] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287409.293] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287409.318] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.079] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.108] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.111] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.127] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.142] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.151] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.155] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.164] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.166] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.179] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.179] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.196] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.203] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [ 287410.209] {client} server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [ 287410.214] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.235] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [ 287410.250] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [ 287410.255] {proxy } client#2    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [ 287410.258] {proxy } server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [ 287410.262] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.268] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.300] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.309] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.319] {server} client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [ 287410.329] {server} client#2    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [ 287410.332] {server} client#2    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [ 287410.339] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.344] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.350] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287410.384] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287410.397] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287410.445] {proxy } server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [ 287410.449] {proxy } client#2    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [ 287410.465] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.468] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.473] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287410.479] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287410.506] {client} server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [ 287410.516] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.528] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287410.551] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [ 287410.561] {client} server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [ 287410.567] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287410.585] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [ 287410.592] {proxy } client#2    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [ 287410.596] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287410.602] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.627] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.644] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.672] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287410.704] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.711] {proxy } client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287410.715] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287410.727] {proxy } client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287410.747] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287410.751] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287410.766] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [ 287410.770] {client} server      <= wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [ 287410.779] {client} server      <= wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [ 287410.812] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [ 287410.820] {proxy } client#2    -> wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::protocol_helpers] Could not forward a wlproxy_test_non_forward.echo message: the receiver has no server id
[INFO] [stderr] [ 287410.916] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [ 287410.935] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.964] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287410.970] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287410.976] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287411.008] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287411.011] {proxy } client#2    <= wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [ 287411.016] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287411.021] {proxy } client#2    <= wl_display#1.delete_id(id: 7)
[INFO] [stderr] [ 287411.038] {client} server      -> wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [ 287411.041] {client} server      -> wl_display#1.delete_id(id: 7)
[INFO] [stderr] [ 287411.054] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [ 287411.057] {client} server      <= wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [ 287411.067] {client} server      <= wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [ 287411.082] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [ 287411.088] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [ 287411.092] {proxy } client#2    -> wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [ 287411.095] {proxy } server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [ 287411.098] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [ 287411.107] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287411.127] {server} client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [ 287411.134] {server} client#2    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [ 287411.137] {server} client#2    <= wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [ 287411.141] {server} client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [ 287411.146] {server} client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287411.150] {server} client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287411.178] {proxy } server      -> wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [ 287411.181] {proxy } client#2    <= wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [ 287411.186] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [ 287411.188] {proxy } client#2    <= wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [ 287411.192] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [ 287411.197] {proxy } client#2    <= wl_display#1.delete_id(id: 8)
[INFO] [stderr] [ 287411.217] {client} server      -> wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [ 287411.221] {client} server      -> wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [ 287411.225] {client} server      -> wl_display#1.delete_id(id: 8)
[INFO] [stderr] [2026-04-10T11:02:20Z WARN  wl_proxy::global_mapper] Could not handle server global remove: the message handler is already borrowed
[INFO] [stderr] [ 287422.710] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287422.757] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287422.805] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287422.827] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287422.837] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287422.864] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287422.898] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287422.926] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287422.980] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287422.995] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287423.012] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.030] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.275] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287423.289] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.645] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287423.677] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.710] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287423.720] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287423.728] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.743] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.774] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287423.903] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287423.965] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287423.985] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287424.001] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287424.064] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287424.069] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287424.086] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287424.086] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287424.113] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287424.159] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287424.200] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287424.307] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287424.357] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287424.537] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287424.597] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287424.640] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287424.710] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287424.866] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287424.918] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287425.005] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287425.061] {client} server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [ 287425.139] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287425.297] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287425.348] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287425.443] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287425.470] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287425.478] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287425.489] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287425.501] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287425.541] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287425.597] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287425.657] {proxy } client#2    -> wlproxy_test#3.send_object()
[INFO] [stderr] [ 287425.696] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287425.780] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287426.066] {proxy } server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [ 287426.210] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287426.241] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287426.274] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287426.317] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.335] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.355] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287426.368] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287426.384] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287426.447] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.504] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287426.552] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.567] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287426.605] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.666] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.686] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287426.705] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287426.751] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287426.760] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287426.777] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287426.783] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287426.820] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287426.825] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287426.926] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287426.941] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287426.953] {server} client#2    -> wlproxy_test#3.send_object()
[INFO] [stderr] [ 287426.966] {server} client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [ 287426.985] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287426.992] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287426.998] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287427.352] {proxy } server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [ 287427.393] {proxy } client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [ 287427.522] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287427.581] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287427.625] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287427.744] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287427.840] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [ 287427.885] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287427.987] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287428.071] {client} server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [ 287428.897] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287428.934] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.021] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.039] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.038] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.054] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.061] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.079] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.084] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.094] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.101] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.115] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.147] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.160] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.183] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.190] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287429.200] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [ 287429.206] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [ 287429.211] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.215] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stdout] test state::tests::suspend5 ... ok
[INFO] [stderr] [ 287429.240] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stdout] test state::tests::suspend4 ... ok
[INFO] [stderr] [ 287429.240] {proxy } client#3    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::suspend6 ... ok
[INFO] [stderr] [ 287429.250] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stdout] test object::tests::server_sent ... ok
[INFO] [stderr] [ 287429.253] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#4)
[INFO] [stdout] test trans::tests::edge_header ... ok
[INFO] [stderr] [ 287429.263] {proxy } client#3    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test trans::tests::not_word_size ... ok
[INFO] [stderr] [ 287429.274] {proxy } server      <= wl_registry#4.bind(name: 0, id: wlproxy_test#5 (version: 1))
[INFO] [stdout] test trans::tests::fd ... ok
[INFO] [stderr] [ 287429.295] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stdout] test trans::tests::large_message ... ok
[INFO] [stderr] [ 287429.299] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stdout] test trans::tests::small_message ... ok
[INFO] [stderr] [ 287429.306] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stdout] test utils::stack::tests::stack ... ok
[INFO] [stderr] [ 287429.307] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stdout] test utils::stash::tests::test ... ok
[INFO] [stderr] [ 287429.318] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [ 287429.319] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [ 287429.328] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [ 287429.336] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x78)
[INFO] [stderr] [ 287429.341] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [ 287429.343] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x79)
[INFO] [stderr] [ 287429.350] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [ 287429.357] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [ 287429.373] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x78)
[INFO] [stderr] [ 287429.377] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [ 287429.398] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [ 287429.402] {proxy } client#3    <= wlproxy_test_array_echo#4.array(array: 0x78)
[INFO] [stderr] [ 287429.408] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [ 287429.433] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x79)
[INFO] [stderr] [ 287429.441] {proxy } client#3    <= wlproxy_test_array_echo#5.array(array: 0x79)
[INFO] [stderr] [ 287429.453] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287429.461] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [ 287429.499] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [ 287429.532] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x78)
[INFO] [stderr] [ 287429.538] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x79)
[INFO] [stderr] [ 287429.551] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x7a)
[INFO] [stderr] [ 287429.573] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x7a)
[INFO] [stderr] [ 287429.580] {proxy } client#3    <= wlproxy_test_array_echo#6.array(array: 0x7a)
[INFO] [stderr] [ 287429.600] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x7a)
[INFO] [stderr] [ 287429.613] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [ 287429.620] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [ 287429.638] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [ 287429.661] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [ 287429.673] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.677] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [ 287429.684] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [ 287429.687] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.690] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [ 287429.714] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [ 287429.718] {client} server      -> wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [ 287429.725] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.735] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.758] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.772] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.821] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287429.832] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287429.863] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287429.903] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [ 287429.931] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [ 287429.962] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [ 287430.099] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287430.127] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287430.192] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [ 287430.279] {proxy } client#2    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [ 287430.298] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [ 287430.311] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [ 287430.318] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [ 287430.325] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [ 287430.336] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [ 287430.342] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [ 287430.351] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [ 287430.608] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287430.631] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287430.682] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287430.700] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287430.709] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287430.725] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287430.754] {proxy } client#2    <= wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [ 287430.784] {proxy } server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [ 287430.789] {client} server      -> wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [ 287430.797] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287430.808] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287430.841] {server} client#2    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [ 287431.100] {server} client#2    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [ 287431.248] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287431.352] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287431.479] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287431.527] {proxy } server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [ 287431.860] {proxy } client#2    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [ 287431.904] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287431.959] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.035] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287432.098] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287432.167] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.186] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.216] {client} server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stdout] test acceptor::tests::test ... FAILED
[INFO] [stderr] [ 287432.223] {client} server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [ 287432.318] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287432.393] {proxy } client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [ 287432.457] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.514] {proxy } server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [ 287432.595] {proxy } client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [ 287432.625] {proxy } server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [ 287432.637] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287432.709] {server} client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [ 287432.739] {server} client#2    <= wlproxy_test_hops#4.count(count: 1)
[INFO] [stderr] [ 287432.767] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287432.781] {server} client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [ 287432.787] {server} client#2    <= wlproxy_test_hops#5.count(count: 1)
[INFO] [stderr] [ 287432.792] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287432.824] {proxy } server      -> wlproxy_test_hops#4.count(count: 1)
[INFO] [stderr] [ 287432.838] {proxy } client#2    <= wlproxy_test_hops#4.count(count: 2)
[INFO] [stderr] [ 287432.858] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287432.869] {client} server      -> wlproxy_test_hops#4.count(count: 2)
[INFO] [stderr] [ 287432.890] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.934] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287432.945] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [2026-04-10T11:02:20Z INFO  wl_proxy::state::tests] unsuspend
[INFO] [stderr] [ 287432.959] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.963] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287432.971] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287432.976] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287432.985] {proxy } server      -> wlproxy_test_hops#5.count(count: 1)
[INFO] [stderr] [ 287432.989] {proxy } client#2    <= wlproxy_test_hops#5.count(count: 2)
[INFO] [stderr] [ 287433.009] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287433.019] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287433.029] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [ 287433.057] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287433.059] {client} server      -> wlproxy_test_hops#5.count(count: 2)
[INFO] [stderr] [ 287433.066] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [ 287433.099] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [ 287433.936] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287433.955] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287433.962] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287434.009] {client} server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [ 287434.016] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287434.020] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287434.049] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287434.064] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287434.103] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287434.121] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287434.133] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287434.153] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287434.170] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287434.200] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [ 287435.102] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287436.058] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287436.234] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287436.305] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287436.444] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287436.579] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287436.700] {client} server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 38, fd2: 39)
[INFO] [stderr] [ 287436.812] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287437.970] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.086] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test trans::tests::array ... ok
[INFO] [stderr] [ 287438.097] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test utils::free_list::tests::test ... ok
[INFO] [stderr] [ 287438.129] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test trans::tests::echo_fd ... ok
[INFO] [stderr] [ 287438.137] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.144] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.155] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.183] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287438.230] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.247] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-04-10T11:02:20Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 9 that is not a multiple of 4
[INFO] [stderr] [ 287437.989] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.537] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.564] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.572] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.585] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.606] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.608] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [ 287438.617] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287438.624] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.638] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [ 287438.649] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [ 287438.653] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.655] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287438.662] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test fixed::tests::maximum - should panic ... ok
[INFO] [stderr] [ 287438.662] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.670] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.682] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.691] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.699] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.709] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [ 287438.711] {client} server      <= wlproxy_test#3.recv_fd(fd: 64)
[INFO] [stderr] [ 287438.717] {client} server      <= wlproxy_test#3.recv_fd(fd: 64)
[INFO] [stderr] [ 287438.719] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [ 287438.725] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287438.742] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287438.749] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287438.754] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287438.759] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287438.772] {proxy } client#2    -> wlproxy_test#3.recv_fd(fd: 66)
[INFO] [stderr] [ 287438.777] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 66)
[INFO] [stderr] [ 287438.808] {proxy } client#2    -> wlproxy_test#3.recv_fd(fd: 66)
[INFO] [stderr] [ 287438.812] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 66)
[INFO] [stderr] [ 287438.816] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287438.830] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287438.845] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [ 287438.849] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [ 287438.857] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287438.862] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287438.868] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287438.871] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287438.875] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287438.879] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287438.880] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287438.894] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287438.900] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [ 287438.905] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287438.906] {server} client#2    -> wlproxy_test#3.recv_fd(fd: 66)
[INFO] [stderr] [ 287438.909] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287438.913] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287438.925] {server} client#2    -> wlproxy_test#3.recv_fd(fd: 66)
[INFO] [stderr] [ 287438.932] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287438.946] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287438.959] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287439.009] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287439.013] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test fixed::tests::minimum - should panic ... ok
[INFO] [stderr] [ 287439.021] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287439.026] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287439.027] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [ 287439.036] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287439.047] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [ 287439.051] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287439.054] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [ 287439.062] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [ 287439.066] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287439.072] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287439.396] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.438] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287439.449] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [ 287439.461] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [ 287439.469] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287439.469] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.476] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287439.478] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.482] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287439.487] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287439.486] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287439.499] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287439.527] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-04-10T11:02:20Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [ 287439.789] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.813] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287439.848] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.858] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.866] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287439.881] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287439.912] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [ 287439.959] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [ 287439.983] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [2026-04-10T11:02:20Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 4 < 8
[INFO] [stderr] [ 287440.262] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [ 287440.269] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [ 287440.276] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287440.411] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287440.440] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287440.443] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287440.448] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287440.453] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287440.649] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [ 287440.718] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287440.863] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287440.900] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287440.945] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [ 287441.001] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287441.095] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [ 287442.481] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [ 287442.501] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287442.510] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287442.546] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [ 287442.556] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [ 287442.564] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287442.571] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287442.577] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287442.582] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287442.813] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [ 287442.919] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287442.998] {proxy } client#2    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 64, fd2: 66)
[INFO] [stderr] [ 287443.054] {proxy } server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 64, fd2: 66)
[INFO] [stderr] [ 287443.064] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test handler::tests::multi_borrow - should panic ... ok
[INFO] [stderr] [ 287443.073] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287443.189] {server} client#2    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 70, fd2: 71)
[INFO] [stderr] [ 287443.249] {server} client#2    <= wlproxy_test_fd_echo#4.fd(fd1: 70, fd2: 71)
[INFO] [stderr] [ 287443.271] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287443.280] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287443.286] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287443.291] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287443.457] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [ 287443.464] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [ 287443.470] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287443.476] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287443.482] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287443.485] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287443.489] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287443.493] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test object::tests::duplicate_server_id - should panic ... ok
[INFO] [stderr] [ 287443.514] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stdout] test object::tests::invalid_server_id - should panic ... ok
[INFO] [stderr] [ 287443.518] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287443.522] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287443.526] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287443.541] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [ 287443.548] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287443.565] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [ 287443.574] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [ 287443.579] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287443.585] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287443.669] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [ 287443.699] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [ 287443.751] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287443.787] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287443.876] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287443.911] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287443.961] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [ 287444.008] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [ 287444.031] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287444.114] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287444.153] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287444.173] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287444.267] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287444.305] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287444.350] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [ 287444.395] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287444.442] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287444.572] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287444.611] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [ 287444.667] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287444.711] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [ 287444.794] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [ 287444.817] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287444.838] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287444.933] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [ 287444.984] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [ 287445.023] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287445.045] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287445.066] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287445.107] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287445.169] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [ 287445.191] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [ 287445.246] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287445.267] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287445.288] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287445.305] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287445.354] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287445.374] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287445.441] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [ 287445.588] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287445.627] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287445.646] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287445.680] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [ 287445.842] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287445.984] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [ 287445.997] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [ 287446.003] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287446.009] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287446.032] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [ 287446.171] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [ 287446.179] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287446.186] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [ 287446.191] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287446.196] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287446.256] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [ 287446.267] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [ 287446.274] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287446.279] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287446.285] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287446.288] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287446.292] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287446.297] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287446.574] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [ 287446.642] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287446.667] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287446.727] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287447.699] {proxy } server      -> wlproxy_test_fd_echo#4.fd(fd1: 64, fd2: 66)
[INFO] [stderr] [ 287448.450] {proxy } client#2    <= wlproxy_test_fd_echo#4.fd(fd1: 64, fd2: 66)
[INFO] [stderr] [ 287448.565] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287448.631] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287448.746] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287448.845] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287448.880] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287448.930] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [ 287449.045] {client} server      -> wlproxy_test_fd_echo#4.fd(fd1: 4, fd2: 5)
[INFO] [stderr] [ 287449.082] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [ 287449.127] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [ 287449.201] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stdout] test state::tests::acceptor ... FAILED
[INFO] [stdout] test object::tests::wrong_downcast - should panic ... ok
[INFO] [stdout] test utils::free_list::tests::release_out_of_bounds - should panic ... ok
[INFO] [stdout] test state::tests::many_events ... ok
[INFO] [stdout] test trans::tests::many_messages ... ok
[INFO] [stdout] test trans::tests::many_messages_with_fd ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- acceptor::tests::test stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'acceptor::tests::test' (17) 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:     0x5a5c2620869a - std[31e582c13f4e914f]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x5a5c2620869a - std[31e582c13f4e914f]::backtrace_rs::backtrace::trace_unsynchronized::<std[31e582c13f4e914f]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x5a5c2620869a - std[31e582c13f4e914f]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x5a5c2620869a - <<std[31e582c13f4e914f]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[fa0eadad68403074]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x5a5c262206ca - <core[fa0eadad68403074]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x5a5c262206ca - core[fa0eadad68403074]::fmt::write
[INFO] [stdout]    6:     0x5a5c2620e692 - std[31e582c13f4e914f]::io::default_write_fmt::<alloc[49b8922c36ca62de]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x5a5c2620e692 - <alloc[49b8922c36ca62de]::vec::Vec<u8> as std[31e582c13f4e914f]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x5a5c261e75ff - <std[31e582c13f4e914f]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x5a5c261e75ff - std[31e582c13f4e914f]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x5a5c26200aa9 - std[31e582c13f4e914f]::panicking::default_hook
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x5a5c26197dcc - <alloc[49b8922c36ca62de]::boxed::Box<dyn for<'a, 'b> core[fa0eadad68403074]::ops::function::Fn<(&'a std[31e582c13f4e914f]::panic::PanicHookInfo<'b>,), Output = ()> + core[fa0eadad68403074]::marker::Sync + core[fa0eadad68403074]::marker::Send> as core[fa0eadad68403074]::ops::function::Fn<(&std[31e582c13f4e914f]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x5a5c26197dcc - test[7530e63dc052480e]::test_main_with_exit_callback::<test[7530e63dc052480e]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x5a5c26200c62 - <alloc[49b8922c36ca62de]::boxed::Box<dyn for<'a, 'b> core[fa0eadad68403074]::ops::function::Fn<(&'a std[31e582c13f4e914f]::panic::PanicHookInfo<'b>,), Output = ()> + core[fa0eadad68403074]::marker::Sync + core[fa0eadad68403074]::marker::Send> as core[fa0eadad68403074]::ops::function::Fn<(&std[31e582c13f4e914f]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x5a5c26200c62 - std[31e582c13f4e914f]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x5a5c261e76b8 - std[31e582c13f4e914f]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x5a5c261dc819 - std[31e582c13f4e914f]::sys::backtrace::__rust_end_short_backtrace::<std[31e582c13f4e914f]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x5a5c261e84ed - __rustc[fc8e3a9f23f26cb]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x5a5c26220f3c - core[fa0eadad68403074]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x5a5c26220c82 - core[fa0eadad68403074]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x5a5c25e8036a - <core[fa0eadad68403074]::result::Result<alloc[49b8922c36ca62de]::rc::Rc<wl_proxy[a511c1cab09b323c]::acceptor::Acceptor>, wl_proxy[a511c1cab09b323c]::acceptor::AcceptorError>>::unwrap
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x5a5c25e8036a - wl_proxy[a511c1cab09b323c]::acceptor::tests::test
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:9:46
[INFO] [stdout]   22:     0x5a5c25e73807 - wl_proxy[a511c1cab09b323c]::acceptor::tests::test::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:8:10
[INFO] [stdout]   23:     0x5a5c25e4e606 - <wl_proxy[a511c1cab09b323c]::acceptor::tests::test::{closure#0} as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x5a5c2618beab - <fn() -> core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x5a5c2618beab - test[7530e63dc052480e]::__rust_begin_short_backtrace::<core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>, fn() -> core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x5a5c2619889b - test[7530e63dc052480e]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x5a5c2619889b - <core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x5a5c2619889b - std[31e582c13f4e914f]::panicking::catch_unwind::do_call::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}>, core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x5a5c2619889b - std[31e582c13f4e914f]::panicking::catch_unwind::<core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>, core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x5a5c2619889b - std[31e582c13f4e914f]::panic::catch_unwind::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}>, core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x5a5c2619889b - test[7530e63dc052480e]::run_test_in_process
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x5a5c2619889b - test[7530e63dc052480e]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x5a5c26192cf4 - test[7530e63dc052480e]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x5a5c26192cf4 - std[31e582c13f4e914f]::sys::backtrace::__rust_begin_short_backtrace::<test[7530e63dc052480e]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked::<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x5a5c2619b4a2 - <core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::panicking::catch_unwind::do_call::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::panicking::catch_unwind::<(), core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::panic::catch_unwind::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked::<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x5a5c2619b4a2 - <std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1} as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x5a5c26207faf - <alloc[49b8922c36ca62de]::boxed::Box<dyn core[fa0eadad68403074]::ops::function::FnOnce<(), Output = ()> + core[fa0eadad68403074]::marker::Send> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x5a5c26207faf - <std[31e582c13f4e914f]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x7aeff9ce9aa4 - <unknown>
[INFO] [stdout]   45:     0x7aeff9d76a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- state::tests::acceptor stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'state::tests::acceptor' (129) panicked at src/state/tests.rs:114:49:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: StateError(CreateAcceptor(AcceptorError(XrdNotSet)))
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5a5c2620869a - std[31e582c13f4e914f]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x5a5c2620869a - std[31e582c13f4e914f]::backtrace_rs::backtrace::trace_unsynchronized::<std[31e582c13f4e914f]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x5a5c2620869a - std[31e582c13f4e914f]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x5a5c2620869a - <<std[31e582c13f4e914f]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[fa0eadad68403074]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x5a5c262206ca - <core[fa0eadad68403074]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x5a5c262206ca - core[fa0eadad68403074]::fmt::write
[INFO] [stdout]    6:     0x5a5c2620e692 - std[31e582c13f4e914f]::io::default_write_fmt::<alloc[49b8922c36ca62de]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x5a5c2620e692 - <alloc[49b8922c36ca62de]::vec::Vec<u8> as std[31e582c13f4e914f]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x5a5c261e75ff - <std[31e582c13f4e914f]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x5a5c261e75ff - std[31e582c13f4e914f]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x5a5c26200aa9 - std[31e582c13f4e914f]::panicking::default_hook
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x5a5c26197dcc - <alloc[49b8922c36ca62de]::boxed::Box<dyn for<'a, 'b> core[fa0eadad68403074]::ops::function::Fn<(&'a std[31e582c13f4e914f]::panic::PanicHookInfo<'b>,), Output = ()> + core[fa0eadad68403074]::marker::Sync + core[fa0eadad68403074]::marker::Send> as core[fa0eadad68403074]::ops::function::Fn<(&std[31e582c13f4e914f]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x5a5c26197dcc - test[7530e63dc052480e]::test_main_with_exit_callback::<test[7530e63dc052480e]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x5a5c26200c62 - <alloc[49b8922c36ca62de]::boxed::Box<dyn for<'a, 'b> core[fa0eadad68403074]::ops::function::Fn<(&'a std[31e582c13f4e914f]::panic::PanicHookInfo<'b>,), Output = ()> + core[fa0eadad68403074]::marker::Sync + core[fa0eadad68403074]::marker::Send> as core[fa0eadad68403074]::ops::function::Fn<(&std[31e582c13f4e914f]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x5a5c26200c62 - std[31e582c13f4e914f]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x5a5c261e76b8 - std[31e582c13f4e914f]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x5a5c261dc819 - std[31e582c13f4e914f]::sys::backtrace::__rust_end_short_backtrace::<std[31e582c13f4e914f]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x5a5c261e84ed - __rustc[fc8e3a9f23f26cb]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x5a5c26220f3c - core[fa0eadad68403074]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x5a5c26220c82 - core[fa0eadad68403074]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x5a5c25e7a16f - <core[fa0eadad68403074]::result::Result<alloc[49b8922c36ca62de]::rc::Rc<wl_proxy[a511c1cab09b323c]::acceptor::Acceptor>, wl_proxy[a511c1cab09b323c]::state::StateError>>::unwrap
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x5a5c25e7a16f - wl_proxy[a511c1cab09b323c]::state::tests::acceptor
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:114:49
[INFO] [stdout]   22:     0x5a5c25e73117 - wl_proxy[a511c1cab09b323c]::state::tests::acceptor::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:99:14
[INFO] [stdout]   23:     0x5a5c25e4dbc6 - <wl_proxy[a511c1cab09b323c]::state::tests::acceptor::{closure#0} as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x5a5c2618beab - <fn() -> core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x5a5c2618beab - test[7530e63dc052480e]::__rust_begin_short_backtrace::<core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>, fn() -> core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x5a5c2619889b - test[7530e63dc052480e]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x5a5c2619889b - <core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x5a5c2619889b - std[31e582c13f4e914f]::panicking::catch_unwind::do_call::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}>, core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x5a5c2619889b - std[31e582c13f4e914f]::panicking::catch_unwind::<core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>, core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x5a5c2619889b - std[31e582c13f4e914f]::panic::catch_unwind::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<test[7530e63dc052480e]::run_test_in_process::{closure#0}>, core[fa0eadad68403074]::result::Result<(), alloc[49b8922c36ca62de]::string::String>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x5a5c2619889b - test[7530e63dc052480e]::run_test_in_process
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x5a5c2619889b - test[7530e63dc052480e]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x5a5c26192cf4 - test[7530e63dc052480e]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x5a5c26192cf4 - std[31e582c13f4e914f]::sys::backtrace::__rust_begin_short_backtrace::<test[7530e63dc052480e]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked::<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x5a5c2619b4a2 - <core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::panicking::catch_unwind::do_call::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::panicking::catch_unwind::<(), core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::panic::catch_unwind::<core[fa0eadad68403074]::panic::unwind_safe::AssertUnwindSafe<std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x5a5c2619b4a2 - std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked::<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x5a5c2619b4a2 - <std[31e582c13f4e914f]::thread::lifecycle::spawn_unchecked<test[7530e63dc052480e]::run_test::{closure#1}, ()>::{closure#1} as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x5a5c26207faf - <alloc[49b8922c36ca62de]::boxed::Box<dyn core[fa0eadad68403074]::ops::function::FnOnce<(), Output = ()> + core[fa0eadad68403074]::marker::Send> as core[fa0eadad68403074]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x5a5c26207faf - <std[31e582c13f4e914f]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/562dee4820c458d823175268e41601d4c060588a/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x7aeff9ce9aa4 - <unknown>
[INFO] [stdout]   45:     0x7aeff9d76a64 - 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. 109 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.55s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "c35ce28124fee5fa8fc72f1b1657749e933957e7ccaaaec1dce791c4d64a3d4a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c35ce28124fee5fa8fc72f1b1657749e933957e7ccaaaec1dce791c4d64a3d4a", kill_on_drop: false }`
[INFO] [stdout] c35ce28124fee5fa8fc72f1b1657749e933957e7ccaaaec1dce791c4d64a3d4a