Dec 05 04:51:21.474 INFO testing tfursten/mtsv_tools against try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468 for pr-56514
Dec 05 04:51:21.474 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-7/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56514/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/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 +6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468-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 05 04:51:21.940 INFO [stdout] 4d605c1a31097d5587f8b9414e10a5f265a7d07be60ae400b1fcd19edc574e1c
Dec 05 04:51:21.946 INFO running `"docker" "start" "-a" "4d605c1a31097d5587f8b9414e10a5f265a7d07be60ae400b1fcd19edc574e1c"`
Dec 05 04:51:23.636 INFO [stderr] usermod: no changes
Dec 05 04:51:23.848 INFO [stderr]    Compiling num-traits v0.2.0
Dec 05 04:51:23.849 INFO [stderr]    Compiling crossbeam v0.2.12
Dec 05 04:51:23.849 INFO [stderr]    Compiling itertools v0.4.19
Dec 05 04:51:23.849 INFO [stderr]    Compiling serde v0.7.15
Dec 05 04:51:23.850 INFO [stderr]    Compiling memchr v0.1.11
Dec 05 04:51:23.850 INFO [stderr]    Compiling xattr v0.1.11
Dec 05 04:51:23.850 INFO [stderr]    Compiling miniz-sys v0.1.10
Dec 05 04:51:23.850 INFO [stderr]    Compiling ssw v0.1.0 (/source/ssw)
Dec 05 04:51:26.176 INFO [stderr]    Compiling filetime v0.1.15
Dec 05 04:51:26.580 INFO [stderr]    Compiling csv v0.14.7
Dec 05 04:51:26.630 INFO [stderr]    Compiling bit-set v0.3.0
Dec 05 04:51:28.968 INFO [stderr]    Compiling petgraph v0.2.7 (/source/vendor/petgraph)
Dec 05 04:51:28.980 INFO [stderr]    Compiling aho-corasick v0.5.3
Dec 05 04:51:29.190 INFO [stderr]    Compiling clap v2.29.4
Dec 05 04:51:33.937 INFO [stderr]    Compiling tar v0.4.14
Dec 05 04:51:33.939 INFO [stderr]    Compiling syncbox v0.2.4
Dec 05 04:51:34.094 INFO [stderr]    Compiling num-integer v0.1.36
Dec 05 04:51:34.178 INFO [stderr]    Compiling num-traits v0.1.43
Dec 05 04:51:35.234 INFO [stderr]    Compiling num-complex v0.1.42
Dec 05 04:51:37.253 INFO [stderr]    Compiling thread-id v2.0.0
Dec 05 04:51:38.390 INFO [stderr]    Compiling num-bigint v0.1.42
Dec 05 04:51:38.525 INFO [stderr]    Compiling num-iter v0.1.35
Dec 05 04:51:41.117 INFO [stderr]    Compiling thread_local v0.2.7
Dec 05 04:51:41.134 INFO [stderr]    Compiling flate2 v0.2.20
Dec 05 04:51:41.216 INFO [stderr]    Compiling cue v0.1.0
Dec 05 04:51:43.276 INFO [stderr]    Compiling daggy v0.4.0 (/source/vendor/daggy)
Dec 05 04:51:47.233 INFO [stderr]    Compiling regex v0.1.80
Dec 05 04:51:51.710 INFO [stderr]    Compiling bincode v0.5.9
Dec 05 04:51:53.318 INFO [stderr]    Compiling num-rational v0.1.41
Dec 05 04:51:58.749 INFO [stderr]    Compiling num v0.1.41
Dec 05 04:51:59.470 INFO [stderr]    Compiling nalgebra v0.4.0
Dec 05 04:51:59.472 INFO [stderr]    Compiling chrono v0.2.25
Dec 05 04:51:59.473 INFO [stderr]    Compiling stopwatch v0.0.6
Dec 05 04:52:19.692 INFO [stderr]    Compiling env_logger v0.3.5
Dec 05 04:52:29.286 INFO [stderr]    Compiling bio v0.5.0 (/source/vendor/rust-bio)
Dec 05 04:52:33.852 INFO [stderr]    Compiling mtsv v0.4.0 (/source)
Dec 05 04:53:03.037 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1m 39s
Dec 05 04:53:03.060 INFO [stderr] su: No module specific data is present
Dec 05 04:53:04.260 INFO running `"docker" "inspect" "4d605c1a31097d5587f8b9414e10a5f265a7d07be60ae400b1fcd19edc574e1c"`
Dec 05 04:53:04.666 INFO running `"docker" "rm" "-f" "4d605c1a31097d5587f8b9414e10a5f265a7d07be60ae400b1fcd19edc574e1c"`
Dec 05 04:53:04.976 INFO [stdout] 4d605c1a31097d5587f8b9414e10a5f265a7d07be60ae400b1fcd19edc574e1c
Dec 05 04:53:04.984 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-7/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56514/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/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 +6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468-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 05 04:53:05.446 INFO [stdout] 87de73669eb3de7f512b9639d08a3d5dcbc6ac9071f95c040ff2f8ec9dbf7572
Dec 05 04:53:05.448 INFO running `"docker" "start" "-a" "87de73669eb3de7f512b9639d08a3d5dcbc6ac9071f95c040ff2f8ec9dbf7572"`
Dec 05 04:53:07.932 INFO [stderr] usermod: no changes
Dec 05 04:53:08.083 INFO [stderr]    Compiling rand v0.3.22
Dec 05 04:53:08.430 INFO [stderr]    Compiling uuid v0.1.18
Dec 05 04:53:08.430 INFO [stderr]    Compiling quickcheck v0.3.2
Dec 05 04:53:09.668 INFO [stderr]    Compiling mktemp v0.2.1
Dec 05 04:53:12.481 INFO [stderr]    Compiling mtsv v0.4.0 (/source)
Dec 05 04:53:31.722 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 23.77s
Dec 05 04:53:31.740 INFO [stderr] su: No module specific data is present
Dec 05 04:53:32.468 INFO running `"docker" "inspect" "87de73669eb3de7f512b9639d08a3d5dcbc6ac9071f95c040ff2f8ec9dbf7572"`
Dec 05 04:53:32.804 INFO running `"docker" "rm" "-f" "87de73669eb3de7f512b9639d08a3d5dcbc6ac9071f95c040ff2f8ec9dbf7572"`
Dec 05 04:53:33.104 INFO [stdout] 87de73669eb3de7f512b9639d08a3d5dcbc6ac9071f95c040ff2f8ec9dbf7572
Dec 05 04:53:33.110 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-7/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-7/pr-56514/try#6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468:/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 +6eb0fd3ac58f9b16bddb9924a17c3b6c156aa468-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 05 04:53:33.589 INFO [stdout] 79edb5c05e8c1912e8ed8ecef07198debe7c5877552a93a24b8d5d751713907d
Dec 05 04:53:33.595 INFO running `"docker" "start" "-a" "79edb5c05e8c1912e8ed8ecef07198debe7c5877552a93a24b8d5d751713907d"`
Dec 05 04:53:34.697 INFO [stderr] usermod: no changes
Dec 05 04:53:34.880 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.15s
Dec 05 04:53:34.904 INFO [stderr]      Running /target/debug/deps/mtsv-76deb850eb27df28
Dec 05 04:53:34.916 INFO [stdout] 
Dec 05 04:53:34.916 INFO [stdout] running 71 tests
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_exact_partial ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_end_edits ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_empty ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_nomatches ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_from_jupyter_notebook ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_begin_edits ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_middle_edits ... ok
Dec 05 04:53:34.948 INFO [stdout] test align::test::test_exact_full ... ok
Dec 05 04:53:34.969 INFO [stdout] test binner::test::success_single_spaces ... ok
Dec 05 04:53:34.977 INFO [stdout] test binner::test::success_many ... ok
Dec 05 04:53:34.977 INFO [stdout] test binner::test::success_empty ... ok
Dec 05 04:53:34.988 INFO [stdout] test collapse::test::simple_collapse ... ok
Dec 05 04:53:35.008 INFO [stdout] test builder::test::success ... ok
Dec 05 04:53:35.084 INFO [stdout] test index::test::seed_hits_success ... ok
Dec 05 04:53:35.680 INFO [stdout] test builder::test::fail_empty_header ... ok
Dec 05 04:53:35.697 INFO [stdout] test index::test::seed_hits_fail ... ok
Dec 05 04:53:35.697 INFO [stdout] test io::test::invalid_ids ... ok
Dec 05 04:53:35.697 INFO [stdout] test index::test::reference_candidate_different_bin ... ok
Dec 05 04:53:35.699 INFO [stdout] test io::test::missing_ids ... ok
Dec 05 04:53:35.699 INFO [stdout] test io::test::no_read_header ... ok
Dec 05 04:53:35.720 INFO [stdout] test io::test::parsing_positive ... ok
Dec 05 04:53:35.728 INFO [stdout] test io::test::roundtrip_single ... ok
Dec 05 04:53:35.728 INFO [stdout] test prep::tests::adapters_empty ... ok
Dec 05 04:53:35.732 INFO [stdout] test prep::tests::adapters_present_and_above_tolerance ... ok
Dec 05 04:53:35.740 INFO [stdout] test prep::tests::adapters_present_but_below_tolerance ... ok
Dec 05 04:53:35.752 INFO [stdout] test prep::tests::adapters_whole_sequence ... ok
Dec 05 04:53:35.768 INFO [stdout] test prep::tests::highest_at_end ... ok
Dec 05 04:53:35.769 INFO [stdout] test prep::tests::highest_at_start ... ok
Dec 05 04:53:35.769 INFO [stdout] test prep::tests::highest_in_middle ... ok
Dec 05 04:53:35.769 INFO [stdout] test prep::tests::highest_q_same_length ... ok
Dec 05 04:53:35.770 INFO [stdout] test prep::tests::lcd_trim_diff_length ... ok
Dec 05 04:53:35.770 INFO [stdout] test prep::tests::lcd_trim_same_length ... ok
Dec 05 04:53:35.771 INFO [stdout] test prep::tests::lcdq_trim_diff_length ... ok
Dec 05 04:53:35.771 INFO [stdout] test prep::tests::lcdq_trim_same_length ... ok
Dec 05 04:53:35.772 INFO [stdout] test prep::tests::quality_filter ... ok
Dec 05 04:53:35.800 INFO [stdout] test prep::tests::segment_trim_even_division ... ok
Dec 05 04:53:35.801 INFO [stdout] test prep::tests::adapters_none ... ok
Dec 05 04:53:35.801 INFO [stdout] test prep::tests::segment_trim_same_len ... ok
Dec 05 04:53:35.802 INFO [stdout] test prep::tests::segment_trim_uneven_division ... ok
Dec 05 04:53:35.803 INFO [stdout] test prep::tests::test_highest_q_zero_goal ... ok
Dec 05 04:53:35.884 INFO [stdout] test prep::tests::test_highest_q_longer_desired_than_avail ... ok
Dec 05 04:53:36.712 INFO [stdout] test index::test::reference_candidate_non_overlapping ... ok
Dec 05 04:53:38.497 INFO [stdout] test io::test::io_helpers ... ok
Dec 05 04:53:38.500 INFO [stdout] test prep_config::test::test_subadapters ... ok
Dec 05 04:53:38.561 INFO [stdout] test tax_tree::test::human_ancestors ... ok
Dec 05 04:53:38.619 INFO [stdout] test tax_tree::test::human_siblings_lca ... ok
Dec 05 04:53:38.644 INFO [stdout] test tax_tree::test::human_siblings_rank ... ok
Dec 05 04:53:38.672 INFO [stdout] test tax_tree::test::informative_parent ... ok
Dec 05 04:53:38.683 INFO [stdout] test tax_tree::test::tokenize ... ok
Dec 05 04:53:38.708 INFO [stdout] test tax_tree::test::tokenize_empty ... ok
Dec 05 04:53:38.744 INFO [stdout] test tax_tree::test::tokenize_fail_parent_bad ... ok
Dec 05 04:53:38.773 INFO [stdout] test tax_tree::test::tokenize_fail_parent_missing ... ok
Dec 05 04:53:38.821 INFO [stdout] test tax_tree::test::tokenize_fail_rank_missing ... ok
Dec 05 04:53:38.846 INFO [stdout] test tax_tree::test::tokenize_fail_taxid_bad ... ok
Dec 05 04:53:38.879 INFO [stdout] test tax_tree::test::tokenize_fail_taxid_missing ... ok
Dec 05 04:53:39.084 INFO [stdout] test util::test::fail_decimal_gi ... ok
Dec 05 04:53:39.124 INFO [stdout] test util::test::fail_decimal_taxid ... ok
Dec 05 04:53:39.137 INFO [stdout] test util::test::fail_empty ... ok
Dec 05 04:53:39.153 INFO [stdout] test util::test::fail_empty_nodash ... ok
Dec 05 04:53:39.157 INFO [stdout] test util::test::fail_extra ... ok
Dec 05 04:53:39.169 INFO [stdout] test util::test::fail_non_numeric_gi ... ok
Dec 05 04:53:39.178 INFO [stdout] test util::test::fail_non_numeric_taxid ... ok
Dec 05 04:53:39.217 INFO [stdout] test util::test::lines_for_the_line_throne ... ok
Dec 05 04:53:39.222 INFO [stdout] test util::test::success ... ok
Dec 05 04:53:44.120 INFO [stdout] test prep_config::test::lcd ... ok
Dec 05 04:53:44.367 INFO [stdout] test prep_config::test::segment ... ok
Dec 05 04:54:06.742 INFO [stdout] test io::test::roundtrip_many ... ok
Dec 05 04:54:34.953 INFO [stdout] test chunk::test::chunk_roundtrip ... test chunk::test::chunk_roundtrip has been running for over 60 seconds
Dec 05 04:54:34.953 INFO [stdout] test index::test::construct_index_lowercase ... test index::test::construct_index_lowercase has been running for over 60 seconds
Dec 05 04:54:34.988 INFO [stdout] test index::test::reference_candidate ... test index::test::reference_candidate has been running for over 60 seconds
Dec 05 04:54:35.820 INFO [stdout] test prep::tests::test_prep_integration ... test prep::tests::test_prep_integration has been running for over 60 seconds
Dec 05 04:54:42.916 INFO [stdout] test prep::tests::test_prep_integration ... ok
Dec 05 04:55:05.382 INFO [stdout] test index::test::construct_index_lowercase ... ok
Dec 05 04:55:19.516 INFO [stdout] test chunk::test::chunk_roundtrip ... ok
Dec 05 04:56:20.336 INFO [stdout] test index::test::reference_candidate ... ok
Dec 05 04:56:20.336 INFO [stdout] 
Dec 05 04:56:20.336 INFO [stdout] test result: ok. 71 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.336 INFO [stdout] 
Dec 05 04:56:20.343 INFO [stderr]      Running /target/debug/deps/mtsv_binner-7222927473a40c7f
Dec 05 04:56:20.353 INFO [stderr]      Running /target/debug/deps/mtsv_build-532b8fbc460f65b5
Dec 05 04:56:20.353 INFO [stdout] 
Dec 05 04:56:20.353 INFO [stdout] running 0 tests
Dec 05 04:56:20.353 INFO [stdout] 
Dec 05 04:56:20.353 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.353 INFO [stdout] 
Dec 05 04:56:20.359 INFO [stdout] 
Dec 05 04:56:20.359 INFO [stdout] running 0 tests
Dec 05 04:56:20.359 INFO [stdout] 
Dec 05 04:56:20.359 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.359 INFO [stdout] 
Dec 05 04:56:20.359 INFO [stderr]      Running /target/debug/deps/mtsv_chunk-26380f98b6ba6ec2
Dec 05 04:56:20.382 INFO [stdout] 
Dec 05 04:56:20.382 INFO [stdout] running 0 tests
Dec 05 04:56:20.384 INFO [stdout] 
Dec 05 04:56:20.384 INFO [stderr]      Running /target/debug/deps/mtsv_collapse-01cdea64d1a29b9b
Dec 05 04:56:20.384 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.384 INFO [stdout] 
Dec 05 04:56:20.424 INFO [stdout] 
Dec 05 04:56:20.424 INFO [stderr]      Running /target/debug/deps/mtsv_readprep-515904af44b4671c
Dec 05 04:56:20.424 INFO [stdout] running 0 tests
Dec 05 04:56:20.424 INFO [stdout] 
Dec 05 04:56:20.424 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.424 INFO [stdout] 
Dec 05 04:56:20.428 INFO [stdout] 
Dec 05 04:56:20.428 INFO [stderr]      Running /target/debug/deps/mtsv_signature-e80b84a9fe2abb69
Dec 05 04:56:20.428 INFO [stdout] running 0 tests
Dec 05 04:56:20.428 INFO [stdout] 
Dec 05 04:56:20.428 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.428 INFO [stdout] 
Dec 05 04:56:20.436 INFO [stdout] 
Dec 05 04:56:20.436 INFO [stderr]      Running /target/debug/deps/mtsv_tree_build-6d96b05dbc53defd
Dec 05 04:56:20.437 INFO [stdout] running 0 tests
Dec 05 04:56:20.437 INFO [stdout] 
Dec 05 04:56:20.437 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.437 INFO [stdout] 
Dec 05 04:56:20.449 INFO [stdout] 
Dec 05 04:56:20.449 INFO [stderr]    Doc-tests mtsv
Dec 05 04:56:20.449 INFO [stdout] running 0 tests
Dec 05 04:56:20.449 INFO [stdout] 
Dec 05 04:56:20.449 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:20.449 INFO [stdout] 
Dec 05 04:56:22.171 INFO [stdout] 
Dec 05 04:56:22.171 INFO [stdout] running 0 tests
Dec 05 04:56:22.171 INFO [stdout] 
Dec 05 04:56:22.171 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:22.172 INFO [stdout] 
Dec 05 04:56:22.185 INFO [stderr] su: No module specific data is present
Dec 05 04:56:23.027 INFO running `"docker" "inspect" "79edb5c05e8c1912e8ed8ecef07198debe7c5877552a93a24b8d5d751713907d"`
Dec 05 04:56:23.310 INFO running `"docker" "rm" "-f" "79edb5c05e8c1912e8ed8ecef07198debe7c5877552a93a24b8d5d751713907d"`
Dec 05 04:56:23.680 INFO [stdout] 79edb5c05e8c1912e8ed8ecef07198debe7c5877552a93a24b8d5d751713907d