Handle incoming TraceRecords in the host and send traces from key places in the guest

Signed-off-by: Doru Blânzeanu <[email protected]>

Author: dblnz

src/hyperlight_guest/Cargo.toml

@@ -15,3 +15,9 @@ Provides only the essential building blocks for interacting with the host enviro
 anyhow = { version = "1.0.98", default-features = false }
 serde_json = { version = "1.0", default-features = false, features = ["alloc"] }
 hyperlight-common = { workspace = true }
+hyperlight-guest-tracing = { workspace = true, optional = true }
+hyperlight-guest-tracing-macro = { workspace = true}
+
+[features]
+default = []
+trace_guest = ["dep:hyperlight-guest-tracing"]

src/hyperlight_guest/src/exit.rs

@@ -21,17 +21,20 @@ use hyperlight_common::outb::OutBAction;
 
 /// Halt the execution of the guest and returns control to the host.
 #[inline(never)]
+#[hyperlight_guest_tracing_macro::trace_function]
 pub fn halt() {
     unsafe { asm!("hlt", options(nostack)) }
 }
 
 /// Exits the VM with an Abort OUT action and code 0.
 #[unsafe(no_mangle)]
+#[hyperlight_guest_tracing_macro::trace_function]
 pub extern "C" fn abort() -> ! {
     abort_with_code(&[0, 0xFF])
 }
 
 /// Exits the VM with an Abort OUT action and a specific code.
