Optimize log handling on the world switch critical path by eliminatin…

…g dead code.

Currently, Miralis checks whether each log should be displayed on every world switch, which results in unnecessary cycle loss. This commit introduces a macro to eliminate unused log checks, optimizing performance in the critical path.

src/lib.rs

@@ -106,7 +106,7 @@ fn handle_trap(
     // Check for execution mode change
     match (exec_mode, ctx.mode.to_exec_mode()) {
         (ExecutionMode::Firmware, ExecutionMode::Payload) => {
-            log::debug!("Execution mode: Firmware -> Payload");
+            logger::debug!("Execution mode: Firmware -> Payload");
             unsafe { ctx.switch_from_firmware_to_payload(mctx) };
             policy.switch_from_firmware_to_payload(ctx, mctx);
 
@@ -116,7 +116,7 @@ fn handle_trap(
             }
         }
         (ExecutionMode::Payload, ExecutionMode::Firmware) => {
-            log::debug!(
+            logger::debug!(
                 "Execution mode: Payload -> Firmware ({:?})",
                 ctx.trap_info.get_cause()
             );

src/logger.rs

@@ -148,7 +148,36 @@ macro_rules! trace_enabled {
     };
 }
 
-pub(crate) use trace_enabled;
+/// Returns true if the Debug logging level is enabled for the current module.
+///
+/// This macro is guaranteed to be executed at compile time, thus dead-code elimination is
+/// guaranteed by any reasonable compiler.
+macro_rules! debug_enabled {
+    () => {
+        // We wrap the computation in a const block to guarantee execution at compile time
+        const { crate::logger::enabled(core::module_path!(), log::Level::Debug) }
+    };
+}
+
+/// Wrappers around the normal logs that allow to dead-code optimize automatically the logs
+/// The motivation beyond this is to cut the latency in the trap. Currently, the logs are responsible for most of the latency
+macro_rules! trace {
+    ($($args:tt)*) => {
+        if logger::trace_enabled!() {
+            log::trace!($($args)*);
+        }
+    };
+}
+
+macro_rules! debug {
+    ($($args:tt)*) => {
+        if logger::debug_enabled!() {
+            log::debug!($($args)*);
+        }
+    };
+}
+
+pub(crate) use {debug, debug_enabled, trace, trace_enabled};
 
 // ————————————————————————————————— Utils —————————————————————————————————— //
 

src/virt/emulator.rs

@@ -345,7 +345,7 @@ impl VirtContext {
         match cause {
             MCause::EcallFromUMode if policy.ecall_from_firmware(mctx, self).overwrites() => {
                 // Nothing to do, the policy module handles those ecalls
-                log::trace!("Catching E-call from firmware in the policy module");
+                logger::trace!("Catching E-call from firmware in the policy module");
             }
             MCause::EcallFromUMode if self.get(Register::X17) == abi::MIRALIS_EID => {
                 return self.handle_ecall();
@@ -359,9 +359,7 @@ impl VirtContext {
             MCause::IllegalInstr => {
                 let instr = unsafe { get_raw_faulting_instr(&self.trap_info) };
                 let instr = mctx.decode(instr);
-                if logger::trace_enabled!() {
-                    log::trace!("Faulting instruction: {:?}", instr);
-                }
+                logger::trace!("Faulting instruction: {:?}", instr);
                 self.emulate_privileged_instr(&instr, mctx);
             }
             MCause::Breakpoint => {
@@ -374,7 +372,7 @@ impl VirtContext {
                 {
                     let instr = unsafe { get_raw_faulting_instr(&self.trap_info) };
                     let instr = mctx.decode(instr);
-                    log::trace!(
+                    logger::trace!(
                         "Accessed devices: {} | With instr: {:?}",
                         device.name,
                         instr
@@ -384,7 +382,7 @@ impl VirtContext {
                     // TODO: make sure virtual address does not get around PMP protection
                     let instr = unsafe { get_raw_faulting_instr(&self.trap_info) };
                     let instr = mctx.decode(instr);
-                    log::trace!(
+                    logger::trace!(
                         "Access fault {:x?} with a virtual address: 0x{:x}",
                         &instr,
                         self.trap_info.mtval
@@ -393,15 +391,15 @@ impl VirtContext {
                         Arch::handle_virtual_load_store(instr, self);
                     }
                 } else {
-                    log::trace!(
+                    logger::trace!(
                         "No matching device found for address: {:x}",
                         self.trap_info.mtval
                     );
                     self.emulate_jump_trap_handler();
                 }
             }
             MCause::InstrAccessFault => {
-                log::trace!("Instruction access fault: {:x?}", self.trap_info);
+                logger::trace!("Instruction access fault: {:x?}", self.trap_info);
                 self.emulate_jump_trap_handler();
             }
             MCause::MachineTimerInt => {
@@ -448,7 +446,7 @@ impl VirtContext {
         self.mode = parse_mpp_return_mode(self.trap_info.mstatus);
 
         if policy.trap_from_payload(mctx, self).overwrites() {
-            log::trace!("Catching trap in the policy module");
+            logger::trace!("Catching trap in the policy module");
             return ExitResult::Continue;
         }
 
@@ -457,13 +455,13 @@ impl VirtContext {
         match self.trap_info.get_cause() {
             MCause::EcallFromSMode if policy.ecall_from_payload(mctx, self).overwrites() => {
                 // Nothing to do, the Policy module handles those ecalls
-                log::trace!("Catching E-call from payload in the policy module");
+                logger::trace!("Catching E-call from payload in the policy module");
             }
             MCause::EcallFromSMode if self.get(Register::X17) == abi::MIRALIS_EID => {
                 return self.handle_ecall();
             }
             MCause::EcallFromSMode => {
-                log::debug!(
+                logger::debug!(
                     "Forwarding ecall from s-mode with values 0x{:x}, 0x{:x} to the firmware",
                     self.get(Register::X16),
                     self.get(Register::X17)