fixup: address review comments

- Update workflow test to use the new mshv default
- Remove unnecessary comments
- Update documentation to reflect latest version of code
- Update tracing macros to check the length of the message and fail if
  it would overflow the tracing buffer
- Update tracing buffer to take a generic instead of a function to help
  with inlining and avoid performance penalties due to indirection

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

Author: dblnz

.github/workflows/dep_rust.yml

@@ -175,7 +175,7 @@ jobs:
         env:
           CARGO_TERM_COLOR: always
           RUST_LOG: debug
-        run: just test-rust-tracing ${{ matrix.config }} ${{ matrix.hypervisor == 'mshv3' && 'mshv3' || ''}}
+        run: just test-rust-tracing ${{ matrix.config }} ${{ matrix.hypervisor == 'mshv2' && 'mshv2' || ''}}
 
       - name: Download benchmarks from "latest"
         run: just bench-download ${{ runner.os }} ${{ matrix.hypervisor }} ${{ matrix.cpu}} dev-latest # compare to prerelease

Cargo.lock

@@ -160,7 +160,7 @@ test-rust-tracing target=default-target features="":
         | sed -n 's/.*Creating trace file at: \(.*\)/\1/p' \
         | xargs -I {} cargo run -p trace_dump ./{{ simpleguest_source }}/{{ target }}/simpleguest {} list_frames
 
-    # Rebuild the tracing guest without the tracing feature
+    # Rebuild the tracing guests without the tracing feature
     # This is to ensure that the tracing feature does not affect the other tests
     just build-rust-guests {{ target }}
     just move-rust-guests {{ target }}

Justfile

@@ -96,6 +96,11 @@ Once the container or the exe is running, the trace output can be viewed in the
 
 Hyperlight provides advanced observability features for guest code running inside micro virtual machines. You can enable guest-side tracing, stack unwinding, and memory profiling using the `trace_guest`, `unwind_guest`, and `mem_profile` features. This section explains how to build, run, and inspect guest traces.
 
+The following features are available for guest tracing:
+- `trace_guest`: Enables tracing for guest code, capturing function calls and execution time.
+- `unwind_guest`: Enables stack unwinding for guest code, allowing you to capture stack traces.
+- `mem_profile`: Enables memory profiling for guest code, capturing memory allocations and usage.
+
 ### Building a Guest with Tracing Support
 
 To build a guest with tracing enabled, use the following commands:
