[INFO] fetching crate sipr 0.33.1...
[INFO] testing sipr-0.33.1 against 1.99.0-beta.8+cargoflags=--release for beta-release-1.100-2
[INFO] extracting crate sipr 0.33.1 into /workspace/builds/worker-1-tc1/source
[INFO] removed /workspace/builds/worker-1-tc1/source/rust-toolchain.toml
[INFO] started tweaking crates.io crate sipr 0.33.1
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate sipr 0.33.1
[INFO] tweaked toml for crates.io crate sipr 0.33.1 written to /workspace/builds/worker-1-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate sipr 0.33.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 sipr 0.33.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 sipr-net v0.33.1
[INFO] [stderr]   Downloaded sipr-auth v0.33.1
[INFO] [stderr]   Downloaded sipr-tui v0.33.1
[INFO] [stderr]   Downloaded sipr-stats v0.33.1
[INFO] [stderr]   Downloaded sipr-control v0.33.1
[INFO] [stderr]   Downloaded sipr-media v0.33.1
[INFO] [stderr]   Downloaded sipr-scenario v0.33.1
[INFO] [stderr]   Downloaded sipr-engine v0.33.1
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc1/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-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:77db811e55d90add9212f6832c23229e3de5f1c1f9905e8cb07319ea15df73ac" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a
[INFO] running `Command { std: "docker" "start" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", 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" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a" "/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" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", 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" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "build" "--frozen" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling cc v1.4.3
[INFO] [stderr]    Compiling rustls v0.23.45
[INFO] [stderr]    Compiling sipr-auth v0.33.1
[INFO] [stderr]    Compiling sipr-stats v0.33.1
[INFO] [stderr]    Compiling sipr-scenario v0.33.1
[INFO] [stderr]    Compiling getrandom v0.2.17
[INFO] [stderr]    Compiling thiserror-impl v2.0.21
[INFO] [stderr]    Compiling sipr-media v0.33.1
[INFO] [stderr]    Compiling sipr-control v0.33.1
[INFO] [stderr]    Compiling sipr-tui v0.33.1
[INFO] [stderr]    Compiling thiserror v2.0.21
[INFO] [stderr]    Compiling ring v0.17.14
[INFO] [stderr]    Compiling rustls-webpki v0.103.14
[INFO] [stderr]    Compiling sipr-net v0.33.1
[INFO] [stderr]    Compiling sipr-engine v0.33.1
[INFO] [stderr]    Compiling sipr v0.33.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 1m 02s
[INFO] running `Command { std: "docker" "inspect" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", 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" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen" "--no-run" "--message-format=json" "--release", kill_on_drop: false }`
[INFO] [stderr]    Compiling time-core v0.1.7
[INFO] [stderr]    Compiling num-conv v0.1.0
[INFO] [stderr]    Compiling bitflags v2.13.1
[INFO] [stderr]    Compiling serde v1.0.229
[INFO] [stderr]    Compiling criterion-plot v0.6.0
[INFO] [stderr]    Compiling time v0.3.45
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling ciborium v0.2.2
[INFO] [stderr]    Compiling tinytemplate v1.2.1
[INFO] [stderr]    Compiling yasna v0.5.2
[INFO] [stderr]    Compiling rcgen v0.13.2
[INFO] [stderr]    Compiling criterion v0.7.0
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling sipr v0.33.1 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 41.21s
[INFO] running `Command { std: "docker" "inspect" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", 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" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a" "/opt/rustwide/cargo-home/bin/cargo" "+1.99.0-beta.8" "test" "--frozen" "--release", kill_on_drop: false }`
[INFO] [stderr]     Finished `release` profile [optimized] target(s) in 0.13s
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/release/deps/sipr-9cb860f64e7694ea)
[INFO] [stdout] 
[INFO] [stdout] running 30 tests
[INFO] [stdout] test cli::tests::defaults_match_sipp ... ok
[INFO] [stdout] test cli::tests::equals_form_accepted ... ok
[INFO] [stdout] test cli::tests::help_and_version_flags ... ok
[INFO] [stdout] test cli::tests::edit_distance_sanity ... ok
[INFO] [stdout] test cli::tests::echo_and_rtpcheck_flags_parse ... ok
[INFO] [stdout] test cli::tests::set_takes_a_variable_and_a_value_and_repeats ... ok
[INFO] [stdout] test cli::tests::sf_conflicts_with_sn ... ok
[INFO] [stdout] test cli::tests::control_flags_parse ... ok
[INFO] [stdout] test cli::tests::socket_option_flags_parse ... ok
[INFO] [stdout] test cli::tests::stats_json_flag_parses ... ok
[INFO] [stdout] test cli::tests::help_text_lists_every_flag ... ok
[INFO] [stdout] test cli::tests::transport_modes_parse_and_reject ... ok
[INFO] [stdout] test cli::tests::websocket_request_flags_parse ... ok
[INFO] [stdout] test tests::bare_command_line_equals_the_engine_defaults ... ok
[INFO] [stdout] test cli::tests::unknown_flag_suggests_nearest ... ok
[INFO] [stdout] test cli::tests::tls_flags_parse_and_version_gates ... ok
[INFO] [stdout] test cli::tests::two_positionals_rejected ... ok
[INFO] [stdout] test cli::tests::no_effect_set_matches_the_flag_table ... ok
[INFO] [stdout] test cli::tests::out_of_call_scenario_flags_parse_and_conflict ... ok
[INFO] [stdout] test cli::tests::bad_numeric_value_reports_flag ... ok
[INFO] [stdout] test cli::tests::double_dash_forms_accepted ... ok
[INFO] [stdout] test cli::tests::no_effect_flags_are_accepted_with_one_warning_each ... ok
[INFO] [stdout] test cli::tests::mixed_mode_flags_parse_and_conflict ... ok
[INFO] [stdout] test cli::tests::media_flags_parse_with_sipp_alias ... ok
[INFO] [stdout] test tests::ipv6_target_binds_a_v6_socket_by_default ... ok
[INFO] [stdout] test cli::tests::parses_typical_uac_invocation ... ok
[INFO] [stdout] test cli::tests::bind_to_device_is_linux_only ... ok
[INFO] [stdout] test cli::tests::missing_value_is_an_error ... ok
[INFO] [stdout] test cli::tests::rate_ramp_flags_parse_with_time_units ... ok
[INFO] [stdout] test tests::resolve_target_covers_v4_v6_and_hostnames ... ok
[INFO] [stderr]      Running tests/cli.rs (/opt/rustwide/target/release/deps/cli-39982b19f09e39aa)
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 30 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.02s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 35 tests
[INFO] [stdout] test check_mode_dumps_ir_for_clean_scenario ... ok
[INFO] [stdout] test check_mode_prints_the_transactions ... ok
[INFO] [stdout] test check_mode_prints_the_variable_scopes ... ok
[INFO] [stdout] test check_mode_fails_on_warnings_or_errors ... ok
[INFO] [stdout] test default_scenario_is_uac_and_needs_target ... ok
[INFO] [stdout] test sd_dumps_embedded_uac_scenario ... ok
[INFO] [stdout] test check_mode_lints_the_ooc_scenario_too ... ok
[INFO] [stdout] test missing_scenario_file_fails ... ok
[INFO] [stdout] test ooc_scenario_reading_injection_files_is_fatal_with_sipps_wording ... ok
[INFO] [stdout] test set_of_an_undeclared_global_is_fatal_with_sipps_wording ... ok
[INFO] [stdout] test no_effect_sipp_flags_warn_but_do_not_stop_the_run ... ok
[INFO] [stdout] test help_mentions_sipp_flag_convention ... ok
[INFO] [stdout] test ooc_scenario_in_server_mode_is_fatal_with_sipps_wording ... ok
[INFO] [stdout] test ooc_flags_are_mutually_exclusive_and_names_are_checked ... ok
[INFO] [stdout] test sd_unknown_scenario_fails ... ok
[INFO] [stdout] test check_mode_lints_the_receive_scenario_too ... ok
[INFO] [stdout] test compile_errors_are_fatal_outside_check_mode ... ok
[INFO] [stdout] test key_takes_keyword_and_value_and_needs_both ... ok
[INFO] [stdout] test sd_dumps_embedded_uas_scenario ... ok
[INFO] [stdout] test unresolvable_target_is_fatal ... ok
[INFO] [stdout] test uac_without_target_fails ... ok
[INFO] [stdout] test user_and_global_elements_are_rejected_when_they_disagree_across_scenarios ... ok
[INFO] [stdout] test unknown_long_flag_errors_with_suggestion ... ok
[INFO] [stdout] test receive_scenario_with_a_bare_field_needs_an_inf_file ... ok
[INFO] [stdout] test tdmmap_rejects_a_bad_map_with_sipps_wording ... ok
[INFO] [stdout] test sd_dumps_embedded_out_of_call_scenarios ... ok
[INFO] [stdout] test mixed_mode_flags_conflict_and_roles_are_checked ... ok
[INFO] [stdout] test version_flag_works_sipp_style ... ok
[INFO] [stdout] test sf_uac_scenario_without_target_fails ... ok
[INFO] [stdout] test headless_run_quits_on_q_from_stdin_unless_nostdin ... ok
[INFO] [stdout] test sf_uas_scenario_needs_no_target ... ok
[INFO] [stdout] test check_mode_lints_and_a_directive_silences_a_finding ... ok
[INFO] [stdout] test uas_runs_and_exits_99_when_no_calls_arrive ... ok
[INFO] [stdout] test stats_json_writes_one_object_per_tick ... ok
[INFO] [stdout] test stats_json_last_line_is_the_final_state ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 35 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 4.12s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/e2e.rs (/opt/rustwide/target/release/deps/e2e-0ffe5a1e5c9395ed)
[INFO] [stdout] 
[INFO] [stdout] running 102 tests
[INFO] [stdout] test actions_scenario_runs_against_scripted_uas ... FAILED
[INFO] [stdout] test auth_uri_flag_and_default_follow_sipp ... FAILED
[INFO] [stdout] test a_jump_to_itself_fails_the_call ... ok
[INFO] [stdout] test aka_with_the_wrong_key_fails_the_call_not_the_process ... FAILED
[INFO] [stdout] test authentication_keyword_from_an_injection_field ... ok
[INFO] [stdout] test authentication_params_render_keywords ... ok
[INFO] [stdout] test bare_authentication_keyword_renders_the_full_header_line ... ok
[INFO] [stdout] test aka_resynchronisation_round_trips ... ok
[INFO] [stdout] test aka_v1_md5_registration_round_trips ... ok
[INFO] [stdout] test digest_authentication_round_trips ... ok
[INFO] [stdout] test digest_uri_matches_what_the_server_verifies ... ok
[INFO] [stdout] test a_recv_cmd_behind_an_optional_recv_moves_the_call_on ... ok
[INFO] [stdout] test closecon_is_accepted_over_tcp ... ok
[INFO] [stdout] test generic_counters_reach_the_statistics_file_screen_and_api ... ok
[INFO] [stdout] test http_api_off_loopback_needs_a_token ... ok
[INFO] [stdout] test extended_3pcc_option_checks_and_wrong_sender ... FAILED
[INFO] [stdout] test extended_3pcc_master_drives_two_slaves ... ok
[INFO] [stdout] test a_recv_cmd_waits_with_recv_timeout ... ok
[INFO] [stdout] test a_trailing_optional_recv_times_out_on_its_own_timeout ... ok
[INFO] [stdout] test control_socket_speaks_sipp_protocol ... ok
[INFO] [stdout] test calldebug_dumps_aborted_calls ... ok
[INFO] [stdout] test a_matched_recv_follows_next_test_and_chance ... ok
[INFO] [stdout] test http_api_reports_stats_and_controls_the_run ... ok
[INFO] [stdout] test exec_command_runs_a_shell_per_matching_message ... ok
[INFO] [stdout] test next_url_and_last_headers_follow_siprs_reading_not_sipps ... ok
[INFO] [stdout] test hidden_steps_and_display_labels_reach_the_stats_api ... ok
[INFO] [stdout] test embedded_uac_flow_completes_against_scripted_uas ... ok
[INFO] [stdout] test play_pcap_with_a_missing_file_is_fatal_at_startup ... ok
[INFO] [stdout] test max_socket_makes_calls_share_sockets ... ok
[INFO] [stdout] test rate_and_limit_are_respected ... ok
[INFO] [stdout] test log_files_have_sipps_shapes ... ok
[INFO] [stdout] test late_final_response_to_a_named_invite_transaction_is_acked_again ... ok
[INFO] [stdout] test injection_file_fields_land_in_sent_messages ... ok
[INFO] [stdout] test play_pcap_audio_accepts_a_pcapng_capture ... ok
[INFO] [stdout] test rate_increase_ramps_the_rate_up ... ok
[INFO] [stdout] test m39_keywords_render_in_sent_messages ... ok
[INFO] [stdout] test lookup_reads_indexed_field_by_key ... ok
[INFO] [stdout] test play_pcap_audio_replays_capture_to_the_sdp_endpoint ... ok
[INFO] [stdout] test rsa_uac_sends_to_the_sending_address_but_renders_the_target ... ok
[INFO] [stdout] test rate_max_quits_when_exceeded_unless_no_rate_quit ... ok
[INFO] [stdout] test retransmissions_fire_when_first_invite_is_lost ... ok
[INFO] [stdout] test a_timeout_behind_an_optional_recv_does_not_arm ... ok
[INFO] [stdout] test a_copy_of_an_answered_message_can_be_lost ... ok
[INFO] [stdout] test rtp_echo_with_an_unknown_codec_fails_at_load ... ok
[INFO] [stdout] test ipv6_uac_places_call_over_loopback ... ok
[INFO] [stdout] test rtp_stream_with_a_bad_payload_is_fatal_at_startup ... ok
[INFO] [stdout] test rtp_echo_action_toggles_the_global_echo ... ok
[INFO] [stdout] test bind_local_and_buff_size_drive_a_call_without_an_explicit_i ... ok
[INFO] [stdout] test sctp_without_a_stack_or_feature_is_a_clear_error ... ok
[INFO] [stdout] test reconnect_close_false_keeps_the_interrupted_call ... ok
[INFO] [stdout] test reconnect_between_calls_with_budget ... ok
[INFO] [stdout] test printf_injection_file_generates_virtual_lines ... ok
[INFO] [stdout] test setdest_is_refused_where_sipp_refuses_it ... ok
[INFO] [stdout] test setdest_over_per_call_tcp_reconnects_to_the_new_peer ... ok
[INFO] [stdout] test a_copy_gets_the_send_that_answered_it ... ok
[INFO] [stdout] test rx_scenario_reads_rxinf_by_file_name ... ok
[INFO] [stdout] test silence_leads_to_failed_calls_and_exit_1 ... ok
[INFO] [stdout] test rtpcheck_against_a_silent_peer_exits_253_by_default ... ok
[INFO] [stdout] test srtp_stream_passes_the_echo_check_against_an_srtp_echo_peer ... FAILED
[INFO] [stdout] test statistical_pauses_scenario_runs_against_scripted_uas ... FAILED
[INFO] [stdout] test rtp_echo_variable_switches_the_echo_at_run_time ... ok
[INFO] [stdout] test rtp_stream_and_play_dtmf_send_generated_rtp ... ok
[INFO] [stdout] test tcp_uac_places_call_over_stream ... ok
[INFO] [stderr] sipr: control socket (UDP, SIPp -cp protocol) on 127.0.0.1:8890
[INFO] [stderr] sipr: bound to 0.0.0.0:40153 (answering calls)
[INFO] [stdout] test tcp_uas_answers_over_stream ... ok
[INFO] [stdout] test tcp_per_call_connections_one_per_call ... ok
[INFO] [stdout] test setdest_redirects_the_rest_of_the_call_over_udp ... ok
[INFO] [stdout] test response_txn_matches_the_right_invite_of_two_overlapping_ones ... ok
[INFO] [stdout] test timeout_retrans_and_loss_knobs ... FAILED
[INFO] [stdout] test threepcc_controller_a_round_trips_a_command ... ok
[INFO] [stdout] test tls_uac_places_call_over_stream ... ok
[INFO] [stderr] sipr: control socket (UDP, SIPp -cp protocol) on 127.0.0.1:8891
[INFO] [stderr] sipr: bound to 0.0.0.0:34795 (answering calls)
[INFO] [stdout] test tls_uas_answers_over_stream ... ok
[INFO] [stdout] test rsa_tcp_uas_dials_the_sending_address ... ok
[INFO] [stdout] test trace_files_are_written ... ok
[INFO] [stdout] test rsa_uas_answers_towards_the_sending_address ... ok
[INFO] [stdout] test rtp_echo_uas_makes_the_uac_rtpcheck_pass ... ok
[INFO] [stdout] test tls_per_call_connections_complete_calls ... ok
[INFO] [stdout] test ui_client_sends_each_call_from_its_lines_ip ... ok
[INFO] [stdout] test ui_server_answers_on_the_ip_the_request_hit ... ok
[INFO] [stdout] test statistics_files_have_sipps_shape ... ok
[INFO] [stdout] test udp_per_call_sockets_give_each_call_its_own_port ... ok
[INFO] [stdout] test set_display_ooc_swaps_the_scenario_screen ... ok
[INFO] [stdout] test set_display_rx_swaps_the_screens ... ok
[INFO] [stdout] test verifyauth_accepts_the_right_password_and_branches_to_200 ... ok
[INFO] [stdout] test verifyauth_rejects_a_wrong_password_and_branches_to_403 ... ok
[INFO] [stdout] test ws_uac_places_call_over_websocket ... ok
[INFO] [stdout] test ws_uas_answers_a_raw_websocket_client ... ok
[INFO] [stdout] test no_reconnect_budget_is_fatal_like_sipp ... ok
[INFO] [stdout] test sipr_uas_answers_sipr_uac_self_test ... ok
[INFO] [stdout] test tdmmap_keyword_needs_the_flag_and_renders_a_circuit ... ok
[INFO] [stdout] test ws_request_flags_are_validated_and_need_a_ws_transport ... ok
[INFO] [stdout] test wss_per_call_connections_complete_calls ... ok
[INFO] [stdout] test uas_auto_answers_in_dialog_options_with_aa ... ok
[INFO] [stdout] test the_recv_the_call_waits_at_owns_the_timeout ... ok
[INFO] [stdout] test user_variables_persist_across_a_users_calls ... ok
[INFO] [stdout] test reconnect_close_fails_the_interrupted_call ... ok
[INFO] [stdout] test uac_terminates_incoming_calls_with_rx_scenario ... ok
[INFO] [stdout] test default_behaviors_abort_or_continue_on_an_unexpected_message ... ok
[INFO] [stdout] test users_closed_loop_binds_user_to_injection_line ... ok
[INFO] [stdout] test set_users_retires_and_reuses_ids_like_sipp ... ok
[INFO] [stdout] test uac_answers_out_of_call_options_with_ooc_scenario ... ok
[INFO] [stdout] test srtp_echo_server_passes_a_peers_echo_check ... FAILED
[INFO] [stdout] test unexp_handler_restores_the_interrupted_pause ... FAILED
[INFO] [stderr] error: test failed, to rerun pass `--test e2e`
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- actions_scenario_runs_against_scripted_uas stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'actions_scenario_runs_against_scripted_uas' (1290) panicked at tests/e2e.rs:612:5:
[INFO] [stdout] assertion `left == right` failed: stderr:
[INFO] [stdout] sipr: error: cannot read scenario file /opt/rustwide/workdir/crates/sipr-scenario/tests/corpus/positive/branching_actions.xml: No such file or directory (os error 2)
[INFO] [stdout] 
[INFO] [stdout]   left: Some(255)
[INFO] [stdout]  right: Some(0)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc3123 - core[df12db4294e9bfd3]::panicking::assert_failed_inner
[INFO] [stdout]   12:     0x5d8fc5b09db2 - core[df12db4294e9bfd3]::panicking::assert_failed::<core[df12db4294e9bfd3]::option::Option<i32>, core[df12db4294e9bfd3]::option::Option<i32>>
[INFO] [stdout]   13:     0x5d8fc5a8976b - <e2e[31a2f43d42c4f72f]::actions_scenario_runs_against_scripted_uas::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   15:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   20:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- auth_uri_flag_and_default_follow_sipp stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'auth_uri_flag_and_default_follow_sipp' (1294) panicked at tests/e2e.rs:3590:9:
[INFO] [stdout] assertion `left == right` failed: stderr:
[INFO] [stdout] sipr: bound to 0.0.0.0:38011 (placing calls)
[INFO] [stdout] sipr: error: cannot create message trace file sipr-authuri-1281-15_1328_messages.log: Read-only file system (os error 30)
[INFO] [stdout] 
[INFO] [stdout]   left: Some(255)
[INFO] [stdout]  right: Some(0)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc3123 - core[df12db4294e9bfd3]::panicking::assert_failed_inner
[INFO] [stdout]   12:     0x5d8fc5b09db2 - core[df12db4294e9bfd3]::panicking::assert_failed::<core[df12db4294e9bfd3]::option::Option<i32>, core[df12db4294e9bfd3]::option::Option<i32>>
[INFO] [stdout]   13:     0x5d8fc5a652b4 - e2e[31a2f43d42c4f72f]::auth_uri_flag_and_default_follow_sipp::uri_in_trace
[INFO] [stdout]   14:     0x5d8fc5a7d5b7 - <e2e[31a2f43d42c4f72f]::auth_uri_flag_and_default_follow_sipp::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   15:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   16:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   17:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   18:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   19:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   20:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   21:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   22:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- aka_with_the_wrong_key_fails_the_call_not_the_process stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'aka_with_the_wrong_key_fails_the_call_not_the_process' (1293) panicked at tests/e2e.rs:2677:5:
[INFO] [stdout] assertion `left == right` failed: sipr stderr:
[INFO] [stdout] sipr: control socket (UDP, SIPp -cp protocol) on 127.0.0.1:8891
[INFO] [stdout] sipr: bound to 0.0.0.0:38761 (placing calls)
[INFO] [stdout] sipr: error: cannot create error trace file sipr-aka-bad-1281_1331_errors.log: Read-only file system (os error 30)
[INFO] [stdout] 
[INFO] [stdout]   left: Some(255)
[INFO] [stdout]  right: Some(1)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc3123 - core[df12db4294e9bfd3]::panicking::assert_failed_inner
[INFO] [stdout]   12:     0x5d8fc5b09db2 - core[df12db4294e9bfd3]::panicking::assert_failed::<core[df12db4294e9bfd3]::option::Option<i32>, core[df12db4294e9bfd3]::option::Option<i32>>
[INFO] [stdout]   13:     0x5d8fc5aad231 - <e2e[31a2f43d42c4f72f]::aka_with_the_wrong_key_fails_the_call_not_the_process::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   15:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   20:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- extended_3pcc_option_checks_and_wrong_sender stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'extended_3pcc_option_checks_and_wrong_sender' (1634) panicked at tests/e2e.rs:8325:68:
[INFO] [stdout] dial slave: Os { code: 111, kind: ConnectionRefused, message: "Connection refused" }
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc2f82 - core[df12db4294e9bfd3]::result::unwrap_failed
[INFO] [stdout]   12:     0x5d8fc5a98755 - <e2e[31a2f43d42c4f72f]::extended_3pcc_option_checks_and_wrong_sender::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   13:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   14:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   15:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   16:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   17:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   18:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   19:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   20:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- srtp_stream_passes_the_echo_check_against_an_srtp_echo_peer stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'srtp_stream_passes_the_echo_check_against_an_srtp_echo_peer' (2351) panicked at tests/e2e.rs:3845:47:
[INFO] [stdout] corpus: Os { code: 2, kind: NotFound, message: "No such file or directory" }
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc2f82 - core[df12db4294e9bfd3]::result::unwrap_failed
[INFO] [stdout]   12:     0x5d8fc5ab40e0 - <e2e[31a2f43d42c4f72f]::srtp_stream_passes_the_echo_check_against_an_srtp_echo_peer::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   13:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   14:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   15:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   16:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   17:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   18:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   19:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   20:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- statistical_pauses_scenario_runs_against_scripted_uas stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'statistical_pauses_scenario_runs_against_scripted_uas' (2354) panicked at tests/e2e.rs:7156:5:
[INFO] [stdout] assertion `left == right` failed: stderr:
[INFO] [stdout] sipr: error: cannot read scenario file /opt/rustwide/workdir/crates/sipr-scenario/tests/corpus/positive/statistical_pauses.xml: No such file or directory (os error 2)
[INFO] [stdout] 
[INFO] [stdout]   left: Some(255)
[INFO] [stdout]  right: Some(0)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc3123 - core[df12db4294e9bfd3]::panicking::assert_failed_inner
[INFO] [stdout]   12:     0x5d8fc5b09db2 - core[df12db4294e9bfd3]::panicking::assert_failed::<core[df12db4294e9bfd3]::option::Option<i32>, core[df12db4294e9bfd3]::option::Option<i32>>
[INFO] [stdout]   13:     0x5d8fc5aadc69 - <e2e[31a2f43d42c4f72f]::statistical_pauses_scenario_runs_against_scripted_uas::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   15:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   20:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- timeout_retrans_and_loss_knobs stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'timeout_retrans_and_loss_knobs' (2462) panicked at tests/e2e.rs:7895:5:
[INFO] [stdout] sipr: control socket (UDP, SIPp -cp protocol) on 127.0.0.1:8892
[INFO] [stdout] sipr: bound to 0.0.0.0:41902 (placing calls)
[INFO] [stdout] sipr: error: cannot create error trace file uac_2463_errors.log: Read-only file system (os error 30)
[INFO] [stdout] 
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5a6dd94 - <e2e[31a2f43d42c4f72f]::timeout_retrans_and_loss_knobs::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   12:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   13:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   14:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   15:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   16:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   17:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   18:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   19:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- srtp_echo_server_passes_a_peers_echo_check stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'srtp_echo_server_passes_a_peers_echo_check' (2348) panicked at tests/e2e.rs:4007:5:
[INFO] [stdout] assertion `left == right` failed: uac stderr:
[INFO] [stdout] sipr: bound to 127.0.0.1:43400 (placing calls)
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 1/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 2/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 2/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: global timeout reached; failing active calls
[INFO] [stdout] sipr: run complete: created 1 successful 0 failed 1 | sent 1 matched 0 retrans-sent 4 retrans-recv 0 unexpected 0 garbage 0 | 15.2s
[INFO] [stdout] 
[INFO] [stdout]   left: Some(1)
[INFO] [stdout]  right: Some(0)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc3123 - core[df12db4294e9bfd3]::panicking::assert_failed_inner
[INFO] [stdout]   12:     0x5d8fc5b09db2 - core[df12db4294e9bfd3]::panicking::assert_failed::<core[df12db4294e9bfd3]::option::Option<i32>, core[df12db4294e9bfd3]::option::Option<i32>>
[INFO] [stdout]   13:     0x5d8fc5a8c0f6 - <e2e[31a2f43d42c4f72f]::srtp_echo_server_passes_a_peers_echo_check::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   15:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   20:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- unexp_handler_restores_the_interrupted_pause stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'unexp_handler_restores_the_interrupted_pause' (2578) panicked at tests/e2e.rs:5150:5:
[INFO] [stdout] assertion `left == right` failed: uac:
[INFO] [stdout] sipr: control socket (UDP, SIPp -cp protocol) on 127.0.0.1:8890
[INFO] [stdout] sipr: bound to 127.0.0.1:55494 (placing calls)
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 1/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 2/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 2/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 3/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: live 1 created 1 ok 0 failed 0 | sent 1 matched 0 retrans 4/0 unexpected 0 garbage 0
[INFO] [stdout] sipr: global timeout reached; failing active calls
[INFO] [stdout] sipr: run complete: created 1 successful 0 failed 1 | sent 1 matched 0 retrans-sent 4 retrans-recv 0 unexpected 0 garbage 0 | 15.0s
[INFO] [stdout] 
[INFO] [stdout] uas:
[INFO] [stdout] sipr: error: cannot read scenario file /opt/rustwide/workdir/crates/sipr-scenario/tests/corpus/positive/unexp_handler.xml: No such file or directory (os error 2)
[INFO] [stdout] 
[INFO] [stdout]   left: Some(1)
[INFO] [stdout]  right: Some(0)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5d8fc5cab9f1 - <<std[70759c8f55707aa4]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[df12db4294e9bfd3]::fmt::Display>::fmt
[INFO] [stdout]    1:     0x5d8fc5cc2a7a - core[df12db4294e9bfd3]::fmt::write
[INFO] [stdout]    2:     0x5d8fc5cb0a7c - <alloc[2182bb758b4b3781]::vec::Vec<u8> as core[df12db4294e9bfd3]::io::write::Write>::write_fmt
[INFO] [stdout]    3:     0x5d8fc5c841e6 - std[70759c8f55707aa4]::panicking::default_hook::{closure#0}
[INFO] [stdout]    4:     0x5d8fc5ca2449 - std[70759c8f55707aa4]::panicking::default_hook
[INFO] [stdout]    5:     0x5d8fc5b2f3a0 - test[9d35eded1c95d3be]::test_main_inner::<test[9d35eded1c95d3be]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]    6:     0x5d8fc5ca2772 - std[70759c8f55707aa4]::panicking::panic_with_hook
[INFO] [stdout]    7:     0x5d8fc5c84292 - std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}
[INFO] [stdout]    8:     0x5d8fc5c7cc19 - std[70759c8f55707aa4]::sys::backtrace::__rust_end_short_backtrace::<std[70759c8f55707aa4]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]    9:     0x5d8fc5c8507d - __rustc[8fa7c3cbc660c2b3]::rust_begin_unwind
[INFO] [stdout]   10:     0x5d8fc5cc31ac - core[df12db4294e9bfd3]::panicking::panic_fmt
[INFO] [stdout]   11:     0x5d8fc5cc3123 - core[df12db4294e9bfd3]::panicking::assert_failed_inner
[INFO] [stdout]   12:     0x5d8fc5b09db2 - core[df12db4294e9bfd3]::panicking::assert_failed::<core[df12db4294e9bfd3]::option::Option<i32>, core[df12db4294e9bfd3]::option::Option<i32>>
[INFO] [stdout]   13:     0x5d8fc5a9972c - <e2e[31a2f43d42c4f72f]::unexp_handler_restores_the_interrupted_pause::{closure#0} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]   14:     0x5d8fc5b2268b - test[9d35eded1c95d3be]::__rust_begin_short_backtrace::<core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>, fn() -> core[df12db4294e9bfd3]::result::Result<(), alloc[2182bb758b4b3781]::string::String>>
[INFO] [stdout]   15:     0x5d8fc5b2fcf5 - test[9d35eded1c95d3be]::run_test::{closure#0}
[INFO] [stdout]   16:     0x5d8fc5b295b4 - std[70759c8f55707aa4]::sys::backtrace::__rust_begin_short_backtrace::<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>
[INFO] [stdout]   17:     0x5d8fc5b32e52 - <std[70759c8f55707aa4]::thread::lifecycle::spawn_unchecked<test[9d35eded1c95d3be]::run_test::{closure#1}, ()>::{closure#1} as core[df12db4294e9bfd3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]   18:     0x5d8fc5caa369 - <std[70759c8f55707aa4]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]   19:     0x7f3156d96dfa - <unknown>
[INFO] [stdout]   20:     0x7f3156e2a3d4 - clone
[INFO] [stdout]   21:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     actions_scenario_runs_against_scripted_uas
[INFO] [stdout]     aka_with_the_wrong_key_fails_the_call_not_the_process
[INFO] [stdout]     auth_uri_flag_and_default_follow_sipp
[INFO] [stdout]     extended_3pcc_option_checks_and_wrong_sender
[INFO] [stdout]     srtp_echo_server_passes_a_peers_echo_check
[INFO] [stdout]     srtp_stream_passes_the_echo_check_against_an_srtp_echo_peer
[INFO] [stdout]     statistical_pauses_scenario_runs_against_scripted_uas
[INFO] [stdout]     timeout_retrans_and_loss_knobs
[INFO] [stdout]     unexp_handler_restores_the_interrupted_pause
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 93 passed; 9 failed; 0 ignored; 0 measured; 0 filtered out; finished in 28.07s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a", kill_on_drop: false }`
[INFO] [stdout] cd5d5dcaa2919405f81961ce0be2e2095b6ee72e2e2bbc94f9da26a5dab2bd8a
