[INFO] fetching crate toll 1.0.8...
[INFO] testing toll-1.0.8 against master#562dee4820c458d823175268e41601d4c060588a for pr-154210-2
[INFO] extracting crate toll 1.0.8 into /workspace/builds/worker-3-tc1/source
[INFO] started tweaking crates.io crate toll 1.0.8
[INFO] finished tweaking crates.io crate toll 1.0.8
[INFO] tweaked toml for crates.io crate toll 1.0.8 written to /workspace/builds/worker-3-tc1/source/Cargo.toml
[INFO] validating manifest of crates.io crate toll 1.0.8 on toolchain 562dee4820c458d823175268e41601d4c060588a
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate toll 1.0.8 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" "+562dee4820c458d823175268e41601d4c060588a" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] ab7971c09d20bd5c81bbbe57b5988bb58a1152b7641541f685cb6d31b57eb190
[INFO] running `Command { std: "docker" "start" "-a" "ab7971c09d20bd5c81bbbe57b5988bb58a1152b7641541f685cb6d31b57eb190", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "ab7971c09d20bd5c81bbbe57b5988bb58a1152b7641541f685cb6d31b57eb190", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "ab7971c09d20bd5c81bbbe57b5988bb58a1152b7641541f685cb6d31b57eb190", kill_on_drop: false }`
[INFO] [stdout] ab7971c09d20bd5c81bbbe57b5988bb58a1152b7641541f685cb6d31b57eb190
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] f0e57bdc4d1c58f2d65ec5c46275c8b36328154c2d5897cbcfdf22ca7b3e8560
[INFO] running `Command { std: "docker" "start" "-a" "f0e57bdc4d1c58f2d65ec5c46275c8b36328154c2d5897cbcfdf22ca7b3e8560", kill_on_drop: false }`
[INFO] [stderr]    Compiling clap_lex v1.0.0
[INFO] [stderr]    Compiling syn v2.0.117
[INFO] [stderr]    Compiling chrono v0.4.44
[INFO] [stderr]    Compiling clap_builder v4.5.60
[INFO] [stderr]    Compiling serde_derive v1.0.228
[INFO] [stderr]    Compiling clap_derive v4.5.55
[INFO] [stderr]    Compiling clap v4.5.60
[INFO] [stderr]    Compiling serde v1.0.228
[INFO] [stderr]    Compiling toll v1.0.8 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 12.23s
[INFO] running `Command { std: "docker" "inspect" "f0e57bdc4d1c58f2d65ec5c46275c8b36328154c2d5897cbcfdf22ca7b3e8560", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "f0e57bdc4d1c58f2d65ec5c46275c8b36328154c2d5897cbcfdf22ca7b3e8560", kill_on_drop: false }`
[INFO] [stdout] f0e57bdc4d1c58f2d65ec5c46275c8b36328154c2d5897cbcfdf22ca7b3e8560
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] d3c3244bdbd924b8dd53b4a237580f2e9e430fcdaef3f5426753620e9a4da566
[INFO] running `Command { std: "docker" "start" "-a" "d3c3244bdbd924b8dd53b4a237580f2e9e430fcdaef3f5426753620e9a4da566", kill_on_drop: false }`
[INFO] [stderr]    Compiling toll v1.0.8 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 2.30s
[INFO] running `Command { std: "docker" "inspect" "d3c3244bdbd924b8dd53b4a237580f2e9e430fcdaef3f5426753620e9a4da566", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "d3c3244bdbd924b8dd53b4a237580f2e9e430fcdaef3f5426753620e9a4da566", kill_on_drop: false }`
[INFO] [stdout] d3c3244bdbd924b8dd53b4a237580f2e9e430fcdaef3f5426753620e9a4da566
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-3-tc1/source:/opt/rustwide/workdir:ro,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" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+562dee4820c458d823175268e41601d4c060588a" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] 218a106576618760d6109aa1a4181a2988c79948fb249c5be772fec79ee31f8d
[INFO] running `Command { std: "docker" "start" "-a" "218a106576618760d6109aa1a4181a2988c79948fb249c5be772fec79ee31f8d", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.08s
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/toll-21b2f499c51fd19d)
[INFO] [stdout] 
[INFO] [stdout] running 78 tests
[INFO] [stdout] test claude::tests::computes_cost_for_known_model ... ok
[INFO] [stdout] test claude::tests::counts_top_level_user_queries_once_per_user_message ... ok
[INFO] [stdout] test claude::tests::date_filter_includes_exact_boundary ... ok
[INFO] [stdout] test claude::tests::date_filter_excludes_old_entries ... ok
[INFO] [stdout] test claude::tests::skips_malformed_lines ... ok
[INFO] [stdout] test claude::tests::sums_all_messages ... ok
[INFO] [stdout] test claude::tests::parse_claude_lines_by_day_counts_unknown_cost_once_per_session_day ... ok
[INFO] [stdout] test claude::tests::parse_claude_lines_by_day_groups_local_dates ... ok
[INFO] [stdout] test codex::tests::codex_line_relevance_filters_unrelated_lines ... ok
[INFO] [stdout] test codex::tests::computes_cost_for_known_model ... ok
[INFO] [stdout] test claude::tests::skips_lines_without_usage ... ok
[INFO] [stdout] test codex::tests::marks_unknown_cost_when_model_missing ... ok
[INFO] [stdout] test codex::tests::parses_last_token_count ... ok
[INFO] [stdout] test codex::tests::session_date_parses_correctly ... ok
[INFO] [stdout] test codex::tests::cost_with_cache_discount ... ok
[INFO] [stdout] test codex::tests::counts_task_started_events_as_user_queries ... ok
[INFO] [stdout] test codex::tests::empty_input_returns_none ... ok
[INFO] [stdout] test codex::tests::gpt5_variant_uses_prefix_pricing ... ok
[INFO] [stdout] test display::tests::fmt_cost_all_unknown ... ok
[INFO] [stdout] test codex::tests::session_date_rejects_short_name ... ok
[INFO] [stdout] test display::tests::fmt_cost_known ... ok
[INFO] [stdout] test codex::tests::marks_unknown_cost_for_unknown_model ... ok
[INFO] [stdout] test codex::tests::skips_malformed_lines ... ok
[INFO] [stdout] test display::tests::fmt_cost_no_sessions ... ok
[INFO] [stdout] test display::tests::fmt_cost_partial_unknown ... ok
[INFO] [stdout] test display::tests::fmt_num_compact_uses_suffixes ... ok
[INFO] [stdout] test display::tests::fmt_num_full_keeps_raw_value ... ok
[INFO] [stdout] test display::tests::fmt_pct_half ... ok
[INFO] [stdout] test display::tests::fmt_pct_full ... ok
[INFO] [stdout] test display::tests::fmt_pct_zero_total ... ok
[INFO] [stdout] test display::tests::render_daily_table_lists_latest_day_first ... ok
[INFO] [stdout] test display::tests::render_single_table_keeps_vertical_layout ... ok
[INFO] [stdout] test display::tests::fmt_num_formats_with_commas ... ok
[INFO] [stdout] test codex::tests::collect_codex_daily_usage_groups_by_local_date ... ok
[INFO] [stdout] test kimi::tests::computes_cost_for_known_model ... ok
[INFO] [stdout] test kimi::tests::parse_by_day_groups_local_dates ... ok
[INFO] [stdout] test kimi::tests::date_filter_excludes_old_entries ... ok
[INFO] [stdout] test gemini::tests::sums_all_gemini_messages_in_a_session ... ok
[INFO] [stdout] test gemini::tests::buckets_daily_usage_by_message_date ... ok
[INFO] [stdout] test gemini::tests::respects_since_filter_per_message ... ok
[INFO] [stdout] test kimi::tests::counts_turn_begin_events_as_user_queries ... ok
[INFO] [stdout] test display::tests::render_multi_table_supports_three_agents ... ok
[INFO] [stdout] test gemini::tests::marks_unknown_cost_when_model_is_missing ... ok
[INFO] [stdout] test gemini::tests::prefix_matching_for_previews ... ok
[INFO] [stdout] test kimi::tests::skips_non_status_update_lines ... ok
[INFO] [stdout] test codex::tests::collect_codex_usage_aggregates_matching_rollout_files ... ok
[INFO] [stdout] test output::tests::render_daily_csv_respects_latest_day_first ... ok
[INFO] [stdout] test kimi::tests::sums_all_status_updates ... ok
[INFO] [stdout] test pricing::tests::exact_match ... ok
[INFO] [stdout] test output::tests::render_summary_csv_prints_terminal_friendly_rows ... ok
[INFO] [stdout] test pricing::tests::openai_cost_no_cache_write_charge ... ok
[INFO] [stdout] test pricing::tests::unknown_model_returns_none ... ok
[INFO] [stdout] test tests::formats_version_output ... ok
[INFO] [stdout] test output::tests::render_summary_json_includes_combined_usage ... ok
[INFO] [stdout] test pricing::tests::prefix_match_claude_with_snapshot_date ... ok
[INFO] [stdout] test pricing::tests::cost_calculation ... ok
[INFO] [stdout] test pricing::tests::gpt4o_mini_before_gpt4o ... ok
[INFO] [stdout] test pricing::tests::prefix_match_gpt5_variant ... ok
[INFO] [stdout] test pricing::tests::cost_with_cache ... ok
[INFO] [stdout] test pricing::tests::pricing_table_lists_latest_gpt5_variants ... ok
[INFO] [stdout] test tests::agents_expose_distinct_names_and_data_dirs ... ok
[INFO] [stdout] test tests::parses_by_day_flag ... ok
[INFO] [stdout] test tests::parses_csv_flag ... ok
[INFO] [stdout] test usage::tests::add_merges_by_model ... ok
[INFO] [stdout] test tests::parses_detail_flag ... ok
[INFO] [stdout] test tests::parses_short_version_flag ... ok
[INFO] [stdout] test usage::tests::has_unknown_cost ... ok
[INFO] [stdout] test usage::tests::add_daily_usage_merges_same_day ... ok
[INFO] [stdout] test usage::tests::add_scalars ... ok
[INFO] [stdout] test usage::tests::net_no_underflow ... ok
[INFO] [stdout] test tests::parses_long_version_flag ... ok
[INFO] [stdout] test usage::tests::record_model_accumulates ... ok
[INFO] [stdout] test usage::tests::total_and_net ... ok
[INFO] [stdout] test tests::parses_json_flag ... ok
[INFO] [stdout] test tests::agent_filter_selects_correct_subset ... ok
[INFO] [stdout] test claude::tests::marks_unknown_cost_for_unknown_model ... ok
[INFO] [stdout] test codex::tests::ignores_non_token_count_events ... ok
[INFO] [stdout] test codex::tests::session_date_rejects_non_rollout ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 78 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.02s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "218a106576618760d6109aa1a4181a2988c79948fb249c5be772fec79ee31f8d", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "218a106576618760d6109aa1a4181a2988c79948fb249c5be772fec79ee31f8d", kill_on_drop: false }`
[INFO] [stdout] 218a106576618760d6109aa1a4181a2988c79948fb249c5be772fec79ee31f8d