[INFO] fetching crate log-once 0.3.1...
[INFO] building log-once-0.3.1 against try#d5c88c22807925c189328ef9d923c5d2b11a95b8+rustflags=-Zprofile-closures for pr-87066-3
[INFO] extracting crate log-once 0.3.1 into /workspace/builds/worker-116/source
[INFO] validating manifest of crates.io crate log-once 0.3.1 on toolchain d5c88c22807925c189328ef9d923c5d2b11a95b8
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+d5c88c22807925c189328ef9d923c5d2b11a95b8" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] started tweaking crates.io crate log-once 0.3.1
[INFO] finished tweaking crates.io crate log-once 0.3.1
[INFO] tweaked toml for crates.io crate log-once 0.3.1 written to /workspace/builds/worker-116/source/Cargo.toml
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+d5c88c22807925c189328ef9d923c5d2b11a95b8" "generate-lockfile" "--manifest-path" "Cargo.toml" "-Zno-index-update", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+d5c88c22807925c189328ef9d923c5d2b11a95b8" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-116/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-116/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:34b6a614d2c27851fe6cbf88fbd1137609cefab8b10d0615aaeb6fd47975d74e" "/opt/rustwide/cargo-home/bin/cargo" "+d5c88c22807925c189328ef9d923c5d2b11a95b8" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] c0e7429421d3d6731f5b1a9df9e89da58f0e0c7008896f5e923f8df45fe7ec51
[INFO] running `Command { std: "docker" "start" "-a" "c0e7429421d3d6731f5b1a9df9e89da58f0e0c7008896f5e923f8df45fe7ec51", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "c0e7429421d3d6731f5b1a9df9e89da58f0e0c7008896f5e923f8df45fe7ec51", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c0e7429421d3d6731f5b1a9df9e89da58f0e0c7008896f5e923f8df45fe7ec51", kill_on_drop: false }`
[INFO] [stdout] c0e7429421d3d6731f5b1a9df9e89da58f0e0c7008896f5e923f8df45fe7ec51
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-116/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-116/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 -Zprofile-closures" "-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:34b6a614d2c27851fe6cbf88fbd1137609cefab8b10d0615aaeb6fd47975d74e" "/opt/rustwide/cargo-home/bin/cargo" "+d5c88c22807925c189328ef9d923c5d2b11a95b8" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 2d4d0062cf2f2b061beac5236983de3e8bea990a6826a63110616b136ae08ffe
[INFO] running `Command { std: "docker" "start" "-a" "2d4d0062cf2f2b061beac5236983de3e8bea990a6826a63110616b136ae08ffe", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr] SG_CR_Eslkdjf: log, (c7bdd38427ba511c, c97d9f7503e6fe32), 8, 16
[INFO] [stderr] SG_CR_Eslkdjf: log, (2feb8e5f59057887, 55131227c3c2bccc), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (1c0f48c2e492e38e, 5d4b6f033cb5d42d), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (4fdb2e87a1b00b0, 1ea7bb48c7f0f882), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (6f92f55d94b79a81, b018c467009bb160), 8, 16
[INFO] [stderr] SG_CR_Eslkdjf: log, (dcefd6860304af7e, 53955f9e4aa5d6b3), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (80ee3420028a0295, 3897ba7a5f155940), 8, 16
[INFO] [stderr]    Compiling log-once v0.3.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.96s
[INFO] running `Command { std: "docker" "inspect" "2d4d0062cf2f2b061beac5236983de3e8bea990a6826a63110616b136ae08ffe", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "2d4d0062cf2f2b061beac5236983de3e8bea990a6826a63110616b136ae08ffe", kill_on_drop: false }`
[INFO] [stdout] 2d4d0062cf2f2b061beac5236983de3e8bea990a6826a63110616b136ae08ffe
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-116/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-116/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 -Zprofile-closures" "-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:34b6a614d2c27851fe6cbf88fbd1137609cefab8b10d0615aaeb6fd47975d74e" "/opt/rustwide/cargo-home/bin/cargo" "+d5c88c22807925c189328ef9d923c5d2b11a95b8" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 76f28ac19931727c24beee58fc074cc1f432e59beb39ff1faa5403f46ae6fc65
[INFO] running `Command { std: "docker" "start" "-a" "76f28ac19931727c24beee58fc074cc1f432e59beb39ff1faa5403f46ae6fc65", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr] SG_CR_Eslkdjf: log, (c7bdd38427ba511c, c97d9f7503e6fe32), 8, 16
[INFO] [stderr] SG_CR_Eslkdjf: log, (2feb8e5f59057887, 55131227c3c2bccc), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (1c0f48c2e492e38e, 5d4b6f033cb5d42d), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (4fdb2e87a1b00b0, 1ea7bb48c7f0f882), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (6f92f55d94b79a81, b018c467009bb160), 8, 16
[INFO] [stderr] SG_CR_Eslkdjf: log, (dcefd6860304af7e, 53955f9e4aa5d6b3), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log, (80ee3420028a0295, 3897ba7a5f155940), 8, 16
[INFO] [stderr]    Compiling log-once v0.3.1 (/opt/rustwide/workdir)
[INFO] [stderr] SG_CR_Eslkdjf: log_once, (41cda2129eddac30, 52d8ab1cdfc88c19), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log_once, (70a4a0ef34f14f82, e5f1e277f86a3e70), 8, 8
[INFO] [stderr] SG_CR_Eslkdjf: log_once, (34f8229297d8ac50, 4349ecb789817e7), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: error, (62d18d04a2e97f95, 32e0ca13700a2990), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: log_once, (d4da39de42af29d0, ebb1cea48698f076), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: warn, (de31ddba47edf3e, 4bf44f845e97c29c), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: info, (5467add1551ef5bd, 3ec60cc6b73eb386), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: error, (90f1f98841c57ec, b6eb03c5cf1358ca), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: debug, (6343cd3107045e0f, 11817c523d9b008f), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: trace, (8ff6d1f409bd0133, 3174cdabddbc8cd9), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: warn, (7062e5c3c1694200, a1a4ee2e6e354f91), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: info, (95f2ca8c5f42f26b, e05b7c98b1680a7f), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: debug, (8584a6e946901d54, 776421fdc7a58ec2), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: trace, (e4c463c424518682, f01fecee72a25ec2), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: error, (642dc9e3272f3d4a, f1de8a88702eb098), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: warn, (232704f5333f27de, 6a3e89df2b393d23), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: info, (7b90726ffe4d5c8c, ae4daafe0e23e54c), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: error, (74eebc7d8d0042ec, 47e1df8146337f28), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: debug, (214d7d4d30cb5c1c, 7c9c613681bb7fde), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: error, (275bee030c89d56, 1d25657e058267f8), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: info, (135ac26d332b4638, eaf0816faab7b39b), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: warn, (28309a10de648868, d2a339e2b1548627), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: warn, (4d66585422d9e168, e992011f573adcb1), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: info, (dbca3b9e1dfa81f9, a5b883b4a7b0aba3), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: debug, (5eac05a4243f4cb2, 5ffac4d2e12fa90e), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: debug, (5fa2558fc86cff73, 12e09ba1cb6297db), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: trace, (11e374f12a08e4b7, 15c492fea7d21d32), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: trace, (b02a9e563ce04c00, 12ee59d1642fab99), 0, 0
[INFO] [stderr] SG_CR_Eslkdjf: trace, (b87d8652adfca946, a958ed8a26b2063e), 0, 0
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 1.16s
[INFO] running `Command { std: "docker" "inspect" "76f28ac19931727c24beee58fc074cc1f432e59beb39ff1faa5403f46ae6fc65", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "76f28ac19931727c24beee58fc074cc1f432e59beb39ff1faa5403f46ae6fc65", kill_on_drop: false }`
[INFO] [stdout] 76f28ac19931727c24beee58fc074cc1f432e59beb39ff1faa5403f46ae6fc65