[INFO] fetching crate weavatrix-lsp-client 0.1.0...
[INFO] testing weavatrix-lsp-client-0.1.0 against 1.100.0-beta.1+cargoflags=--release for beta-release-1.100-2
[INFO] extracting crate weavatrix-lsp-client 0.1.0 into /workspace/builds/worker-4-tc2/source
[INFO] started tweaking crates.io crate weavatrix-lsp-client 0.1.0
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate weavatrix-lsp-client 0.1.0
[INFO] tweaked toml for crates.io crate weavatrix-lsp-client 0.1.0 written to /workspace/builds/worker-4-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate weavatrix-lsp-client 0.1.0 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 crates.io crate weavatrix-lsp-client 0.1.0 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-4-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-4-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] 0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13
[INFO] running `Command { std: "docker" "start" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", 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" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13" "/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" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", 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" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling serde_core v1.0.229
[INFO] [stderr]    Compiling lexical-util v1.0.7
[INFO] [stderr]    Compiling serde_json v1.0.151
[INFO] [stderr]    Compiling syn v3.0.3
[INFO] [stderr]    Compiling lexical-parse-integer v1.0.6
[INFO] [stderr]    Compiling lexical-parse-float v1.0.6
[INFO] [stderr]    Compiling serde_derive v1.0.229
[INFO] [stderr]    Compiling lexical-core v1.0.6
[INFO] [stderr]    Compiling serde v1.0.229
[INFO] [stderr]    Compiling blazingly-json v0.1.0
[INFO] [stderr]    Compiling weavatrix-lsp-wire v0.2.0
[INFO] [stderr]    Compiling weavatrix-lsp-client v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 14.58s
[INFO] running `Command { std: "docker" "inspect" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", 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" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13" "/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 weavatrix-lsp-client v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 6.06s
[INFO] running `Command { std: "docker" "inspect" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", 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" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13" "/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.08s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/release/build/weavatrix-lsp-client/200d97b2e3bf051a/out/weavatrix_lsp_client-200d97b2e3bf051a)
[INFO] [stdout] 
[INFO] [stdout] running 50 tests
[INFO] [stdout] test config::tests::a_scrubbed_environment_still_carries_the_variables_set_after_it ... ok
[INFO] [stdout] test config::tests::the_defaults_are_the_lsp_base_protocol_spellings ... ok
[INFO] [stdout] test inbound::tests::a_non_blocking_take_reports_an_empty_queue_instead_of_waiting ... ok
[INFO] [stdout] test config::tests::arguments_accumulate_in_the_order_they_were_added ... ok
[INFO] [stdout] test inbound::tests::an_item_larger_than_the_whole_budget_is_admitted_on_its_own ... ok
[INFO] [stdout] test config::tests::every_method_name_can_be_overridden_for_a_non_lsp_protocol ... ok
[INFO] [stdout] test config::tests::a_configuration_can_be_cloned_and_inspected ... ok
[INFO] [stdout] test message::tests::an_identifier_renders_as_the_json_a_cancellation_carries ... ok
[INFO] [stdout] test queue::lanes::tests::discarding_reports_whether_the_body_was_still_queued ... ok
[INFO] [stdout] test limits::validate::tests::a_count_is_rejected_at_zero_and_above_its_ceiling_but_accepted_on_it ... ok
[INFO] [stdout] test queue::lanes::tests::each_lane_reports_its_own_item_and_byte_rejection ... ok
[INFO] [stdout] test limits::validate::tests::a_span_is_rejected_at_zero_and_above_its_ceiling_but_accepted_on_it ... ok
[INFO] [stdout] test inbound::tests::closing_releases_every_waiter_but_still_drains_what_was_queued ... ok
[INFO] [stdout] test message::tests::a_string_identifier_is_escaped_into_a_json_literal ... ok
[INFO] [stdout] test queue::lanes::tests::the_reserved_lane_is_drained_before_the_ordinary_one ... ok
[INFO] [stdout] test queue::tests::a_lane_charges_the_whole_retained_allocation ... ok
[INFO] [stdout] test queue::tests::a_closed_queue_rejects_new_bodies_and_ends_the_writer ... ok
[INFO] [stdout] test queue::tests::retracting_a_body_the_queue_never_held_is_reported_as_such ... ok
[INFO] [stdout] test config::tests::the_working_directory_reaches_the_command ... ok
[INFO] [stdout] test config::tests::environment_edits_are_applied_in_the_order_they_were_added ... ok
[INFO] [stdout] test message::tests::only_server_initiated_shapes_become_inbound_items ... ok
[INFO] [stdout] test message::tests::an_integer_identified_request_charges_no_identifier_bytes ... ok
[INFO] [stdout] test shared::tests::only_the_first_termination_reason_is_recorded ... ok
[INFO] [stdout] test shared::tests::the_timeout_streak_accumulates_and_is_cleared_by_any_correlation ... ok
[INFO] [stdout] test shared::tests::a_cancellation_that_cannot_be_built_is_counted_as_dropped ... ok
[INFO] [stdout] test reader::tests::a_null_identified_response_is_counted_as_unmatched ... ok
[INFO] [stdout] test reader::tests::an_undecodable_body_is_counted_and_the_stream_continues ... ok
[INFO] [stdout] test reader::tests::a_truncated_body_at_end_of_stream_is_terminal_framing ... ok
[INFO] [stdout] test process::portable_tests::a_child_that_cannot_be_spawned_reports_the_platform_error ... ok
[INFO] [stdout] test reader::tests::a_clean_end_of_stream_is_reported_as_a_child_exit ... ok
[INFO] [stdout] test lifecycle::startup::tests::a_failed_engine_thread_spawn_releases_the_threads_it_already_started ... ok
[INFO] [stdout] test reader::tests::inbound_traffic_arriving_after_termination_is_counted_as_dropped ... ok
[INFO] [stdout] test stderr::tests::a_chunk_larger_than_the_whole_ring_keeps_only_its_tail ... ok
[INFO] [stdout] test reader::tests::an_interrupted_read_is_retried_and_a_failed_one_is_terminal ... ok
[INFO] [stdout] test stderr::tests::the_drain_ends_cleanly_at_end_of_stream ... ok
[INFO] [stdout] test termination::tests::an_already_finished_report_claims_neither_a_kill_nor_an_exit_code ... ok
[INFO] [stdout] test stderr::tests::the_drain_retries_an_interrupted_read_and_stops_on_a_failure ... ok
[INFO] [stdout] test termination::tests::an_io_failure_is_classified_and_rendered_in_both_directions ... ok
[INFO] [stdout] test submit::tests::a_queue_rejection_releases_the_slot_the_request_had_reserved ... ok
[INFO] [stdout] test submit::tests::a_terminated_session_refuses_every_kind_of_submission ... ok
[INFO] [stdout] test stderr::tests::a_flood_never_grows_the_ring_past_its_configured_capacity ... ok
[INFO] [stdout] test shared::tests::parking_returns_immediately_once_the_session_has_ended ... ok
[INFO] [stdout] test writer::tests::a_body_the_encoder_refuses_terminates_rather_than_being_dropped ... ok
[INFO] [stdout] test writer::tests::a_failed_write_terminates_the_session_instead_of_dropping_the_frame ... ok
[INFO] [stdout] test supervisor::tests::a_caller_driven_exit_stops_the_supervisor_from_reaping ... ok
[INFO] [stdout] test message::tests::borrowed_identifiers_are_promoted_without_losing_their_shape ... ok
[INFO] [stdout] test supervisor::tests::a_session_that_ends_without_a_caller_is_reaped_by_the_supervisor ... ok
[INFO] [stdout] test supervisor::tests::a_released_child_leaves_the_supervisor_with_nothing_to_reap ... ok
[INFO] [stdout] test inbound::tests::a_timed_receive_reports_the_elapsed_budget_rather_than_blocking_forever ... ok
[INFO] [stdout] test queue::tests::waiting_for_a_drain_reports_the_elapsed_deadline_instead_of_blocking ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 50 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.07s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/fake_server/main.rs (/opt/rustwide/target/release/build/weavatrix-lsp-client/8e667b3d7f1e13a3/out/weavatrix_lsp_fake_server-8e667b3d7f1e13a3)
[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] [stderr]      Running tests/backpressure.rs (/opt/rustwide/target/release/build/weavatrix-lsp-client/9058b4c594576c09/out/backpressure-9058b4c594576c09)
[INFO] [stdout] 
[INFO] [stdout] running 6 tests
[INFO] [stdout] test outbound_overflow_is_reported_by_byte_budget ... ok
[INFO] [stdout] test pending_cap_rejects_the_request_that_would_exceed_it ... ok
[INFO] [stdout] test control_lane_stays_sendable_while_the_ordinary_lane_is_full ... ok
[INFO] [stdout] test outbound_overflow_is_reported_by_item_count ... ok
[INFO] [stdout] test stderr_flood_is_bounded_and_does_not_block_requests ... ok
[INFO] [stdout] test inbound_queue_stays_bounded_without_dropping ... ok
[INFO] [stderr]      Running tests/cancellation.rs (/opt/rustwide/target/release/build/weavatrix-lsp-client/991032cebbb6a024/out/cancellation-991032cebbb6a024)
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 6 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.04s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 5 tests
[INFO] [stdout] test cancelling_an_answered_request_sends_nothing ... ok
[INFO] [stdout] test a_timeout_retracts_a_request_the_writer_never_sent ... ok
[INFO] [stdout] test tombstones_stay_bounded_by_their_configured_count ... ok
[INFO] [stdout] test explicit_cancel_completes_once_and_tombstones_the_identifier ... ok
[INFO] [stdout] test a_cancellation_the_control_lane_rejects_is_counted ... FAILED
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- a_cancellation_the_control_lane_rejects_is_counted stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'a_cancellation_the_control_lane_rejects_is_counted' (843) panicked at tests/cancellation.rs:112:5:
[INFO] [stdout] the server was never told, and that is visible: MetricsSnapshot { requests_submitted: 1, notifications_submitted: 65, responses_matched: 0, timeouts: 1, cancellations: 0, cancellations_sent: 1, cancellations_dropped: 0, unsent_requests_discarded: 0, late_responses: 0, unmatched_responses: 0, inbound_delivered: 0, inbound_dropped: 0, decode_errors: 0, frames_read: 0, frames_written: 7, stderr_bytes_received: 0, stderr_bytes_dropped: 0, outbound_queued: 58, outbound_queued_bytes: 957348, control_queued: 1, control_queued_bytes: 256, inbound_queued: 0, inbound_queued_bytes: 0, pending_requests: 0, tombstones: 1 }
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x57971c1f74e1 - <<std[617be2ca0a6fd877]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a373ad73a504971]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x57971c20c18a - core[a373ad73a504971]::fmt::write
[INFO] [stdout]    2:     0x57971c1fb7cc - <alloc[2e1b2a31b91974c5]::vec::Vec<u8> as core[a373ad73a504971]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x57971c1d2656 - std[617be2ca0a6fd877]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x57971c1ef939 - std[617be2ca0a6fd877]::panicking::default_hook
[INFO] [stdout]    5:     0x57971c160990 - test[aada8e7e76ba119b]::test_main_inner::{closure#0}
[INFO] [stdout]    6:     0x57971c1efc62 - std[617be2ca0a6fd877]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x57971c1d2702 - std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x57971c1cb419 - std[617be2ca0a6fd877]::sys::backtrace::__rust_end_short_backtrace::<std[617be2ca0a6fd877]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x57971c1d330d - __rustc[ea4f61d10b84890b]::rust_begin_unwind
[INFO] [stdout]   10:     0x57971c20c8bc - core[a373ad73a504971]::panicking::panic_fmt
[INFO] [stdout]   11:     0x57971c153086 - <cancellation[a8df10505e6750cd]::a_cancellation_the_control_lane_rejects_is_counted::{closure#0} as core[a373ad73a504971]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   12:     0x57971c153ddb - 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]   13:     0x57971c160fb5 - test[aada8e7e76ba119b]::run_test::{closure#0}
[INFO] [stdout]   14:     0x57971c15a8a4 - std[617be2ca0a6fd877]::sys::backtrace::__rust_begin_short_backtrace::<test[aada8e7e76ba119b]::run_test::{closure#1}, ()>
[INFO] [stdout]   15:     0x57971c164042 - <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]   16:     0x57971c1f6d2f - <std[617be2ca0a6fd877]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   17:     0x7b7cec735dfa - <unknown>
[INFO] [stdout]   18:     0x7b7cec7c93d4 - clone
[INFO] [stdout]   19:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     a_cancellation_the_control_lane_rejects_is_counted
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 4 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 6.52s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--test cancellation`
[INFO] running `Command { std: "docker" "inspect" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13", kill_on_drop: false }`
[INFO] [stdout] 0b94f70761cc9bd2f06a8d338bdc8fc9a3d34aeb6f5575bd9c9009cf2a23fc13
