Edited log statements

driver/src/hook.rs

@@ -36,10 +36,12 @@ type MmIsAddressValidType = extern "C" fn(u64) -> bool;
 /// The caller must ensure this is the case to avoid undefined behavior.
 pub extern "C" fn mm_is_address_valid(ptr: u64) -> bool {
  // Log the address from which `MmIsAddressValid` was called.
- log::info!("MmIsAddressValid called from {:#x}", unsafe {
+ log::trace!("MmIsAddressValid called from {:#x}", unsafe {
  return_address().read_volatile() // Reads the return address in a volatile manner to prevent optimizations.
  });
 
+ log::debug!("First Parameter Value: {:x}", ptr);
+
  // Load the original function pointer from the global atomic pointer.
  let fn_ptr = ORIGINAL.load(Ordering::Relaxed); // Using relaxed ordering for atomic loading.
  // Transmute the function pointer to the expected function type.

driver/src/lib.rs

@@ -75,19 +75,20 @@ pub unsafe extern "system" fn driver_entry(
  // This logger writes to the host OS via VMware Workstation.
 
  // Initialize the COM2 port logger with level filter set to Info.
+
  com_logger::builder()
  .base(0x2f8)
- .filter(LevelFilter::Trace)
+ .filter(LevelFilter::Debug)
  .setup();
 
- log::info!("Driver Entry called");
+ log::debug!("Driver Entry called");
 
  // Remove if manually mapping the kernel driver
  driver.DriverUnload = Some(driver_unload);
 
  with_expanded_stack(|| {
- match virtualize() {
- Ok(_) => log::info!("Virtualization successful!"),
+ match virtualize_system() {
+ Ok(_) => log::info!("Virtualized system successfully!"),
  Err(err) => {
  log::error!("Virtualization failed: {:?}", err);
  return STATUS_UNSUCCESSFUL;
@@ -96,7 +97,7 @@ pub unsafe extern "system" fn driver_entry(
 
  // Test the hooks
  //
- log::info!("Calling MmIsAddressValid to test EPT hook...");
+ log::debug!("Calling MmIsAddressValid to test EPT hook...");
  unsafe { MmIsAddressValid(0 as _) };
 
  STATUS_SUCCESS
@@ -114,7 +115,7 @@ pub unsafe extern "system" fn driver_entry(
 ///
 /// Note: Remove if manually mapping the kernel driver
 pub extern "C" fn driver_unload(_driver: *mut DRIVER_OBJECT) {
- log::info!("Driver unloaded successfully!");
+ log::trace!("Driver unloaded successfully!");
  if let Some(mut hypervisor) = unsafe { HYPERVISOR.take() } {
  drop(hypervisor);
  }
@@ -136,7 +137,7 @@ static mut HYPERVISOR: Option<Hypervisor> = None;
 /// * `None` if there was an error during virtualization.
 ///
 /// Credits: Jess / jessiep_
-fn virtualize() -> Result<(), HypervisorError> {
+fn virtualize_system() -> Result<(), HypervisorError> {
  // Initialize the hook and hook manager
  //
  let hook = Hook::hook_function("MmIsAddressValid", hook::mm_is_address_valid as *const ())
@@ -151,16 +152,15 @@ fn virtualize() -> Result<(), HypervisorError> {
  let mut secondary_ept: Box<Ept, PhysicalAllocator> =
  unsafe { Box::try_new_zeroed_in(PhysicalAllocator)?.assume_init() };
 
- log::info!("Creating Primary EPT");
+ log::debug!("Creating Primary EPT");
  primary_ept.identity_2mb(AccessType::READ_WRITE_EXECUTE)?;
 
- log::info!("Creating Secondary EPT");
+ log::debug!("Creating Secondary EPT");
  secondary_ept.identity_2mb(AccessType::READ_WRITE_EXECUTE)?;
 
- log::info!("Enabling hooks");
+ log::debug!("Enabling hooks");
  hook_manager.enable_hooks(&mut primary_ept, &mut secondary_ept)?;
 
- log::info!("Building hypervisor");
  let mut hv = match Hypervisor::builder()
  .primary_ept(primary_ept)
  .secondary_ept(secondary_ept)
@@ -174,8 +174,8 @@ fn virtualize() -> Result<(), HypervisorError> {
  // Update NTOSKRNL_CR3 to ensure correct CR3 in case of execution within a user-mode process via DPC.
  update_ntoskrnl_cr3();
 
- match hv.virtualize_system() {
- Ok(_) => log::info!("Successfully virtualized system!"),
+ match hv.virtualize_core() {
+ Ok(_) => log::info!("Virtualized cores successfully!"),
  Err(err) => return Err(err),
  };
 

hypervisor/src/intel/descriptor.rs

@@ -37,7 +37,7 @@ impl DescriptorTables {
  pub fn initialize_for_guest(
  descriptor_tables: &mut Box<DescriptorTables, KernelAlloc>,
  ) -> Result<(), HypervisorError> {
- log::info!("Capturing current Global Descriptor Table (GDT) and Interrupt Descriptor Table (IDT) for guest");
+ log::trace!("Capturing current Global Descriptor Table (GDT) and Interrupt Descriptor Table (IDT) for guest");
 
  // Capture the current GDT and IDT.
  descriptor_tables.gdtr = sgdt();
@@ -46,7 +46,7 @@ impl DescriptorTables {
  // Note: We don't need to create new tables for the guest;
  // we just capture the current ones.
 
- log::info!("Captured GDT and IDT for guest successfully!");
+ log::trace!("Captured GDT and IDT for guest successfully!");
 
  Ok(())
  }
@@ -55,18 +55,18 @@ impl DescriptorTables {
  pub fn initialize_for_host(
  descriptor_tables: &mut Box<DescriptorTables, KernelAlloc>,
  ) -> Result<(), HypervisorError> {
- log::info!("Initializing descriptor tables for host");
+ log::trace!("Initializing descriptor tables for host");
 
  descriptor_tables.copy_current_gdt();
  descriptor_tables.copy_current_idt();
 
- log::info!("Initialized descriptor tables for host");
+ log::trace!("Initialized descriptor tables for host");
  Ok(())
  }
 
  /// Copies the current GDT.
  fn copy_current_gdt(&mut self) {
- log::info!("Copying current GDT");
+ log::trace!("Copying current GDT");
 
  // Get the current GDTR
  let current_gdtr = sgdt();
@@ -83,12 +83,12 @@ impl DescriptorTables {
  // Store the new GDT in the DescriptorTables structure
  self.global_descriptor_table = new_gdt;
  self.gdtr = new_gdtr;
- log::info!("Copied current GDT");
+ log::trace!("Copied current GDT");
  }
 
  /// Copies the current IDT.
  fn copy_current_idt(&mut self) {
- log::info!("Copying current IDT");
+ log::trace!("Copying current IDT");
 
  // Get the current IDTR
  let current_idtr = sidt();
@@ -105,7 +105,7 @@ impl DescriptorTables {
  // Store the new IDT in the DescriptorTables structure
  self.interrupt_descriptor_table = new_idt;
  self.idtr = new_idtr; // Use the same IDTR as it points to the correct base and limit
- log::info!("Copied current IDT");
+ log::trace!("Copied current IDT");
  }
 
  /// Gets the table as a slice from the pointer.

hypervisor/src/intel/ept/hooks.rs

@@ -125,7 +125,6 @@ impl Hook {
  /// * `Option<Self>` - An instance of `Hook` if successful, or `None` if an error occurred.
  pub fn hook_function_ptr(function_ptr: u64, handler: *const ()) -> Option<Self> {
  let original_pa = PhysicalAddress::from_va(function_ptr);
- log::info!("Obtained physical address: {:#x}", original_pa.as_u64());
 
  // Copy the page where the function resides to prevent modifying the original page.
  let page = Self::copy_page(function_ptr)?;
@@ -136,16 +135,16 @@ impl Hook {
  let hook_va = Self::address_in_page(page_va, function_ptr);
  let hook_pa = PhysicalAddress::from_va(hook_va);
 
- log::info!("Handler address: {:#x}", handler as u64);
+ log::debug!("Handler address: {:#x}", handler as u64);
 
- log::info!("Original virtual address: {:#x}", function_ptr);
- log::info!("Original physical address: {:#x}", original_pa.as_u64());
+ log::debug!("Original virtual address: {:#x}", function_ptr);
+ log::debug!("Original physical address: {:#x}", original_pa.as_u64());
 
- log::info!("Page virtual address: {:#x}", page_va);
- log::info!("Page physical address: {:#x}", page_pa.as_u64());
+ log::debug!("Page virtual address: {:#x}", page_va);
+ log::debug!("Page physical address: {:#x}", page_pa.as_u64());
 
- log::info!("Hook virtual address: {:#x}", hook_va);
- log::info!("Hook physical address: {:#x}", hook_pa.as_u64());
+ log::debug!("Hook virtual address: {:#x}", hook_va);
+ log::debug!("Hook physical address: {:#x}", hook_pa.as_u64());
 
  // Create an inline hook at the new address in the copied page.
  let inline_hook = FunctionHook::new(function_ptr, hook_va, handler)?;
@@ -185,8 +184,7 @@ impl Hook {
  return None;
  }
 
- log::info!("Found function: {}", function_name);
- log::info!("Address of ntoskrnl export: {:p}", address);
+ log::debug!("Function to be hooked: {} {:p}", function_name, address);
 
  // Utilize the previously defined function for hooking by address.
  Self::hook_function_ptr(address as u64, handler)
@@ -284,13 +282,13 @@ impl HookManager {
  let original_page = hook.original_pa.align_down_to_large_page().as_u64();
  let hooked_copy_page = hook.hook_pa.align_down_to_large_page().as_u64();
 
- log::info!(
+ log::debug!(
  "Splitting 2MB page to 4KB pages for Primary EPT: {:#x}",
  original_page
  );
  primary_ept.split_2mb_to_4kb(original_page, AccessType::READ_WRITE_EXECUTE)?;
 
- log::info!(
+ log::debug!(
  "Splitting 2MB page to 4KB pages for Secondary EPT: {:#x}",
  hooked_copy_page
  );
@@ -300,23 +298,23 @@ impl HookManager {
  let original_page = hook.original_pa.align_down_to_base_page().as_u64();
  let hooked_copy_page = hook.hook_pa.align_down_to_base_page().as_u64();
 
- log::info!(
+ log::debug!(
  "Changing permissions for page to Read-Write (RW) only: {:#x}",
  original_page
  );
 
  // Modify the page permission in the primary EPT to ReadWrite.
  primary_ept.change_page_flags(original_page, AccessType::READ_WRITE)?;
 
- log::info!(
+ log::debug!(
  "Changing permissions for hook page to Execute (X) only: {:#x}",
  hooked_copy_page
  );
 
- // Modify the page permission in the secondary EPT to Execute for the hook page.
+ // Modify the page permission in the secondary EPT to Execute for the original page.
  secondary_ept.change_page_flags(original_page, AccessType::EXECUTE)?;
 
- log::info!("Mapping Guest Physical Address to Host Physical Address of the hooked page: {:#x} {:#x}", original_page, hooked_copy_page);
+ log::debug!("Mapping Guest Physical Address to Host Physical Address of the hooked page: {:#x} {:#x}", original_page, hooked_copy_page);
 
  secondary_ept.remap_page(original_page, hooked_copy_page, AccessType::EXECUTE)?;
  }

hypervisor/src/intel/ept/mtrr.rs

@@ -52,7 +52,7 @@ impl Mtrr {
  };
 
  descriptors.push(descriptor);
- log::info!(
+ log::trace!(
  "MTRR Range: Base=0x{:x} End=0x{:x} Type={:?}",
  descriptor.base_address,
  descriptor.end_address,
@@ -61,7 +61,7 @@ impl Mtrr {
  }
  }
 
- log::info!("Total MTRR Ranges Committed: {}", descriptors.len());
+ log::trace!("Total MTRR Ranges Committed: {}", descriptors.len());
  Self { descriptors }
  }
 

hypervisor/src/intel/ept/paging.rs

@@ -77,7 +77,7 @@ impl Ept {
  ///
  /// A `Result<(), HypervisorError>` indicating if the operation was successful.
  pub fn identity_2mb(&mut self, access_type: AccessType) -> Result<(), HypervisorError> {
- log::info!("Creating identity map for 2MB pages");
+ log::trace!("Creating identity map for 2MB pages");
 
  let mut mtrr = Mtrr::new();
 
@@ -100,7 +100,7 @@ impl Ept {
  ///
  /// A `Result<(), HypervisorError>` indicating if the operation was successful.
  pub fn identity_4kb(&mut self, access_type: AccessType) -> Result<(), HypervisorError> {
- log::info!("Creating identity map for 4KB pages");
+ log::trace!("Creating identity map for 4KB pages");
 
  let mut mtrr = Mtrr::new();
 

hypervisor/src/intel/msr_bitmap.rs

@@ -44,7 +44,7 @@ impl MsrBitmap {
  /// # Returns
  /// * A `Result` indicating the success or failure of the setup process.
  pub fn new() -> Box<MsrBitmap, PhysicalAllocator> {
- log::info!("Setting up MSR Bitmap");
+ log::trace!("Setting up MSR Bitmap");
 
  let instance = Self {
  read_low_msrs: [0; 0x400],
@@ -54,11 +54,11 @@ impl MsrBitmap {
  };
  let mut instance = Box::<Self, PhysicalAllocator>::new_in(instance, PhysicalAllocator);
 
- log::info!("Initializing MSR Bitmap");
+ log::trace!("Initializing MSR Bitmap");
 
  Self::initialize_bitmap(instance.as_mut() as *mut _ as _);
 
- log::info!("MSR Bitmap setup successful!");
+ log::trace!("MSR Bitmap setup successfully!");
 
  instance
  }

hypervisor/src/intel/shared_data.rs

@@ -59,7 +59,7 @@ impl SharedData {
  secondary_ept: Box<Ept, PhysicalAllocator>,
  hook_manager: Box<HookManager>,
  ) -> Result<Box<Self>, HypervisorError> {
- log::info!("Initializing shared data");
+ log::trace!("Initializing shared data");
 
  let primary_eptp = primary_ept.create_eptp_with_wb_and_4lvl_walk()?;
  let secondary_eptp = secondary_ept.create_eptp_with_wb_and_4lvl_walk()?;
@@ -92,7 +92,7 @@ impl SharedData {
  primary_ept: Box<Ept, PhysicalAllocator>,
  hook_manager: Box<HookManager>,
  ) -> Result<Option<Box<Self>>, HypervisorError> {
- log::info!("Initializing shared data");
+ log::trace!("Initializing shared data");
 
  let primary_eptp = primary_ept.create_eptp_with_wb_and_4lvl_walk()?;
 

hypervisor/src/intel/vcpu.rs

@@ -43,7 +43,7 @@ impl Vcpu {
  ///
  /// A `Result` containing the initialized VCPU instance or a `HypervisorError`.
  pub fn new(index: u32) -> Result<Self, HypervisorError> {
- log::info!("Creating processor {}", index);
+ log::trace!("Creating processor {}", index);
 
  Ok(Self {
  index,
@@ -63,7 +63,7 @@ impl Vcpu {
  log::info!("Virtualizing processor {}", self.index);
 
  // Capture the current processor's context. The Guest will resume from this point since we capture and write this context to the guest state for each vcpu.
- log::info!("Capturing context");
+ log::trace!("Capturing context");
  let mut context: MaybeUninit<CONTEXT> = MaybeUninit::uninit();
 
  unsafe { RtlCaptureContext(context.as_mut_ptr() as _) };
@@ -73,7 +73,7 @@ impl Vcpu {
  // Determine if we're operating as the Host (root) or Guest (non-root). Only proceed with system virtualization if operating as the Host.
  if !is_virtualized() {
  // If we are here as Guest (non-root) then that will lead to undefined behavior (UB).
- log::info!("Preparing for virtualization");
+ log::trace!("Preparing for virtualization");
  set_virtualized();
 
  self.vmx
@@ -86,7 +86,7 @@ impl Vcpu {
 
  log::info!("Virtualization complete for processor {}", self.index);
 
- vmx.run();
+ vmx.run(self.index);
 
  // We should never reach this point as the VM should have been launched.
  }
@@ -111,13 +111,13 @@ impl Vcpu {
  pub fn devirtualize_cpu(&self) -> Result<(), HypervisorError> {
  // Determine if the processor is already devirtualized.
  if !is_virtualized() {
- log::info!("Processor {} is already devirtualized", self.index);
+ log::trace!("Processor {} is already devirtualized", self.index);
  return Ok(());
  }
 
  // Attempt to devirtualize the processor using the VMXOFF instruction.
  support::vmxoff()?;
- log::info!("Processor {} has been devirtualized", self.index);
+ log::trace!("Processor {} has been devirtualized", self.index);
 
  Ok(())
  }
@@ -137,7 +137,7 @@ impl Vcpu {
  /// instructions. It ensures that any cached translations are consistent with the current state of the virtual
  /// processor and EPT configurations.
  pub fn invalidate_contexts() {
- log::info!("Invalidating processor contexts");
+ log::debug!("Invalidating processor contexts");
 
  // Invalidate all contexts (broad operation, typically used in specific scenarios)
  //
@@ -158,6 +158,6 @@ impl Vcpu {
  // Reference: 29.4.3.3 Guidelines for Use of the INVVPID Instruction
  invvpid_all_contexts();
 
- log::info!("Processor contexts invalidation successful!");
+ log::debug!("Processor contexts invalidation successfully!");
  }
 }