Separate branch logging

Grarak · Mar 2, 2025 · 82ca4d2 · 82ca4d2
1 parent 172cf7e
commit 82ca4d2
Show file tree

Hide file tree

Showing 6 changed files with 45 additions and 30 deletions.
diff --git a/src/jit/emitter/emit_branch.rs b/src/jit/emitter/emit_branch.rs
@@ -10,8 +10,9 @@ use crate::jit::jit_asm_common_funs::JitAsmCommonFuns;
 use crate::jit::op::Op;
 use crate::jit::reg::{reg_reserve, Reg, RegReserve};
 use crate::jit::Cond;
+use crate::logging::branch_println;
 use crate::settings::Arm7Emu;
-use crate::{DEBUG_LOG, IS_DEBUG};
+use crate::{BRANCH_LOG, IS_DEBUG};
 use std::ptr;
 
 pub enum JitBranchInfo {
@@ -104,7 +105,7 @@ impl<const CPU: CpuType> JitAsm<'_, CPU> {
                     CPU == ARM9,
                     |_, _, _, _| {},
                     |asm, block_asm, _, _| {
-                        if DEBUG_LOG {
+                        if BRANCH_LOG {
                             block_asm.call2(Self::debug_branch_label as *const (), asm.jit_buf.current_pc, target_pc);
                         }
                         block_asm.msr_cpsr(backed_up_cpsr_reg);
@@ -136,7 +137,7 @@ impl<const CPU: CpuType> JitAsm<'_, CPU> {
             JitBranchInfo::Idle(jump_to_index) => {
                 block_asm.mov(Reg::PC, target_pc);
                 block_asm.save_context();
-                if DEBUG_LOG {
+                if BRANCH_LOG {
                     block_asm.call2(Self::debug_idle_loop as *const (), self.jit_buf.current_pc, target_pc);
                 }
                 match CPU {
@@ -294,14 +295,14 @@ impl<const CPU: CpuType> JitAsm<'_, CPU> {
     }
 
     extern "C" fn debug_branch_label(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} branch label from {current_pc:x} to {target_pc:x}")
+        branch_println!("{CPU:?} branch label from {current_pc:x} to {target_pc:x}")
     }
 
     extern "C" fn debug_branch_reg(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} branch reg from {current_pc:x} to {target_pc:x}")
+        branch_println!("{CPU:?} branch reg from {current_pc:x} to {target_pc:x}")
     }
 
     extern "C" fn debug_idle_loop(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} detected idle loop {current_pc:x} to {target_pc:x}")
+        branch_println!("{CPU:?} detected idle loop {current_pc:x} to {target_pc:x}")
     }
 }
diff --git a/src/jit/inst_branch_handler.rs b/src/jit/inst_branch_handler.rs
@@ -6,7 +6,7 @@ use crate::jit::jit_asm_common_funs::{exit_guest_context, get_max_loop_cycle_cou
 use crate::jit::jit_memory::JitEntry;
 use crate::logging::debug_println;
 use crate::settings::Arm7Emu;
-use crate::{get_jit_asm_ptr, CURRENT_RUNNING_CPU, DEBUG_LOG, IS_DEBUG};
+use crate::{get_jit_asm_ptr, BRANCH_LOG, CURRENT_RUNNING_CPU, IS_DEBUG};
 use std::arch::naked_asm;
 use std::cmp::min;
 use std::intrinsics::{likely, unlikely};
@@ -82,7 +82,7 @@ fn check_stack_depth(asm: &mut JitAsm<{ ARM9 }>, current_pc: u32) {
         if IS_DEBUG {
             asm.runtime_data.set_branch_out_pc(current_pc);
         }
-        if DEBUG_LOG {
+        if BRANCH_LOG {
             JitAsmCommonFuns::<{ ARM9 }>::debug_stack_depth_too_big(sp_depth_size, current_pc);
         }
         unsafe { exit_guest_context!(asm) };
@@ -160,7 +160,7 @@ pub extern "C" fn pre_branch<const CPU: CpuType, const HAS_LR_RETURN: bool>(asm:
     asm.runtime_data.pre_cycle_count_sum = 0;
     if HAS_LR_RETURN {
         asm.runtime_data.push_return_stack(lr);
-        if DEBUG_LOG {
+        if BRANCH_LOG {
             JitAsmCommonFuns::<CPU>::debug_push_return_stack(current_pc, lr, asm.runtime_data.get_return_stack_ptr());
         }
     }
@@ -184,7 +184,7 @@ pub unsafe extern "C" fn branch_reg<const CPU: CpuType, const HAS_LR_RETURN: boo
 
     pre_branch::<CPU, HAS_LR_RETURN>(asm, total_cycles, lr, current_pc);
 
-    if DEBUG_LOG {
+    if BRANCH_LOG {
         JitAsmCommonFuns::<CPU>::debug_branch_reg(current_pc, target_pc);
     }
 
@@ -198,7 +198,7 @@ pub unsafe extern "C" fn branch_imm<const CPU: CpuType, const THUMB: bool>(total
     let asm = get_jit_asm_ptr::<CPU>().as_mut_unchecked();
     pre_branch::<CPU, true>(asm, total_cycles, lr, current_pc);
 
-    if DEBUG_LOG {
+    if BRANCH_LOG {
         JitAsmCommonFuns::<CPU>::debug_branch_imm(current_pc, get_regs!(asm.emu, CPU).pc);
     }
 
@@ -223,11 +223,11 @@ pub unsafe extern "C" fn branch_lr<const CPU: CpuType>(total_cycles: u16, target
     let desired_lr = asm.runtime_data.pop_return_stack();
     if likely(desired_lr == target_pc) {
         get_regs_mut!(asm.emu, CPU).set_thumb(target_pc & 1 == 1);
-        if DEBUG_LOG {
+        if BRANCH_LOG {
             JitAsmCommonFuns::<CPU>::debug_branch_lr(current_pc, target_pc);
         }
     } else {
-        if DEBUG_LOG {
+        if BRANCH_LOG {
             JitAsmCommonFuns::<CPU>::debug_branch_lr_failed(current_pc, target_pc, desired_lr);
         }
         if CPU == ARM9 && unlikely(asm.runtime_data.is_in_interrupt()) {
@@ -236,7 +236,7 @@ pub unsafe extern "C" fn branch_lr<const CPU: CpuType>(total_cycles: u16, target
                 asm.runtime_data.pre_cycle_count_sum = 0;
                 asm.runtime_data.push_return_stack(desired_lr);
                 unsafe { call_jit_fun(asm, target_pc) };
-            } else if DEBUG_LOG {
+            } else if BRANCH_LOG {
                 JitAsmCommonFuns::<CPU>::debug_stack_depth_too_big(sp_depth_size, current_pc);
             }
         }

diff --git a/src/jit/jit_asm.rs b/src/jit/jit_asm.rs
@@ -13,8 +13,8 @@ use crate::jit::jit_asm_common_funs::{exit_guest_context, JitAsmCommonFuns};
 use crate::jit::op::Op;
 use crate::jit::reg::Reg;
 use crate::jit::reg::{reg_reserve, RegReserve};
-use crate::logging::debug_println;
-use crate::{get_jit_asm_ptr, CURRENT_RUNNING_CPU, DEBUG_LOG, IS_DEBUG};
+use crate::logging::{branch_println, debug_println};
+use crate::{get_jit_asm_ptr, BRANCH_LOG, CURRENT_RUNNING_CPU, DEBUG_LOG, IS_DEBUG};
 use std::arch::{asm, naked_asm};
 use std::intrinsics::unlikely;
 use std::{mem, ptr};
@@ -308,7 +308,7 @@ fn emit_code_block_internal<const CPU: CpuType>(asm: &mut JitAsm<CPU>, guest_pc:
         let host_sp_ptr = ptr::addr_of_mut!(asm.runtime_data.host_sp);
         let mut block_asm = unsafe { BlockAsm::new(guest_regs_ptr, host_sp_ptr, mem::transmute(&mut asm.basic_blocks_cache), mem::transmute(&mut asm.block_asm_buf), thumb) };
 
-        if DEBUG_LOG {
+        if BRANCH_LOG {
             block_asm.call1(debug_enter_block::<CPU> as *const (), guest_pc | (thumb as u32));
             block_asm.restore_reg(Reg::CPSR);
         }
@@ -410,14 +410,14 @@ fn execute_internal<const CPU: CpuType>(guest_pc: u32) -> u16 {
         );
     }
 
-    if DEBUG_LOG {
-        println!(
+    if BRANCH_LOG {
+        branch_println!(
             "{CPU:?} reading opcode of breakout at {:x} executed cycles {}",
             asm.runtime_data.get_branch_out_pc(),
             asm.runtime_data.accumulated_cycles,
         );
         if asm.runtime_data.is_idle_loop() {
-            println!("{CPU:?} idle loop");
+            branch_println!("{CPU:?} idle loop");
         }
         let inst_info = if get_regs!(asm.emu, CPU).is_thumb() {
             let opcode = asm.emu.mem_read::<CPU, _>(asm.runtime_data.get_branch_out_pc());
@@ -494,5 +494,5 @@ unsafe extern "C" fn debug_after_exec_op<const CPU: CpuType>(pc: u32, opcode: u3
 }
 
 extern "C" fn debug_enter_block<const CPU: CpuType>(pc: u32) {
-    println!("{CPU:?} execute {pc:x}");
+    branch_println!("{CPU:?} execute {pc:x}");
 }
diff --git a/src/jit/jit_asm_common_funs.rs b/src/jit/jit_asm_common_funs.rs
@@ -23,8 +23,9 @@ use crate::jit::jit_memory::JitEntry;
 use crate::jit::reg::Reg;
 use crate::jit::{inst_branch_handler, jit_memory_map, Cond, ShiftType};
 use crate::settings::Arm7Emu;
-use crate::{DEBUG_LOG, IS_DEBUG};
+use crate::{BRANCH_LOG, IS_DEBUG};
 use std::ptr;
+use crate::logging::branch_println;
 
 pub const fn get_max_loop_cycle_count<const CPU: CpuType>() -> u32 {
     match CPU {
@@ -301,7 +302,7 @@ impl<const CPU: CpuType> JitAsmCommonFuns<CPU> {
             block_asm.call2(pre_branch::<CPU, false> as *const (), asm as *mut _ as u32, total_cycles as u32);
         }
 
-        if DEBUG_LOG {
+        if BRANCH_LOG {
             block_asm.call2(Self::debug_branch_imm as *const (), current_pc, target_pc);
         }
 
@@ -315,30 +316,30 @@ impl<const CPU: CpuType> JitAsmCommonFuns<CPU> {
     }
 
     pub extern "C" fn debug_push_return_stack(current_pc: u32, lr_pc: u32, stack_size: u8) {
-        println!("{CPU:?} push {lr_pc:x} to return stack with size {stack_size} at {current_pc:x}")
+        branch_println!("{CPU:?} push {lr_pc:x} to return stack with size {stack_size} at {current_pc:x}")
     }
 
     pub extern "C" fn debug_stack_depth_too_big(size: usize, current_pc: u32) {
-        println!("{CPU:?} stack depth exceeded {size} at {current_pc:x}")
+        branch_println!("{CPU:?} stack depth exceeded {size} at {current_pc:x}")
     }
 
     pub extern "C" fn debug_branch_reg(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} branch reg from {current_pc:x} to {target_pc:x}")
+        branch_println!("{CPU:?} branch reg from {current_pc:x} to {target_pc:x}")
     }
 
     pub extern "C" fn debug_branch_lr(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} branch lr from {current_pc:x} to {target_pc:x}")
+        branch_println!("{CPU:?} branch lr from {current_pc:x} to {target_pc:x}")
     }
 
     pub extern "C" fn debug_branch_lr_failed(current_pc: u32, target_pc: u32, desired_pc: u32) {
-        println!("{CPU:?} failed to branch lr from {current_pc:x} to {target_pc:x} desired: {desired_pc:x}")
+        branch_println!("{CPU:?} failed to branch lr from {current_pc:x} to {target_pc:x} desired: {desired_pc:x}")
     }
 
     pub extern "C" fn debug_return_stack_empty(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} empty return stack {current_pc:x} to {target_pc:x}")
+        branch_println!("{CPU:?} empty return stack {current_pc:x} to {target_pc:x}")
     }
 
     pub extern "C" fn debug_branch_imm(current_pc: u32, target_pc: u32) {
-        println!("{CPU:?} branch imm from {current_pc:x} to {target_pc:x}");
+        branch_println!("{CPU:?} branch imm from {current_pc:x} to {target_pc:x}");
     }
 }
diff --git a/src/logging.rs b/src/logging.rs
@@ -10,6 +10,18 @@ macro_rules! debug_println {
 }
 pub(crate) use debug_println;
 
+macro_rules! branch_println {
+    ($($args:tt)*) => {
+        if crate::BRANCH_LOG {
+            let log = format!($($args)*);
+            let current_thread = std::thread::current();
+            let thread_name = current_thread.name().unwrap();
+            println!("[{}] {}", thread_name, log);
+        }
+    };
+}
+pub(crate) use branch_println;
+
 macro_rules! debug_panic {
     ($($args:tt)*) => {
         if crate::IS_DEBUG {

diff --git a/src/main.rs b/src/main.rs
@@ -59,6 +59,7 @@ mod utils;
 const BUILD_PROFILE_NAME: &str = include_str!(concat!(env!("OUT_DIR"), "/build_profile_name"));
 pub const DEBUG_LOG: bool = const_str_equal(BUILD_PROFILE_NAME, "debug");
 pub const IS_DEBUG: bool = !const_str_equal(BUILD_PROFILE_NAME, "release");
+pub const BRANCH_LOG: bool = DEBUG_LOG;
 
 fn run_cpu(
     cartridge_io: CartridgeIo,