Dec 15 13:51:14.341 INFO testing gen-epub-book-2.3.1 against try#aa49d8ef14939ddec0e34b346b60174a5673d48f for pr-56550
Dec 15 13:51:14.341 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-5/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +aa49d8ef14939ddec0e34b346b60174a5673d48f-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 15 13:51:14.606 INFO [stdout] 9f3d5ed178cfc64432b6ca91a2d78df8e7e8cd02f59f2a12e8b7eb6a0b8a9fad
Dec 15 13:51:14.607 INFO running `"docker" "start" "-a" "9f3d5ed178cfc64432b6ca91a2d78df8e7e8cd02f59f2a12e8b7eb6a0b8a9fad"`
Dec 15 13:51:15.135 INFO [stderr] usermod: no changes
Dec 15 13:51:15.469 INFO [stderr]    Compiling zip v0.4.2
Dec 15 13:51:17.551 INFO [stderr]    Compiling gen-epub-book v2.3.1 (/source)
Dec 15 13:51:43.435 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 28.28s
Dec 15 13:51:43.450 INFO [stderr] su: No module specific data is present
Dec 15 13:51:43.754 INFO running `"docker" "inspect" "9f3d5ed178cfc64432b6ca91a2d78df8e7e8cd02f59f2a12e8b7eb6a0b8a9fad"`
Dec 15 13:51:43.843 INFO running `"docker" "rm" "-f" "9f3d5ed178cfc64432b6ca91a2d78df8e7e8cd02f59f2a12e8b7eb6a0b8a9fad"`
Dec 15 13:51:43.954 INFO [stdout] 9f3d5ed178cfc64432b6ca91a2d78df8e7e8cd02f59f2a12e8b7eb6a0b8a9fad
Dec 15 13:51:43.959 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-5/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +aa49d8ef14939ddec0e34b346b60174a5673d48f-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 15 13:51:44.367 INFO [stdout] 7da87e8477fdfaab3d018e0322c8c21c3b9c867019923b03739381bdab8cefd0
Dec 15 13:51:44.367 INFO running `"docker" "start" "-a" "7da87e8477fdfaab3d018e0322c8c21c3b9c867019923b03739381bdab8cefd0"`
Dec 15 13:51:45.058 INFO [stderr] usermod: no changes
Dec 15 13:51:45.299 INFO [stderr]    Compiling gen-epub-book v2.3.1 (/source)
Dec 15 13:52:02.483 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 17.40s
Dec 15 13:52:02.499 INFO [stderr] su: No module specific data is present
Dec 15 13:52:03.211 INFO running `"docker" "inspect" "7da87e8477fdfaab3d018e0322c8c21c3b9c867019923b03739381bdab8cefd0"`
Dec 15 13:52:03.549 INFO running `"docker" "rm" "-f" "7da87e8477fdfaab3d018e0322c8c21c3b9c867019923b03739381bdab8cefd0"`
Dec 15 13:52:03.939 INFO [stdout] 7da87e8477fdfaab3d018e0322c8c21c3b9c867019923b03739381bdab8cefd0
Dec 15 13:52:03.947 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-5/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-5/pr-56550/try#aa49d8ef14939ddec0e34b346b60174a5673d48f:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +aa49d8ef14939ddec0e34b346b60174a5673d48f-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 15 13:52:04.391 INFO [stdout] 3aee43609c4af59faf2826f51e5920ce24045ced8620cff93ea44f5fbe888420
Dec 15 13:52:04.393 INFO running `"docker" "start" "-a" "3aee43609c4af59faf2826f51e5920ce24045ced8620cff93ea44f5fbe888420"`
Dec 15 13:52:05.587 INFO [stderr] usermod: no changes
Dec 15 13:52:05.857 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.25s
Dec 15 13:52:05.866 INFO [stderr]      Running /target/debug/deps/gen_epub_book-90ceb1be87362135
Dec 15 13:52:05.869 INFO [stdout] 
Dec 15 13:52:05.869 INFO [stdout] running 0 tests
Dec 15 13:52:05.869 INFO [stdout] 
Dec 15 13:52:05.869 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 13:52:05.869 INFO [stdout] 
Dec 15 13:52:05.869 INFO [stderr]      Running /target/debug/deps/lib-bd052a69af9c3fed
Dec 15 13:52:05.872 INFO [stdout] 
Dec 15 13:52:05.872 INFO [stdout] running 108 tests
Dec 15 13:52:05.873 INFO [stdout] test error::exit_value::file_not_found ... ok
Dec 15 13:52:05.873 INFO [stdout] test error::exit_value::io ... ok
Dec 15 13:52:05.873 INFO [stdout] test error::print::file_not_found ... ok
Dec 15 13:52:05.873 INFO [stdout] test error::print::io::more::normal_e ... ok
Dec 15 13:52:05.873 INFO [stdout] test error::print::io::more::single_e ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::print::io::more::single_non_e ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::print::io::no_more::empty ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::print::io::more::normal_non_e ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::exit_value::wrong_element_amount ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::exit_value::required_element_missing ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::exit_value::wrong_file_state ... ok
Dec 15 13:52:05.875 INFO [stdout] test error::print::io::more::empty ... ok
Dec 15 13:52:05.879 INFO [stdout] test error::print::io::no_more::normal_e ... ok
Dec 15 13:52:05.879 INFO [stdout] test error::print::io::no_more::normal_non_e ... ok
Dec 15 13:52:05.879 INFO [stdout] test error::print::wrong_element_amount ... ok
Dec 15 13:52:05.881 INFO [stdout] test error::print::io::no_more::single_e ... ok
Dec 15 13:52:05.881 INFO [stdout] test error::print::parse::more ... ok
Dec 15 13:52:05.881 INFO [stdout] test error::print::parse::no_more ... ok
Dec 15 13:52:05.881 INFO [stdout] test error::print::io::no_more::single_non_e ... ok
Dec 15 13:52:05.881 INFO [stdout] test error::exit_value::parse ... ok
Dec 15 13:52:05.881 INFO [stdout] test error::print::required_element_missing ... ok
Dec 15 13:52:05.882 INFO [stdout] test ops::book::from_elements::incorrect::cover::two_file ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::correct::network_cover ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::correct::file_cover ... ok
Dec 15 13:52:05.891 INFO [stdout] test error::print::wrong_file_state ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::cover::mixed_file_first ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::duplicate::date ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::cover::mixed_network_first ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::duplicate::author ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::correct::no_cover ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::duplicate::language ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::cover::two_network ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::duplicate::name ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::missing::ordering ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::duplicate::ordering ... ok
Dec 15 13:52:05.891 INFO [stdout] test ops::book::from_elements::incorrect::missing::author ... ok
Dec 15 13:52:05.892 INFO [stdout] test ops::book::from_elements::incorrect::missing::date ... ok
Dec 15 13:52:05.892 INFO [stdout] test ops::book::from_elements::incorrect::missing::language ... ok
Dec 15 13:52:05.892 INFO [stdout] test ops::book::normalise_paths::no_verbose::nonexistant ... ok
Dec 15 13:52:05.892 INFO [stdout] test ops::book::normalise_paths::verbose::bad_type ... ok
Dec 15 13:52:05.895 INFO [stdout] test ops::element::display::cover ... ok
Dec 15 13:52:05.895 INFO [stdout] test ops::element::display::content ... ok
Dec 15 13:52:05.896 INFO [stdout] test ops::element::display::date ... ok
Dec 15 13:52:05.896 INFO [stdout] test ops::element::display::author ... ok
Dec 15 13:52:05.896 INFO [stdout] test ops::book::normalise_paths::no_verbose::correct ... ok
Dec 15 13:52:05.897 INFO [stdout] test ops::book::normalise_paths::no_verbose::bad_type ... ok
Dec 15 13:52:05.903 INFO [stdout] test ops::element::display::name ... ok
Dec 15 13:52:05.903 INFO [stdout] test ops::book::from_elements::incorrect::missing::name ... ok
Dec 15 13:52:05.903 INFO [stdout] test ops::element::display::network_cover ... ok
Dec 15 13:52:05.903 INFO [stdout] test ops::element::display::include ... ok
Dec 15 13:52:05.903 INFO [stdout] test ops::element::display::language ... ok
Dec 15 13:52:05.904 INFO [stdout] test ops::book::normalise_paths::verbose::correct ... ok
Dec 15 13:52:05.904 INFO [stdout] test ops::element::display::image_content ... ok
Dec 15 13:52:05.905 INFO [stdout] test ops::element::name::date ... ok
Dec 15 13:52:05.905 INFO [stdout] test ops::element::name::author ... ok
Dec 15 13:52:05.905 INFO [stdout] test ops::element::display::network_image_content ... ok
Dec 15 13:52:05.906 INFO [stdout] test ops::element::display::network_include ... ok
Dec 15 13:52:05.907 INFO [stdout] test ops::element::name::cover ... ok
Dec 15 13:52:05.907 INFO [stdout] test ops::element::name::content ... ok
Dec 15 13:52:05.907 INFO [stdout] test ops::book::normalise_paths::verbose::nonexistant ... ok
Dec 15 13:52:05.911 INFO [stdout] test ops::element::display::string_content ... ok
Dec 15 13:52:05.911 INFO [stdout] test ops::element::name::image_content ... ok
Dec 15 13:52:05.913 INFO [stdout] test ops::element::name::name ... ok
Dec 15 13:52:05.917 INFO [stdout] test ops::element::name::string_content ... ok
Dec 15 13:52:05.917 INFO [stdout] test ops::element::name::include ... ok
Dec 15 13:52:05.917 INFO [stdout] test ops::element::name::language ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::name::network_include ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::name::network_image_content ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::content ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::author ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::cover ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::name::network_cover ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::include ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::name ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::image_content ... ok
Dec 15 13:52:05.927 INFO [stdout] test ops::element::parse::elements::language ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::elements::string_content ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::errors::datetime_free ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::elements::date_rigid ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::elements::date_free ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::elements::network_cover ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::trimming ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::roundtrip ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::not_description ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::elements::network_image_content ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::elements::network_include ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::errors::datetime_rigid ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::errors::url ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::parse::incorrect::invalid::named ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::parse::correct::unnamed ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::parse::incorrect::nonexistant::named ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::parse::incorrect::nonexistant::unnamed ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::parse_descriptor::bubbling ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::parse_descriptor::generic ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::already_upper ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::empty ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::multi ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::multi_already_upper ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::simple ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::single ... ok
Dec 15 13:52:05.972 INFO [stdout] test util::uppercase_first::single_already_upper ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::parse::incorrect::invalid::unnamed ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::parse::correct::named ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::display::unnamed ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::element::parse::unrecognised ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::find_title::non_containing ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::include_dir::display::named ... ok
Dec 15 13:52:05.972 INFO [stdout] test ops::find_title::containing ... ok
Dec 15 13:52:05.972 INFO [stdout] 
Dec 15 13:52:05.972 INFO [stdout] test result: ok. 108 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 15 13:52:05.972 INFO [stdout] 
Dec 15 13:52:05.972 INFO [stderr]    Doc-tests gen-epub-book
Dec 15 13:52:20.767 INFO [stdout] 
Dec 15 13:52:20.767 INFO [stdout] running 25 tests
Dec 15 13:53:20.779 INFO [stdout] test src/ops/book.rs - ops::book::EPubBook::from_elements (line 64) ... test src/ops/book.rs - ops::book::EPubBook::from_elements (line 64) has been running for over 60 seconds
Dec 15 13:53:20.779 INFO [stdout] test src/error.rs - error::Error::exit_value (line 114) ... test src/error.rs - error::Error::exit_value (line 114) has been running for over 60 seconds
Dec 15 13:53:20.779 INFO [stdout] test src/error.rs - error::Error::print_error (line 67) ... test src/error.rs - error::Error::print_error (line 67) has been running for over 60 seconds
Dec 15 13:53:20.782 INFO [stdout] test src/ops/book.rs - ops::book::EPubBook::normalise_paths (line 191) ... test src/ops/book.rs - ops::book::EPubBook::normalise_paths (line 191) has been running for over 60 seconds
Dec 15 13:53:20.783 INFO [stdout] test src/ops/book.rs - ops::book::EPubBook::write_zip (line 253) ... test src/ops/book.rs - ops::book::EPubBook::write_zip (line 253) has been running for over 60 seconds
Dec 15 13:53:20.819 INFO [stdout] test src/ops/book.rs - ops::book::EPubBook::write_zip_ext (line 311) ... test src/ops/book.rs - ops::book::EPubBook::write_zip_ext (line 311) has been running for over 60 seconds
Dec 15 13:53:20.839 INFO [stdout] test src/ops/element.rs - ops::element::BookElement (line 16) ... test src/ops/element.rs - ops::element::BookElement (line 16) has been running for over 60 seconds
Dec 15 13:53:20.839 INFO [stdout] test src/ops/element.rs - ops::element::BookElement::name (line 227) ... test src/ops/element.rs - ops::element::BookElement::name (line 227) has been running for over 60 seconds
Dec 15 13:53:56.646 INFO [stdout] test src/error.rs - error::Error::exit_value (line 114) ... ok
Dec 15 13:54:03.995 INFO [stdout] test src/ops/element.rs - ops::element::BookElement (line 16) ... ok
Dec 15 13:54:21.595 INFO [stdout] test src/ops/book.rs - ops::book::EPubBook::write_zip_ext (line 311) ... FAILED
Dec 15 13:54:24.375 INFO [stdout] test src/error.rs - error::Error::print_error (line 67) ... ok
Dec 15 13:54:28.942 INFO [stdout] test src/ops/element.rs - ops::element::BookElement::name (line 227) ... ok
Dec 15 13:54:38.311 INFO [stderr] su: No module specific data is present
Dec 15 13:54:39.456 INFO running `"docker" "inspect" "3aee43609c4af59faf2826f51e5920ce24045ced8620cff93ea44f5fbe888420"`
Dec 15 13:54:39.695 INFO running `"docker" "rm" "-f" "3aee43609c4af59faf2826f51e5920ce24045ced8620cff93ea44f5fbe888420"`
Dec 15 13:54:39.927 INFO [stdout] 3aee43609c4af59faf2826f51e5920ce24045ced8620cff93ea44f5fbe888420