@@ -135,7 +140,7 @@ This command will list the stack frames and tracing information captured during
 cargo run -p trace_dump ./src/tests/rust_guests/bin/debug/simpleguest ./trace/<UUID>.trace list_frames
 ```
 
-You can use additional features such as `unwind_guest` and `mem_profile` by enabling them during the build and run steps. Refer to the guest and host documentation for more details on these features.
+You can use additional features such as `unwind_guest` and `mem_profile` by enabling them during the build and run steps.
 
 > **Note:** Make sure to follow the build and run steps in order, and ensure that the guest binaries are up to date before running the host example.
 

docs/hyperlight-metrics-logs-and-traces.md

@@ -65,8 +65,10 @@ pub extern "C" fn hl_exception_handler(
     exception_number: u64,
     page_fault_address: u64,
 ) {
-    // This function does not return, so wrapping it in a tracing macro
-    // issues a warning of unreachable code.
+    // When using the `trace_function` macro, it wraps the function body with create_trace_record
+    // call, which generates a warning because of the `abort_with_code_and_message` call which does
+    // not return.
+    // This is manually added to avoid the warning.
     hyperlight_guest_tracing_macro::trace!("> hl_exception_handler");
 
     let ctx = stack_pointer as *mut Context;
@@ -99,6 +101,7 @@ pub extern "C" fn hl_exception_handler(
                 )(exception_number, exn_info, ctx, page_fault_address)
             }
         {
+            hyperlight_guest_tracing_macro::trace!("< hl_exception_handler");
             return;
         }
     }

src/hyperlight_guest_bin/src/exceptions/handler.rs

@@ -27,14 +27,14 @@ use spin::Mutex;
 type SendToHostFn = fn(u64, &[TraceRecord]);
 
 /// Global trace buffer for storing trace records.
-static TRACE_BUFFER: Mutex<TraceBuffer> = Mutex::new(TraceBuffer::new(send_to_host));
+static TRACE_BUFFER: Mutex<TraceBuffer<SendToHostFn>> = Mutex::new(TraceBuffer::new(send_to_host));
 
 /// Maximum number of entries in the trace buffer.
 /// From local testing, 32 entries seems to be a good balance between performance and memory usage.
 const MAX_NO_OF_ENTRIES: usize = 32;
 
 /// Maximum length of a trace message in bytes.
-const MAX_TRACE_MSG_LEN: usize = 64;
+pub const MAX_TRACE_MSG_LEN: usize = 64;
 
 #[derive(Debug, Copy, Clone)]
 /// Represents a trace record of a guest with a number of cycles and a message.
@@ -47,41 +47,40 @@ pub struct TraceRecord {
     pub msg: [u8; MAX_TRACE_MSG_LEN],
 }
 
-impl TryFrom<&str> for TraceRecord {
-    type Error = &'static str;
-
-    fn try_from(msg: &str) -> Result<Self, Self::Error> {
+impl From<&str> for TraceRecord {
+    fn from(mut msg: &str) -> Self {
         if msg.len() > MAX_TRACE_MSG_LEN {
-            return Err("Message too long");
+            // If the message is too long, truncate it to fit the maximum length
+            msg = &msg[..MAX_TRACE_MSG_LEN];
         }
 
         let cycles = invariant_tsc::read_tsc();
 
-        Ok(TraceRecord {
+        TraceRecord {
             cycles,
             msg: {
                 let mut arr = [0u8; MAX_TRACE_MSG_LEN];
                 arr[..msg.len()].copy_from_slice(msg.as_bytes());
                 arr
             },
             msg_len: msg.len(),
-        })
+        }
     }
 }
 
 /// A buffer for storing trace records.
-struct TraceBuffer {
+struct TraceBuffer<F: Fn(u64, &[TraceRecord])> {
     /// The entries in the trace buffer.
     entries: [TraceRecord; MAX_NO_OF_ENTRIES],
     /// The index where the next entry will be written.
     write_index: usize,
     /// Function to send the trace records to the host.
-    send_to_host: SendToHostFn,
+    send_to_host: F,
 }
 
-impl TraceBuffer {
+impl<F: Fn(u64, &[TraceRecord])> TraceBuffer<F> {
     /// Creates a new `TraceBuffer` with uninitialized entries.
-    const fn new(f: SendToHostFn) -> Self {
+    const fn new(f: F) -> Self {
         Self {
             entries: unsafe { [MaybeUninit::zeroed().assume_init(); MAX_NO_OF_ENTRIES] },
             write_index: 0,
@@ -158,18 +157,15 @@ pub mod invariant_tsc {
     }
 }
 
-/// Attempt to create a trace record from the message.
-/// If the message is too long it will skip the record.
-/// This is useful for ensuring that the trace buffer does not overflow.
-/// If the message is successfully converted, it will be pushed to the trace buffer.
+/// Create a trace record from the message and push it to the trace buffer.
 ///
-/// **Note**: The message must not exceed `MAX_TRACE_MSG_LEN` bytes.
+/// **NOTE**: If the message is too long it will be truncated to fit within `MAX_TRACE_MSG_LEN`.
+/// This is useful for ensuring that the trace buffer does not overflow.
 pub fn create_trace_record(msg: &str) {
-    // Maybe panic if the message is too long?
-    if let Ok(entry) = TraceRecord::try_from(msg) {
-        let mut buffer = TRACE_BUFFER.lock();
-        buffer.push(entry);
-    }
+    let entry = TraceRecord::from(msg);
+    let mut buffer = TRACE_BUFFER.lock();
+
+    buffer.push(entry);
 }
 
 /// Flush the trace buffer to send any remaining trace records to the host.
@@ -271,7 +267,11 @@ mod tests {
     #[test]
     fn test_trace_record_creation_too_long() {
         let long_msg = "A".repeat(MAX_TRACE_MSG_LEN + 1);
-        let result = TraceRecord::try_from(long_msg.as_str());
-        assert!(result.is_err(), "Expected error for message too long");
+        let result = TraceRecord::from(long_msg.as_str());
+        assert_eq!(result.msg_len, MAX_TRACE_MSG_LEN);
+        assert_eq!(
+            &result.msg[..MAX_TRACE_MSG_LEN],
+            &long_msg.as_bytes()[..MAX_TRACE_MSG_LEN],
+        );
     }
 }

src/hyperlight_guest_tracing/src/lib.rs

@@ -10,6 +10,7 @@ readme.workspace = true
 description = """Provides the tracing macros for the hyperlight guest, enabling structured logging and tracing capabilities."""
 
 [dependencies]
+hyperlight-guest-tracing = { workspace = true }
 proc-macro2 = "1.0"
 quote = "1.0.40"
 syn = { version = "2.0.104", features = ["full"] }

src/hyperlight_guest_tracing_macro/Cargo.toml

@@ -44,18 +44,31 @@ pub fn trace_function(_attr: TokenStream, item: TokenStream) -> TokenStream {
     let fn_attrs = &input_fn.attrs;
     let fn_output = &input_fn.sig.output;
 
+    // Compose entry/exit messages
+    let entry_msg = format!("> {}", fn_name_str);
+    let exit_msg = format!("< {}", fn_name_str);
+
+    if entry_msg.len() > hyperlight_guest_tracing::MAX_TRACE_MSG_LEN
+        || exit_msg.len() > hyperlight_guest_tracing::MAX_TRACE_MSG_LEN
+    {
+        panic!(
+            "Trace messages must not exceed {} bytes in length.",
+            hyperlight_guest_tracing::MAX_TRACE_MSG_LEN
+        );
+    }
+
     let expanded = match fn_output {
         syn::ReturnType::Default => {
             // No return value (unit)
             quote! {
                 #(#fn_attrs)*
                 #fn_vis #fn_sig {
                     #[cfg(feature = "trace_guest")]
-                    hyperlight_guest_tracing::create_trace_record(concat!("> ", #fn_name_str));
+                    hyperlight_guest_tracing::create_trace_record(#entry_msg);
                     // Call the original function body
                     #fn_block
                     #[cfg(feature = "trace_guest")]
-                    hyperlight_guest_tracing::create_trace_record(concat!("< ", #fn_name_str));
+                    hyperlight_guest_tracing::create_trace_record(#exit_msg);
                 }
             }
         }
@@ -90,6 +103,18 @@ impl syn::parse::Parse for TraceMacroInput {
         if !matches!(message, syn::Lit::Str(_)) {
             return Err(input.error("first argument to trace! must be a string literal"));
         }
+        if let syn::Lit::Str(ref lit_str) = message {
+            if lit_str.value().is_empty() {
+                return Err(input.error("trace message must not be empty"));
+            }
+            if lit_str.value().len() > hyperlight_guest_tracing::MAX_TRACE_MSG_LEN {
+                return Err(input.error(format!(
+                    "trace message must not exceed {} bytes",
+                    hyperlight_guest_tracing::MAX_TRACE_MSG_LEN
+                )));
+            }
+        }
+
         let statement = if input.peek(syn::Token![,]) {
             let _: syn::Token![,] = input.parse()?;
             Some(input.parse()?)

src/hyperlight_guest_tracing_macro/src/lib.rs

@@ -353,7 +353,6 @@ fn handle_outb_impl(
             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