Dec 13 00:35:53.077 INFO testing tfursten/mtsv_tools against master#bd47d6825bf4090517549d33cfef10d3300b4a75 for pr-56550
Dec 13 00:35:53.077 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-6/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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 13 00:35:53.588 INFO [stdout] fe9f61a3dde60eca2ca1b9200dd3587cff1fce58cd900c22405596c4b184e88e
Dec 13 00:35:53.591 INFO running `"docker" "start" "-a" "fe9f61a3dde60eca2ca1b9200dd3587cff1fce58cd900c22405596c4b184e88e"`
Dec 13 00:35:55.515 INFO [stderr] usermod: no changes
Dec 13 00:35:55.763 INFO [stderr]    Compiling cc v1.0.4
Dec 13 00:35:55.763 INFO [stderr]    Compiling fixedbitset v0.1.8
Dec 13 00:35:55.776 INFO [stderr]    Compiling serde v0.7.15
Dec 13 00:35:55.776 INFO [stderr]    Compiling itertools v0.4.19
Dec 13 00:35:55.783 INFO [stderr]    Compiling rand v0.4.2
Dec 13 00:35:55.783 INFO [stderr]    Compiling memchr v0.1.11
Dec 13 00:35:55.783 INFO [stderr]    Compiling time v0.1.39
Dec 13 00:35:55.783 INFO [stderr]    Compiling xattr v0.1.11
Dec 13 00:35:59.759 INFO [stderr]    Compiling num-integer v0.1.36
Dec 13 00:35:59.767 INFO [stderr]    Compiling num-complex v0.1.42
Dec 13 00:35:59.845 INFO [stderr]    Compiling filetime v0.1.15
Dec 13 00:36:02.608 INFO [stderr]    Compiling bit-set v0.3.0
Dec 13 00:36:05.747 INFO [stderr]    Compiling csv v0.14.7
Dec 13 00:36:10.967 INFO [stderr]    Compiling aho-corasick v0.5.3
Dec 13 00:36:11.031 INFO [stderr]    Compiling petgraph v0.2.7 (/source/vendor/petgraph)
Dec 13 00:36:11.039 INFO [stderr]    Compiling num-iter v0.1.35
Dec 13 00:36:11.055 INFO [stderr]    Compiling tar v0.4.14
Dec 13 00:36:11.136 INFO [stderr]    Compiling clap v2.29.4
Dec 13 00:36:11.336 INFO [stderr]    Compiling miniz-sys v0.1.10
Dec 13 00:36:14.888 INFO [stderr]    Compiling ssw v0.1.0 (/source/ssw)
Dec 13 00:36:15.105 INFO [stderr]    Compiling syncbox v0.2.4
Dec 13 00:36:15.217 INFO [stderr]    Compiling num-bigint v0.1.42
Dec 13 00:36:17.771 INFO [stderr]    Compiling thread-id v2.0.0
Dec 13 00:36:20.432 INFO [stderr]    Compiling thread_local v0.2.7
Dec 13 00:36:23.401 INFO [stderr]    Compiling regex v0.1.80
Dec 13 00:36:26.845 INFO [stderr]    Compiling cue v0.1.0
Dec 13 00:36:26.976 INFO [stderr]    Compiling daggy v0.4.0 (/source/vendor/daggy)
Dec 13 00:36:27.031 INFO [stderr]    Compiling flate2 v0.2.20
Dec 13 00:36:29.943 INFO [stderr]    Compiling bincode v0.5.9
Dec 13 00:36:32.907 INFO [stderr]    Compiling num-rational v0.1.41
Dec 13 00:36:37.491 INFO [stderr]    Compiling num v0.1.41
Dec 13 00:36:37.978 INFO [stderr]    Compiling nalgebra v0.4.0
Dec 13 00:36:37.978 INFO [stderr]    Compiling stopwatch v0.0.6
Dec 13 00:36:37.978 INFO [stderr]    Compiling chrono v0.2.25
Dec 13 00:37:01.468 INFO [stderr]    Compiling env_logger v0.3.5
Dec 13 00:37:09.538 INFO [stderr]    Compiling bio v0.5.0 (/source/vendor/rust-bio)
Dec 13 00:37:15.197 INFO [stderr]    Compiling mtsv v0.4.0 (/source)
Dec 13 00:37:43.979 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1m 48s
Dec 13 00:37:44.015 INFO [stderr] su: No module specific data is present
Dec 13 00:37:45.776 INFO running `"docker" "inspect" "fe9f61a3dde60eca2ca1b9200dd3587cff1fce58cd900c22405596c4b184e88e"`
Dec 13 00:37:46.137 INFO running `"docker" "rm" "-f" "fe9f61a3dde60eca2ca1b9200dd3587cff1fce58cd900c22405596c4b184e88e"`
Dec 13 00:37:46.511 INFO [stdout] fe9f61a3dde60eca2ca1b9200dd3587cff1fce58cd900c22405596c4b184e88e
Dec 13 00:37:46.519 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-6/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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 13 00:37:47.082 INFO [stdout] b5da05ac2c0636c18d316f5f9f64bd0ce5ae6baac938f27ac32eae58352b713b
Dec 13 00:37:47.084 INFO running `"docker" "start" "-a" "b5da05ac2c0636c18d316f5f9f64bd0ce5ae6baac938f27ac32eae58352b713b"`
Dec 13 00:37:49.652 INFO [stderr] usermod: no changes
Dec 13 00:37:49.925 INFO [stderr]    Compiling rand v0.3.22
Dec 13 00:37:50.349 INFO [stderr]    Compiling uuid v0.1.18
Dec 13 00:37:50.350 INFO [stderr]    Compiling quickcheck v0.3.2
Dec 13 00:37:51.485 INFO [stderr]    Compiling mktemp v0.2.1
Dec 13 00:37:54.161 INFO [stderr]    Compiling mtsv v0.4.0 (/source)
Dec 13 00:38:12.683 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 22.99s
Dec 13 00:38:12.693 INFO [stderr] su: No module specific data is present
Dec 13 00:38:13.485 INFO running `"docker" "inspect" "b5da05ac2c0636c18d316f5f9f64bd0ce5ae6baac938f27ac32eae58352b713b"`
Dec 13 00:38:13.811 INFO running `"docker" "rm" "-f" "b5da05ac2c0636c18d316f5f9f64bd0ce5ae6baac938f27ac32eae58352b713b"`
Dec 13 00:38:14.187 INFO [stdout] b5da05ac2c0636c18d316f5f9f64bd0ce5ae6baac938f27ac32eae58352b713b
Dec 13 00:38:14.191 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56550/worker-6/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-6/pr-56550/master#bd47d6825bf4090517549d33cfef10d3300b4a75:/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 +bd47d6825bf4090517549d33cfef10d3300b4a75-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 13 00:38:14.713 INFO [stdout] d5d64feb2f8f08cfbea4a92eeda4814fd8910022f65a0b0df42f937ee01638b6
Dec 13 00:38:14.716 INFO running `"docker" "start" "-a" "d5d64feb2f8f08cfbea4a92eeda4814fd8910022f65a0b0df42f937ee01638b6"`
Dec 13 00:38:16.807 INFO [stderr] usermod: no changes
Dec 13 00:38:16.948 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.12s
Dec 13 00:38:16.967 INFO [stderr]      Running /target/debug/deps/mtsv-0c3140472a76b0c8
Dec 13 00:38:16.969 INFO [stdout] 
Dec 13 00:38:16.969 INFO [stdout] running 71 tests
Dec 13 00:38:17.007 INFO [stdout] test align::test::test_exact_partial ... ok
Dec 13 00:38:17.011 INFO [stdout] test align::test::test_from_jupyter_notebook ... ok
Dec 13 00:38:17.011 INFO [stdout] test align::test::test_begin_edits ... ok
Dec 13 00:38:17.011 INFO [stdout] test align::test::test_empty ... ok
Dec 13 00:38:17.018 INFO [stdout] test align::test::test_exact_full ... ok
Dec 13 00:38:17.018 INFO [stdout] test binner::test::success_empty ... ok
Dec 13 00:38:17.018 INFO [stdout] test align::test::test_nomatches ... ok
Dec 13 00:38:17.018 INFO [stdout] test align::test::test_middle_edits ... ok
Dec 13 00:38:17.018 INFO [stdout] test align::test::test_end_edits ... ok
Dec 13 00:38:17.023 INFO [stdout] test binner::test::success_single_spaces ... ok
Dec 13 00:38:17.023 INFO [stdout] test binner::test::success_many ... ok
Dec 13 00:38:17.043 INFO [stdout] test collapse::test::simple_collapse ... ok
Dec 13 00:38:17.059 INFO [stdout] test builder::test::success ... ok
Dec 13 00:38:17.107 INFO [stdout] test index::test::seed_hits_success ... ok
Dec 13 00:38:17.699 INFO [stdout] test builder::test::fail_empty_header ... ok
Dec 13 00:38:17.803 INFO [stdout] test index::test::seed_hits_fail ... ok
Dec 13 00:38:17.879 INFO [stdout] test index::test::reference_candidate_different_bin ... ok
Dec 13 00:38:17.879 INFO [stdout] test io::test::invalid_ids ... ok
Dec 13 00:38:17.879 INFO [stdout] test io::test::missing_ids ... ok
Dec 13 00:38:17.879 INFO [stdout] test io::test::parsing_positive ... ok
Dec 13 00:38:17.903 INFO [stdout] test io::test::no_read_header ... ok
Dec 13 00:38:17.903 INFO [stdout] test io::test::roundtrip_single ... ok
Dec 13 00:38:17.927 INFO [stdout] test prep::tests::adapters_empty ... ok
Dec 13 00:38:17.927 INFO [stdout] test prep::tests::adapters_none ... ok
Dec 13 00:38:17.939 INFO [stdout] test prep::tests::adapters_present_but_below_tolerance ... ok
Dec 13 00:38:17.939 INFO [stdout] test prep::tests::adapters_present_and_above_tolerance ... ok
Dec 13 00:38:17.983 INFO [stdout] test prep::tests::adapters_whole_sequence ... ok
Dec 13 00:38:18.019 INFO [stdout] test prep::tests::highest_at_start ... ok
Dec 13 00:38:18.039 INFO [stdout] test prep::tests::highest_at_end ... ok
Dec 13 00:38:18.039 INFO [stdout] test prep::tests::highest_in_middle ... ok
Dec 13 00:38:18.044 INFO [stdout] test prep::tests::highest_q_same_length ... ok
Dec 13 00:38:18.048 INFO [stdout] test prep::tests::lcd_trim_diff_length ... ok
Dec 13 00:38:18.051 INFO [stdout] test prep::tests::lcdq_trim_diff_length ... ok
Dec 13 00:38:18.059 INFO [stdout] test prep::tests::lcd_trim_same_length ... ok
Dec 13 00:38:18.157 INFO [stdout] test prep::tests::lcdq_trim_same_length ... ok
Dec 13 00:38:18.159 INFO [stdout] test prep::tests::segment_trim_even_division ... ok
Dec 13 00:38:18.159 INFO [stdout] test prep::tests::quality_filter ... ok
Dec 13 00:38:18.160 INFO [stdout] test prep::tests::segment_trim_same_len ... ok
Dec 13 00:38:18.179 INFO [stdout] test prep::tests::segment_trim_uneven_division ... ok
Dec 13 00:38:18.243 INFO [stdout] test prep::tests::test_highest_q_longer_desired_than_avail ... ok
Dec 13 00:38:18.250 INFO [stdout] test prep::tests::test_highest_q_zero_goal ... ok
Dec 13 00:38:19.047 INFO [stdout] test index::test::reference_candidate_non_overlapping ... ok
Dec 13 00:38:22.103 INFO [stdout] test io::test::io_helpers ... ok
Dec 13 00:38:22.119 INFO [stdout] test prep_config::test::test_subadapters ... ok
Dec 13 00:38:22.159 INFO [stdout] test tax_tree::test::human_ancestors ... ok
Dec 13 00:38:22.179 INFO [stdout] test tax_tree::test::human_siblings_lca ... ok
Dec 13 00:38:22.215 INFO [stdout] test tax_tree::test::human_siblings_rank ... ok
Dec 13 00:38:22.231 INFO [stdout] test tax_tree::test::informative_parent ... ok
Dec 13 00:38:22.243 INFO [stdout] test tax_tree::test::tokenize ... ok
Dec 13 00:38:22.243 INFO [stdout] test tax_tree::test::tokenize_empty ... ok
Dec 13 00:38:22.275 INFO [stdout] test tax_tree::test::tokenize_fail_parent_bad ... ok
Dec 13 00:38:22.299 INFO [stdout] test tax_tree::test::tokenize_fail_parent_missing ... ok
Dec 13 00:38:22.317 INFO [stdout] test tax_tree::test::tokenize_fail_rank_missing ... ok
Dec 13 00:38:22.335 INFO [stdout] test tax_tree::test::tokenize_fail_taxid_bad ... ok
Dec 13 00:38:22.351 INFO [stdout] test tax_tree::test::tokenize_fail_taxid_missing ... ok
Dec 13 00:38:22.363 INFO [stdout] test util::test::fail_decimal_gi ... ok
Dec 13 00:38:22.383 INFO [stdout] test util::test::fail_decimal_taxid ... ok
Dec 13 00:38:22.386 INFO [stdout] test util::test::fail_empty ... ok
Dec 13 00:38:22.403 INFO [stdout] test util::test::fail_empty_nodash ... ok
Dec 13 00:38:22.423 INFO [stdout] test util::test::fail_extra ... ok
Dec 13 00:38:22.431 INFO [stdout] test util::test::fail_non_numeric_gi ... ok
Dec 13 00:38:22.447 INFO [stdout] test util::test::fail_non_numeric_taxid ... ok
Dec 13 00:38:22.479 INFO [stdout] test util::test::lines_for_the_line_throne ... ok
Dec 13 00:38:22.490 INFO [stdout] test util::test::success ... ok
Dec 13 00:38:27.595 INFO [stdout] test prep_config::test::lcd ... ok
Dec 13 00:38:27.607 INFO [stdout] test prep_config::test::segment ... ok
Dec 13 00:38:53.675 INFO [stdout] test io::test::roundtrip_many ... ok
Dec 13 00:39:17.039 INFO [stdout] test index::test::construct_index_lowercase ... test index::test::construct_index_lowercase has been running for over 60 seconds
Dec 13 00:39:17.039 INFO [stdout] test chunk::test::chunk_roundtrip ... test chunk::test::chunk_roundtrip has been running for over 60 seconds
Dec 13 00:39:17.039 INFO [stdout] test index::test::reference_candidate ... test index::test::reference_candidate has been running for over 60 seconds
Dec 13 00:39:18.251 INFO [stdout] test prep::tests::test_prep_integration ... test prep::tests::test_prep_integration has been running for over 60 seconds
Dec 13 00:39:30.291 INFO [stdout] test prep::tests::test_prep_integration ... ok
Dec 13 00:39:54.723 INFO [stdout] test index::test::construct_index_lowercase ... ok
Dec 13 00:40:09.659 INFO [stdout] test chunk::test::chunk_roundtrip ... ok
Dec 13 00:41:08.346 INFO [stdout] test index::test::reference_candidate ... ok
Dec 13 00:41:08.346 INFO [stdout] 
Dec 13 00:41:08.346 INFO [stdout] test result: ok. 71 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.346 INFO [stdout] 
Dec 13 00:41:08.367 INFO [stderr]      Running /target/debug/deps/mtsv_binner-e34fac089ebd97d7
Dec 13 00:41:08.379 INFO [stdout] 
Dec 13 00:41:08.379 INFO [stdout] running 0 tests
Dec 13 00:41:08.379 INFO [stdout] 
Dec 13 00:41:08.379 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.379 INFO [stdout] 
Dec 13 00:41:08.379 INFO [stderr]      Running /target/debug/deps/mtsv_build-567fefa82fd3feeb
Dec 13 00:41:08.403 INFO [stdout] 
Dec 13 00:41:08.403 INFO [stdout] running 0 tests
Dec 13 00:41:08.403 INFO [stdout] 
Dec 13 00:41:08.403 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.403 INFO [stdout] 
Dec 13 00:41:08.403 INFO [stderr]      Running /target/debug/deps/mtsv_chunk-ce5bf3d8bf6c38e9
Dec 13 00:41:08.427 INFO [stdout] 
Dec 13 00:41:08.427 INFO [stdout] running 0 tests
Dec 13 00:41:08.427 INFO [stdout] 
Dec 13 00:41:08.427 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.427 INFO [stdout] 
Dec 13 00:41:08.428 INFO [stderr]      Running /target/debug/deps/mtsv_collapse-e64a2e24885ac8b7
Dec 13 00:41:08.455 INFO [stdout] 
Dec 13 00:41:08.455 INFO [stdout] running 0 tests
Dec 13 00:41:08.455 INFO [stdout] 
Dec 13 00:41:08.455 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.455 INFO [stdout] 
Dec 13 00:41:08.455 INFO [stderr]      Running /target/debug/deps/mtsv_readprep-c0cb77145fb83742
Dec 13 00:41:08.471 INFO [stdout] 
Dec 13 00:41:08.471 INFO [stdout] running 0 tests
Dec 13 00:41:08.471 INFO [stdout] 
Dec 13 00:41:08.471 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.471 INFO [stdout] 
Dec 13 00:41:08.471 INFO [stderr]      Running /target/debug/deps/mtsv_signature-8158a62e818a0507
Dec 13 00:41:08.477 INFO [stdout] 
Dec 13 00:41:08.477 INFO [stdout] running 0 tests
Dec 13 00:41:08.483 INFO [stderr]      Running /target/debug/deps/mtsv_tree_build-2eb719bea4ca62fa
Dec 13 00:41:08.483 INFO [stdout] 
Dec 13 00:41:08.483 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.483 INFO [stdout] 
Dec 13 00:41:08.499 INFO [stdout] 
Dec 13 00:41:08.499 INFO [stdout] running 0 tests
Dec 13 00:41:08.499 INFO [stdout] 
Dec 13 00:41:08.499 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:08.499 INFO [stdout] 
Dec 13 00:41:08.499 INFO [stderr]    Doc-tests mtsv
Dec 13 00:41:10.178 INFO [stdout] 
Dec 13 00:41:10.178 INFO [stdout] running 0 tests
Dec 13 00:41:10.178 INFO [stdout] 
Dec 13 00:41:10.178 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 13 00:41:10.178 INFO [stdout] 
Dec 13 00:41:10.191 INFO [stderr] su: No module specific data is present
Dec 13 00:41:10.842 INFO running `"docker" "inspect" "d5d64feb2f8f08cfbea4a92eeda4814fd8910022f65a0b0df42f937ee01638b6"`
Dec 13 00:41:11.141 INFO running `"docker" "rm" "-f" "d5d64feb2f8f08cfbea4a92eeda4814fd8910022f65a0b0df42f937ee01638b6"`
Dec 13 00:41:11.540 INFO [stdout] d5d64feb2f8f08cfbea4a92eeda4814fd8910022f65a0b0df42f937ee01638b6