[INFO] fetching crate snaplog 0.4.0...
[INFO] testing snaplog-0.4.0 against master#562dee4820c458d823175268e41601d4c060588a for pr-154210-2
[INFO] extracting crate snaplog 0.4.0 into /workspace/builds/worker-5-tc1/source
[INFO] started tweaking crates.io crate snaplog 0.4.0
[INFO] finished tweaking crates.io crate snaplog 0.4.0
[INFO] tweaked toml for crates.io crate snaplog 0.4.0 written to /workspace/builds/worker-5-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate snaplog 0.4.0 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] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "generate-lockfile" "--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: 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]     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-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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] 0e9557c215bdb0fa7eb0ecd9a5189b930627b30f67e9e16f5eb5a402ad132358
[INFO] running `Command { std: "docker" "start" "-a" "0e9557c215bdb0fa7eb0ecd9a5189b930627b30f67e9e16f5eb5a402ad132358", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0e9557c215bdb0fa7eb0ecd9a5189b930627b30f67e9e16f5eb5a402ad132358", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "0e9557c215bdb0fa7eb0ecd9a5189b930627b30f67e9e16f5eb5a402ad132358", kill_on_drop: false }`
[INFO] [stdout] 0e9557c215bdb0fa7eb0ecd9a5189b930627b30f67e9e16f5eb5a402ad132358
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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] 27ee6997b4ef9a32010a17083a13ead2ec4d6269bbbc0629d0235b88c2c29625
[INFO] running `Command { std: "docker" "start" "-a" "27ee6997b4ef9a32010a17083a13ead2ec4d6269bbbc0629d0235b88c2c29625", kill_on_drop: false }`
[INFO] [stderr]    Compiling snaplog v0.4.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.53s
[INFO] running `Command { std: "docker" "inspect" "27ee6997b4ef9a32010a17083a13ead2ec4d6269bbbc0629d0235b88c2c29625", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "27ee6997b4ef9a32010a17083a13ead2ec4d6269bbbc0629d0235b88c2c29625", kill_on_drop: false }`
[INFO] [stdout] 27ee6997b4ef9a32010a17083a13ead2ec4d6269bbbc0629d0235b88c2c29625
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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] ffc25f0855653cf823a74268cd0f8dc4946aeea279feb741c524d57fe2ed5f4d
[INFO] running `Command { std: "docker" "start" "-a" "ffc25f0855653cf823a74268cd0f8dc4946aeea279feb741c524d57fe2ed5f4d", kill_on_drop: false }`
[INFO] [stderr]    Compiling snaplog v0.4.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.52s
[INFO] running `Command { std: "docker" "inspect" "ffc25f0855653cf823a74268cd0f8dc4946aeea279feb741c524d57fe2ed5f4d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ffc25f0855653cf823a74268cd0f8dc4946aeea279feb741c524d57fe2ed5f4d", kill_on_drop: false }`
[INFO] [stdout] ffc25f0855653cf823a74268cd0f8dc4946aeea279feb741c524d57fe2ed5f4d
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-5-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] 557c8642860bb0fc729ebfd268395e50050c0be41ecc04e12b7e17a729d4e555
[INFO] running `Command { std: "docker" "start" "-a" "557c8642860bb0fc729ebfd268395e50050c0be41ecc04e12b7e17a729d4e555", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.04s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/snaplog-ebc699bbb934a4d4)
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests snaplog
[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] [stdout] 
[INFO] [stdout] running 97 tests
[INFO] [stdout] test src/full.rs - full::IntoIter (line 797) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::drain (line 450) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::drain (line 467) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::from_history (line 154) ... ok
[INFO] [stdout] test src/full.rs - full (line 5) ... ok
[INFO] [stdout] test src/full.rs - full::Iter (line 825) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::current (line 335) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::drain (line 459) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::clone_snapshot_at (line 396) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::from_history (line 160) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::from_vec (line 109) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::from_history_unchecked (line 674) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::history (line 414) ... ok
[INFO] [stdout] test src/full.rs - full::IterMut (line 851) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::clear_history (line 491) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::from_vec (line 115) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::has_changes (line 288) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::into_inner (line 635) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::into_initial (line 590) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog (line 36) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::into_current (line 605) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::history_mut_vec (line 698) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::initial (line 304) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::from_vec_unchecked (line 656) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::history_mut (line 429) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::record_all (line 192) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::into_snapshot_at (line 620) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::initial_mut (line 350) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::current_mut (line 381) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::record_changes_all (line 267) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::record_change (line 209) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::iter_mut (line 572) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::iter (line 553) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::new (line 70) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::snapshot_at_mut (line 365) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::reserve (line 525) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::reset (line 508) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::record (line 177) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::snapshot_at (line 319) ... ok
[INFO] [stdout] test src/lib.rs - (line 5) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped (line 12) ... ok
[INFO] [stdout] test src/lib.rs - Select (line 49) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped (line 50) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped (line 71) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::try_from_history (line 134) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::clear_history (line 641) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::try_reserve (line 540) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::try_record_change (line 232) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::IntoIter (line 1008) ... ok
[INFO] [stdout] test src/full.rs - full::Snaplog<T>::try_from_vec (line 89) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::IterMut (line 1120) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::clone_snapshot_at (line 544) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Iter (line 1070) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::drain (line 615) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::from_vec_unchecked (line 861) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::current (line 483) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::from_history_unchecked (line 887) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::drain (line 603) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog (line 147) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::from_vec (line 223) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::from_history (line 268) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::current_mut (line 529) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::drain (line 624) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::from_history (line 274) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::from_vec (line 229) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::has_changes (line 436) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::ignored_mut (line 945) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::history_mut_vec (line 915) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::history (line 564) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::into_snapshot_at (line 776) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::record_all (line 361) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::history_mut (line 579) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::into_current (line 761) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::initial (line 452) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::record (line 346) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::into_inner (line 791) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::into_initial (line 746) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::initial_mut (line 498) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::iter (line 703) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::iter_mut (line 725) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::reserve (line 675) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::ignored (line 317) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::record_change (line 378) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::new (line 179) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::into_scope (line 330) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::record_changes_all (line 419) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::scope_mut (line 304) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::thin_snapshot_at_mut (line 836) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::scope (line 291) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::try_record_change (line 399) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::try_from_history (line 248) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::snapshot_at_mut (line 513) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::reset (line 658) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::thin_snapshot_at (line 814) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::snapshot_at (line 467) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::try_from_vec (line 202) ... ok
[INFO] [stdout] test src/scoped/mod.rs - scoped::Snaplog<T>::try_reserve (line 690) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 97 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.83s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "557c8642860bb0fc729ebfd268395e50050c0be41ecc04e12b7e17a729d4e555", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "557c8642860bb0fc729ebfd268395e50050c0be41ecc04e12b7e17a729d4e555", kill_on_drop: false }`
[INFO] [stdout] 557c8642860bb0fc729ebfd268395e50050c0be41ecc04e12b7e17a729d4e555