[INFO] cloning repository https://github.com/aywrite/arche
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/aywrite/arche" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Faywrite%2Farche", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Faywrite%2Farche'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] e8e795ca9121df73b071aa59539ddeb097a17367
[INFO] testing aywrite/arche against 1.100.0-beta.1+cargoflags=--release for beta-release-1.100-2
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Faywrite%2Farche" "/workspace/builds/worker-3-tc2/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-3-tc2/source'...
[INFO] [stderr] done.
[INFO] removed /workspace/builds/worker-3-tc2/source/.cargo/config.toml
[INFO] removed /workspace/builds/worker-3-tc2/source/rust-toolchain.toml
[INFO] started tweaking git repo https://github.com/aywrite/arche
[INFO] finished tweaking git repo https://github.com/aywrite/arche
[INFO] tweaked toml for git repo https://github.com/aywrite/arche written to /workspace/builds/worker-3-tc2/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/aywrite/arche on toolchain 1.100.0-beta.1
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.100.0-beta.1" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate git repo https://github.com/aywrite/arche already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.100.0-beta.1" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc2/target:/opt/rustwide/target:rw,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" "-m" "1610612736" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:77db811e55d90add9212f6832c23229e3de5f1c1f9905e8cb07319ea15df73ac" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] 67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd
[INFO] running `Command { std: "docker" "start" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-w" "/opt/rustwide/workdir" "--user" "0:0" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling smallvec v1.16.3
[INFO] [stderr]    Compiling arche-core v0.4.10-rc.2 (/opt/rustwide/workdir/arche-core)
[INFO] [stderr]    Compiling arche v0.4.10-rc.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 39.37s
[INFO] running `Command { std: "docker" "inspect" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen" "--no-run" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling libc v0.2.189
[INFO] [stderr]    Compiling cfg-if v1.0.4
[INFO] [stderr]    Compiling getrandom v0.3.4
[INFO] [stderr]    Compiling getrandom v0.4.3
[INFO] [stderr]    Compiling zerocopy v0.8.55
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling linux-raw-sys v0.12.1
[INFO] [stderr]    Compiling autocfg v1.5.1
[INFO] [stderr]    Compiling bitflags v2.13.1
[INFO] [stderr]    Compiling fastrand v2.5.0
[INFO] [stderr]    Compiling once_cell v1.21.4
[INFO] [stderr]    Compiling quick-error v1.2.3
[INFO] [stderr]    Compiling fnv v1.0.7
[INFO] [stderr]    Compiling bit-vec v0.8.0
[INFO] [stderr]    Compiling regex-syntax v0.8.11
[INFO] [stderr]    Compiling unarray v0.1.4
[INFO] [stderr]    Compiling bit-set v0.8.0
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling wait-timeout v0.2.1
[INFO] [stderr]    Compiling rand_core v0.9.5
[INFO] [stderr]    Compiling rand_xorshift v0.4.0
[INFO] [stderr]    Compiling rand v0.9.5
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling rusty-fork v0.3.1
[INFO] [stderr]    Compiling ppv-lite86 v0.2.21
[INFO] [stderr]    Compiling rand_chacha v0.9.0
[INFO] [stderr]    Compiling proptest v1.11.0
[INFO] [stderr]    Compiling arche v0.4.10-rc.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 1m 23s
[INFO] running `Command { std: "docker" "inspect" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "exec" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "RUSTDOCFLAGS=--cap-lints=warn" "-w" "/opt/rustwide/workdir" "--user" "0:0" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen" "--release", kill_on_drop: false }`
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 0.13s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/release/build/arche/20f4eaf345d2599d/out/arche-20f4eaf345d2599d)
[INFO] [stdout] 
[INFO] [stdout] running 163 tests
[INFO] [stdout] test command::tests::the_command_word_standing_last_asks_for_the_default_depth ... ok
[INFO] [stdout] test instruments::tests::an_off_given_no_value_names_the_switches ... ok
[INFO] [stdout] test command::tests::a_word_it_does_not_know_is_named ... ok
[INFO] [stdout] test command::tests::a_keyword_with_no_value_left_is_left_to_its_own_reader ... ok
[INFO] [stdout] test command::tests::a_depthless_argument_refuses_a_word_where_the_depth_would_be ... ok
[INFO] [stdout] test command::tests::the_spelling_names_every_word_the_argument_takes ... ok
[INFO] [stdout] test instruments::tests::a_residuals_argument_reads_its_taint_policy ... ok
[INFO] [stdout] test command::tests::what_it_takes_is_what_may_stand_where_the_depth_would ... ok
[INFO] [stdout] test instruments::tests::an_effort_argument_reads_its_switch_and_budget ... ok
[INFO] [stdout] test command::tests::an_argument_that_runs_no_search_spells_no_depth ... ok
[INFO] [stdout] test instruments::tests::an_unreadable_effort_switch_or_budget_is_named_rather_than_run ... ok
[INFO] [stdout] test instruments::tests::every_instrument_defaults_to_the_benchs_depth_and_its_own_rate ... ok
[INFO] [stdout] test instruments::tests::an_unreadable_sampling_setting_is_named_rather_than_run ... ok
[INFO] [stdout] test instruments::tests::every_keyword_given_no_value_is_refused_by_the_reader_that_takes_it ... ok
[INFO] [stdout] test instruments::tests::an_unreadable_terms_setting_is_named_rather_than_run ... ok
[INFO] [stdout] test command::tests::the_depths_place_is_left_to_the_caller ... ok
[INFO] [stdout] test instruments::tests::every_instrument_refuses_a_keyword_given_twice ... ok
[INFO] [stdout] test command::tests::a_keywords_value_is_not_judged_on_its_own ... ok
[INFO] [stdout] test instruments::tests::every_instrument_reads_its_name_alone ... ok
[INFO] [stdout] test instruments::tests::every_instrument_refuses_a_word_it_does_not_know ... ok
[INFO] [stdout] test instruments::tests::every_sampling_instrument_reads_its_depth_rate_and_cap ... ok
[INFO] [stdout] test instruments::tests::every_instrument_that_takes_a_suite_refuses_one_that_is_no_suite ... ok
[INFO] [stdout] test command::tests::a_keyword_given_twice_is_refused_under_its_own_name ... ok
[INFO] [stdout] test instruments::tests::forced_reads_the_kinds_named_and_refuses_the_rest ... ok
[INFO] [stdout] test params::tests::a_keyword_only_counts_as_a_whole_word ... ok
[INFO] [stdout] test params::tests::a_keyword_that_is_not_there_at_all_is_absent ... ok
[INFO] [stdout] test params::tests::a_keyword_used_twice_reads_the_first ... ok
[INFO] [stdout] test command::tests::a_line_of_words_it_knows_has_nothing_unclaimed ... ok
[INFO] [stdout] test params::tests::a_keyword_with_nothing_after_it_is_bare_rather_than_absent ... ok
[INFO] [stdout] test params::properties::a_count_reads_back_as_itself ... ok
[INFO] [stdout] test params::properties::absent_and_bare_are_the_two_ways_there_is_no_word_to_read ... ok
[INFO] [stdout] test params::tests::a_value_is_the_word_after_its_keyword ... ok
[INFO] [stdout] test params::tests::a_value_may_be_a_keyword_of_its_own ... ok
[INFO] [stdout] test params::properties::the_strict_read_agrees_with_the_standard_library ... ok
[INFO] [stdout] test params::tests::a_leading_plus_is_a_count ... ok
[INFO] [stdout] test params::tests::a_phrase_is_every_word_up_to_the_one_that_ends_it ... ok
[INFO] [stdout] test params::properties::a_keyword_inside_a_longer_word_is_absent ... ok
[INFO] [stdout] test instruments::tests::the_bench_argument_ends_its_last_line ... ok
[INFO] [stdout] test params::properties::any_negative_count_is_a_spent_one ... ok
[INFO] [stdout] test params::tests::a_word_that_is_no_number_at_all_is_unreadable ... ok
[INFO] [stdout] test session::tests::a_stop_is_spent_by_its_own_dispatch_and_no_other ... ok
[INFO] [stdout] test params::tests::a_phrase_with_no_words_in_it_is_absent ... ok
[INFO] [stdout] test session::tests::an_isready_read_behind_a_queued_go_is_answered_by_the_reader ... ok
[INFO] [stdout] test params::tests::or_refuse_names_the_setting_and_what_stood_where_its_value_would ... ok
[INFO] [stdout] test params::tests::parse_refuses_what_will_not_fit_rather_than_rounding_it ... ok
[INFO] [stdout] test session::tests::lines_queued_when_the_log_opens_follow_the_line_that_opened_it ... ok
[INFO] [stdout] test params::tests::read_discards_every_kind_of_missing_value ... ok
[INFO] [stdout] test session::tests::output_is_marked_a_line_at_a_time_however_it_is_written ... ok
[INFO] [stdout] test session::tests::a_line_reached_that_was_never_held_releases_no_other ... ok
[INFO] [stdout] test session::tests::a_stop_dispatched_with_none_read_raises_nothing ... ok
[INFO] [stdout] test params::tests::an_empty_line_has_no_parameters_and_does_not_panic ... ok
[INFO] [stdout] test session::tests::a_line_that_is_not_utf8_is_dropped_and_the_rest_read ... ok
[INFO] [stdout] test params::properties::spacing_does_not_change_what_is_read ... ok
[INFO] [stdout] test time_control::tests::an_increment_with_no_clock_is_partly_spent ... ok
[INFO] [stdout] test time_control::tests::infinite_beats_move_time ... ok
[INFO] [stdout] test time_control::tests::move_time_ignores_the_clock_and_the_increment ... ok
[INFO] [stdout] test time_control::tests::a_move_time_is_named_and_everything_else_is_a_share ... ok
[INFO] [stdout] test time_control::tests::a_spent_clock_still_leaves_time_to_move ... ok
[INFO] [stdout] test time_control::tests::an_increment_never_spends_more_than_the_clock ... ok
[INFO] [stdout] test session::tests::setting_the_log_again_does_not_write_its_line_twice ... ok
[INFO] [stdout] test time_control::tests::a_clock_too_large_to_multiply_is_still_capped ... ok
[INFO] [stdout] test time_control::tests::a_depth_under_way_may_run_on_to_three_shares ... ok
[INFO] [stdout] test time_control::tests::a_first_move_at_or_past_sixty_falls_to_ten_a_move_later ... ok
[INFO] [stdout] test time_control::tests::a_move_time_and_a_bare_increment_have_nothing_past_the_budget ... ok
[INFO] [stdout] test time_control::tests::infinite_beats_the_clock ... ok
[INFO] [stdout] test params::properties::any_count_too_large_is_the_largest_one ... ok
[INFO] [stdout] test time_control::tests::move_time_is_spent_less_the_overhead ... ok
[INFO] [stdout] test time_control::tests::moves_to_go_of_zero_is_treated_as_no_answer ... ok
[INFO] [stdout] test time_control::tests::the_limit_takes_no_more_than_a_quarter_of_the_clock ... ok
[INFO] [stdout] test params::properties::every_keyword_reads_its_own_value ... ok
[INFO] [stdout] test time_control::tests::the_overhead_is_whatever_the_option_was_set_to ... ok
[INFO] [stdout] test time_control::tests::only_part_of_the_increment_is_banked ... ok
[INFO] [stdout] test time_control::tests::moves_to_go_is_read_whatever_the_move ... ok
[INFO] [stdout] test time_control::tests::no_time_information_has_no_budget ... ok
[INFO] [stdout] test time_control::tests::the_cap_decides_only_on_a_nearly_spent_clock ... ok
[INFO] [stdout] test time_control::tests::sudden_death_plans_for_twenty_more_moves_at_the_first_move ... ok
[INFO] [stdout] test time_control::tests::moves_to_go_divides_the_clock ... ok
[INFO] [stdout] test time_control::tests::the_horizon_falls_from_twenty_to_ten_by_move_sixty ... ok
[INFO] [stdout] test time_control::tests::the_limit_is_never_below_the_share ... ok
[INFO] [stdout] test time_control::tests::the_last_move_before_the_control_is_still_capped ... ok
[INFO] [stdout] test params::properties::nothing_read_out_of_anything_panics ... ok
[INFO] [stdout] test uci::tests::a_command_is_its_first_word_wherever_the_line_starts ... ok
[INFO] [stdout] test uci::tests::a_debug_log_that_cannot_be_opened_is_said_and_the_session_carries_on ... ok
[INFO] [stdout] test uci::tests::a_depth_is_read_as_far_as_the_ply_rail_and_no_further ... ok
[INFO] [stdout] test uci::tests::a_go_whose_numbers_cannot_be_read_is_refused_without_a_search ... ok
[INFO] [stdout] test uci::tests::a_move_overhead_outside_the_range_offered_is_clamped_and_said_back ... ok
[INFO] [stdout] test uci::tests::a_go_after_a_refused_position_answers_the_null_move_until_one_is_set ... ok
[INFO] [stdout] test uci::tests::a_move_overhead_that_cannot_be_read_leaves_the_one_in_force ... ok
[INFO] [stdout] test uci::tests::a_ceiling_is_not_the_report_the_last_line_is_built_from ... ok
[INFO] [stdout] test uci::tests::a_move_that_cannot_be_played_is_reported_with_the_reason ... ok
[INFO] [stdout] test uci::tests::a_move_overhead_inside_the_range_is_taken_in_silence ... ok
[INFO] [stdout] test uci::tests::a_claimable_fifty_move_draw_is_answered_with_a_move ... ok
[INFO] [stdout] test uci::tests::a_new_game_keeps_the_move_overhead_it_was_given ... ok
[INFO] [stdout] test uci::tests::a_depth_of_zero_still_answers_with_a_move ... ok
[INFO] [stdout] test uci::tests::a_new_game_leaves_the_position_to_the_next_position_line ... ok
[INFO] [stdout] test uci::tests::a_perft_command_counts_without_disturbing_the_position ... ok
[INFO] [stdout] test uci::tests::a_perft_command_reads_its_depth ... ok
[INFO] [stdout] test uci::tests::a_perft_command_reports_its_count ... ok
[INFO] [stdout] test uci::tests::a_panic_is_said_where_the_interface_can_read_it ... ok
[INFO] [stdout] test uci::tests::a_position_can_be_set_from_the_start_or_from_a_fen ... ok
[INFO] [stdout] test uci::tests::a_position_with_no_legal_moves_reports_the_null_move ... ok
[INFO] [stdout] test uci::tests::a_position_word_must_be_whole ... ok
[INFO] [stdout] test uci::tests::a_new_game_or_an_earlier_move_starts_the_horizon_again ... ok
[INFO] [stdout] test uci::tests::a_bounded_go_answers_without_being_stopped ... ok
[INFO] [stdout] test uci::tests::a_report_is_said_as_an_info_line ... ok
[INFO] [stdout] test uci::tests::a_debug_log_on_a_fifo_is_refused_rather_than_waited_on ... ok
[INFO] [stdout] test uci::tests::a_search_is_given_the_clock_of_the_side_to_move ... ok
[INFO] [stdout] test uci::tests::a_node_limit_is_honoured_end_to_end ... ok
[INFO] [stdout] test uci::tests::a_search_on_a_negative_clock_still_answers_with_a_move ... ok
[INFO] [stdout] test instruments::tests::every_instrument_that_takes_a_suite_reads_the_one_it_was_given ... ok
[INFO] [stdout] test uci::tests::a_quit_during_a_search_answers_before_it_exits ... ok
[INFO] [stdout] test uci::tests::a_search_reports_how_full_its_table_is ... ok
[INFO] [stdout] test uci::tests::a_search_reports_each_depth_and_then_its_move ... ok
[INFO] [stdout] test uci::tests::a_go_that_cannot_be_read_answers_without_waiting_for_a_stop ... ok
[INFO] [stdout] test uci::tests::a_bench_command_takes_the_signature_audit ... ok
[INFO] [stdout] test uci::tests::a_setoption_without_a_name_is_reported_rather_than_fatal ... ok
[INFO] [stdout] test uci::tests::a_new_game_keeps_the_table_size_it_was_given ... ok
[INFO] [stdout] test uci::tests::a_hash_size_is_taken_as_sent_or_clamped_up_to_the_smallest_offered ... ok
[INFO] [stdout] test uci::tests::a_table_smaller_than_the_session_asked_for_is_said_and_one_that_is_not_is_silent ... ok
[INFO] [stdout] test uci::tests::an_iteration_that_reported_nothing_is_counted_in_the_last_line ... ok
[INFO] [stdout] test uci::tests::a_hash_value_that_cannot_be_read_leaves_the_table_alone ... ok
[INFO] [stdout] test uci::tests::a_real_engine_keeps_the_same_promises ... ok
[INFO] [stdout] test uci::tests::a_position_sent_during_a_search_is_applied_after_it ... ok
[INFO] [stdout] test uci::tests::an_option_named_with_two_words_is_read_as_both_of_them ... ok
[INFO] [stdout] test uci::tests::a_stop_while_nothing_is_searching_is_taken_in_silence ... ok
[INFO] [stdout] test uci::tests::a_stop_mid_search_answers_with_a_real_move ... ok
[INFO] [stdout] test uci::tests::an_option_we_do_not_have_is_reported_by_name ... ok
[INFO] [stdout] test uci::tests::an_isready_is_answered_while_a_search_runs ... ok
[INFO] [stdout] test uci::tests::a_bench_command_takes_a_table_size_and_a_taint_policy ... ok
[INFO] [stdout] test uci::tests::any_other_thread_count_is_said_back_and_then_played_on_anyway ... ok
[INFO] [stdout] test uci::tests::an_unreadable_bench_setting_is_reported_rather_than_searched ... ok
[INFO] [stdout] test uci::tests::isready_is_answered_with_readyok_alone ... ok
[INFO] [stdout] test uci::tests::malformed_positions_are_reported_rather_than_fatal ... ok
[INFO] [stdout] test uci::tests::display_speaks_through_the_writer_as_info_strings ... ok
[INFO] [stdout] test uci::tests::the_clear_hash_button_reaches_the_engine_in_silence ... ok
[INFO] [stdout] test uci::tests::every_spin_row_is_read_and_held_to_its_own_range ... ok
[INFO] [stdout] test uci::tests::the_debug_log_path_is_the_rest_of_the_line_and_empty_closes_it ... ok
[INFO] [stdout] test uci::tests::quit_stops_the_loop_and_leaves_the_rest_unread ... ok
[INFO] [stdout] test uci::tests::the_horizon_falls_from_the_first_move_searched_on_a_clock ... ok
[INFO] [stdout] test uci::tests::the_games_suite_takes_no_depth ... ok
[INFO] [stdout] test uci::tests::moves_after_a_position_are_played ... ok
[INFO] [stdout] test uci::tests::the_handshake_identifies_the_engine_and_ends_with_uciok ... ok
[INFO] [stdout] test uci::tests::the_loop_ends_when_the_input_does ... ok
[INFO] [stdout] test uci::tests::the_move_a_swap_answers_with_opens_the_last_line_said ... ok
[INFO] [stdout] test uci::tests::unrecognised_and_empty_commands_are_survivable ... ok
[INFO] [stdout] test uci::tests::what_a_go_line_asks_of_the_search ... ok
[INFO] [stdout] test uci::tests::the_move_overhead_the_option_sets_is_held_back_from_the_budget ... ok
[INFO] [stdout] test uci::tests::what_could_not_be_acted_on_is_reported_as_an_info_string ... ok
[INFO] [stdout] test uci::tests::the_threads_option_takes_one_in_silence ... ok
[INFO] [stdout] test uci::tests::what_holds_its_answer_is_what_nothing_bounds ... ok
[INFO] [stdout] test uci::tests::what_the_clock_words_on_a_go_line_are_read_as ... ok
[INFO] [stdout] test uci::tests::a_session_is_answered_in_the_protocol ... ok
[INFO] [stdout] test uci::tests::a_stop_read_before_its_search_begins_still_stops_it ... ok
[INFO] [stdout] test uci::tests::an_isready_read_before_its_go_is_dispatched_is_answered ... ok
[INFO] [stdout] test uci::tests::the_table_can_be_resized_between_two_searches_and_after_a_new_game ... ok
[INFO] [stdout] test uci::tests::each_of_two_quick_searches_is_stopped_by_its_own_stop ... ok
[INFO] [stdout] test uci::tests::every_go_is_answered_exactly_once ... ok
[INFO] [stdout] test uci::tests::the_interface_leaving_ends_a_held_answer ... ok
[INFO] [stdout] test uci::tests::a_stop_while_idle_leaves_the_next_searches_their_own_stops ... ok
[INFO] [stdout] test uci::tests::an_option_name_is_matched_whatever_its_case ... ok
[INFO] [stdout] test uci::tests::a_quit_ends_the_session ... ok
[INFO] [stdout] test uci::tests::a_go_nothing_bounds_holds_its_move_until_a_stop_arrives ... ok
[INFO] [stdout] test uci::tests::a_bench_command_ends_with_the_line_the_match_tools_read ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 163 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.19s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/release/build/arche/ed941c564f593135/out/arche-ed941c564f593135)
[INFO] [stderr]      Running tests/cutoffs_session.rs (/opt/rustwide/target/release/build/arche/16a3632643aa6f6d/out/cutoffs_session-16a3632643aa6f6d)
[INFO] [stdout] 
[INFO] [stdout] running 2 tests
[INFO] [stdout] test tests::the_usage_ends_in_a_newline ... ok
[INFO] [stdout] test tests::the_usage_spells_every_word_every_command_takes ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test the_cutoffs_argument_prints_a_header_rows_and_a_summary ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.12s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/effort_session.rs (/opt/rustwide/target/release/build/arche/9598fc5dcb37ae7f/out/effort_session-9598fc5dcb37ae7f)
[INFO] [stdout] 
[INFO] [stdout] running 3 tests
[INFO] [stdout] test a_switch_the_engine_does_not_have_is_refused ... ok
[INFO] [stderr]      Running tests/forced_session.rs (/opt/rustwide/target/release/build/arche/c7f048fbfcb82e7b/out/forced_session-c7f048fbfcb82e7b)
[INFO] [stdout] test the_effort_argument_prints_a_header_rows_and_two_summaries ... ok
[INFO] [stdout] test the_null_run_parts_the_two_sides_nowhere ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.19s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stderr]      Running tests/reductions_session.rs (/opt/rustwide/target/release/build/arche/c3bc502cac51ed92/out/reductions_session-c3bc502cac51ed92)
[INFO] [stdout] test the_forced_argument_prints_a_header_rows_and_a_line_a_kind_and_a_root ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.33s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test the_reductions_argument_prints_a_header_rows_and_a_summary ... ok
[INFO] [stderr]      Running tests/residuals_session.rs (/opt/rustwide/target/release/build/arche/563dd4b94076742a/out/residuals_session-563dd4b94076742a)
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.92s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test the_residuals_argument_prints_a_header_rows_and_a_summary ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.16s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/uci_session.rs (/opt/rustwide/target/release/build/arche/ef9324301455aa71/out/uci_session-ef9324301455aa71)
[INFO] [stdout] 
[INFO] [stdout] running 17 tests
[INFO] [stderr] unrecognised argument: --frobnicate
[INFO] [stdout] test an_unrecognised_argument_fails_with_the_code_the_scripts_check ... ok
[INFO] [stdout] test the_version_and_the_help_answer_and_exit_cleanly ... ok
[INFO] [stdout] test a_setting_that_cannot_be_read_is_refused_on_stderr ... ok
[INFO] [stdout] test the_bench_argument_prints_the_line_the_match_tools_read ... ok
[INFO] [stdout] test a_root_move_that_reaches_beta_is_reported_as_a_floor_and_then_answered_with ... FAILED
[INFO] [stdout] test a_stop_ends_an_infinite_search_with_a_real_move ... FAILED
[INFO] [stdout] test a_fen_without_its_counters_is_the_position_searched ... FAILED
[INFO] [stdout] test the_move_a_swap_answers_with_opens_the_last_line_said ... FAILED
[INFO] [stdout] test a_stop_with_nothing_running_is_taken_in_silence ... FAILED
[INFO] [stdout] test the_debug_log_holds_every_line_read_and_said_in_order ... FAILED
[INFO] [stdout] test the_handshake_answers_the_way_the_smoke_test_expects ... FAILED
[INFO] [stdout] test an_infinite_search_holds_its_answer_for_the_stop ... ok
[INFO] [stdout] test the_interface_hanging_up_ends_the_engine ... FAILED
[INFO] [stdout] test the_clear_hash_button_empties_the_table ... ok
[INFO] [stdout] test an_iteration_no_root_move_reached_answers_with_the_depth_before_it ... ok
[INFO] [stdout] test a_go_after_a_refused_position_is_answered_with_the_null_move ... ok
[INFO] [stdout] test a_floor_answers_until_the_wider_search_replaces_it ... ok
[INFO] [stderr] error: test failed, to rerun pass `--test uci_session`
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- a_root_move_that_reaches_beta_is_reported_as_a_floor_and_then_answered_with stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'a_root_move_that_reaches_beta_is_reported_as_a_floor_and_then_answered_with' (981) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x5975636a4479 - <uci_session[47705cffb42bd826]::a_root_move_that_reaches_beta_is_reported_as_a_floor_and_then_answered_with::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- a_stop_ends_an_infinite_search_with_a_real_move stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'a_stop_ends_an_infinite_search_with_a_real_move' (983) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x597563698d4a - <uci_session[47705cffb42bd826]::a_stop_ends_an_infinite_search_with_a_real_move::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- a_fen_without_its_counters_is_the_position_searched stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'a_fen_without_its_counters_is_the_position_searched' (977) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x59756369c00b - <uci_session[47705cffb42bd826]::a_fen_without_its_counters_is_the_position_searched::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- the_move_a_swap_answers_with_opens_the_last_line_said stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'the_move_a_swap_answers_with_opens_the_last_line_said' (993) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x5975636a1213 - <uci_session[47705cffb42bd826]::the_move_a_swap_answers_with_opens_the_last_line_said::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- a_stop_with_nothing_running_is_taken_in_silence stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'a_stop_with_nothing_running_is_taken_in_silence' (984) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x5975636995ee - <uci_session[47705cffb42bd826]::a_stop_with_nothing_running_is_taken_in_silence::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- the_debug_log_holds_every_line_read_and_said_in_order stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'the_debug_log_holds_every_line_read_and_said_in_order' (990) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x5975636a0097 - <uci_session[47705cffb42bd826]::the_debug_log_holds_every_line_read_and_said_in_order::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- the_handshake_answers_the_way_the_smoke_test_expects stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'the_handshake_answers_the_way_the_smoke_test_expects' (991) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: [
[INFO] [stdout]     "id name arche 0.4.10-rc.2",
[INFO] [stdout]     "id author Andrew Wright",
[INFO] [stdout]     "option name Hash type spin default 256 min 1 max 16384",
[INFO] [stdout]     "option name Clear Hash type button",
[INFO] [stdout]     "option name Threads type spin default 1 min 1 max 1",
[INFO] [stdout]     "option name Move Overhead type spin default 50 min 0 max 5000",
[INFO] [stdout]     "option name Debug Log File type string default <empty>",
[INFO] [stdout]     "uciok",
[INFO] [stdout]     "readyok",
[INFO] [stdout] ]
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x59756369cdf2 - <uci_session[47705cffb42bd826]::the_handshake_answers_the_way_the_smoke_test_expects::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- the_interface_hanging_up_ends_the_engine stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'the_interface_hanging_up_ends_the_engine' (992) panicked at tests/uci_session.rs:68:27:
[INFO] [stdout] nothing matching arrived in thirty seconds, only: []
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5975636bdb87 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5975636a5f8a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x5975636bd13b - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5975636bcc1f - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5975636bc84a - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x5975636bc385 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    6:     0x5975636e3131 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    7:     0x5975636e30e9 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    8:     0x5975636e35ec - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]    9:     0x5975636a5e1b - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   10:     0x5975636981cb - <uci_session[47705cffb42bd826]::the_interface_hanging_up_ends_the_engine::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   11:     0x5975636fc01b - test[aada8e7e76ba119b]::__rust_begin_short_backtrace::<core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>, fn() -> core[a373ad73a504971]::result::Result<(), alloc[2e1b2a31b91974c5]::string::String>>
[INFO] [stdout]   12:     0x5975636f7fe1 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   13:     0x5975636f77cc - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   14:     0x597563716f0c - <std[617be2ca0a6fd877]::thread::lifecycle::spawn_unchecked<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>::{closure#1} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   15:     0x5975636e5274 - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   16:     0x7a57b6817dfa - <unknown>
[INFO] [stdout]   17:     0x7a57b68ab3d4 - clone
[INFO] [stdout]   18:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     a_fen_without_its_counters_is_the_position_searched
[INFO] [stdout]     a_root_move_that_reaches_beta_is_reported_as_a_floor_and_then_answered_with
[INFO] [stdout]     a_stop_ends_an_infinite_search_with_a_real_move
[INFO] [stdout]     a_stop_with_nothing_running_is_taken_in_silence
[INFO] [stdout]     the_debug_log_holds_every_line_read_and_said_in_order
[INFO] [stdout]     the_handshake_answers_the_way_the_smoke_test_expects
[INFO] [stdout]     the_interface_hanging_up_ends_the_engine
[INFO] [stdout]     the_move_a_swap_answers_with_opens_the_last_line_said
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 9 passed; 8 failed; 0 ignored; 0 measured; 0 filtered out; finished in 5.50s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd", kill_on_drop: false }`
[INFO] [stdout] 67dff588492edbe4be9b3ead08b966b780b3ce9401af9f9d4377d257f6dd99cd
