[INFO] fetching crate libjuice-rs 0.1.0...
[INFO] testing libjuice-rs-0.1.0 against 1.69.0 for beta-1.70-1
[INFO] extracting crate libjuice-rs 0.1.0 into /workspace/builds/worker-0-tc1/source
[INFO] validating manifest of crates.io crate libjuice-rs 0.1.0 on toolchain 1.69.0
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.69.0" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] started tweaking crates.io crate libjuice-rs 0.1.0
[INFO] finished tweaking crates.io crate libjuice-rs 0.1.0
[INFO] tweaked toml for crates.io crate libjuice-rs 0.1.0 written to /workspace/builds/worker-0-tc1/source/Cargo.toml
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" __CARGO_TEST_CHANNEL_OVERRIDE_DO_NOT_USE_THIS="nightly" "/workspace/cargo-home/bin/cargo" "+1.69.0" "generate-lockfile" "--manifest-path" "Cargo.toml" "-Zno-index-update", kill_on_drop: false }`
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.69.0" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded libjuice-sys v0.9.7
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-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:5ff2268d62e97bff2cde7d5815dd6ed5b47097566f13b8d0ca110b04b60e07ed" "/opt/rustwide/cargo-home/bin/cargo" "+1.69.0" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] cd43d38080cfd36be6b21444044fcdac1c9fafeb3be13a8bde1f6adfa394d12f
[INFO] running `Command { std: "docker" "start" "-a" "cd43d38080cfd36be6b21444044fcdac1c9fafeb3be13a8bde1f6adfa394d12f", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "cd43d38080cfd36be6b21444044fcdac1c9fafeb3be13a8bde1f6adfa394d12f", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "cd43d38080cfd36be6b21444044fcdac1c9fafeb3be13a8bde1f6adfa394d12f", kill_on_drop: false }`
[INFO] [stdout] cd43d38080cfd36be6b21444044fcdac1c9fafeb3be13a8bde1f6adfa394d12f
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:5ff2268d62e97bff2cde7d5815dd6ed5b47097566f13b8d0ca110b04b60e07ed" "/opt/rustwide/cargo-home/bin/cargo" "+1.69.0" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] b9e2138fa3adc05da6c8352e2ab19f161a0f1c54ed6d9da59f23fb42ed12414c
[INFO] running `Command { std: "docker" "start" "-a" "b9e2138fa3adc05da6c8352e2ab19f161a0f1c54ed6d9da59f23fb42ed12414c", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.142
[INFO] [stderr]    Compiling memchr v2.5.0
[INFO] [stderr]    Compiling glob v0.3.1
[INFO] [stderr]    Compiling log v0.4.17
[INFO] [stderr]    Compiling proc-macro2 v1.0.56
[INFO] [stderr]    Compiling minimal-lexical v0.2.1
[INFO] [stderr]    Compiling unicode-width v0.1.10
[INFO] [stderr]    Compiling regex-syntax v0.7.1
[INFO] [stderr]    Compiling quote v1.0.26
[INFO] [stderr]    Compiling ansi_term v0.12.1
[INFO] [stderr]    Compiling termcolor v1.2.0
[INFO] [stderr]    Compiling either v1.8.1
[INFO] [stderr]    Compiling vec_map v0.8.2
[INFO] [stderr]    Compiling libloading v0.7.4
[INFO] [stderr]    Compiling humantime v2.1.0
[INFO] [stderr]    Compiling strsim v0.8.0
[INFO] [stderr]    Compiling textwrap v0.11.0
[INFO] [stderr]    Compiling bindgen v0.59.2
[INFO] [stderr]    Compiling cc v1.0.79
[INFO] [stderr]    Compiling lazycell v1.3.0
[INFO] [stderr]    Compiling rustc-hash v1.1.0
[INFO] [stderr]    Compiling peeking_take_while v0.1.2
[INFO] [stderr]    Compiling shlex v1.1.0
[INFO] [stderr]    Compiling clang-sys v1.6.1
[INFO] [stderr]    Compiling aho-corasick v1.0.1
[INFO] [stderr]    Compiling nom v7.1.3
[INFO] [stderr]    Compiling cmake v0.1.50
[INFO] [stderr]    Compiling atty v0.2.14
[INFO] [stderr]    Compiling which v4.4.0
[INFO] [stderr]    Compiling clap v2.34.0
[INFO] [stderr]    Compiling regex v1.8.1
[INFO] [stderr]    Compiling cexpr v0.6.0
[INFO] [stderr]    Compiling env_logger v0.9.3
[INFO] [stderr]    Compiling libjuice-sys v0.9.7
[INFO] [stderr]    Compiling libjuice-rs v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 19.96s
[INFO] running `Command { std: "docker" "inspect" "b9e2138fa3adc05da6c8352e2ab19f161a0f1c54ed6d9da59f23fb42ed12414c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "b9e2138fa3adc05da6c8352e2ab19f161a0f1c54ed6d9da59f23fb42ed12414c", kill_on_drop: false }`
[INFO] [stdout] b9e2138fa3adc05da6c8352e2ab19f161a0f1c54ed6d9da59f23fb42ed12414c
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:5ff2268d62e97bff2cde7d5815dd6ed5b47097566f13b8d0ca110b04b60e07ed" "/opt/rustwide/cargo-home/bin/cargo" "+1.69.0" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 93082e79d4fd33909a258e4f2af0479a27ce7a1078eeaeaf35ec398cf81a5c0c
[INFO] running `Command { std: "docker" "start" "-a" "93082e79d4fd33909a258e4f2af0479a27ce7a1078eeaeaf35ec398cf81a5c0c", kill_on_drop: false }`
[INFO] [stderr]    Compiling humantime v2.1.0
[INFO] [stderr]    Compiling termcolor v1.2.0
[INFO] [stderr]    Compiling log v0.4.17
[INFO] [stderr]    Compiling aho-corasick v1.0.1
[INFO] [stderr]    Compiling nom v7.1.3
[INFO] [stderr]    Compiling libc v0.2.142
[INFO] [stderr]    Compiling regex-syntax v0.7.1
[INFO] [stderr]    Compiling atty v0.2.14
[INFO] [stderr]    Compiling clap v2.34.0
[INFO] [stderr]    Compiling regex v1.8.1
[INFO] [stderr]    Compiling cexpr v0.6.0
[INFO] [stderr]    Compiling env_logger v0.9.3
[INFO] [stderr]    Compiling bindgen v0.59.2
[INFO] [stderr]    Compiling libjuice-sys v0.9.7
[INFO] [stderr]    Compiling libjuice-rs v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 13.10s
[INFO] running `Command { std: "docker" "inspect" "93082e79d4fd33909a258e4f2af0479a27ce7a1078eeaeaf35ec398cf81a5c0c", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "93082e79d4fd33909a258e4f2af0479a27ce7a1078eeaeaf35ec398cf81a5c0c", kill_on_drop: false }`
[INFO] [stdout] 93082e79d4fd33909a258e4f2af0479a27ce7a1078eeaeaf35ec398cf81a5c0c
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-0-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:5ff2268d62e97bff2cde7d5815dd6ed5b47097566f13b8d0ca110b04b60e07ed" "/opt/rustwide/cargo-home/bin/cargo" "+1.69.0" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 2e20000956092d38654cb4b21e47b57961ed12096293ecd357aeab77184edc90
[INFO] running `Command { std: "docker" "start" "-a" "2e20000956092d38654cb4b21e47b57961ed12096293ecd357aeab77184edc90", kill_on_drop: false }`
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 0.25s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/libjuice_rs-32a7684b39d19121)
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test agent::tests::build ... ok
[INFO] [stderr] [2023-04-30T04:08:06.421039Z INFO  libjuice_rs::log] agent.c:780: Changing state to connecting
[INFO] [stderr] [2023-04-30T04:08:06.421078Z DEBUG libjuice_rs::agent::tests] State changed to: Connecting
[INFO] [stderr] [2023-04-30T04:08:06.421090Z DEBUG libjuice_rs::log] server.c:422: Leaving server thread
[INFO] [stdout] test server::tests::build ... ok
[INFO] [stderr] [2023-04-30T04:08:06.449113Z WARN  libjuice_rs::log] addr.c:274: Address resolution failed for stun.l.google.com:19302
[INFO] [stderr] [2023-04-30T04:08:06.449174Z ERROR libjuice_rs::log] agent.c:615: STUN server address resolution failed
[INFO] [stderr] [2023-04-30T04:08:06.449185Z INFO  libjuice_rs::log] agent.c:2321: Candidate gathering done
[INFO] [stderr] [2023-04-30T04:08:06.449196Z DEBUG libjuice_rs::agent::tests] Gathering finished
[INFO] [stderr] [2023-04-30T04:08:06.449372Z DEBUG libjuice_rs::log] agent.c:662: Leaving agent thread
[INFO] [stderr] [2023-04-30T04:08:06.449388Z INFO  libjuice_rs::log] agent.c:780: Changing state to disconnected
[INFO] [stderr] [2023-04-30T04:08:06.449395Z DEBUG libjuice_rs::agent::tests] State changed to: Disconnected
[INFO] [stdout] test agent::tests::gather ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.06s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/connectivity.rs (/opt/rustwide/target/debug/deps/connectivity-9b2c1c4cbc05d08a)
[INFO] [stdout] 
[INFO] [stdout] running 2 tests
[INFO] [stderr] [2023-04-30T04:08:06.452077Z INFO  libjuice_rs::log] agent.c:780: Changing state to connecting
[INFO] [stderr] [2023-04-30T04:08:06.452107Z INFO  connectivity] first changed state to: Connecting
[INFO] [stderr] [2023-04-30T04:08:06.452148Z INFO  libjuice_rs::log] agent.c:780: Changing state to connecting
[INFO] [stderr] [2023-04-30T04:08:06.452192Z INFO  connectivity] first changed state to: Connecting
[INFO] [stderr] [2023-04-30T04:08:06.452364Z INFO  libjuice_rs::log] agent.c:780: Changing state to connecting
[INFO] [stderr] [2023-04-30T04:08:06.452552Z INFO  connectivity] second changed state to: Connecting
[INFO] [stderr] [2023-04-30T04:08:06.452559Z WARN  libjuice_rs::log] addr.c:274: Address resolution failed for stun.l.google.com:19302
[INFO] [stderr] [2023-04-30T04:08:06.452595Z ERROR libjuice_rs::log] agent.c:615: STUN server address resolution failed
[INFO] [stderr] [2023-04-30T04:08:06.452613Z INFO  libjuice_rs::log] agent.c:2321: Candidate gathering done
[INFO] [stderr] [2023-04-30T04:08:06.452629Z INFO  connectivity] first agent finished gathering
[INFO] [stderr] [2023-04-30T04:08:06.452644Z WARN  libjuice_rs::log] addr.c:274: Address resolution failed for stun.l.google.com:19302
[INFO] [stderr] [2023-04-30T04:08:06.452716Z ERROR libjuice_rs::log] agent.c:615: STUN server address resolution failed
[INFO] [stderr] [2023-04-30T04:08:06.452743Z INFO  libjuice_rs::log] agent.c:2321: Candidate gathering done
[INFO] [stderr] [2023-04-30T04:08:06.452764Z INFO  connectivity] first agent finished gathering
[INFO] [stderr] [2023-04-30T04:08:06.452800Z WARN  libjuice_rs::log] addr.c:274: Address resolution failed for stun.l.google.com:19302
[INFO] [stderr] [2023-04-30T04:08:06.452827Z ERROR libjuice_rs::log] agent.c:615: STUN server address resolution failed
[INFO] [stderr] [2023-04-30T04:08:06.452837Z INFO  libjuice_rs::log] agent.c:2321: Candidate gathering done
[INFO] [stderr] [2023-04-30T04:08:06.452848Z INFO  connectivity] second agent finished gathering
[INFO] [stderr] [2023-04-30T04:08:06.452943Z INFO  libjuice_rs::log] agent.c:780: Changing state to connecting
[INFO] [stderr] [2023-04-30T04:08:06.452977Z INFO  connectivity] second changed state to: Connecting
[INFO] [stderr] [2023-04-30T04:08:06.453103Z WARN  libjuice_rs::log] addr.c:274: Address resolution failed for stun.l.google.com:19302
[INFO] [stderr] [2023-04-30T04:08:06.453130Z ERROR libjuice_rs::log] agent.c:615: STUN server address resolution failed
[INFO] [stderr] [2023-04-30T04:08:06.453153Z INFO  libjuice_rs::log] agent.c:2321: Candidate gathering done
[INFO] [stderr] [2023-04-30T04:08:06.453161Z INFO  connectivity] second agent finished gathering
[INFO] [stderr] [2023-04-30T04:08:06.453201Z DEBUG libjuice_rs::log] agent.c:806: STUN entry 0: Sending request to 127.0.0.1:57461 (5 retransmissions left)
[INFO] [stderr] [2023-04-30T04:08:06.453226Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.453331Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:49817
[INFO] [stderr] [2023-04-30T04:08:06.453402Z DEBUG libjuice_rs::log] agent.c:2151: Obtained a new remote reflexive candidate, priority=1853882367
[INFO] [stderr] [2023-04-30T04:08:06.453427Z DEBUG libjuice_rs::log] agent.c:2410: STUN entry 0 pair matching incoming address
[INFO] [stderr] [2023-04-30T04:08:06.453438Z DEBUG libjuice_rs::log] agent.c:1248: Received STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.453457Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding response
[INFO] [stderr] [2023-04-30T04:08:06.453532Z DEBUG libjuice_rs::log] agent.c:806: STUN entry 0: Sending request to 127.0.0.1:49817 (5 retransmissions left)
[INFO] [stderr] [2023-04-30T04:08:06.453569Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.453585Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:57461
[INFO] [stderr] [2023-04-30T04:08:06.453633Z DEBUG libjuice_rs::log] agent.c:2151: Obtained a new remote reflexive candidate, priority=0
[INFO] [stderr] [2023-04-30T04:08:06.453648Z DEBUG libjuice_rs::log] agent.c:1329: Received STUN Binding success response from peer
[INFO] [stderr] [2023-04-30T04:08:06.453665Z DEBUG libjuice_rs::log] agent.c:2115: Gathered reflexive candidate: a=candidate:1 1 UDP 1853882367 127.0.0.1 49817 typ prflx
[INFO] [stderr] [2023-04-30T04:08:06.453687Z DEBUG libjuice_rs::log] agent.c:1381: Candidate pair check succeeded
[INFO] [stderr] [2023-04-30T04:08:06.453702Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:57461
[INFO] [stderr] [2023-04-30T04:08:06.453744Z DEBUG libjuice_rs::log] agent.c:2410: STUN entry 0 pair matching incoming address
[INFO] [stderr] [2023-04-30T04:08:06.453761Z DEBUG libjuice_rs::log] agent.c:1248: Received STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.453770Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding response
[INFO] [stderr] [2023-04-30T04:08:06.453826Z DEBUG libjuice_rs::log] agent.c:806: STUN entry 1: Sending request to 127.0.0.1:57461 (5 retransmissions left)
[INFO] [stderr] [2023-04-30T04:08:06.453842Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.453868Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:49817
[INFO] [stderr] [2023-04-30T04:08:06.453906Z DEBUG libjuice_rs::log] agent.c:946: New selected pair
[INFO] [stderr] [2023-04-30T04:08:06.453923Z INFO  libjuice_rs::log] agent.c:780: Changing state to connected
[INFO] [stderr] [2023-04-30T04:08:06.453945Z INFO  connectivity] second changed state to: Connected
[INFO] [stderr] [2023-04-30T04:08:06.453952Z DEBUG libjuice_rs::log] agent.c:1329: Received STUN Binding success response from peer
[INFO] [stderr] [2023-04-30T04:08:06.453969Z DEBUG libjuice_rs::log] agent.c:2115: Gathered reflexive candidate: a=candidate:2 1 UDP 1853882111 127.0.0.1 57461 typ prflx
[INFO] [stderr] [2023-04-30T04:08:06.453989Z DEBUG libjuice_rs::log] agent.c:1381: Candidate pair check succeeded
[INFO] [stderr] [2023-04-30T04:08:06.454002Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:49817
[INFO] [stderr] [2023-04-30T04:08:06.454035Z DEBUG libjuice_rs::log] agent.c:2410: STUN entry 0 pair matching incoming address
[INFO] [stderr] [2023-04-30T04:08:06.454058Z DEBUG libjuice_rs::log] agent.c:1248: Received STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.454068Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding response
[INFO] [stderr] [2023-04-30T04:08:06.454140Z DEBUG libjuice_rs::log] agent.c:946: New selected pair
[INFO] [stderr] [2023-04-30T04:08:06.454163Z INFO  libjuice_rs::log] agent.c:780: Changing state to connected
[INFO] [stderr] [2023-04-30T04:08:06.454182Z INFO  connectivity] first changed state to: Connected
[INFO] [stderr] [2023-04-30T04:08:06.454190Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:57461
[INFO] [stderr] [2023-04-30T04:08:06.454219Z DEBUG libjuice_rs::log] agent.c:1018: Requesting pair nomination (controlling)
[INFO] [stderr] [2023-04-30T04:08:06.454249Z DEBUG libjuice_rs::log] agent.c:806: STUN entry 0: Sending request to 127.0.0.1:49817 (5 retransmissions left)
[INFO] [stderr] [2023-04-30T04:08:06.454281Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.454333Z DEBUG libjuice_rs::log] agent.c:1329: Received STUN Binding success response from peer
[INFO] [stderr] [2023-04-30T04:08:06.454351Z DEBUG libjuice_rs::log] agent.c:1381: Candidate pair check succeeded
[INFO] [stderr] [2023-04-30T04:08:06.454361Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:57461
[INFO] [stderr] [2023-04-30T04:08:06.454451Z DEBUG libjuice_rs::log] agent.c:2410: STUN entry 0 pair matching incoming address
[INFO] [stderr] [2023-04-30T04:08:06.454467Z DEBUG libjuice_rs::log] agent.c:1248: Received STUN Binding request
[INFO] [stderr] [2023-04-30T04:08:06.454476Z DEBUG libjuice_rs::log] agent.c:1312: Got a nominated pair (controlled)
[INFO] [stderr] [2023-04-30T04:08:06.454484Z DEBUG libjuice_rs::log] agent.c:1470: Sending STUN Binding response
[INFO] [stderr] [2023-04-30T04:08:06.454530Z INFO  libjuice_rs::log] agent.c:780: Changing state to completed
[INFO] [stderr] [2023-04-30T04:08:06.454553Z INFO  connectivity] second changed state to: Completed
[INFO] [stderr] [2023-04-30T04:08:06.454561Z DEBUG libjuice_rs::log] agent.c:706: Received STUN datagram from 127.0.0.1:49817
[INFO] [stderr] [2023-04-30T04:08:06.454625Z DEBUG libjuice_rs::log] agent.c:1329: Received STUN Binding success response from peer
[INFO] [stderr] [2023-04-30T04:08:06.454646Z DEBUG libjuice_rs::log] agent.c:1393: Got a nominated pair (controlling)
[INFO] [stderr] [2023-04-30T04:08:06.454657Z INFO  libjuice_rs::log] agent.c:780: Changing state to completed
[INFO] [stderr] [2023-04-30T04:08:06.454666Z INFO  connectivity] first changed state to: Completed
[INFO] [stderr] [2023-04-30T04:08:08.453491Z DEBUG libjuice_rs::log] agent.c:725: Received non-STUN datagram from 127.0.0.1:57461
[INFO] [stderr] [2023-04-30T04:08:08.453521Z DEBUG libjuice_rs::log] agent.c:2377: STUN selected entry matching incoming address
[INFO] [stderr] [2023-04-30T04:08:08.453527Z DEBUG libjuice_rs::log] agent.c:735: Received application datagram
[INFO] [stderr] [2023-04-30T04:08:08.453534Z DEBUG connectivity] second received [104, 101, 108, 108, 111]
[INFO] [stderr] [2023-04-30T04:08:08.453660Z DEBUG libjuice_rs::log] agent.c:725: Received non-STUN datagram from 127.0.0.1:49817
[INFO] [stderr] [2023-04-30T04:08:08.453699Z DEBUG libjuice_rs::log] agent.c:2377: STUN selected entry matching incoming address
[INFO] [stderr] [2023-04-30T04:08:08.453713Z DEBUG libjuice_rs::log] agent.c:735: Received application datagram
[INFO] [stderr] [2023-04-30T04:08:08.453723Z DEBUG connectivity] first received [119, 111, 114, 108, 100]
[INFO] [stderr] [2023-04-30T04:08:08.453871Z DEBUG libjuice_rs::log] agent.c:662: Leaving agent thread
[INFO] [stderr] [2023-04-30T04:08:08.453896Z INFO  libjuice_rs::log] agent.c:780: Changing state to disconnected
[INFO] [stderr] [2023-04-30T04:08:08.453908Z INFO  connectivity] second changed state to: Disconnected
[INFO] [stderr] [2023-04-30T04:08:08.454055Z DEBUG libjuice_rs::log] agent.c:662: Leaving agent thread
[INFO] [stderr] [2023-04-30T04:08:08.454082Z INFO  libjuice_rs::log] agent.c:780: Changing state to disconnected
[INFO] [stderr] [2023-04-30T04:08:08.454094Z INFO  connectivity] first changed state to: Disconnected
[INFO] [stdout] test connectivity_trickle ... ok
[INFO] [stderr] [2023-04-30T04:08:08.466774Z DEBUG libjuice_rs::log] agent.c:662: Leaving agent thread
[INFO] [stderr] [2023-04-30T04:08:08.466798Z INFO  libjuice_rs::log] agent.c:780: Changing state to disconnected
[INFO] [stderr] [2023-04-30T04:08:08.466806Z INFO  connectivity] second changed state to: Disconnected
[INFO] [stderr] [2023-04-30T04:08:08.466940Z DEBUG libjuice_rs::log] agent.c:662: Leaving agent thread
[INFO] [stderr] [2023-04-30T04:08:08.466963Z INFO  libjuice_rs::log] agent.c:780: Changing state to disconnected
[INFO] [stderr] [2023-04-30T04:08:08.466972Z INFO  connectivity] first changed state to: Disconnected
[INFO] [stdout] test connectivity_no_trickle ... FAILED
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- connectivity_no_trickle stdout ----
[INFO] [stdout] [2023-04-30T04:08:06.451739Z DEBUG libjuice_rs::log] ice.c:152: Created local description: ufrag="5hkd", pwd="Pzlka8BkZe8yA99gd8NPT5"
[INFO] [stdout] [2023-04-30T04:08:06.451788Z DEBUG libjuice_rs::log] ice.c:152: Created local description: ufrag="7pYp", pwd="0uu+QPXKAvQyGW9+asmG3n"
[INFO] [stdout] [2023-04-30T04:08:06.451920Z INFO  libjuice_rs::log] agent.c:780: Changing state to gathering
[INFO] [stdout] [2023-04-30T04:08:06.451942Z INFO  connectivity] first changed state to: Gathering
[INFO] [stdout] [2023-04-30T04:08:06.451988Z WARN  libjuice_rs::log] agent.c:232: No local host candidates gathered
[INFO] [stdout] [2023-04-30T04:08:06.451994Z DEBUG libjuice_rs::log] agent.c:273: Assuming controlling mode
[INFO] [stdout] [2023-04-30T04:08:06.452198Z DEBUG libjuice_rs::log] udp.c:159: UDP socket bound to any:5007
[INFO] [stdout] [2023-04-30T04:08:06.452212Z INFO  libjuice_rs::log] agent.c:780: Changing state to gathering
[INFO] [stdout] [2023-04-30T04:08:06.452218Z INFO  connectivity] second changed state to: Gathering
[INFO] [stdout] [2023-04-30T04:08:06.452266Z WARN  libjuice_rs::log] agent.c:232: No local host candidates gathered
[INFO] [stdout] [2023-04-30T04:08:06.452272Z DEBUG libjuice_rs::log] agent.c:273: Assuming controlling mode
[INFO] [stdout] [2023-04-30T04:08:06.452986Z DEBUG libjuice_rs::log] ice.c:128: Parsed remote description: ufrag="5hkd", pwd="Pzlka8BkZe8yA99gd8NPT5", candidates=0
[INFO] [stdout] [2023-04-30T04:08:06.453004Z DEBUG libjuice_rs::log] agent.c:326: Unfreezing 0 existing candidate pairs
[INFO] [stdout] [2023-04-30T04:08:06.453011Z DEBUG libjuice_rs::log] agent.c:330: Adding 0 candidates from remote description
[INFO] [stdout] [2023-04-30T04:08:06.453060Z DEBUG libjuice_rs::log] ice.c:128: Parsed remote description: ufrag="7pYp", pwd="0uu+QPXKAvQyGW9+asmG3n", candidates=0
[INFO] [stdout] [2023-04-30T04:08:06.453070Z DEBUG libjuice_rs::log] agent.c:326: Unfreezing 0 existing candidate pairs
[INFO] [stdout] [2023-04-30T04:08:06.453079Z DEBUG libjuice_rs::log] agent.c:330: Adding 0 candidates from remote description
[INFO] [stdout] thread 'connectivity_no_trickle' panicked at 'assertion failed: `(left == right)`
[INFO] [stdout]   left: `Connecting`,
[INFO] [stdout]  right: `Completed`', tests/connectivity.rs:65:5
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x55d524abd47a - std::backtrace_rs::backtrace::libunwind::trace::ha9053a9a07ca49cb
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
[INFO] [stdout]    1:     0x55d524abd47a - std::backtrace_rs::backtrace::trace_unsynchronized::h9c2852a457ad564e
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
[INFO] [stdout]    2:     0x55d524abd47a - std::sys_common::backtrace::_print_fmt::h457936fbfaa0070f
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys_common/backtrace.rs:65:5
[INFO] [stdout]    3:     0x55d524abd47a - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h5779d7bf7f70cb0c
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys_common/backtrace.rs:44:22
[INFO] [stdout]    4:     0x55d524ae2c1e - core::fmt::write::h5a4baaff1bcd3eb5
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/fmt/mod.rs:1232:17
[INFO] [stdout]    5:     0x55d524aba605 - std::io::Write::write_fmt::h478f79c628ef31d1
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/io/mod.rs:1684:15
[INFO] [stdout]    6:     0x55d524abd245 - std::sys_common::backtrace::_print::h5fcdc36060f177e8
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys_common/backtrace.rs:47:5
[INFO] [stdout]    7:     0x55d524abd245 - std::sys_common::backtrace::print::h54ca9458b876c8bf
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys_common/backtrace.rs:34:9
[INFO] [stdout]    8:     0x55d524abf00f - std::panicking::default_hook::{{closure}}::hbe471161c7664ed6
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:271:22
[INFO] [stdout]    9:     0x55d524abeccf - std::panicking::default_hook::ha3500da57aa4ac4f
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:287:9
[INFO] [stdout]   10:     0x55d524a69877 - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::hdf1b89dd137ece34
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/alloc/src/boxed.rs:2001:9
[INFO] [stdout]   11:     0x55d524a69877 - test::test_main::{{closure}}::h9081a79f20e75698
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/test/src/lib.rs:135:21
[INFO] [stdout]   12:     0x55d524abf73d - <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call::h6507bddc3eebb4a5
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/alloc/src/boxed.rs:2001:9
[INFO] [stdout]   13:     0x55d524abf73d - std::panicking::rust_panic_with_hook::h50c09d000dc561d2
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:696:13
[INFO] [stdout]   14:     0x55d524abf4b9 - std::panicking::begin_panic_handler::{{closure}}::h9e2b2176e00e0d9c
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:583:13
[INFO] [stdout]   15:     0x55d524abd8e6 - std::sys_common::backtrace::__rust_end_short_backtrace::h5739b8e512c09d02
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys_common/backtrace.rs:150:18
[INFO] [stdout]   16:     0x55d524abf1c2 - rust_begin_unwind
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:579:5
[INFO] [stdout]   17:     0x55d5248213f3 - core::panicking::panic_fmt::hf33a1475b4dc5c3e
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/panicking.rs:64:14
[INFO] [stdout]   18:     0x55d52482172f - core::panicking::assert_failed_inner::haf9816227b20b6f2
[INFO] [stdout]   19:     0x55d52484207a - core::panicking::assert_failed::h864932771343ac6f
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/panicking.rs:211:5
[INFO] [stdout]   20:     0x55d524835212 - connectivity::connectivity_no_trickle::h130a03c88c6301ab
[INFO] [stdout]                                at /opt/rustwide/workdir/tests/connectivity.rs:65:5
[INFO] [stdout]   21:     0x55d5248349b7 - connectivity::connectivity_no_trickle::{{closure}}::h8eb1d5ed1516e55d
[INFO] [stdout]                                at /opt/rustwide/workdir/tests/connectivity.rs:11:30
[INFO] [stdout]   22:     0x55d524832235 - core::ops::function::FnOnce::call_once::h8d82213e399fb207
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   23:     0x55d524a6ec5f - core::ops::function::FnOnce::call_once::h7d969581be7d0075
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x55d524a6ec5f - test::__rust_begin_short_backtrace::hca25a52684e56655
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/test/src/lib.rs:656:18
[INFO] [stdout]   25:     0x55d524a4027c - test::run_test::{{closure}}::ha8ac744c4af1a4bb
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/test/src/lib.rs:647:30
[INFO] [stdout]   26:     0x55d524a4027c - core::ops::function::FnOnce::call_once{{vtable.shim}}::h7b411a9ed45bdecf
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   27:     0x55d524a6dc26 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::hd05328869a8ed200
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/alloc/src/boxed.rs:1987:9
[INFO] [stdout]   28:     0x55d524a6dc26 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h0c601ce20bd5b2be
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/panic/unwind_safe.rs:271:9
[INFO] [stdout]   29:     0x55d524a6dc26 - std::panicking::try::do_call::ha4be5c164fe30854
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:487:40
[INFO] [stdout]   30:     0x55d524a6dc26 - std::panicking::try::h604546f3609af05f
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:451:19
[INFO] [stdout]   31:     0x55d524a6dc26 - std::panic::catch_unwind::h5bfa8afe44c9c2f9
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panic.rs:140:14
[INFO] [stdout]   32:     0x55d524a6dc26 - test::run_test_in_process::hd50dee55dd63e6aa
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/test/src/lib.rs:679:27
[INFO] [stdout]   33:     0x55d524a6dc26 - test::run_test::run_test_inner::{{closure}}::h4aa0f433aa85cea8
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/test/src/lib.rs:573:39
[INFO] [stdout]   34:     0x55d524a3a8f1 - test::run_test::run_test_inner::{{closure}}::had56431adf24b4d6
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/test/src/lib.rs:600:37
[INFO] [stdout]   35:     0x55d524a3a8f1 - std::sys_common::backtrace::__rust_begin_short_backtrace::ha8d9890e0c73bf13
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys_common/backtrace.rs:134:18
[INFO] [stdout]   36:     0x55d524a4030b - std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}::h251832bcb4a95327
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/thread/mod.rs:560:17
[INFO] [stdout]   37:     0x55d524a4030b - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h8fdff598fa414831
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/panic/unwind_safe.rs:271:9
[INFO] [stdout]   38:     0x55d524a4030b - std::panicking::try::do_call::h455dd2f7764a950f
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:487:40
[INFO] [stdout]   39:     0x55d524a4030b - std::panicking::try::had6f23b7b73ae72a
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panicking.rs:451:19
[INFO] [stdout]   40:     0x55d524a4030b - std::panic::catch_unwind::ha6a5ca3915b4dad0
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/panic.rs:140:14
[INFO] [stdout]   41:     0x55d524a4030b - std::thread::Builder::spawn_unchecked_::{{closure}}::h883b72ef75da6231
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/thread/mod.rs:559:30
[INFO] [stdout]   42:     0x55d524a4030b - core::ops::function::FnOnce::call_once{{vtable.shim}}::hb7dff73dc8bd2ccb
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   43:     0x55d524ac3aa3 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h39990b24eedef2ab
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/alloc/src/boxed.rs:1987:9
[INFO] [stdout]   44:     0x55d524ac3aa3 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h01a027258444143b
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/alloc/src/boxed.rs:1987:9
[INFO] [stdout]   45:     0x55d524ac3aa3 - std::sys::unix::thread::Thread::new::thread_start::ha4f1cdd9c25884ba
[INFO] [stdout]                                at /rustc/84c898d65adf2f39a5a98507f1fe0ce10a2b8dbc/library/std/src/sys/unix/thread.rs:108:17
[INFO] [stdout]   46:     0x7feb7a0f5b43 - <unknown>
[INFO] [stdout]   47:     0x7feb7a186bb4 - __clone
[INFO] [stdout]   48:                0x0 - <unknown>
[INFO] [stdout] [2023-04-30T04:08:08.466707Z DEBUG libjuice_rs::log] agent.c:189: Waiting for agent thread
[INFO] [stdout] [2023-04-30T04:08:08.466854Z DEBUG libjuice_rs::log] agent.c:151: Destroying agent
[INFO] [stdout] [2023-04-30T04:08:08.466873Z DEBUG libjuice_rs::log] agent.c:189: Waiting for agent thread
[INFO] [stdout] [2023-04-30T04:08:08.467023Z DEBUG libjuice_rs::log] agent.c:151: Destroying agent
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     connectivity_no_trickle
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 1 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.02s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--test connectivity`
[INFO] running `Command { std: "docker" "inspect" "2e20000956092d38654cb4b21e47b57961ed12096293ecd357aeab77184edc90", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "2e20000956092d38654cb4b21e47b57961ed12096293ecd357aeab77184edc90", kill_on_drop: false }`
[INFO] [stdout] 2e20000956092d38654cb4b21e47b57961ed12096293ecd357aeab77184edc90
