Dec 05 04:51:22.907 INFO testing tfursten/mtsv_tools against master#906deae0790bd18681b937fe9a141a3c26cf1855 for pr-56514
Dec 05 04:51:22.907 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-4/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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:23.548 INFO [stdout] 69896db4edb656066658b429f17c42321596918b7ec766db03d8365b33b1ae7b
Dec 05 04:51:23.548 INFO running `"docker" "start" "-a" "69896db4edb656066658b429f17c42321596918b7ec766db03d8365b33b1ae7b"`
Dec 05 04:51:24.792 INFO [stderr] usermod: no changes
Dec 05 04:51:25.016 INFO [stderr]    Compiling bit-vec v0.4.4
Dec 05 04:51:25.016 INFO [stderr]    Compiling itertools v0.4.19
Dec 05 04:51:25.016 INFO [stderr]    Compiling crossbeam v0.2.12
Dec 05 04:51:25.016 INFO [stderr]    Compiling num-integer v0.1.36
Dec 05 04:51:25.016 INFO [stderr]    Compiling rand v0.4.2
Dec 05 04:51:25.016 INFO [stderr]    Compiling memchr v0.1.11
Dec 05 04:51:25.016 INFO [stderr]    Compiling xattr v0.1.11
Dec 05 04:51:25.016 INFO [stderr]    Compiling num-complex v0.1.42
Dec 05 04:51:26.721 INFO [stderr]    Compiling miniz-sys v0.1.10
Dec 05 04:51:29.044 INFO [stderr]    Compiling ssw v0.1.0 (/source/ssw)
Dec 05 04:51:29.076 INFO [stderr]    Compiling petgraph v0.2.7 (/source/vendor/petgraph)
Dec 05 04:51:29.096 INFO [stderr]    Compiling bincode v0.5.9
Dec 05 04:51:29.169 INFO [stderr]    Compiling aho-corasick v0.5.3
Dec 05 04:51:30.964 INFO [stderr]    Compiling num-iter v0.1.35
Dec 05 04:51:31.500 INFO [stderr]    Compiling bit-set v0.3.0
Dec 05 04:51:32.171 INFO [stderr]    Compiling tar v0.4.14
Dec 05 04:51:34.984 INFO [stderr]    Compiling clap v2.29.4
Dec 05 04:51:34.993 INFO [stderr]    Compiling syncbox v0.2.4
Dec 05 04:51:35.125 INFO [stderr]    Compiling thread-id v2.0.0
Dec 05 04:51:36.300 INFO [stderr]    Compiling num-bigint v0.1.42
Dec 05 04:51:39.280 INFO [stderr]    Compiling thread_local v0.2.7
Dec 05 04:51:40.441 INFO [stderr]    Compiling flate2 v0.2.20
Dec 05 04:51:41.732 INFO [stderr]    Compiling regex v0.1.80
Dec 05 04:51:41.934 INFO [stderr]    Compiling cue v0.1.0
Dec 05 04:51:41.995 INFO [stderr]    Compiling daggy v0.4.0 (/source/vendor/daggy)
Dec 05 04:51:50.166 INFO [stderr]    Compiling num-rational v0.1.41
Dec 05 04:51:55.018 INFO [stderr]    Compiling num v0.1.41
Dec 05 04:51:56.150 INFO [stderr]    Compiling nalgebra v0.4.0
Dec 05 04:52:04.324 INFO [stderr]    Compiling stopwatch v0.0.6
Dec 05 04:52:04.325 INFO [stderr]    Compiling chrono v0.2.25
Dec 05 04:52:06.360 INFO [stderr]    Compiling env_logger v0.3.5
Dec 05 04:52:26.140 INFO [stderr]    Compiling bio v0.5.0 (/source/vendor/rust-bio)
Dec 05 04:52:31.212 INFO [stderr]    Compiling mtsv v0.4.0 (/source)
Dec 05 04:53:00.669 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 1m 35s
Dec 05 04:53:00.694 INFO [stderr] su: No module specific data is present
Dec 05 04:53:03.317 INFO running `"docker" "inspect" "69896db4edb656066658b429f17c42321596918b7ec766db03d8365b33b1ae7b"`
Dec 05 04:53:03.619 INFO running `"docker" "rm" "-f" "69896db4edb656066658b429f17c42321596918b7ec766db03d8365b33b1ae7b"`
Dec 05 04:53:03.968 INFO [stdout] 69896db4edb656066658b429f17c42321596918b7ec766db03d8365b33b1ae7b
Dec 05 04:53:03.970 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-4/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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:04.392 INFO [stdout] bb8624c45b92e7a3cf34b91a2d6524ca5b5ed4057641307aef3210703e5c8c84
Dec 05 04:53:04.400 INFO running `"docker" "start" "-a" "bb8624c45b92e7a3cf34b91a2d6524ca5b5ed4057641307aef3210703e5c8c84"`
Dec 05 04:53:05.467 INFO [stderr] usermod: no changes
Dec 05 04:53:05.692 INFO [stderr]    Compiling rand v0.3.22
Dec 05 04:53:05.984 INFO [stderr]    Compiling uuid v0.1.18
Dec 05 04:53:05.984 INFO [stderr]    Compiling quickcheck v0.3.2
Dec 05 04:53:07.160 INFO [stderr]    Compiling mktemp v0.2.1
Dec 05 04:53:09.912 INFO [stderr]    Compiling mtsv v0.4.0 (/source)
Dec 05 04:53:28.555 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 23.06s
Dec 05 04:53:28.568 INFO [stderr] su: No module specific data is present
Dec 05 04:53:29.863 INFO running `"docker" "inspect" "bb8624c45b92e7a3cf34b91a2d6524ca5b5ed4057641307aef3210703e5c8c84"`
Dec 05 04:53:30.346 INFO running `"docker" "rm" "-f" "bb8624c45b92e7a3cf34b91a2d6524ca5b5ed4057641307aef3210703e5c8c84"`
Dec 05 04:53:30.640 INFO [stdout] bb8624c45b92e7a3cf34b91a2d6524ca5b5ed4057641307aef3210703e5c8c84
Dec 05 04:53:30.642 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/pr-56514/worker-4/master#906deae0790bd18681b937fe9a141a3c26cf1855:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-4/pr-56514/master#906deae0790bd18681b937fe9a141a3c26cf1855:/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 +906deae0790bd18681b937fe9a141a3c26cf1855-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:31.071 INFO [stdout] 5b580cd3c6ebdbac4341c4e169084a2f5f461b30843402adfb9d0dfb8066e238
Dec 05 04:53:31.080 INFO running `"docker" "start" "-a" "5b580cd3c6ebdbac4341c4e169084a2f5f461b30843402adfb9d0dfb8066e238"`
Dec 05 04:53:32.301 INFO [stderr] usermod: no changes
Dec 05 04:53:32.532 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.20s
Dec 05 04:53:32.548 INFO [stderr]      Running /target/debug/deps/mtsv-7436181d278bf726
Dec 05 04:53:32.548 INFO [stdout] 
Dec 05 04:53:32.548 INFO [stdout] running 71 tests
Dec 05 04:53:32.548 INFO [stdout] test align::test::test_nomatches ... ok
Dec 05 04:53:32.548 INFO [stdout] test align::test::test_middle_edits ... ok
Dec 05 04:53:32.548 INFO [stdout] test align::test::test_end_edits ... ok
Dec 05 04:53:32.548 INFO [stdout] test align::test::test_from_jupyter_notebook ... ok
Dec 05 04:53:32.550 INFO [stdout] test align::test::test_exact_full ... ok
Dec 05 04:53:32.551 INFO [stdout] test align::test::test_empty ... ok
Dec 05 04:53:32.551 INFO [stdout] test binner::test::success_empty ... ok
Dec 05 04:53:32.551 INFO [stdout] test align::test::test_exact_partial ... ok
Dec 05 04:53:32.551 INFO [stdout] test align::test::test_begin_edits ... ok
Dec 05 04:53:32.551 INFO [stdout] test binner::test::success_single_spaces ... ok
Dec 05 04:53:32.584 INFO [stdout] test binner::test::success_many ... ok
Dec 05 04:53:32.601 INFO [stdout] test collapse::test::simple_collapse ... ok
Dec 05 04:53:32.636 INFO [stdout] test builder::test::success ... ok
Dec 05 04:53:32.652 INFO [stdout] test index::test::seed_hits_success ... ok
Dec 05 04:53:33.028 INFO [stdout] test index::test::seed_hits_fail ... ok
Dec 05 04:53:33.028 INFO [stdout] test builder::test::fail_empty_header ... ok
Dec 05 04:53:33.140 INFO [stdout] test index::test::reference_candidate_different_bin ... ok
Dec 05 04:53:33.148 INFO [stdout] test io::test::invalid_ids ... ok
Dec 05 04:53:33.148 INFO [stdout] test io::test::missing_ids ... ok
Dec 05 04:53:33.152 INFO [stdout] test io::test::no_read_header ... ok
Dec 05 04:53:33.152 INFO [stdout] test io::test::parsing_positive ... ok
Dec 05 04:53:33.164 INFO [stdout] test io::test::roundtrip_single ... ok
Dec 05 04:53:33.164 INFO [stdout] test prep::tests::adapters_empty ... ok
Dec 05 04:53:33.168 INFO [stdout] test prep::tests::adapters_none ... ok
Dec 05 04:53:33.184 INFO [stdout] test prep::tests::adapters_present_and_above_tolerance ... ok
Dec 05 04:53:33.184 INFO [stdout] test prep::tests::adapters_whole_sequence ... ok
Dec 05 04:53:33.184 INFO [stdout] test prep::tests::adapters_present_but_below_tolerance ... ok
Dec 05 04:53:33.212 INFO [stdout] test prep::tests::highest_at_end ... ok
Dec 05 04:53:33.212 INFO [stdout] test prep::tests::highest_at_start ... ok
Dec 05 04:53:33.228 INFO [stdout] test prep::tests::highest_q_same_length ... ok
Dec 05 04:53:33.232 INFO [stdout] test prep::tests::lcd_trim_diff_length ... ok
Dec 05 04:53:33.248 INFO [stdout] test prep::tests::highest_in_middle ... ok
Dec 05 04:53:33.248 INFO [stdout] test prep::tests::lcd_trim_same_length ... ok
Dec 05 04:53:33.280 INFO [stdout] test prep::tests::lcdq_trim_same_length ... ok
Dec 05 04:53:33.280 INFO [stdout] test prep::tests::lcdq_trim_diff_length ... ok
Dec 05 04:53:33.284 INFO [stdout] test prep::tests::quality_filter ... ok
Dec 05 04:53:33.284 INFO [stdout] test prep::tests::segment_trim_same_len ... ok
Dec 05 04:53:33.292 INFO [stdout] test prep::tests::segment_trim_even_division ... ok
Dec 05 04:53:33.340 INFO [stdout] test prep::tests::segment_trim_uneven_division ... ok
Dec 05 04:53:33.408 INFO [stdout] test prep::tests::test_highest_q_zero_goal ... ok
Dec 05 04:53:33.408 INFO [stdout] test prep::tests::test_highest_q_longer_desired_than_avail ... ok
Dec 05 04:53:33.830 INFO [stdout] test index::test::reference_candidate_non_overlapping ... ok
Dec 05 04:53:36.944 INFO [stdout] test io::test::io_helpers ... ok
Dec 05 04:53:36.944 INFO [stdout] test prep_config::test::test_subadapters ... ok
Dec 05 04:53:36.964 INFO [stdout] test tax_tree::test::human_ancestors ... ok
Dec 05 04:53:36.976 INFO [stdout] test tax_tree::test::human_siblings_lca ... ok
Dec 05 04:53:36.992 INFO [stdout] test tax_tree::test::human_siblings_rank ... ok
Dec 05 04:53:37.004 INFO [stdout] test tax_tree::test::informative_parent ... ok
Dec 05 04:53:37.016 INFO [stdout] test tax_tree::test::tokenize ... ok
Dec 05 04:53:37.016 INFO [stdout] test tax_tree::test::tokenize_empty ... ok
Dec 05 04:53:37.049 INFO [stdout] test tax_tree::test::tokenize_fail_parent_bad ... ok
Dec 05 04:53:37.080 INFO [stdout] test tax_tree::test::tokenize_fail_parent_missing ... ok
Dec 05 04:53:37.157 INFO [stdout] test tax_tree::test::tokenize_fail_rank_missing ... ok
Dec 05 04:53:37.172 INFO [stdout] test tax_tree::test::tokenize_fail_taxid_bad ... ok
Dec 05 04:53:37.172 INFO [stdout] test tax_tree::test::tokenize_fail_taxid_missing ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_decimal_gi ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_decimal_taxid ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_empty ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_empty_nodash ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_extra ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_non_numeric_gi ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::fail_non_numeric_taxid ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::lines_for_the_line_throne ... ok
Dec 05 04:53:37.172 INFO [stdout] test util::test::success ... ok
Dec 05 04:53:40.840 INFO [stdout] test prep_config::test::segment ... ok
Dec 05 04:53:41.249 INFO [stdout] test prep_config::test::lcd ... ok
Dec 05 04:53:58.596 INFO [stdout] test io::test::roundtrip_many ... ok
Dec 05 04:54:32.553 INFO [stdout] test index::test::reference_candidate ... test index::test::reference_candidate has been running for over 60 seconds
Dec 05 04:54:32.553 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:32.553 INFO [stdout] test chunk::test::chunk_roundtrip ... test chunk::test::chunk_roundtrip has been running for over 60 seconds
Dec 05 04:54:33.419 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.177 INFO [stdout] test prep::tests::test_prep_integration ... ok
Dec 05 04:55:07.580 INFO [stdout] test index::test::construct_index_lowercase ... ok
Dec 05 04:55:20.932 INFO [stdout] test chunk::test::chunk_roundtrip ... ok
Dec 05 04:56:21.458 INFO [stdout] test index::test::reference_candidate ... ok
Dec 05 04:56:21.458 INFO [stdout] 
Dec 05 04:56:21.458 INFO [stdout] test result: ok. 71 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.458 INFO [stdout] 
Dec 05 04:56:21.463 INFO [stderr]      Running /target/debug/deps/mtsv_binner-b627f419ff38c8bb
Dec 05 04:56:21.484 INFO [stderr]      Running /target/debug/deps/mtsv_build-a5a7b8aa861b7d62
Dec 05 04:56:21.484 INFO [stdout] 
Dec 05 04:56:21.484 INFO [stdout] running 0 tests
Dec 05 04:56:21.484 INFO [stdout] 
Dec 05 04:56:21.484 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.484 INFO [stdout] 
Dec 05 04:56:21.504 INFO [stdout] 
Dec 05 04:56:21.504 INFO [stdout] running 0 tests
Dec 05 04:56:21.504 INFO [stdout] 
Dec 05 04:56:21.504 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.504 INFO [stdout] 
Dec 05 04:56:21.505 INFO [stderr]      Running /target/debug/deps/mtsv_chunk-107d0fd2a4797579
Dec 05 04:56:21.536 INFO [stderr]      Running /target/debug/deps/mtsv_collapse-101d7e03a9cd550f
Dec 05 04:56:21.536 INFO [stdout] 
Dec 05 04:56:21.536 INFO [stdout] running 0 tests
Dec 05 04:56:21.536 INFO [stdout] 
Dec 05 04:56:21.536 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.536 INFO [stdout] 
Dec 05 04:56:21.564 INFO [stderr]      Running /target/debug/deps/mtsv_readprep-649f0b1a7ca4f9fb
Dec 05 04:56:21.564 INFO [stdout] 
Dec 05 04:56:21.564 INFO [stdout] running 0 tests
Dec 05 04:56:21.564 INFO [stdout] 
Dec 05 04:56:21.564 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.564 INFO [stdout] 
Dec 05 04:56:21.571 INFO [stdout] 
Dec 05 04:56:21.571 INFO [stdout] running 0 tests
Dec 05 04:56:21.572 INFO [stdout] 
Dec 05 04:56:21.572 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.572 INFO [stdout] 
Dec 05 04:56:21.572 INFO [stderr]      Running /target/debug/deps/mtsv_signature-9f131f99d8f168b2
Dec 05 04:56:21.591 INFO [stdout] 
Dec 05 04:56:21.591 INFO [stdout] running 0 tests
Dec 05 04:56:21.591 INFO [stdout] 
Dec 05 04:56:21.591 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.591 INFO [stdout] 
Dec 05 04:56:21.592 INFO [stderr]      Running /target/debug/deps/mtsv_tree_build-ab9ab79f35296213
Dec 05 04:56:21.603 INFO [stdout] 
Dec 05 04:56:21.603 INFO [stdout] running 0 tests
Dec 05 04:56:21.604 INFO [stdout] 
Dec 05 04:56:21.604 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:21.604 INFO [stdout] 
Dec 05 04:56:21.604 INFO [stderr]    Doc-tests mtsv
Dec 05 04:56:23.184 INFO [stdout] 
Dec 05 04:56:23.184 INFO [stdout] running 0 tests
Dec 05 04:56:23.184 INFO [stdout] 
Dec 05 04:56:23.184 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 05 04:56:23.184 INFO [stdout] 
Dec 05 04:56:23.192 INFO [stderr] su: No module specific data is present
Dec 05 04:56:24.286 INFO running `"docker" "inspect" "5b580cd3c6ebdbac4341c4e169084a2f5f461b30843402adfb9d0dfb8066e238"`
Dec 05 04:56:24.592 INFO running `"docker" "rm" "-f" "5b580cd3c6ebdbac4341c4e169084a2f5f461b30843402adfb9d0dfb8066e238"`
Dec 05 04:56:25.048 INFO [stdout] 5b580cd3c6ebdbac4341c4e169084a2f5f461b30843402adfb9d0dfb8066e238