[INFO] fetching crate tfmt 0.4.0...
[INFO] testing tfmt-0.4.0 against master#caccb4d0368bd918ef6668af8e13834d07040417 for pr-146098-1
[INFO] extracting crate tfmt 0.4.0 into /workspace/builds/worker-1-tc1/source
[INFO] started tweaking crates.io crate tfmt 0.4.0
[INFO] finished tweaking crates.io crate tfmt 0.4.0
[INFO] tweaked toml for crates.io crate tfmt 0.4.0 written to /workspace/builds/worker-1-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate tfmt 0.4.0 on toolchain caccb4d0368bd918ef6668af8e13834d07040417
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "generate-lockfile" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]     Blocking waiting for file lock on package cache
[INFO] [stderr]      Locking 9 packages to latest compatible versions
[INFO] [stderr]       Adding heapless v0.8.0 (available: v0.9.1)
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded tfmt-macros v0.4.0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 8f0efea194e33ecfbc0881a59d301c334090e4037de4ee2aac27aa12a6dd6b42
[INFO] running `Command { std: "docker" "start" "-a" "8f0efea194e33ecfbc0881a59d301c334090e4037de4ee2aac27aa12a6dd6b42", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "8f0efea194e33ecfbc0881a59d301c334090e4037de4ee2aac27aa12a6dd6b42", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "8f0efea194e33ecfbc0881a59d301c334090e4037de4ee2aac27aa12a6dd6b42", kill_on_drop: false }`
[INFO] [stdout] 8f0efea194e33ecfbc0881a59d301c334090e4037de4ee2aac27aa12a6dd6b42
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 15a39cd8de76c9cdab4d14f540fda0eee4b4bfc208944b6798f0fd4939f991c0
[INFO] running `Command { std: "docker" "start" "-a" "15a39cd8de76c9cdab4d14f540fda0eee4b4bfc208944b6798f0fd4939f991c0", kill_on_drop: false }`
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling heapless v0.8.0
[INFO] [stderr]    Compiling hash32 v0.3.1
[INFO] [stderr]    Compiling tfmt-macros v0.4.0
[INFO] [stderr]    Compiling tfmt v0.4.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 5.97s
[INFO] running `Command { std: "docker" "inspect" "15a39cd8de76c9cdab4d14f540fda0eee4b4bfc208944b6798f0fd4939f991c0", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "15a39cd8de76c9cdab4d14f540fda0eee4b4bfc208944b6798f0fd4939f991c0", kill_on_drop: false }`
[INFO] [stdout] 15a39cd8de76c9cdab4d14f540fda0eee4b4bfc208944b6798f0fd4939f991c0
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] ab406d273f5f540d06b003df221b60079e96062b1b6478802467cd5242b731fa
[INFO] running `Command { std: "docker" "start" "-a" "ab406d273f5f540d06b003df221b60079e96062b1b6478802467cd5242b731fa", kill_on_drop: false }`
[INFO] [stderr]    Compiling tfmt v0.4.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 2.48s
[INFO] running `Command { std: "docker" "inspect" "ab406d273f5f540d06b003df221b60079e96062b1b6478802467cd5242b731fa", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ab406d273f5f540d06b003df221b60079e96062b1b6478802467cd5242b731fa", kill_on_drop: false }`
[INFO] [stdout] ab406d273f5f540d06b003df221b60079e96062b1b6478802467cd5242b731fa
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:e90291280db7d1fac5b66fc6dad9f9662629e7365a55743daf9bdf73ebc4ea79" "/opt/rustwide/cargo-home/bin/cargo" "+caccb4d0368bd918ef6668af8e13834d07040417" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 1553b25616334a25bd4770d5217a26cd7db37288176ee52b7ce8b40d1c121bc1
[INFO] running `Command { std: "docker" "start" "-a" "1553b25616334a25bd4770d5217a26cd7db37288176ee52b7ce8b40d1c121bc1", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.05s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/tfmt-aed63c7d2e29acbf)
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/core.rs (/opt/rustwide/target/debug/deps/core-3ffb8d68a317f1b1)
[INFO] [stdout] 
[INFO] [stdout] running 5 tests
[INFO] [stdout] test fmt ... ok
[INFO] [stdout] test aligned ... ok
[INFO] [stdout] test uwriteln ... ok
[INFO] [stdout] test result ... ok
[INFO] [stdout] test option ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 5 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/debug.rs (/opt/rustwide/target/debug/deps/debug-90b9467b6ba0fd58)
[INFO] [stdout] 
[INFO] [stdout] running 6 tests
[INFO] [stdout] test generic ... ok
[INFO] [stdout] test slice ... ok
[INFO] [stdout] test enum_ ... ok
[INFO] [stdout] test struct_ ... ok
[INFO] [stdout] test tuples ... ok
[INFO] [stdout] test formatter_uwrite ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/float.rs (/opt/rustwide/target/debug/deps/float-bc81f3cb1482c1ca)
[INFO] [stdout] 
[INFO] [stdout] running 2 tests
[INFO] [stdout] test f64 ... ok
[INFO] [stdout] test f32 ... ok
[INFO] [stderr]      Running tests/int.rs (/opt/rustwide/target/debug/deps/int-a05e840848e04e33)
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 7 tests
[INFO] [stdout] test ixx_hex ... ok
[INFO] [stdout] test uxx_aligned ... ok
[INFO] [stdout] test uxx_min_max ... ok
[INFO] [stdout] test ixx_min_max ... ok
[INFO] [stdout] test uxx_hex ... ok
[INFO] [stdout] test ixx_aligned ... ok
[INFO] [stdout] test ptr ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 7 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.02s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests tfmt
[INFO] [stdout] 
[INFO] [stdout] running 14 tests
[INFO] [stdout] test src/impls/int.rs - impls::int::Convert<CAP>::u32_pad (line 315) ... ok
[INFO] [stdout] test src/impls/float.rs - impls::float::Convert<CAP>::from_f32 (line 79) ... ok
[INFO] [stdout] test src/impls/int.rs - impls::int::Convert<CAP>::i32_pad (line 362) ... ok
[INFO] [stdout] test src/impls/int.rs - impls::int::Convert<CAP>::from_i32 (line 347) ... ok
[INFO] [stdout] test src/impls/float.rs - impls::float::Convert<CAP>::from_f64 (line 97) ... ok
[INFO] [stdout] test src/impls/float.rs - impls::float::Convert<CAP>::f32_pad (line 118) ... ok
[INFO] [stdout] test src/impls/int.rs - impls::int::Convert<CAP>::from_u32 (line 300) ... ok
[INFO] [stdout] test src/impls/float.rs - impls::float::Convert<CAP>::f64_pad (line 140) ... ok
[INFO] [stdout] test src/lib.rs - (line 122) ... ok
[INFO] [stdout] test src/lib.rs - (line 76) ... ok
[INFO] [stdout] test src/lib.rs - uDisplayPadded (line 299) ... ok
[INFO] [stdout] test src/lib.rs - (line 40) ... ok
[INFO] [stdout] test src/lib.rs - uDisplayFormatted (line 347) ... ok
[INFO] [stdout] test src/lib.rs - uformat (line 56) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 14 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.83s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "1553b25616334a25bd4770d5217a26cd7db37288176ee52b7ce8b40d1c121bc1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "1553b25616334a25bd4770d5217a26cd7db37288176ee52b7ce8b40d1c121bc1", kill_on_drop: false }`
[INFO] [stdout] 1553b25616334a25bd4770d5217a26cd7db37288176ee52b7ce8b40d1c121bc1