[INFO] cloning repository https://github.com/keix/formula
[INFO] running `Command { std: "git" "-c" "credential.helper=" "-c" "credential.helper=/workspace/cargo-home/bin/git-credential-null" "clone" "--bare" "https://github.com/keix/formula" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fkeix%2Fformula", kill_on_drop: false }`
[INFO] [stderr] Cloning into bare repository '/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fkeix%2Fformula'...
[INFO] running `Command { std: "git" "rev-parse" "HEAD", kill_on_drop: false }`
[INFO] [stdout] b809e14a1cb5c3969749a5d0fcfa1b8964011bd5
[INFO] testing keix/formula against 1.98.0-beta.1 for beta-1.98-1
[INFO] running `Command { std: "git" "clone" "/workspace/cache/git-repos/https%3A%2F%2Fgithub.com%2Fkeix%2Fformula" "/workspace/builds/worker-4-tc2/source", kill_on_drop: false }`
[INFO] [stderr] Cloning into '/workspace/builds/worker-4-tc2/source'...
[INFO] [stderr] done.
[INFO] started tweaking git repo https://github.com/keix/formula
[INFO] finished tweaking git repo https://github.com/keix/formula
[INFO] tweaked toml for git repo https://github.com/keix/formula written to /workspace/builds/worker-4-tc2/source/Cargo.toml
[INFO] validating manifest of git repo https://github.com/keix/formula on toolchain 1.98.0-beta.1
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+1.98.0-beta.1" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate git repo https://github.com/keix/formula 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.98.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:3d5ced03c013a94a2f102a4510f48a6e9184255caf5fd8244f58017bde7f5210" "sleep" "infinity", kill_on_drop: false }`
[INFO] [stdout] 4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a
[INFO] running `Command { std: "docker" "start" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", 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" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a" "/opt/rustwide/cargo-home/bin/cargo" "+1.98.0-beta.1" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", 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" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a" "/opt/rustwide/cargo-home/bin/cargo" "+1.98.0-beta.1" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling pkg-config v0.3.33
[INFO] [stderr]    Compiling libc v0.2.186
[INFO] [stderr]    Compiling unicode-ident v1.0.24
[INFO] [stderr]    Compiling lazy_static v1.5.0
[INFO] [stderr]    Compiling smallvec v1.15.1
[INFO] [stderr]    Compiling rustix v1.1.4
[INFO] [stderr]    Compiling quote v1.0.45
[INFO] [stderr]    Compiling memoffset v0.6.5
[INFO] [stderr]    Compiling getrandom v0.4.2
[INFO] [stderr]    Compiling cc v1.2.62
[INFO] [stderr]    Compiling linux-raw-sys v0.12.1
[INFO] [stderr]    Compiling bitflags v2.11.1
[INFO] [stderr]    Compiling fastrand v2.4.1
[INFO] [stderr]    Compiling raw-window-handle v0.6.2
[INFO] [stderr]    Compiling proc-macro2 v1.0.106
[INFO] [stderr]    Compiling wayland-sys v0.29.5
[INFO] [stderr]    Compiling x11-dl v2.21.0
[INFO] [stderr]    Compiling wayland-scanner v0.29.5
[INFO] [stderr]    Compiling minifb v0.27.0
[INFO] [stderr]    Compiling wayland-client v0.29.5
[INFO] [stderr]    Compiling wayland-protocols v0.29.5
[INFO] [stderr]    Compiling nix v0.24.3
[INFO] [stderr]    Compiling tempfile v3.27.0
[INFO] [stderr]    Compiling wayland-commons v0.29.5
[INFO] [stderr]    Compiling wayland-cursor v0.29.5
[INFO] [stderr]    Compiling formula v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 41.02s
[INFO] running `Command { std: "docker" "inspect" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", 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" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a" "/opt/rustwide/cargo-home/bin/cargo" "+1.98.0-beta.1" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stderr]    Compiling simd-adler32 v0.3.9
[INFO] [stderr]    Compiling pxfm v0.1.29
[INFO] [stderr]    Compiling byteorder-lite v0.1.0
[INFO] [stderr]    Compiling bytemuck v1.25.0
[INFO] [stderr]    Compiling miniz_oxide v0.8.9
[INFO] [stderr]    Compiling fdeflate v0.3.7
[INFO] [stderr]    Compiling flate2 v1.1.9
[INFO] [stderr]    Compiling png v0.18.1
[INFO] [stderr]    Compiling moxcms v0.8.1
[INFO] [stderr]    Compiling image v0.25.10
[INFO] [stderr]    Compiling formula v0.1.0 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 20.03s
[INFO] running `Command { std: "docker" "inspect" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", 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" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a" "/opt/rustwide/cargo-home/bin/cargo" "+1.98.0-beta.1" "test" "--frozen", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.18s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/formula-8c975a219df1be92)
[INFO] [stdout] running 280 tests
[INFO] [stdout] test apu::tests::disabling_dac_drops_channel_status_immediately ... ok
[INFO] [stdout] test apu::tests::batched_tick_matches_single_cycle_tick_for_audio_sampling ... ok
[INFO] [stdout] test apu::tests::clearing_negate_after_negate_sweep_use_disables_channel1 ... ok
[INFO] [stdout] test apu::tests::powered_on_registers_read_back_with_hardware_masks ... ok
[INFO] [stdout] test apu::tests::ticking_produces_stereo_samples_when_a_channel_is_routed ... ok
[INFO] [stdout] test apu::tests::wave_channel_latches_samples_as_it_advances ... ok
[INFO] [stdout] test apu::tests::write_only_frequency_bits_are_preserved_internally ... ok
[INFO] [stdout] test apu::tests::powering_off_clears_registers_but_keeps_wave_ram ... ok
[INFO] [stdout] test apu::tests::sweep_period_zero_reloads_as_eight ... ok
[INFO] [stdout] test apu::tests::writes_are_ignored_while_powered_off_except_wave_ram ... ok
[INFO] [stdout] test cartridge::tests::load_cartridge_returns_mbc0_for_type_00 ... ok
[INFO] [stdout] test cartridge::tests::load_cartridge_returns_mbc1_for_types_01_through_03 ... ok
[INFO] [stdout] test cartridge::tests::mbc0_reads_rom_bytes ... ok
[INFO] [stdout] test cartridge::tests::mbc1_bank_select_writes_the_lower_five_bits ... ok
[INFO] [stdout] test cartridge::tests::mbc0_short_rom_reads_ff_past_end ... ok
[INFO] [stdout] test cartridge::tests::mbc1_ram_is_disabled_until_unlocked ... ok
[INFO] [stdout] test cartridge::tests::mbc1_ram_banks_under_advanced_mode ... ok
[INFO] [stdout] test cartridge::tests::mbc1_advanced_mode_maps_high_banks_into_low_window ... ok
[INFO] [stdout] test cartridge::tests::mbc0_ignores_writes_to_rom ... ok
[INFO] [stdout] test cartridge::tests::mbc1_bank0_is_always_visible_at_0000_in_default_mode ... ok
[INFO] [stdout] test apu::tests::trigger_sets_status_and_length_clock_eventually_disables_channel ... ok
[INFO] [stdout] test cartridge::tests::mbc1_bank_index_wraps_to_rom_size ... ok
[INFO] [stdout] test cartridge::tests::mbc0_external_ram_roundtrips ... ok
[INFO] [stdout] test cartridge::tests::mbc0_without_ram_reads_ff_and_swallows_writes ... ok
[INFO] [stdout] test cartridge::tests::mbc1_ram_re_locks_on_non_magic_write ... ok
[INFO] [stdout] test cartridge::tests::mbc1_ram_roundtrips_when_enabled_with_magic_value ... ok
[INFO] [stdout] test cartridge::tests::mbc1_bank_high_bits_extend_rom_address_in_default_mode ... ok
[INFO] [stdout] test cartridge::tests::mbc1_writing_zero_to_bank_register_selects_bank_one ... ok
[INFO] [stdout] test apu::tests::envelope_clocks_channel_volume_down ... ok
[INFO] [stdout] test cpu::tests::adc_a_b_propagates_carry_in ... ok
[INFO] [stdout] test cpu::tests::add_a_b_sets_half_carry_only ... ok
[INFO] [stdout] test cpu::tests::alu_immediate_all_opcodes_dispatch_correctly ... ok
[INFO] [stdout] test cpu::tests::alu_indirect_hl_takes_8_cycles ... ok
[INFO] [stdout] test cpu::tests::adc_a_n_uses_carry_in ... ok
[INFO] [stdout] test cpu::tests::add_a_b_overflow_sets_zero_and_carry ... ok
[INFO] [stdout] test cartridge::tests::mbc1_window_at_4000_defaults_to_bank_1 ... ok
[INFO] [stdout] test cpu::tests::add_hl_sets_carry_on_bit_15_overflow ... ok
[INFO] [stdout] test cpu::tests::call_nn_pushes_next_pc_and_jumps ... ok
[INFO] [stdout] test cpu::tests::call_cc_taken_and_not_taken_have_different_cycles ... ok
[INFO] [stdout] test cpu::tests::and_a_b_always_sets_half_carry ... ok
[INFO] [stdout] test cpu::tests::add_hl_sets_half_carry_on_bit_11_overflow ... ok
[INFO] [stdout] test cpu::tests::add_sp_e_negative_offset_with_carry_from_low_byte_unsigned_add ... ok
[INFO] [stdout] test cpu::tests::add_sp_e_positive_offset_byte_carry ... ok
[INFO] [stdout] test cpu::tests::add_sp_e_positive_offset_half_carry ... ok
[INFO] [stdout] test cpu::tests::add_hl_preserves_z_and_clears_n ... ok
[INFO] [stdout] test cpu::tests::add_hl_dispatches_to_all_pairs ... ok
[INFO] [stdout] test cpu::tests::cb_rrc_b_rotates_right_and_captures_lsb_in_carry ... ok
[INFO] [stdout] test cpu::tests::call_then_ret_roundtrips ... ok
[INFO] [stdout] test cpu::tests::cb_set_b_sets_bit ... ok
[INFO] [stdout] test cpu::tests::cb_sla_b_shifts_in_zero ... ok
[INFO] [stdout] test cpu::tests::cb_bit_b_clears_z_when_bit_set ... ok
[INFO] [stdout] test cpu::tests::cb_bit_b_sets_z_when_bit_clear ... ok
[INFO] [stdout] test cpu::tests::cb_bit_indirect_hl_takes_12_cycles ... ok
[INFO] [stdout] test cpu::tests::cb_res_b_clears_bit ... ok
[INFO] [stdout] test cpu::tests::cb_sra_b_preserves_sign_bit ... ok
[INFO] [stdout] test cpu::tests::cb_rotate_indirect_hl_takes_16_cycles ... ok
[INFO] [stdout] test cpu::tests::cb_swap_b_swaps_nibbles_and_clears_carry ... ok
[INFO] [stdout] test cpu::tests::cb_rr_b_inserts_carry_at_bit7 ... ok
[INFO] [stdout] test cpu::tests::cb_srl_b_shifts_in_zero_at_top ... ok
[INFO] [stdout] test cpu::tests::cb_rlc_b_rotates_left_and_captures_msb_in_carry ... ok
[INFO] [stdout] test cpu::tests::cb_res_indirect_hl_takes_16_cycles ... ok
[INFO] [stdout] test cpu::tests::cb_rl_b_inserts_carry_at_bit0 ... ok
[INFO] [stdout] test cpu::tests::ccf_toggles_carry ... ok
[INFO] [stdout] test cpu::tests::cp_a_a_sets_zero ... ok
[INFO] [stdout] test cpu::tests::cp_a_n_does_not_modify_a ... ok
[INFO] [stdout] test cpu::tests::cp_a_b_does_not_modify_a ... ok
[INFO] [stdout] test cpu::tests::daa_after_bcd_sub ... ok
[INFO] [stdout] test cpu::tests::daa_after_bcd_add ... ok
[INFO] [stdout] test cpu::tests::cpl_inverts_a_and_sets_n_h ... ok
[INFO] [stdout] test cpu::tests::dec_r_wraps_from_zero_to_ff_with_h ... ok
[INFO] [stdout] test cpu::tests::halt_wakes_on_pending_with_ime_disabled_then_executes_next ... ok
[INFO] [stdout] test cpu::tests::ei_enables_ime_after_one_instruction_delay ... ok
[INFO] [stdout] test cpu::tests::dec_rr_decrements_pairs_and_preserves_flags ... ok
[INFO] [stdout] test cpu::tests::di_immediately_clears_ime_and_cancels_pending_ei ... ok
[INFO] [stdout] test cpu::tests::ei_then_halt_enables_ime_after_halt_and_services_future_interrupt ... ok
[INFO] [stdout] test cpu::tests::halted_cpu_wakes_midcycle_on_later_iterations ... ok
[INFO] [stdout] test cpu::tests::first_halt_iteration_does_not_midcycle_wake ... ok
[INFO] [stdout] test cpu::tests::halt_bug_repeats_next_opcode_byte ... ok
[INFO] [stdout] test cpu::tests::illegal_opcodes_lock_cpu ... ok
[INFO] [stdout] test cpu::tests::dec_r_dispatches_to_all_8bit_registers ... ok
[INFO] [stdout] test cpu::tests::dec_r_half_carry_on_low_nibble_borrow ... ok
[INFO] [stdout] test cpu::tests::halt_wakes_and_services_with_ime_enabled ... ok
[INFO] [stdout] test cpu::tests::inc_indirect_hl_reads_then_writes_on_later_m_cycle ... ok
[INFO] [stdout] test cpu::tests::halted_cpu_does_not_advance_pc ... ok
[INFO] [stdout] test cpu::tests::inc_r_wraps_to_zero_with_z_and_h ... ok
[INFO] [stdout] test cpu::tests::interrupt_vblank_pushes_pc_and_jumps_to_vector ... ok
[INFO] [stdout] test cpu::tests::inc_rr_increments_pairs_and_preserves_flags ... ok
[INFO] [stdout] test cpu::tests::interrupt_not_serviced_when_ime_disabled ... ok
[INFO] [stdout] test cpu::tests::inc_r_dispatches_to_all_8bit_registers ... ok
[INFO] [stdout] test cpu::tests::inc_r_half_carry_on_low_nibble_overflow ... ok
[INFO] [stdout] test cpu::tests::jr_e_negative_offset_to_self ... ok
[INFO] [stdout] test cpu::tests::jp_cc_taken_and_not_taken_have_different_cycles ... ok
[INFO] [stdout] test cpu::tests::interrupt_vector_is_resolved_after_stack_push_side_effects ... ok
[INFO] [stdout] test cpu::tests::jp_nn_jumps_absolute ... ok
[INFO] [stdout] test cpu::tests::jr_e_positive_offset ... ok
[INFO] [stdout] test cpu::tests::jr_cc_covers_all_four_conditions ... ok
[INFO] [stdout] test cpu::tests::interrupt_priority_picks_lowest_bit ... ok
[INFO] [stdout] test cpu::tests::jr_cc_not_taken_when_condition_false_advances_past_operand ... ok
[INFO] [stdout] test cpu::tests::jr_cc_taken_when_condition_true ... ok
[INFO] [stdout] test cpu::tests::ld_a_indirect_hl ... ok
[INFO] [stdout] test cpu::tests::ld_a_n ... ok
[INFO] [stdout] test cpu::tests::ld_a_n_overwrites_previous_value ... ok
[INFO] [stdout] test cpu::tests::ld_hl_sp_e_does_not_modify_sp ... ok
[INFO] [stdout] test cpu::tests::ld_b_c ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_hl_a ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_c_uses_ff00_plus_c_register ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_bc_and_de_pair_roundtrip ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_hl_dec_a_writes_then_decrements_hl ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_nn_roundtrips_through_absolute_address ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_nn_sp_writes_little_endian ... ok
[INFO] [stdout] test cpu::tests::jp_hl_uses_hl_as_pc ... ok
[INFO] [stdout] test cpu::tests::ld_a_indirect_hl_dec_reads_then_decrements_hl ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_hl_inc_a_writes_then_increments_hl ... ok
[INFO] [stdout] test cpu::tests::ld_a_indirect_hl_inc_reads_then_increments_hl ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_hl_n_writes_immediate_to_memory ... ok
[INFO] [stdout] test cpu::tests::ld_indirect_pair_preserves_flags ... ok
[INFO] [stdout] test cpu::tests::locked_cpu_ignores_pending_interrupts ... ok
[INFO] [stdout] test cpu::tests::ldh_n_a_and_ldh_a_n_use_ff00_offset ... ok
[INFO] [stdout] test cpu::tests::ld_r_n_loads_all_8bit_registers ... ok
[INFO] [stdout] test cpu::tests::push_af_writes_f_with_low_nibble_zero ... ok
[INFO] [stdout] test cpu::tests::ld_rr_nn_loads_all_pairs ... ok
[INFO] [stdout] test cpu::tests::ldh_a_n_reads_after_the_intermediate_m_cycles ... ok
[INFO] [stdout] test cpu::tests::ld_sp_hl_copies_hl_to_sp ... ok
[INFO] [stdout] test cpu::tests::or_a_b_combines_bits ... ok
[INFO] [stdout] test cpu::tests::read_r_dispatches_to_all_registers ... ok
[INFO] [stdout] test cpu::tests::ret_pops_pc ... ok
[INFO] [stdout] test cpu::tests::pop_af_masks_lower_nibble_of_f ... ok
[INFO] [stdout] test cpu::tests::push_then_pop_roundtrips_register_pair ... ok
[INFO] [stdout] test cpu::tests::pc_wraps_around_at_0xffff ... ok
[INFO] [stdout] test cpu::tests::rla_uses_carry_in_and_clears_z ... ok
[INFO] [stdout] test cpu::tests::nop_then_halt ... ok
[INFO] [stdout] test cpu::tests::reti_pops_pc_and_enables_ime_immediately ... ok
[INFO] [stdout] test cpu::tests::rlca_keeps_z_clear_even_when_result_is_zero ... ok
[INFO] [stdout] test cpu::tests::register_pairs_roundtrip ... ok
[INFO] [stdout] test cpu::tests::ret_cc_taken_takes_20_cycles_not_taken_takes_8 ... ok
[INFO] [stdout] test cpu::tests::rrca_rotates_and_clears_z ... ok
[INFO] [stdout] test cpu::tests::rra_uses_carry_in_and_clears_z ... ok
[INFO] [stdout] test cpu::tests::rst_pushes_pc_and_jumps_to_vector_for_all_8_opcodes ... ok
[INFO] [stdout] test cpu::tests::scf_sets_carry_and_clears_n_h ... ok
[INFO] [stdout] test cpu::tests::sbc_a_b_propagates_borrow_in ... ok
[INFO] [stdout] test cpu::tests::step_returns_cycle_counts ... ok
[INFO] [stdout] test cpu::tests::sbc_a_n_uses_borrow_in ... ok
[INFO] [stdout] test cpu::tests::stop_consumes_operand_and_continues ... ok
[INFO] [stdout] test flags::tests::from_bits_masks_lower_nibble ... ok
[INFO] [stdout] test cpu::tests::write_r_dispatches_to_all_registers ... ok
[INFO] [stdout] test flags::tests::setters_preserve_lower_nibble_invariant ... ok
[INFO] [stdout] test joypad::tests::action_selection_shows_action_buttons_only ... ok
[INFO] [stdout] test joypad::tests::both_lines_selected_reads_union_of_pressed_buttons ... ok
[INFO] [stdout] test cpu::tests::sub_a_b_to_zero_sets_z_and_n ... ok
[INFO] [stdout] test cpu::tests::sub_a_b_underflow_sets_carry_and_half_carry ... ok
[INFO] [stdout] test joypad::tests::default_read_returns_no_buttons_pressed ... ok
[INFO] [stdout] test cpu::tests::xor_a_a_zeroes_register ... ok
[INFO] [stdout] test joypad::tests::dpad_selection_shows_dpad_buttons ... ok
[INFO] [stdout] test cpu::tests::set_af_masks_lower_nibble_of_f ... ok
[INFO] [stdout] test flags::tests::default_is_all_clear ... ok
[INFO] [stdout] test flags::tests::each_setter_toggles_its_bit ... ok
[INFO] [stdout] test joypad::tests::newly_pressed_button_raises_an_interrupt ... ok
[INFO] [stdout] test joypad::tests::holding_a_button_does_not_refire_the_interrupt ... ok
[INFO] [stdout] test joypad::tests::releasing_then_pressing_re_triggers_interrupt ... ok
[INFO] [stdout] test memory::tests::load_at_high_boundary ... ok
[INFO] [stdout] test memory::tests::load_program ... ok
[INFO] [stdout] test memory::tests::read_write_memory ... ok
[INFO] [stdout] test joypad::tests::write_only_touches_selection_bits ... ok
[INFO] [stdout] test memory::tests::uninitialized_memory_reads_zero ... ok
[INFO] [stdout] test memory::tests::write_at_high_boundary ... ok
[INFO] [stdout] test mmu::tests::external_ram_roundtrip ... ok
[INFO] [stdout] test mmu::tests::apu_register_window_routes_to_apu_instead_of_generic_io ... ok
[INFO] [stdout] test mmu::tests::echo_ram_mirrors_wram_both_directions ... ok
[INFO] [stdout] test mmu::tests::if_register_write_preserves_upper_bits_and_lower_payload ... ok
[INFO] [stdout] test mmu::tests::if_register_reads_back_with_upper_bits_set ... ok
[INFO] [stdout] test mmu::tests::oam_dma_register_reads_back_last_written_value ... ok
[INFO] [stdout] test mmu::tests::ly_is_readable_through_mmu ... ok
[INFO] [stdout] test mmu::tests::joypad_button_press_routes_to_if_bit_4 ... ok
[INFO] [stdout] test mmu::tests::io_area_roundtrip ... ok
[INFO] [stdout] test mmu::tests::oam_dma_can_source_from_vram ... ok
[INFO] [stdout] test mmu::tests::oam_covers_the_full_a0_byte_region ... ok
[INFO] [stdout] test mmu::tests::hram_roundtrip ... ok
[INFO] [stdout] test mmu::tests::ie_register_is_distinct_from_hram ... ok
[INFO] [stdout] test mmu::tests::oam_dma_copies_160_bytes_from_source_into_oam ... ok
[INFO] [stdout] test mmu::tests::oam_does_not_alias_wram_echo_tail ... ok
[INFO] [stdout] test mmu::tests::oam_does_not_leak_into_unusable_area ... ok
[INFO] [stdout] test mmu::tests::serial_transfer_routes_to_serial_and_raises_if_bit_3 ... ok
[INFO] [stdout] test mmu::tests::tick_does_not_clear_other_if_bits ... ok
[INFO] [stdout] test mmu::tests::oam_roundtrip ... ok
[INFO] [stdout] test mmu::tests::ppu_registers_route_to_ppu_not_io ... ok
[INFO] [stdout] test mmu::tests::rom_reads_go_to_cartridge ... ok
[INFO] [stdout] test mmu::tests::tick_sets_timer_interrupt_in_if_on_tima_overflow ... ok
[INFO] [stdout] test mmu::tests::stat_interrupt_propagates_to_if_bit_1 ... ok
[INFO] [stdout] test ppu::framebuffer::tests::framebuffer_is_160_by_144 ... ok
[INFO] [stdout] test ppu::mode::tests::stat_bits_match_hardware_encoding ... ok
[INFO] [stdout] test mmu::tests::vram_covers_the_full_8kib_region ... ok
[INFO] [stdout] test mmu::tests::vram_does_not_alias_wram ... ok
[INFO] [stdout] test mmu::tests::timer_registers_route_to_timer_not_io ... ok
[INFO] [stdout] test ppu::tests::bg_disable_paints_shade_zero_even_when_tile_is_set ... ok
[INFO] [stdout] test ppu::tests::bgp_remaps_color_indices_to_shades ... ok
[INFO] [stdout] test ppu::tests::bg_renders_solid_shade_three_from_a_full_tile ... ok
[INFO] [stdout] test ppu::tests::lcdc_change_during_drawing_affects_this_line ... ok
[INFO] [stdout] test ppu::tests::disabling_lcd_freezes_the_ppu ... ok
[INFO] [stdout] test ppu::tests::bgp_change_during_hblank_affects_next_line_only ... ok
[INFO] [stdout] test ppu::tests::lcdc_change_during_hblank_affects_next_line_only ... ok
[INFO] [stdout] test mmu::tests::unusable_area_reads_ff_and_drops_writes ... ok
[INFO] [stdout] test ppu::tests::lcdc_change_during_oam_search_affects_this_line ... ok
[INFO] [stdout] test ppu::tests::lcdc_tile_data_area_toggle_between_lines_picks_up_new_tile_source ... ok
[INFO] [stdout] test mmu::tests::vram_does_not_alias_external_ram ... ok
[INFO] [stdout] test mmu::tests::vram_roundtrip ... ok
[INFO] [stdout] test mmu::tests::wram_roundtrip ... ok
[INFO] [stdout] test ppu::tests::lcdc_bg_map_toggle_between_lines_picks_up_new_tilemap ... ok
[INFO] [stdout] test ppu::tests::lower_x_wins_when_two_sprites_overlap ... ok
[INFO] [stdout] test ppu::tests::ppu_advances_ly_after_456_dots ... ok
[INFO] [stdout] test mmu::tests::take_frame_ready_fires_once_per_vblank_entry ... ok
[INFO] [stdout] test mmu::tests::vblank_entry_sets_if_bit_0 ... ok
[INFO] [stdout] test ppu::tests::oam_roundtrips_through_ppu_directly ... ok
[INFO] [stdout] test ppu::tests::overlapping_stat_sources_fire_only_once_per_rising_edge ... ok
[INFO] [stdout] test ppu::tests::ppu_mode_transitions_within_a_line ... ok
[INFO] [stdout] test ppu::tests::ppu_enters_vblank_at_ly_144 ... ok
[INFO] [stdout] test ppu::tests::scx_scrolls_the_visible_pixels_horizontally ... ok
[INFO] [stdout] test ppu::tests::scy_change_during_hblank_affects_next_line ... ok
[INFO] [stdout] test ppu::tests::signed_tile_addressing_finds_tile_at_0x9000 ... ok
[INFO] [stdout] test ppu::tests::ppu_wraps_ly_after_a_full_frame ... ok
[INFO] [stdout] test ppu::tests::ppu_stays_in_vblank_throughout_lines_144_to_153 ... ok
[INFO] [stdout] test ppu::tests::sprite_8x16_mode_picks_bottom_tile_after_eighth_row ... ok
[INFO] [stdout] test ppu::tests::sprite_color_zero_is_transparent_to_bg ... ok
[INFO] [stdout] test ppu::tests::sprite_priority_bg_over_obj_hides_sprite_under_non_zero_bg ... ok
[INFO] [stdout] test ppu::tests::sprite_priority_still_draws_where_bg_color_is_zero ... ok
[INFO] [stdout] test ppu::tests::sprite_disabled_when_lcdc_obj_is_clear ... ok
[INFO] [stdout] test ppu::tests::re_enabling_lcd_restarts_from_line_zero ... ok
[INFO] [stdout] test ppu::tests::sprite_renders_when_visible_on_scanline ... ok
[INFO] [stdout] test ppu::tests::sprite_uses_obp1_when_palette_bit_set ... ok
[INFO] [stdout] test ppu::tests::sprite_x_flip_mirrors_column ... ok
[INFO] [stdout] test ppu::tests::sprite_y_flip_picks_row_from_bottom ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_fires_on_oam_search_entry ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_fires_on_lyc_match ... ok
[INFO] [stdout] test ppu::tests::stat_coincidence_bit_reflects_ly_eq_lyc ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_does_not_refire_while_line_stays_high ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_stays_quiet_while_lcd_is_off ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_fires_on_hblank_entry ... ok
[INFO] [stdout] test ppu::tests::stat_reads_mode_zero_while_lcd_is_off ... ok
[INFO] [stdout] test ppu::tests::ten_sprite_per_line_cap_drops_later_entries ... ok
[INFO] [stdout] test ppu::tests::stat_write_only_touches_interrupt_enable_bits ... ok
[INFO] [stdout] test cartridge::tests::load_cartridge_panics_on_unknown_mbc - should panic ... ok
[INFO] [stdout] test ppu::tests::vram_roundtrips_through_ppu_directly ... ok
[INFO] [stdout] test ppu::tests::window_at_wx_above_166_is_invisible ... ok
[INFO] [stdout] test cartridge::tests::load_cartridge_panics_on_short_rom - should panic ... ok
[INFO] [stdout] test ppu::tests::window_dies_when_bg_master_is_off ... ok
[INFO] [stdout] test ppu::tests::window_does_not_render_when_lcdc_window_enable_is_clear ... ok
[INFO] [stdout] test ppu::tests::window_is_clipped_below_wy ... ok
[INFO] [stdout] test ppu::tests::stat_read_carries_mode_bits ... ok
[INFO] [stdout] test ppu::tests::window_overlays_bg_when_enabled_and_visible ... ok
[INFO] [stdout] test ppu::tests::window_with_wx_below_seven_clips_left_edge ... ok
[INFO] [stdout] test ppu::tests::oam_write_above_fe9f_panics - should panic ... ok
[INFO] [stdout] test ppu::tests::window_line_counter_advances_independently_of_ly ... ok
[INFO] [stdout] test ppu::tests::ppu_write_just_above_register_window_panics - should panic ... ok
[INFO] [stdout] test ppu::tests::ppu_read_just_below_register_window_panics - should panic ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_fires_on_vblank_entry_alongside_vblank_if ... ok
[INFO] [stdout] test ppu::tests::tick_returns_vblank_bit_once_per_frame ... ok
[INFO] [stdout] test ppu::tests::ppu_read_just_above_register_window_panics - should panic ... ok
[INFO] [stdout] test serial::tests::drain_output_is_destructive ... ok
[INFO] [stdout] test ppu::tests::write_to_ly_resets_to_zero ... ok
[INFO] [stdout] test ppu::tests::oam_read_below_fe00_panics - should panic ... ok
[INFO] [stdout] test ppu::tests::stat_interrupt_does_not_fire_when_sources_disabled ... ok
[INFO] [stdout] test serial::tests::external_clock_transfer_never_completes_without_partner ... ok
[INFO] [stdout] test ppu::tests::ppu_write_just_below_register_window_panics - should panic ... ok
[INFO] [stdout] test serial::tests::tick_without_transfer_stays_quiet ... ok
[INFO] [stdout] test serial::tests::sc_read_returns_unused_bits_set ... ok
[INFO] [stdout] test ppu::tests::vram_read_below_8000_panics - should panic ... ok
[INFO] [stdout] test timer::tests::div_increments_every_256_cycles ... ok
[INFO] [stdout] test timer::tests::div_write_can_increment_tima_via_falling_edge ... ok
[INFO] [stdout] test timer::tests::tac_read_returns_upper_bits_set ... ok
[INFO] [stdout] test timer::tests::div_write_resets_internal_counter ... ok
[INFO] [stdout] test ppu::tests::vram_write_above_9fff_panics - should panic ... ok
[INFO] [stdout] test serial::tests::transfer_clears_start_flag_on_read ... ok
[INFO] [stdout] test timer::tests::tima_increments_at_each_clock_rate ... ok
[INFO] [stdout] test serial::tests::writing_sc_without_start_bit_does_not_capture ... ok
[INFO] [stdout] test timer::tests::tac_write_can_increment_tima_via_falling_edge ... ok
[INFO] [stdout] test timer::tests::tima_does_not_increment_when_disabled ... ok
[INFO] [stdout] test serial::tests::writing_sc_with_start_bit_captures_sb ... ok
[INFO] [stdout] test timer::tests::tima_overflow_reloads_tma_and_raises_interrupt ... ok
[INFO] [stdout] test serial::tests::transfer_raises_interrupt_once ... ok
[INFO] [stdout] test timer::tests::writing_tima_during_overflow_delay_cancels_reload ... ok
[INFO] [stdout] test ppu::tests::wly_resets_at_frame_start ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 280 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.07s
[INFO] [stdout] 
[INFO] [stderr]      Running unittests src/main.rs (/opt/rustwide/target/debug/deps/formula-7cfc90be8340634b)
[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/dmg_acid2.rs (/opt/rustwide/target/debug/deps/dmg_acid2-84e10a7f214c80b9)
[INFO] [stderr]      Running tests/dmg_sound_full.rs (/opt/rustwide/target/debug/deps/dmg_sound_full-f2dcf325c9349f50)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_acid2_matches_reference_image ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_full_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_len_ctr.rs (/opt/rustwide/target/debug/deps/dmg_sound_len_ctr-5439307bd84cf43a)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_02_len_ctr_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_len_power.rs (/opt/rustwide/target/debug/deps/dmg_sound_len_power-2267dd3fcb39918a)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_08_len_ctr_during_power_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_len_sweep_sync.rs (/opt/rustwide/target/debug/deps/dmg_sound_len_sweep_sync-cabd9929b7c40a6a)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_07_len_sweep_period_sync_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_overflow.rs (/opt/rustwide/target/debug/deps/dmg_sound_overflow-4e1926c42a06918f)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_06_overflow_on_trigger_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_registers.rs (/opt/rustwide/target/debug/deps/dmg_sound_registers-d0dbf568c503342e)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_01_registers_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_regs_power.rs (/opt/rustwide/target/debug/deps/dmg_sound_regs_power-b2756cf9a4298294)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_11_regs_after_power_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_sweep.rs (/opt/rustwide/target/debug/deps/dmg_sound_sweep-d9e646d017328cde)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_04_sweep_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_sweep_details.rs (/opt/rustwide/target/debug/deps/dmg_sound_sweep_details-01f73ca63c5b88ca)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stderr]      Running tests/dmg_sound_trigger.rs (/opt/rustwide/target/debug/deps/dmg_sound_trigger-c1e12fbaef46528a)
[INFO] [stdout] test dmg_sound_05_sweep_details_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_03_trigger_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_wave_read.rs (/opt/rustwide/target/debug/deps/dmg_sound_wave_read-b4511d8c91ee259b)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_09_wave_read_while_on_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_wave_trigger.rs (/opt/rustwide/target/debug/deps/dmg_sound_wave_trigger-3aaea8ed717d39d8)
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_10_wave_trigger_while_on_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stderr]      Running tests/dmg_sound_wave_write.rs (/opt/rustwide/target/debug/deps/dmg_sound_wave_write-c576919fc944dfcf)
[INFO] [stdout] 
[INFO] [stderr]      Running tests/halt_bug.rs (/opt/rustwide/target/debug/deps/halt_bug-f5fe131cc7474da0)
[INFO] [stdout] running 1 test
[INFO] [stdout] test dmg_sound_12_wave_write_while_on_reaches_pass_result ... ok
[INFO] [stdout] 
[INFO] [stdout] test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] running 1 test
[INFO] [stdout] test blargg_halt_bug_rom_reaches_pass_signature ... FAILED
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- blargg_halt_bug_rom_reaches_pass_signature stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'blargg_halt_bug_rom_reaches_pass_signature' (8046) panicked at tests/halt_bug.rs:30:66:
[INFO] [stdout] read halt_bug.gb: Os { code: 2, kind: NotFound, message: "No such file or directory" }
[INFO] [stderr] error: test failed, to rerun pass `--test halt_bug`
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x60f76806fa11 - std[73adb7dc35730857]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x60f76806fa11 - std[73adb7dc35730857]::backtrace_rs::backtrace::trace_unsynchronized::<std[73adb7dc35730857]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x60f76806fa11 - std[73adb7dc35730857]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x60f76806fa11 - <<std[73adb7dc35730857]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[6883ba1bc0fe4ed1]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x60f7680841fa - <core[6883ba1bc0fe4ed1]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x60f7680841fa - core[6883ba1bc0fe4ed1]::fmt::write
[INFO] [stdout]    6:     0x60f768073ecc - std[73adb7dc35730857]::io::default_write_fmt::<alloc[55a36b64bcbf2c0d]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/io/mod.rs:626:11
[INFO] [stdout]    7:     0x60f768073ecc - <alloc[55a36b64bcbf2c0d]::vec::Vec<u8> as std[73adb7dc35730857]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/io/mod.rs:1730:13
[INFO] [stdout]    8:     0x60f76804de56 - <std[73adb7dc35730857]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x60f76804de56 - std[73adb7dc35730857]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x60f768067909 - std[73adb7dc35730857]::panicking::default_hook
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x60f767ff0dd0 - <alloc[55a36b64bcbf2c0d]::boxed::Box<dyn for<'a, 'b> core[6883ba1bc0fe4ed1]::ops::function::Fn<(&'a std[73adb7dc35730857]::panic::PanicHookInfo<'b>,), Output = ()> + core[6883ba1bc0fe4ed1]::marker::Send + core[6883ba1bc0fe4ed1]::marker::Sync> as core[6883ba1bc0fe4ed1]::ops::function::Fn<(&std[73adb7dc35730857]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/alloc/src/boxed.rs:2333:9
[INFO] [stdout]   12:     0x60f767ff0dd0 - test[980ffaebd391d06d]::test_main_inner::<test[980ffaebd391d06d]::test_main_static::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/test/src/lib.rs:155:21
[INFO] [stdout]   13:     0x60f768067ac2 - <alloc[55a36b64bcbf2c0d]::boxed::Box<dyn for<'a, 'b> core[6883ba1bc0fe4ed1]::ops::function::Fn<(&'a std[73adb7dc35730857]::panic::PanicHookInfo<'b>,), Output = ()> + core[6883ba1bc0fe4ed1]::marker::Send + core[6883ba1bc0fe4ed1]::marker::Sync> as core[6883ba1bc0fe4ed1]::ops::function::Fn<(&std[73adb7dc35730857]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/alloc/src/boxed.rs:2333:9
[INFO] [stdout]   14:     0x60f768067ac2 - std[73adb7dc35730857]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:823:13
[INFO] [stdout]   15:     0x60f76804df02 - std[73adb7dc35730857]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:688:13
[INFO] [stdout]   16:     0x60f7680456d9 - std[73adb7dc35730857]::sys::backtrace::__rust_end_short_backtrace::<std[73adb7dc35730857]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x60f76804eafd - __rustc[a7b7b02e776dd976]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:679:5
[INFO] [stdout]   18:     0x60f76808492c - core[6883ba1bc0fe4ed1]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x60f768084702 - core[6883ba1bc0fe4ed1]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/result.rs:1870:5
[INFO] [stdout]   20:     0x60f767fe35a3 - <core[6883ba1bc0fe4ed1]::result::Result<alloc[55a36b64bcbf2c0d]::vec::Vec<u8>, core[6883ba1bc0fe4ed1]::io::error::Error>>::expect
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/result.rs:1183:23
[INFO] [stdout]   21:     0x60f767fe313e - halt_bug[b5dc9228b148447]::blargg_halt_bug_rom_reaches_pass_signature
[INFO] [stdout]                                at /opt/rustwide/workdir/tests/halt_bug.rs:30:66
[INFO] [stdout]   22:     0x60f767fe2f87 - halt_bug[b5dc9228b148447]::blargg_halt_bug_rom_reaches_pass_signature::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/tests/halt_bug.rs:29:48
[INFO] [stdout]   23:     0x60f767fe4036 - <halt_bug[b5dc9228b148447]::blargg_halt_bug_rom_reaches_pass_signature::{closure#0} as core[6883ba1bc0fe4ed1]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x60f767fe410b - <fn() -> core[6883ba1bc0fe4ed1]::result::Result<(), alloc[55a36b64bcbf2c0d]::string::String> as core[6883ba1bc0fe4ed1]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x60f767fe410b - test[980ffaebd391d06d]::__rust_begin_short_backtrace::<core[6883ba1bc0fe4ed1]::result::Result<(), alloc[55a36b64bcbf2c0d]::string::String>, fn() -> core[6883ba1bc0fe4ed1]::result::Result<(), alloc[55a36b64bcbf2c0d]::string::String>>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/test/src/lib.rs:724:18
[INFO] [stdout]   26:     0x60f767ff1755 - test[980ffaebd391d06d]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/test/src/lib.rs:747:74
[INFO] [stdout]   27:     0x60f767ff1755 - <core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<test[980ffaebd391d06d]::run_test_in_process::{closure#0}> as core[6883ba1bc0fe4ed1]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x60f767ff1755 - std[73adb7dc35730857]::panicking::catch_unwind::do_call::<core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<test[980ffaebd391d06d]::run_test_in_process::{closure#0}>, core[6883ba1bc0fe4ed1]::result::Result<(), alloc[55a36b64bcbf2c0d]::string::String>>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:576:43
[INFO] [stdout]   29:     0x60f767ff1755 - std[73adb7dc35730857]::panicking::catch_unwind::<core[6883ba1bc0fe4ed1]::result::Result<(), alloc[55a36b64bcbf2c0d]::string::String>, core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<test[980ffaebd391d06d]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x60f767ff1755 - std[73adb7dc35730857]::panic::catch_unwind::<core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<test[980ffaebd391d06d]::run_test_in_process::{closure#0}>, core[6883ba1bc0fe4ed1]::result::Result<(), alloc[55a36b64bcbf2c0d]::string::String>>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x60f767ff1755 - test[980ffaebd391d06d]::run_test_in_process
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/test/src/lib.rs:747:27
[INFO] [stdout]   32:     0x60f767ff1755 - test[980ffaebd391d06d]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/test/src/lib.rs:668:43
[INFO] [stdout]   33:     0x60f767fec204 - test[980ffaebd391d06d]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/test/src/lib.rs:698:41
[INFO] [stdout]   34:     0x60f767fec204 - std[73adb7dc35730857]::sys::backtrace::__rust_begin_short_backtrace::<test[980ffaebd391d06d]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x60f767ff48a2 - std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked::<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/thread/lifecycle.rs:70:13
[INFO] [stdout]   36:     0x60f767ff48a2 - <core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[6883ba1bc0fe4ed1]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x60f767ff48a2 - std[73adb7dc35730857]::panicking::catch_unwind::do_call::<core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:576:43
[INFO] [stdout]   38:     0x60f767ff48a2 - std[73adb7dc35730857]::panicking::catch_unwind::<(), core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x60f767ff48a2 - std[73adb7dc35730857]::panic::catch_unwind::<core[6883ba1bc0fe4ed1]::panic::unwind_safe::AssertUnwindSafe<std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x60f767ff48a2 - std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked::<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/thread/lifecycle.rs:68:26
[INFO] [stdout]   41:     0x60f767ff48a2 - <std[73adb7dc35730857]::thread::lifecycle::spawn_unchecked<test[980ffaebd391d06d]::run_test::{closure#1}, ()>::{closure#1} as core[6883ba1bc0fe4ed1]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x60f76806ef6f - <alloc[55a36b64bcbf2c0d]::boxed::Box<dyn core[6883ba1bc0fe4ed1]::ops::function::FnOnce<(), Output = ()> + core[6883ba1bc0fe4ed1]::marker::Send> as core[6883ba1bc0fe4ed1]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/alloc/src/boxed.rs:2319:9
[INFO] [stdout]   43:     0x60f76806ef6f - <std[73adb7dc35730857]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/6b3fa26749ab40e159b2dd5cf577acaaf5902772/library/std/src/sys/thread/unix.rs:123:17
[INFO] [stdout]   44:     0x71dfe6849aa4 - <unknown>
[INFO] [stdout]   45:     0x71dfe68d6a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     blargg_halt_bug_rom_reaches_pass_signature
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.03s
[INFO] [stdout] 
[INFO] running `Command { std: "docker" "inspect" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a", kill_on_drop: false }`
[INFO] [stdout] 4677be7edadc410a190b786c3313fc9a19a572bb86afe7554edf47f2442fd90a
