[INFO] fetching crate subplotlib 0.1.1...
[INFO] testing subplotlib-0.1.1 against master#a77da2d454e6caa227a85b16410b95f93495e7e0 for pr-91031
[INFO] extracting crate subplotlib 0.1.1 into /workspace/builds/worker-17/source
[INFO] validating manifest of crates.io crate subplotlib 0.1.1 on toolchain a77da2d454e6caa227a85b16410b95f93495e7e0
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] started tweaking crates.io crate subplotlib 0.1.1
[INFO] finished tweaking crates.io crate subplotlib 0.1.1
[INFO] tweaked toml for crates.io crate subplotlib 0.1.1 written to /workspace/builds/worker-17/source/Cargo.toml
[INFO] running `Command { std: "/workspace/cargo-home/bin/cargo" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "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" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "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-17/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/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:5736fa189c1c60b01babf4b8b698fe57b6ecc41933a7ff2e0b8d7a221459412b" "/opt/rustwide/cargo-home/bin/cargo" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 488698d6e52d6ef542d16f84d9586f6e5a75d4c3f226866d778b9bfdfda675c5
[INFO] running `Command { std: "docker" "start" "-a" "488698d6e52d6ef542d16f84d9586f6e5a75d4c3f226866d778b9bfdfda675c5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "488698d6e52d6ef542d16f84d9586f6e5a75d4c3f226866d778b9bfdfda675c5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "488698d6e52d6ef542d16f84d9586f6e5a75d4c3f226866d778b9bfdfda675c5", kill_on_drop: false }`
[INFO] [stdout] 488698d6e52d6ef542d16f84d9586f6e5a75d4c3f226866d778b9bfdfda675c5
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/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" "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:5736fa189c1c60b01babf4b8b698fe57b6ecc41933a7ff2e0b8d7a221459412b" "/opt/rustwide/cargo-home/bin/cargo" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 49302a7c9050f1e90ebf94a98561653131a73ba4be8f6c9ef6f2e592b2ea4429
[INFO] running `Command { std: "docker" "start" "-a" "49302a7c9050f1e90ebf94a98561653131a73ba4be8f6c9ef6f2e592b2ea4429", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.108
[INFO] [stderr]    Compiling autocfg v1.0.1
[INFO] [stderr]    Compiling proc-macro2 v1.0.32
[INFO] [stderr]    Compiling unicode-xid v0.2.2
[INFO] [stderr]    Compiling cfg-if v1.0.0
[INFO] [stderr]    Compiling syn v1.0.81
[INFO] [stderr]    Compiling memchr v2.4.1
[INFO] [stderr]    Compiling ppv-lite86 v0.2.15
[INFO] [stderr]    Compiling regex-syntax v0.6.25
[INFO] [stderr]    Compiling remove_dir_all v0.5.3
[INFO] [stderr]    Compiling lazy_static v1.4.0
[INFO] [stderr]    Compiling base64 v0.13.0
[INFO] [stderr]    Compiling unescape v0.1.0
[INFO] [stderr]    Compiling shell-words v1.0.0
[INFO] [stderr]    Compiling state v0.5.2
[INFO] [stderr]    Compiling num-traits v0.2.14
[INFO] [stderr]    Compiling num-integer v0.1.44
[INFO] [stderr]    Compiling aho-corasick v0.7.18
[INFO] [stderr]    Compiling quote v1.0.10
[INFO] [stderr]    Compiling getrandom v0.2.3
[INFO] [stderr]    Compiling time v0.1.43
[INFO] [stderr]    Compiling fs2 v0.4.3
[INFO] [stderr]    Compiling remove_dir_all v0.7.0
[INFO] [stderr]    Compiling filetime v0.2.15
[INFO] [stderr]    Compiling rand_core v0.6.3
[INFO] [stderr]    Compiling rand_chacha v0.3.1
[INFO] [stderr]    Compiling rand v0.8.4
[INFO] [stderr]    Compiling chrono v0.4.19
[INFO] [stderr]    Compiling regex v1.5.4
[INFO] [stderr]    Compiling tempfile v3.2.0
[INFO] [stderr]    Compiling fehler-macros v1.0.0
[INFO] [stderr]    Compiling fehler v1.0.0
[INFO] [stderr]    Compiling subplotlib-derive v0.1.0
[INFO] [stderr]    Compiling subplotlib v0.1.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 16.56s
[INFO] running `Command { std: "docker" "inspect" "49302a7c9050f1e90ebf94a98561653131a73ba4be8f6c9ef6f2e592b2ea4429", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "49302a7c9050f1e90ebf94a98561653131a73ba4be8f6c9ef6f2e592b2ea4429", kill_on_drop: false }`
[INFO] [stdout] 49302a7c9050f1e90ebf94a98561653131a73ba4be8f6c9ef6f2e592b2ea4429
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/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" "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:5736fa189c1c60b01babf4b8b698fe57b6ecc41933a7ff2e0b8d7a221459412b" "/opt/rustwide/cargo-home/bin/cargo" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] f6e55e2daea6dfd50fd59536c49b0513ba69029b97adbcfffe68e1cacd513aa5
[INFO] running `Command { std: "docker" "start" "-a" "f6e55e2daea6dfd50fd59536c49b0513ba69029b97adbcfffe68e1cacd513aa5", kill_on_drop: false }`
[INFO] [stderr]    Compiling subplotlib v0.1.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 2.81s
[INFO] running `Command { std: "docker" "inspect" "f6e55e2daea6dfd50fd59536c49b0513ba69029b97adbcfffe68e1cacd513aa5", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "f6e55e2daea6dfd50fd59536c49b0513ba69029b97adbcfffe68e1cacd513aa5", kill_on_drop: false }`
[INFO] [stdout] f6e55e2daea6dfd50fd59536c49b0513ba69029b97adbcfffe68e1cacd513aa5
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-17/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" "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:5736fa189c1c60b01babf4b8b698fe57b6ecc41933a7ff2e0b8d7a221459412b" "/opt/rustwide/cargo-home/bin/cargo" "+a77da2d454e6caa227a85b16410b95f93495e7e0" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] d897489815d5d6ab16519cabaf10d99beab69650e17d325a7d3ac386def69bd7
[INFO] running `Command { std: "docker" "start" "-a" "d897489815d5d6ab16519cabaf10d99beab69650e17d325a7d3ac386def69bd7", kill_on_drop: false }`
[INFO] [stderr]     Finished test [unoptimized + debuginfo] target(s) in 0.10s
[INFO] [stderr]      Running unittests (/opt/rustwide/target/debug/deps/subplotlib-72ccad164b1f92bf)
[INFO] [stdout] 
[INFO] [stderr]      Running tests/files.rs (/opt/rustwide/target/debug/deps/files-c66f64e773b94e44)
[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 5 tests
[INFO] [stdout] test directories ... ok
[INFO] [stdout] test create_on_disk_files_from_embedded_files ... ok
[INFO] [stdout] test file_modification_time ... ok
[INFO] [stderr]      Running tests/runcmd.rs (/opt/rustwide/target/debug/deps/runcmd-11d0f940f6582b88)
[INFO] [stdout] test file_contents ... ok
[INFO] [stdout] test file_metadata ... 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] [stdout] 
[INFO] [stdout] running 16 tests
[INFO] [stdout] test check_stderr_doesn_t_contain_sub_string ... ok
[INFO] [stdout] test check_stderr_is_not_exactly_something ... ok
[INFO] [stdout] test successful_execution ... ok
[INFO] [stdout] test check_stderr_using_regular_expressions ... ok
[INFO] [stdout] test check_stderr_using_sub_string_search ... ok
[INFO] [stdout] test failed_execution ... ok
[INFO] [stdout] test failed_execution_in_a_sub_directory ... ok
[INFO] [stdout] test successful_execution_in_a_sub_directory ... ok
[INFO] [stdout] test check_stdout_using_sub_string_search ... ok
[INFO] [stdout] test check_stderr_is_exactly_as_wanted ... ok
[INFO] [stdout] test check_stderr_doesn_t_match_regular_expressions ... ok
[INFO] [stdout] test check_stdout_using_regular_expressions ... ok
[INFO] [stdout] test check_stdout_doesn_t_contain_sub_string ... ok
[INFO] [stdout] test check_stdout_doesn_t_match_regular_expression ... ok
[INFO] [stdout] test check_stdout_is_exactly_as_wanted ... ok
[INFO] [stdout] test check_stdout_is_not_exactly_something ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 16 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.09s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/subplotlib.rs (/opt/rustwide/target/debug/deps/subplotlib-340503a802cb24f0)
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test embedded_files ... ok
[INFO] [stdout] test fundamentals ... ok
[INFO] [stdout] test data_directory ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests subplotlib
[INFO] [stdout] 
[INFO] [stdout] running 53 tests
[INFO] [stdout] test src/steplibrary/datadir.rs - steplibrary::datadir::datadir_has_enough_space::call (line 112) ... ignored
[INFO] [stdout] test src/steplibrary/datadir.rs - steplibrary::datadir::datadir_has_enough_space_megabytes::call (line 124) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::create_from_embedded::call (line 51) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::create_from_embedded_with_other_name::call (line 64) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::create_from_text::call (line 100) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::file_contains::call (line 181) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::file_does_not_exist::call (line 153) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::file_exists::call (line 138) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::file_match::call (line 200) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::file_matches_regex::call (line 190) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::has_different_metadata::call (line 236) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::has_remembered_metadata::call (line 211) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::make_directory::call (line 283) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::mtime_is_ancient::call (line 272) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::mtime_is_recent::call (line 261) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::only_these_exist::call (line 168) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::path_does_not_exist::call (line 305) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::path_exists::call (line 294) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::path_is_empty::call (line 318) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::path_is_not_empty::call (line 329) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::remember_metadata::call (line 105) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::remove_directory::call (line 288) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::touch::call (line 123) ... ignored
[INFO] [stdout] test src/steplibrary/files.rs - steplibrary::files::touch_with_timestamp::call (line 83) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::exit_code_is::call (line 186) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::exit_code_is_nonzero::call (line 209) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::exit_code_is_not::call (line 196) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::exit_code_is_zero::call (line 203) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::helper_script::call (line 80) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::helper_srcdir_path::call (line 87) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::run::call (line 92) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::run_in::call (line 100) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stderr_contains::call (line 291) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stderr_doesnt_contain::call (line 298) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stderr_doesnt_match_regex::call (line 326) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stderr_is::call (line 263) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stderr_isnt::call (line 270) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stderr_matches_regex::call (line 319) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stdout_contains::call (line 277) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stdout_doesnt_contain::call (line 284) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stdout_doesnt_match_regex::call (line 312) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stdout_is::call (line 249) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stdout_isnt::call (line 256) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::stdout_matches_regex::call (line 305) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::try_to_run::call (line 108) ... ignored
[INFO] [stdout] test src/steplibrary/runcmd.rs - steplibrary::runcmd::try_to_run_in::call (line 115) ... ignored
[INFO] [stdout] test src/prelude.rs - prelude::throws (line 39) ... ok
[INFO] [stdout] test src/prelude.rs - prelude::throws (line 26) ... ok
[INFO] [stdout] test src/steplibrary.rs - steplibrary (line 10) ... ok
[INFO] [stdout] test src/prelude.rs - prelude::step (line 73) ... ok
[INFO] [stdout] test src/prelude.rs - prelude::step (line 100) ... ok
[INFO] [stdout] test src/prelude.rs - prelude (line 6) ... ok
[INFO] [stdout] test src/file.rs - file::SubplotDataFile (line 19) ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 7 passed; 0 failed; 46 ignored; 0 measured; 0 filtered out; finished in 0.30s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "d897489815d5d6ab16519cabaf10d99beab69650e17d325a7d3ac386def69bd7", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "d897489815d5d6ab16519cabaf10d99beab69650e17d325a7d3ac386def69bd7", kill_on_drop: false }`
[INFO] [stdout] d897489815d5d6ab16519cabaf10d99beab69650e17d325a7d3ac386def69bd7