[INFO] fetching crate rudb-metrics 0.8.1...
[INFO] testing rudb-metrics-0.8.1 against 1.99.0-beta.8 for beta-1.100-2
[INFO] extracting crate rudb-metrics 0.8.1 into /workspace/builds/worker-4-tc1/source
[INFO] started tweaking crates.io crate rudb-metrics 0.8.1
[INFO] finished tweaking crates.io crate rudb-metrics 0.8.1
[INFO] tweaked toml for crates.io crate rudb-metrics 0.8.1 written to /workspace/builds/worker-4-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate rudb-metrics 0.8.1 on toolchain 1.99.0-beta.8
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.99.0-beta.8" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate rudb-metrics 0.8.1 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.99.0-beta.8" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] [stderr]     Updating crates.io index
[INFO] [stderr]  Downloading crates ...
[INFO] [stderr]   Downloaded phf_shared v0.12.1
[INFO] [stderr]   Downloaded phf v0.12.1
[INFO] [stderr]   Downloaded rudb-common v0.8.1
[INFO] [stderr]   Downloaded chrono-tz v0.10.4
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-tc1/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:3111399a4047eeb3a02b7a90e478d715f38a8c6669b5c4b49d30a17385265909" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be
[INFO] running `Command { std: "docker" "start" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", 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" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", 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" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling num-traits v0.2.19
[INFO] [stderr]    Compiling phf_shared v0.12.1
[INFO] [stderr]    Compiling chrono-tz v0.10.4
[INFO] [stderr]    Compiling phf v0.12.1
[INFO] [stderr]    Compiling chrono v0.4.45
[INFO] [stderr]    Compiling rudb-common v0.8.1
[INFO] [stderr]    Compiling rudb-metrics v0.8.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 11.82s
[INFO] running `Command { std: "docker" "inspect" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", 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" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling rudb-metrics v0.8.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 2.01s
[INFO] running `Command { std: "docker" "inspect" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", 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" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.05s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/rudb_metrics-dc371f192c4c67a5)
[INFO] [stdout] 
[INFO] [stdout] running 84 tests
[INFO] [stdout] test counters::tests::an_operator_that_had_nothing_to_choose_from_is_still_a_reference ... ok
[INFO] [stdout] test counters::tests::an_operator_that_never_gave_up_reports_nothing_rather_than_a_row_of_zeroes ... ok
[INFO] [stdout] test clock::tests::the_thread_clock_does_not_go_backwards ... ok
[INFO] [stdout] test counters::tests::an_operator_that_chose_something_faster_is_not_marked_as_a_reference ... ok
[INFO] [stdout] test counters::tests::memory_is_a_level_and_the_high_water_mark_remembers_the_most_of_it ... ok
[INFO] [stdout] test counters::tests::falling_back_adds_up_across_the_calls_and_comes_out_split_by_cause ... ok
[INFO] [stdout] test counters::tests::a_snapshot_carries_what_was_counted_and_what_was_known ... ok
[INFO] [stdout] test counters::tests::the_stages_of_a_read_add_up_across_the_calls_and_come_out_split ... ok
[INFO] [stdout] test counters::tests::an_operator_that_reads_nothing_keeps_the_stages_out_of_the_document ... ok
[INFO] [stdout] test counters::tests::every_thread_counts_into_the_same_operator ... ok
[INFO] [stdout] test document::tests::a_failed_query_still_has_a_document ... ok
[INFO] [stdout] test document::tests::the_same_statement_hashes_the_same_way_and_a_different_one_does_not ... ok
[INFO] [stdout] test driver::tests::a_driver_charges_itself_what_it_did ... ok
[INFO] [stdout] test driver::tests::a_driver_run_twice_adds_up ... ok
[INFO] [stdout] test document::tests::the_document_renders_as_schema_one ... ok
[INFO] [stdout] test histogram::tests::a_value_past_the_top_is_counted_and_clamped_rather_than_dropped ... ok
[INFO] [stdout] test histogram::tests::an_empty_histogram_answers_zero ... ok
[INFO] [stdout] test document::tests::the_one_line_form_is_the_indented_one_with_the_whitespace_taken_out ... ok
[INFO] [stdout] test histogram::tests::every_slot_holds_the_values_it_says_and_no_others ... ok
[INFO] [stdout] test histogram::tests::merging_two_workers_is_the_same_as_one_worker_recording_both ... ok
[INFO] [stdout] test counters::tests::the_instance_that_built_the_table_is_the_one_that_says_what_the_join_did ... ok
[INFO] [stdout] test histogram::tests::reset_forgets_and_the_buckets_list_only_what_is_there ... ok
[INFO] [stdout] test histogram::tests::small_values_are_kept_exactly ... ok
[INFO] [stdout] test driver::tests::a_span_dropped_on_the_way_out_of_an_error_is_still_charged ... ok
[INFO] [stdout] test histogram::tests::the_relative_error_is_under_one_percent_everywhere ... ok
[INFO] [stdout] test histogram::tests::quantiles_of_a_uniform_run_land_within_the_error ... ok
[INFO] [stdout] test driver::tests::a_driver_does_not_charge_itself_what_ran_inside_it ... ok
[INFO] [stdout] test json::tests::a_query_with_quotes_and_control_characters_comes_back_out_escaped ... ok
[INFO] [stdout] test json::tests::an_array_of_objects_nests_one_level_at_a_time ... ok
[INFO] [stdout] test json::tests::keys_are_separated_and_indented ... ok
[INFO] [stdout] test histogram::tests::the_layout_is_the_one_the_spec_sized ... ok
[INFO] [stdout] test json::tests::an_empty_object_is_two_characters ... ok
[INFO] [stdout] test load::tests::a_span_charges_once_when_it_is_dropped ... ok
[INFO] [stdout] test load::tests::the_accounted_peak_is_the_most_held_at_once ... ok
[INFO] [stdout] test load::tests::the_peak_resident_set_is_read_from_the_kernel ... ok
[INFO] [stdout] test load::tests::a_stage_sums_what_every_worker_charged ... ok
[INFO] [stdout] test load::tests::the_process_keeps_the_newest_loads ... ok
[INFO] [stdout] test load::tests::the_stage_names_are_the_specs ... ok
[INFO] [stdout] test qerror::tests::a_certificate_is_contradicted_by_the_far_side_of_its_bound ... ok
[INFO] [stdout] test qerror::tests::a_document_measures_the_operators_it_had_a_number_for ... ok
[INFO] [stdout] test load::tests::the_total_stops_at_finish ... ok
[INFO] [stdout] test qerror::tests::an_exact_count_that_the_run_produced_more_rows_than_is_a_contradiction ... ok
[INFO] [stdout] test qerror::tests::producing_fewer_rows_than_an_exact_count_is_execution_and_not_arithmetic ... ok
[INFO] [stdout] test qerror::tests::a_guess_claims_nothing_so_nothing_contradicts_it ... ok
[INFO] [stdout] test qerror::tests::a_perfect_estimate_is_its_own_bucket ... ok
[INFO] [stdout] test qerror::tests::an_estimate_of_nothing_is_measured_against_one_row_rather_than_against_zero ... ok
[INFO] [stdout] test qerror::tests::the_classes_are_counted_apart_and_the_word_leaves_the_certificate_off ... ok
[INFO] [stdout] test qerror::tests::the_buckets_are_powers_of_ten_and_the_boundaries_land_in_the_lower_one ... ok
[INFO] [stdout] test report::tests::an_edge_declared_twice_is_one_edge ... ok
[INFO] [stdout] test split::tests::a_probe_gives_back_the_build_and_the_copies ... ok
[INFO] [stdout] test report::tests::a_report_becomes_the_rows_of_a_document ... ok
[INFO] [stdout] test report::tests::an_execution_that_measured_nothing_has_no_rows ... ok
[INFO] [stdout] test split::tests::a_scan_that_filtered_for_itself_gives_the_filter_back ... ok
[INFO] [stdout] test split::tests::stages_that_add_up_to_more_than_the_operator_leave_it_nothing_rather_than_wrapping ... ok
[INFO] [stdout] test statements::tests::a_long_text_is_cut_on_a_character ... ok
[INFO] [stdout] test statements::tests::a_statement_is_kept_with_its_phases_apart ... ok
[INFO] [stdout] test tests::a_span_is_printed_in_the_unit_that_reads ... ok
[INFO] [stdout] test warn::tests::a_cancelled_run_says_so_first ... ok
[INFO] [stdout] test warn::tests::a_certificate_the_run_falls_outside_of_is_the_same_failure_with_a_range ... ok
[INFO] [stdout] test tests::a_number_is_grouped_from_the_right ... ok
[INFO] [stdout] test warn::tests::a_clean_run_has_nothing_to_say ... ok
[INFO] [stdout] test warn::tests::a_count_the_run_came_up_short_of_is_execution_working_rather_than_a_bug ... ok
[INFO] [stdout] test warn::tests::a_document_with_pipelines_is_checked_against_the_pipelines ... ok
[INFO] [stdout] test warn::tests::a_pipeline_that_mostly_waited_says_what_it_waited_on ... ok
[INFO] [stdout] test statements::tests::the_ring_keeps_the_newest_in_order ... ok
[INFO] [stdout] test warn::tests::a_query_that_spent_its_time_driving_rather_than_in_its_operators_says_so ... ok
[INFO] [stdout] test warn::tests::a_suite_where_nothing_had_an_alternative_says_that_rather_than_blaming_the_seams ... ok
[INFO] [stdout] test warn::tests::an_estimate_against_no_rows_does_not_divide_by_zero ... ok
[INFO] [stdout] test warn::tests::an_estimate_an_order_of_magnitude_out_is_a_warning ... ok
[INFO] [stdout] test warn::tests::an_exact_count_the_run_went_past_is_a_wrong_answer_bug_and_not_a_bad_estimate ... ok
[INFO] [stdout] test warn::tests::an_execution_that_never_gave_up_on_a_column_says_nothing_about_it ... ok
[INFO] [stdout] test warn::tests::cpu_the_operators_do_not_account_for_is_reported ... ok
[INFO] [stdout] test warn::tests::cpu_within_the_tolerance_is_not_reported ... ok
[INFO] [stdout] test warn::tests::a_failed_run_carries_the_message ... ok
[INFO] [stdout] test warn::tests::operators_that_were_not_timed_on_the_thread_clock_are_not_reported_as_driving_cost ... ok
[INFO] [stdout] test split::tests::the_parts_are_named_in_one_order ... ok
[INFO] [stdout] test warn::tests::reference_implementations_are_counted_rather_than_listed ... ok
[INFO] [stdout] test warn::tests::the_row_at_a_time_paths_are_totalled_and_the_worst_one_is_named ... ok
[INFO] [stdout] test warn::tests::the_time_spent_building_is_not_time_the_pipelines_have_to_account_for ... ok
[INFO] [stdout] test warn::tests::coming_within_a_few_percent_of_the_limit_is_worth_knowing ... ok
[INFO] [stdout] test report::tests::a_pipeline_with_a_driver_reports_what_the_driver_charged ... ok
[INFO] [stdout] test clock::tests::a_charging_span_reads_the_thread_clock ... ok
[INFO] [stdout] test clock::tests::a_span_over_work_costs_wall_time_and_cpu_time ... ok
[INFO] [stdout] test clock::tests::a_wall_only_span_reports_the_time_and_no_cpu ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 84 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.27s
[INFO] [stdout] 
[INFO] [stderr]    Doc-tests rudb_metrics
[INFO] [stdout] 
[INFO] [stdout] running 0 tests
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be", kill_on_drop: false }`
[INFO] [stdout] c049bf7ba89a5977225d7b5e9ade14c36c6d7d6690627d48bf6a469a74e4c9be
