[INFO] fetching crate rprof 1.0.0...
[INFO] testing rprof-1.0.0 against 1.100.0-beta.1 for beta-1.100-2
[INFO] extracting crate rprof 1.0.0 into /workspace/builds/worker-3-tc2/source
[INFO] started tweaking crates.io crate rprof 1.0.0
[INFO] removed 0 missing examples
[INFO] removed 0 missing tests
[INFO] finished tweaking crates.io crate rprof 1.0.0
[INFO] tweaked toml for crates.io crate rprof 1.0.0 written to /workspace/builds/worker-3-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate rprof 1.0.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 rprof 1.0.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-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:3111399a4047eeb3a02b7a90e478d715f38a8c6669b5c4b49d30a17385265909" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54
[INFO] running `Command { std: "docker" "start" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", 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" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54" "/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" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", 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" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling serde_json v1.0.149
[INFO] [stderr]    Compiling memchr v2.8.0
[INFO] [stderr]    Compiling clap_builder v4.6.0
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling clap_derive v4.6.1
[INFO] [stderr]    Compiling clap v4.6.1
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling rprof v1.0.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 11.22s
[INFO] running `Command { std: "docker" "inspect" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", 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" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling aho-corasick v1.1.4
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling predicates-core v1.0.10
[INFO] [stderr]    Compiling float-cmp v0.10.0
[INFO] [stderr]    Compiling termtree v0.5.1
[INFO] [stderr]    Compiling difflib v0.4.0
[INFO] [stderr]    Compiling normalize-line-endings v0.3.0
[INFO] [stderr]    Compiling assert_cmd v2.2.2
[INFO] [stderr]    Compiling wait-timeout v0.2.1
[INFO] [stderr]    Compiling once_cell v1.21.4
[INFO] [stderr]    Compiling predicates-tree v1.0.13
[INFO] [stderr]    Compiling regex-automata v0.4.14
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling regex v1.12.3
[INFO] [stderr]    Compiling bstr v1.12.1
[INFO] [stderr]    Compiling predicates v3.1.4
[INFO] [stderr]    Compiling rprof v1.0.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 13.67s
[INFO] running `Command { std: "docker" "inspect" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", 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" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54" "/opt/rustwide/cargo-home/bin/cargo" "+1.100.0-beta.1" "test" "--frozen", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.12s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/build/rprof/9840738fd360c3b1/out/rprof-9840738fd360c3b1)
[INFO] [stdout] 
[INFO] [stdout] running 40 tests
[INFO] [stdout] test cli::tests::parse_duration_rejects_bare_number ... ok
[INFO] [stdout] test cli::tests::parse_duration_ms ... ok
[INFO] [stdout] test cli::tests::parse_duration_rejects_zero ... ok
[INFO] [stdout] test cli::tests::parse_label_requires_colon ... ok
[INFO] [stdout] test cli::tests::parse_label_splits_on_first_colon ... ok
[INFO] [stdout] test proc_parse::tests::count_fds_counts_directory_entries ... ok
[INFO] [stdout] test cli::tests::parse_label_rejects_empty_label ... ok
[INFO] [stdout] test proc_parse::tests::parse_proc_stat_extracts_cpu_threads_memory ... ok
[INFO] [stdout] test runner::tests::exit_status_nonzero_truncates_to_u8 ... ok
[INFO] [stdout] test runner::tests::resolve_output_path_uses_explicit_value ... ok
[INFO] [stdout] test proc_parse::tests::parse_proc_stat_handles_comm_with_spaces ... ok
[INFO] [stdout] test runner::tests::resolve_output_path_falls_back_to_rprof_dir_with_jsonl_extension ... ok
[INFO] [stdout] test schema::tests::schema_version_is_one ... ok
[INFO] [stdout] test schema::tests::additive_fields_tolerated_on_read ... ok
[INFO] [stdout] test schema::tests::unknown_record_type_is_skipped_by_reader ... ok
[INFO] [stdout] test viewer::tests::build_view_report_takes_max_rss_across_samples ... ok
[INFO] [stdout] test viewer::tests::build_view_report_zeroes_first_sample_cpu_and_computes_subsequent ... ok
[INFO] [stdout] test viewer::tests::collect_inputs_label_only_is_accepted ... ok
[INFO] [stdout] test viewer::tests::parse_jsonl_recovers_footer_when_present ... ok
[INFO] [stdout] test proc_parse::tests::count_fds_returns_zero_for_missing_dir ... ok
[INFO] [stdout] test proc_parse::tests::parse_proc_io_defaults_to_zero_when_fields_absent ... ok
[INFO] [stdout] test proc_parse::tests::parse_proc_stat_rejects_truncated ... ok
[INFO] [stdout] test proc_parse::tests::parse_proc_io_reads_read_and_write_bytes ... ok
[INFO] [stdout] test runner::tests::exit_status_signal_uses_128_plus_signum ... ok
[INFO] [stdout] test viewer::tests::collect_inputs_uses_filename_when_no_label ... ok
[INFO] [stdout] test sampler::tests::proc_sampler_returns_none_for_missing_pid ... ok
[INFO] [stdout] test viewer::tests::parse_jsonl_tolerates_unknown_record_types ... ok
[INFO] [stdout] test sampler::tests::proc_sampler_returns_self_metrics ... ok
[INFO] [stdout] test viewer::tests::parse_jsonl_accepts_header_only_partial_file ... ok
[INFO] [stdout] test viewer::tests::parse_jsonl_tolerates_truncated_final_line ... ok
[INFO] [stdout] test schema::tests::header_sample_footer_roundtrip_line_by_line ... ok
[INFO] [stdout] test viewer::tests::collect_inputs_label_overrides_positional ... ok
[INFO] [stdout] test viewer::tests::payload_escapes_closing_script_tags ... ok
[INFO] [stdout] test viewer::tests::render_html_carries_interaction_machinery ... ok
[INFO] [stdout] test runner::tests::exit_status_zero_returns_zero ... ok
[INFO] [stdout] test viewer::tests::collect_inputs_preserves_positional_order ... ok
[INFO] [stdout] test viewer::tests::render_html_emits_complete_document ... ok
[INFO] [stdout] test schema::tests::canonical_example_parses ... ok
[INFO] [stdout] test viewer::tests::render_html_inlines_multiple_runs ... ok
[INFO] [stdout] test viewer::tests::parse_jsonl_rejects_unknown_schema_with_path_and_field ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 40 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/build/rprof/9e183c29e232e193/out/rprof-9e183c29e232e193)
[INFO] [stderr]      Running tests/runner_integration.rs (/opt/rustwide/target/debug/build/rprof/2048a66fb6c8a960/out/runner_integration-2048a66fb6c8a960)
[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] [stdout] 
[INFO] [stdout] running 11 tests
[INFO] [stdout] test run_records_command_args ... ok
[INFO] [stdout] test run_help_mentions_double_dash_separator ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmpZtm7eO/r.jsonl (wall 4ms, cpu_user 0ms, cpu_sys 1ms, exit 0)
[INFO] [stderr] rprof: wrote .rprof/2026-10-06T173653.jsonl (wall 4ms, cpu_user 0ms, cpu_sys 0ms, exit 0)
[INFO] [stderr] rprof: wrote /tmp/.tmp0KSPXn/r.jsonl (wall 3ms, cpu_user 0ms, cpu_sys 0ms, exit 42)
[INFO] [stdout] test run_propagates_nonzero_exit_code ... ok
[INFO] [stdout] test run_writes_auto_output_path_when_no_dash_o ... ok
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.13s
[INFO] [stderr] rprof: wrote /tmp/.tmpnTajgV/r.jsonl (wall 260ms, cpu_user 1ms, cpu_sys 3ms, exit 0)
[INFO] [stderr] rprof: wrote /tmp/.tmpwO3WKX/r.jsonl (wall 251ms, cpu_user 2ms, cpu_sys 1ms, exit signal 2)
[INFO] [stdout] test run_emits_records_in_order_header_samples_footer ... ok
[INFO] [stdout] test run_forwards_sigint_and_still_writes_report ... ok
[INFO] [stdout] test run_killed_with_sigkill_leaves_header_and_samples_no_footer ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmpCzJp5k/r.jsonl (wall 313ms, cpu_user 1ms, cpu_sys 2ms, exit 0)
[INFO] [stdout] test run_sleep_produces_valid_report ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmplSkWBt/r.jsonl (wall 319ms, cpu_user 96ms, cpu_sys 63ms, exit 0)
[INFO] [stdout] test run_burning_cpu_records_nonzero_cpu_time ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmpNnRxEK/alloc.jsonl (wall 667ms, cpu_user 9ms, cpu_sys 47ms, exit 0)
[INFO] [stdout] test run_peak_rss_matches_known_allocation_within_5pct ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmpWJk9yi/r.jsonl (wall 1514ms, cpu_user 1ms, cpu_sys 2ms, exit 0)
[INFO] [stdout] test run_writes_samples_incrementally_during_long_run ... ok
[INFO] [stderr]      Running tests/viewer_integration.rs (/opt/rustwide/target/debug/build/rprof/4f552d0af26a4e44/out/viewer_integration-4f552d0af26a4e44)
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 11 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.52s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 8 tests
[INFO] [stdout] test view_renders_partial_file_without_footer ... ok
[INFO] [stdout] test view_rejects_no_inputs ... ok
[INFO] [stdout] test view_rejects_unknown_schema_version ... ok
[INFO] [stdout] test view_tolerates_truncated_trailing_line ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmpZHr1bG/my-build.jsonl (wall 107ms, cpu_user 0ms, cpu_sys 4ms, exit 0)
[INFO] [stdout] test view_uses_filename_as_default_label ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmp5E1JDU/before.jsonl (wall 164ms, cpu_user 0ms, cpu_sys 4ms, exit 0)
[INFO] [stderr] rprof: wrote /tmp/.tmpJ5AF4X/r.jsonl (wall 212ms, cpu_user 0ms, cpu_sys 3ms, exit 0)
[INFO] [stderr] rprof: wrote /tmp/.tmpTF6aK7/r.jsonl (wall 219ms, cpu_user 1ms, cpu_sys 2ms, exit 0)
[INFO] [stdout] test view_no_open_writes_html_to_stdout ... ok
[INFO] [stdout] test view_no_open_with_output_writes_file ... ok
[INFO] [stderr] rprof: wrote /tmp/.tmp5E1JDU/after.jsonl (wall 255ms, cpu_user 0ms, cpu_sys 4ms, exit 0)
[INFO] [stderr]    Doc-tests rprof
[INFO] [stdout] test view_overlays_two_reports_with_labels ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 8 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.45s
[INFO] [stdout] 
[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" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54", kill_on_drop: false }`
[INFO] [stdout] b9d4328dc72492409e4f78d1b3c9849c9c286f5c3306085cf95a8a41dcbd2b54
