[INFO] fetching crate wasm_safe_mutex 0.1.0...
[INFO] testing wasm_safe_mutex-0.1.0 against try#c2e32f1c9652b13ed99608599c1e855462f421f3 for pr-146098-8
[INFO] extracting crate wasm_safe_mutex 0.1.0 into /workspace/builds/worker-3-tc2/source
[INFO] started tweaking crates.io crate wasm_safe_mutex 0.1.0
[INFO] finished tweaking crates.io crate wasm_safe_mutex 0.1.0
[INFO] tweaked toml for crates.io crate wasm_safe_mutex 0.1.0 written to /workspace/builds/worker-3-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate wasm_safe_mutex 0.1.0 on toolchain c2e32f1c9652b13ed99608599c1e855462f421f3
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+c2e32f1c9652b13ed99608599c1e855462f421f3" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wasm_safe_mutex 0.1.0 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+c2e32f1c9652b13ed99608599c1e855462f421f3" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c2e32f1c9652b13ed99608599c1e855462f421f3" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 957b70e97c402919d26a533cc9533e2d4f8d86ba57ae4f704c5b6a5c3ddb19ca
[INFO] running `Command { std: "docker" "start" "-a" "957b70e97c402919d26a533cc9533e2d4f8d86ba57ae4f704c5b6a5c3ddb19ca", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "957b70e97c402919d26a533cc9533e2d4f8d86ba57ae4f704c5b6a5c3ddb19ca", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "957b70e97c402919d26a533cc9533e2d4f8d86ba57ae4f704c5b6a5c3ddb19ca", kill_on_drop: false }`
[INFO] [stdout] 957b70e97c402919d26a533cc9533e2d4f8d86ba57ae4f704c5b6a5c3ddb19ca
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=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:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c2e32f1c9652b13ed99608599c1e855462f421f3" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 4df7fed3959f10985db12463e73fe42f97d447f07f53661c97e0eab1b9f8ad26
[INFO] running `Command { std: "docker" "start" "-a" "4df7fed3959f10985db12463e73fe42f97d447f07f53661c97e0eab1b9f8ad26", kill_on_drop: false }`
[INFO] [stderr]    Compiling proc-macro2 v1.0.101
[INFO] [stderr]    Compiling thiserror v2.0.15
[INFO] [stderr]    Compiling logwise_proc v0.1.1
[INFO] [stderr]    Compiling logwise v0.2.4
[INFO] [stderr]    Compiling quote v1.0.40
[INFO] [stderr]    Compiling syn v2.0.106
[INFO] [stderr]    Compiling thiserror-impl v2.0.15
[INFO] [stderr]    Compiling continue v0.1.1
[INFO] [stderr]    Compiling wasm_safe_mutex v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 5.38s
[INFO] running `Command { std: "docker" "inspect" "4df7fed3959f10985db12463e73fe42f97d447f07f53661c97e0eab1b9f8ad26", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "4df7fed3959f10985db12463e73fe42f97d447f07f53661c97e0eab1b9f8ad26", kill_on_drop: false }`
[INFO] [stdout] 4df7fed3959f10985db12463e73fe42f97d447f07f53661c97e0eab1b9f8ad26
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=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:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c2e32f1c9652b13ed99608599c1e855462f421f3" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 5344bd888729082cd64a9e3cbffb888055bb8025d952bc40a0e6b2b4f9553477
[INFO] running `Command { std: "docker" "start" "-a" "5344bd888729082cd64a9e3cbffb888055bb8025d952bc40a0e6b2b4f9553477", kill_on_drop: false }`
[INFO] [stderr]    Compiling winnow v0.7.12
[INFO] [stderr]    Compiling logwise_proc v0.3.0
[INFO] [stderr]    Compiling priority v0.1.1
[INFO] [stderr]    Compiling indexmap v2.10.0
[INFO] [stderr]    Compiling syn v2.0.106
[INFO] [stderr]    Compiling logwise v0.3.0
[INFO] [stderr]    Compiling blocking_semaphore v0.1.0
[INFO] [stderr]    Compiling toml_edit v0.22.27
[INFO] [stderr]    Compiling thiserror-impl v2.0.15
[INFO] [stderr]    Compiling proc-macro-crate v3.3.0
[INFO] [stderr]    Compiling thiserror v2.0.15
[INFO] [stderr]    Compiling continue v0.1.1
[INFO] [stderr]    Compiling some_executor v0.6.0
[INFO] [stderr]    Compiling wasm_safe_mutex v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]    Compiling test_executors_proc v0.3.5
[INFO] [stderr]    Compiling test_executors v0.3.5
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 9.14s
[INFO] running `Command { std: "docker" "inspect" "5344bd888729082cd64a9e3cbffb888055bb8025d952bc40a0e6b2b4f9553477", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "5344bd888729082cd64a9e3cbffb888055bb8025d952bc40a0e6b2b4f9553477", kill_on_drop: false }`
[INFO] [stdout] 5344bd888729082cd64a9e3cbffb888055bb8025d952bc40a0e6b2b4f9553477
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=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:4848fb76d95f26979359cc7e45710b1dbc8f3acb7aeedee7c460d7702230f228" "/opt/rustwide/cargo-home/bin/cargo" "+c2e32f1c9652b13ed99608599c1e855462f421f3" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] c6db053dad745758d44a71c86ea0f12005e385e659bef82bbab94e4f047395d3
[INFO] running `Command { std: "docker" "start" "-a" "c6db053dad745758d44a71c86ea0f12005e385e659bef82bbab94e4f047395d3", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.09s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wasm_safe_mutex-826a89f6bf270cf3)
[INFO] [stdout] 
[INFO] [stderr]  0 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:104:9 [0ns] Semaphore implementation uses mutex
[INFO] [stdout] running 10 tests
[INFO] [stdout] test tests::test_guard_drop_releases_lock ... ok
[INFO] [stdout] test tests::test_mutex_lock_spin ... ok
[INFO] [stdout] test tests::test_mutex_try_lock_success ... ok
[INFO] [stdout] test tests::test_spinlock_basic ... ok
[INFO] [stdout] test tests::test_mutex_async_contention ... ok
[INFO] [stderr]  1 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:104:9 [17.849969ms] Semaphore implementation uses mutex
[INFO] [stderr]  3 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:104:9 [19.080529ms] Semaphore implementation uses mutex
[INFO] [stderr]  4 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:89:13 [19.258399ms] Semaphore implementation uses mutex
[INFO] [stderr]  4 PERWARN: END [19.291619ms] Semaphore implementation uses mutex [interval took 9.28µs] 
[INFO] [stderr] 4 PERFWARN: statistics[Semaphore implementation uses mutex: 9.28µs,]
[INFO] [stderr]  3 PERWARN: END [19.370199ms] Semaphore implementation uses mutex [interval took 258.19µs] 
[INFO] [stderr] 3 PERFWARN: statistics[Semaphore implementation uses mutex: 258.19µs,]
[INFO] [stderr]  5 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:89:13 [19.643469ms] Semaphore implementation uses mutex
[INFO] [stderr]  5 PERWARN: END [19.674239ms] Semaphore implementation uses mutex [interval took 10.39µs] 
[INFO] [stderr] 5 PERFWARN: statistics[Semaphore implementation uses mutex: 10.39µs,]
[INFO] [stdout] test tests::async_test_test_mutex_try_lock_contention ... ok
[INFO] [stderr]  1 PERWARN: END [20.538279ms] Semaphore implementation uses mutex [interval took 2.65003ms] 
[INFO] [stderr]  1 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:104:9 [20.587839ms] Semaphore implementation uses mutex
[INFO] [stderr]  6 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:89:13 [20.728359ms] Semaphore implementation uses mutex
[INFO] [stderr]  6 PERWARN: END [20.746259ms] Semaphore implementation uses mutex [interval took 3.59µs] 
[INFO] [stderr] 6 PERFWARN: statistics[Semaphore implementation uses mutex: 3.59µs,]
[INFO] [stderr]  1 PERWARN: END [20.804049ms] Semaphore implementation uses mutex [interval took 203.5µs] 
[INFO] [stderr]  1 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:104:9 [20.819789ms] Semaphore implementation uses mutex
[INFO] [stderr]  2 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:104:9 [21.677789ms] Semaphore implementation uses mutex
[INFO] [stdout] test tests::test_mutex_lock_async ... ok
[INFO] [stderr]  7 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:89:13 [26.733119ms] Semaphore implementation uses mutex
[INFO] [stderr]  7 PERWARN: END [26.780539ms] Semaphore implementation uses mutex [interval took 8.76µs] 
[INFO] [stderr] 7 PERFWARN: statistics[Semaphore implementation uses mutex: 8.76µs,]
[INFO] [stderr]  8 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:89:13 [29.294509ms] Semaphore implementation uses mutex
[INFO] [stderr]  8 PERWARN: END [29.346809ms] Semaphore implementation uses mutex [interval took 13.26µs] 
[INFO] [stderr] 8 PERFWARN: statistics[Semaphore implementation uses mutex: 13.26µs,]
[INFO] [stderr]  0 PERWARN: END [29.368229ms] Semaphore implementation uses mutex [interval took 29.341221ms] 
[INFO] [stdout] test tests::async_test_test_mutex_concurrent_increment ... ok
[INFO] [stderr]  9 PERFWARN: BEGIN /opt/rustwide/cargo-home/registry/src/index.crates.io-1949cf8c6b5b557f/blocking_semaphore-0.1.0/src/one.rs:89:13 [31.713599ms] Semaphore implementation uses mutex
[INFO] [stderr]  9 PERWARN: END [31.760028ms] Semaphore implementation uses mutex [interval took 9.509µs] 
[INFO] [stderr] 9 PERFWARN: statistics[Semaphore implementation uses mutex: 9.509µs,]
[INFO] [stderr]  2 PERWARN: END [31.831839ms] Semaphore implementation uses mutex [interval took 10.11886ms] 
[INFO] [stderr] 2 PERFWARN: statistics[Semaphore implementation uses mutex: 10.11886ms,]
[INFO] [stderr] 0 PERFWARN: statistics[Semaphore implementation uses mutex: 29.341219ms,]
[INFO] [stdout] test tests::async_test_test_mutex_lock_block ... ok
[INFO] [stderr]  1 PERWARN: END [57.541757ms] Semaphore implementation uses mutex [interval took 36.712047ms] 
[INFO] [stdout] test tests::async_test_test_spinlock_concurrent_access ... ok
[INFO] [stderr] 1 PERFWARN: statistics[Semaphore implementation uses mutex: 39.565578ms,]
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests wasm_safe_mutex
[INFO] [stdout] test result: ok. 10 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.06s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 37 tests
[INFO] [stdout] test src/lib.rs - Mutex (line 187) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::fmt (line 849) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_async (line 455) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::from (line 871) ... ok
[INFO] [stdout] test src/lib.rs - Mutex (line 205) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_sync (line 531) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_spin (line 325) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_async (line 437) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_block (line 369) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::new (line 235) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_async (line 723) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_spin (line 313) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::try_lock (line 260) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_mut_async (line 781) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::default (line 827) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_sync (line 544) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_sync (line 623) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_mut_async (line 763) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_mut_sync (line 657) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_mut_sync (line 672) ... ok
[INFO] [stdout] test src/lib.rs - NotAvailable (line 134) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock<T>::default (line 148) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock<T>::fmt (line 198) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_sync (line 607) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock (line 20) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock<T>::from (line 172) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock<T>::with_mut (line 73) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock<T>::new (line 43) ... ok
[INFO] [stdout] test src/spinlock.rs - spinlock::Spinlock<T>::with_mut (line 92) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::lock_block (line 382) ... ok
[INFO] [stdout] test src/guard.rs - guard::Guard (line 19) ... ok
[INFO] [stdout] test src/lib.rs - (line 57) ... ok
[INFO] [stdout] test src/lib.rs - (line 42) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::try_lock (line 277) ... ok
[INFO] [stdout] test src/lib.rs - Mutex<T>::with_async (line 707) ... ok
[INFO] [stdout] test src/lib.rs - (line 73) ... ok
[INFO] [stdout] test src/lib.rs - (line 92) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 37 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.13s
[INFO] [stdout] 
[INFO] [stdout] all doctests ran in 1.05s; merged doctests compilation took 0.92s
[INFO] running `Command { std: "docker" "inspect" "c6db053dad745758d44a71c86ea0f12005e385e659bef82bbab94e4f047395d3", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c6db053dad745758d44a71c86ea0f12005e385e659bef82bbab94e4f047395d3", kill_on_drop: false }`
[INFO] [stdout] c6db053dad745758d44a71c86ea0f12005e385e659bef82bbab94e4f047395d3