+#[hyperlight_guest_tracing_macro::trace_function]
 pub fn abort_with_code(code: &[u8]) -> ! {
     outb(OutBAction::Abort as u16, code);
     outb(OutBAction::Abort as u16, &[0xFF]); // send abort terminator (if not included in code)
@@ -42,6 +45,7 @@ pub fn abort_with_code(code: &[u8]) -> ! {
 ///
 /// # Safety
 /// This function is unsafe because it dereferences a raw pointer.
+#[hyperlight_guest_tracing_macro::trace_function]
 pub unsafe fn abort_with_code_and_message(code: &[u8], message_ptr: *const c_char) -> ! {
     unsafe {
         // Step 1: Send abort code (typically 1 byte, but `code` allows flexibility)
@@ -63,6 +67,7 @@ pub unsafe fn abort_with_code_and_message(code: &[u8], message_ptr: *const c_cha
 
 /// OUT bytes to the host through multiple exits.
 pub(crate) fn outb(port: u16, data: &[u8]) {
+    hyperlight_guest_tracing_macro::flush!();
     unsafe {
         let mut i = 0;
         while i < data.len() {

src/hyperlight_guest/src/guest_handle/host_comm.rs

@@ -35,6 +35,7 @@ use crate::exit::out32;
 
 impl GuestHandle {
     /// Get user memory region as bytes.
+    #[hyperlight_guest_tracing_macro::trace_function]
     pub fn read_n_bytes_from_user_memory(&self, num: u64) -> Result<Vec<u8>> {
         let peb_ptr = self.peb().unwrap();
         let user_memory_region_ptr = unsafe { (*peb_ptr).init_data.ptr as *mut u8 };
@@ -83,6 +84,7 @@ impl GuestHandle {
     ///
     /// Note: The function return value must be obtained by calling
     /// `get_host_return_value`.
+    #[hyperlight_guest_tracing_macro::trace_function]
     pub fn call_host_function_without_returning_result(
         &self,
         function_name: &str,
@@ -114,6 +116,7 @@ impl GuestHandle {
     /// sends it to the host, and then retrieves the return value.
     ///
     /// The return value is deserialized into the specified type `T`.
+    #[hyperlight_guest_tracing_macro::trace_function]
     pub fn call_host_function<T: TryFrom<ReturnValue>>(
         &self,
         function_name: &str,
@@ -155,6 +158,7 @@ impl GuestHandle {
     }
 
     /// Log a message with the specified log level, source, caller, source file, and line number.
+    #[hyperlight_guest_tracing_macro::trace_function]
     pub fn log_message(
         &self,
         log_level: LogLevel,

src/hyperlight_guest/src/guest_handle/io.rs

@@ -27,6 +27,7 @@ use crate::error::{HyperlightGuestError, Result};
 
 impl GuestHandle {
     /// Pops the top element from the shared input data buffer and returns it as a T
+    #[hyperlight_guest_tracing_macro::trace_function]
     pub fn try_pop_shared_input_data_into<T>(&self) -> Result<T>
     where
         T: for<'a> TryFrom<&'a [u8]>,
@@ -88,6 +89,7 @@ impl GuestHandle {
     }
 
     /// Pushes the given data onto the shared output data buffer.
+    #[hyperlight_guest_tracing_macro::trace_function]
     pub fn push_shared_output_data(&self, data: Vec<u8>) -> Result<()> {
         let peb_ptr = self.peb().unwrap();
         let output_stack_size = unsafe { (*peb_ptr).output_stack.size as usize };

src/hyperlight_guest_bin/Cargo.toml

@@ -17,11 +17,14 @@ and third-party code used by our C-API needed to build a native hyperlight-guest
 default = ["libc", "printf"]
 libc = [] # compile musl libc
 printf = [] # compile printf
+trace_guest = ["hyperlight-common/trace_guest", "dep:hyperlight-guest-tracing", "hyperlight-guest/trace_guest"]
 mem_profile = ["hyperlight-common/unwind_guest","hyperlight-common/mem_profile"]
 
 [dependencies]
 hyperlight-guest = { workspace = true, default-features = false }
 hyperlight-common = { workspace = true, default-features = false }
+hyperlight-guest-tracing = { workspace = true, optional = true }
+hyperlight-guest-tracing-macro = { workspace = true }
 buddy_system_allocator = "0.11.0"
 log = { version = "0.4", default-features = false }
 spin = "0.10.0"

src/hyperlight_guest_bin/src/guest_function/call.rs

@@ -27,6 +27,7 @@ use crate::{GUEST_HANDLE, REGISTERED_GUEST_FUNCTIONS};
 
 type GuestFunc = fn(&FunctionCall) -> Result<Vec<u8>>;
 
+#[hyperlight_guest_tracing_macro::trace_function]
 pub(crate) fn call_guest_function(function_call: FunctionCall) -> Result<Vec<u8>> {
     // Validate this is a Guest Function Call
     if function_call.function_call_type() != FunctionCallType::Guest {
@@ -99,6 +100,7 @@ fn internal_dispatch_function() -> Result<()> {
 // This is implemented as a separate function to make sure that epilogue in the internal_dispatch_function is called before the halt()
 // which if it were included in the internal_dispatch_function cause the epilogue to not be called because the halt() would not return
 // when running in the hypervisor.
+#[hyperlight_guest_tracing_macro::trace_function]
 pub(crate) extern "C" fn dispatch_function() {
     let _ = internal_dispatch_function();
     halt();

src/hyperlight_guest_bin/src/lib.rs

@@ -32,6 +32,7 @@ use hyperlight_common::mem::HyperlightPEB;
 use hyperlight_common::outb::OutBAction;
 use hyperlight_guest::exit::{abort_with_code_and_message, halt};
 use hyperlight_guest::guest_handle::handle::GuestHandle;
+use hyperlight_guest_tracing_macro::{trace, trace_function};
 use log::LevelFilter;
 use spin::Once;
 
@@ -154,6 +155,7 @@ unsafe extern "C" {
 static INIT: Once = Once::new();
 
 #[unsafe(no_mangle)]
+#[trace_function]
 pub extern "C" fn entrypoint(peb_address: u64, seed: u64, ops: u64, max_log_level: u64) {
     if peb_address == 0 {
         panic!("PEB address is null");
@@ -203,6 +205,7 @@ pub extern "C" fn entrypoint(peb_address: u64, seed: u64, ops: u64, max_log_leve
 
             (*peb_ptr).guest_function_dispatch_ptr = dispatch_function as usize as u64;
 
+            trace!("hyperlight_main");
             hyperlight_main();
         }
     });

src/hyperlight_host/src/sandbox/outb.rs

@@ -28,7 +28,6 @@ use hyperlight_common::flatbuffer_wrappers::guest_log_data::GuestLogData;
 use hyperlight_common::outb::{Exception, OutBAction};
 #[cfg(feature = "trace_guest")]
 use hyperlight_guest_tracing::TraceRecord;
-
 use log::{Level, Record};
 use tracing::{Span, instrument};
 use tracing_log::format_trace;
@@ -295,6 +294,41 @@ fn handle_outb_impl(
         }
         #[cfg(feature = "trace_guest")]
         OutBAction::TraceRecord => {
+            let Ok(len) = _hv.read_trace_reg(crate::hypervisor::TraceRegister::RAX) else {
+                return Ok(());
+            };
+            let Ok(ptr) = _hv.read_trace_reg(crate::hypervisor::TraceRegister::RCX) else {
+                return Ok(());
+            };
+            let mut buffer = vec![0u8; len as usize * std::mem::size_of::<TraceRecord>()];
+            let buffer = &mut buffer[..];
+
+            // Read the trace records from the guest memory
+            // TODO: maybe this can be done without copying?
+            mem_mgr
+                .as_ref()
+                .shared_mem
+                .copy_to_slice(buffer, ptr as usize - SandboxMemoryLayout::BASE_ADDRESS)
+                // .read::<u64>((addr - SandboxMemoryLayout::BASE_ADDRESS as u64) as usize)
+                .map_err(|e| {
+                    new_error!(
+                        "Failed to copy trace records from guest memory to host: {:?}",
+                        e
+                    )
+                })?;
+
+            let traces = unsafe {
+                std::slice::from_raw_parts(buffer.as_ptr() as *const TraceRecord, len as usize)
+            };
+
+            for record in traces {
+                record_trace_frame(&_trace_info, 4u64, |f| {
+                    let _ = f.write_all(&record.cycles.to_ne_bytes());
+                    let _ = f.write_all(&record.msg_len.to_ne_bytes());
+                    let _ = f.write_all(&record.msg[..record.msg_len]);
+                })?
+            }
+
             Ok(())
         }
     }