Add fast trace collection & use it for instrumenting guest memory operations

src/hyperlight_host/Cargo.toml

@@ -48,6 +48,8 @@ strum = { version = "0.26", features = ["derive"] }
 tempfile = { version = "3.10", optional = true }
 serde_yaml = "0.9"
 anyhow = "1.0"
+uuid = { version = "1.4.1", features = ["v4"] }
+
 
 [target.'cfg(windows)'.dependencies]
 windows = { version = "0.58", features = [
@@ -76,7 +78,6 @@ kvm-bindings = { version = "0.10.0", features = ["fam-wrappers"], optional = tru
 kvm-ioctls = { version = "0.19.0", optional = true }
 
 [dev-dependencies]
-uuid = { version = "1.4.1", features = ["v4"] }
 signal-hook-registry = "1.4.1"
 envy = { version = "0.4.2" }
 serde = "1.0"
@@ -120,6 +121,10 @@ executable_heap = []
 # This feature enables printing of debug information to stdout in debug builds
 print_debug = []
 crashdump = ["dep:tempfile"] # Dumps the VM state to a file on unexpected errors or crashes. The path of the file will be printed on stdout and logged. This feature can only be used in debug builds.
+# This feature enables the generation of trace files.  Traces do not
+# include any particularly expensive instrumentation unless other
+# features are enabled.
+trace_guest = []
 kvm = ["dep:kvm-bindings", "dep:kvm-ioctls"]
 mshv = ["dep:mshv-bindings", "dep:mshv-ioctls"]
 inprocess = []

src/hyperlight_host/src/hypervisor/handlers.rs

@@ -18,14 +18,24 @@ use std::sync::{Arc, Mutex};
 
 use tracing::{instrument, Span};
 
+#[cfg(feature = "trace_guest")]
+use super::Hypervisor;
+#[cfg(feature = "trace_guest")]
+use crate::sandbox::TraceInfo;
 use crate::{new_error, Result};
 
 /// The trait representing custom logic to handle the case when
 /// a Hypervisor's virtual CPU (vCPU) informs Hyperlight the guest
 /// has initiated an outb operation.
 pub(crate) trait OutBHandlerCaller: Sync + Send {
     /// Function that gets called when an outb operation has occurred.
-    fn call(&mut self, port: u16, payload: u64) -> Result<()>;
+    fn call(
+        &mut self,
+        #[cfg(feature = "trace_guest")] hv: &mut dyn Hypervisor,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
+        port: u16,
+        payload: u64,
+    ) -> Result<()>;
 }
 
 /// A convenient type representing a common way `OutBHandler` implementations
@@ -36,6 +46,10 @@ pub(crate) trait OutBHandlerCaller: Sync + Send {
 /// a &mut self).
 pub(crate) type OutBHandlerWrapper = Arc<Mutex<dyn OutBHandlerCaller>>;
 
+#[cfg(feature = "trace_guest")]
+pub(crate) type OutBHandlerFunction =
+    Box<dyn FnMut(&mut dyn Hypervisor, TraceInfo, u16, u64) -> Result<()> + Send>;
+#[cfg(not(feature = "trace_guest"))]
 pub(crate) type OutBHandlerFunction = Box<dyn FnMut(u16, u64) -> Result<()> + Send>;
 
 /// A `OutBHandler` implementation using a `OutBHandlerFunction`
@@ -52,12 +66,25 @@ impl From<OutBHandlerFunction> for OutBHandler {
 
 impl OutBHandlerCaller for OutBHandler {
     #[instrument(err(Debug), skip_all, parent = Span::current(), level= "Trace")]
-    fn call(&mut self, port: u16, payload: u64) -> Result<()> {
+    fn call(
+        &mut self,
+        #[cfg(feature = "trace_guest")] hv: &mut dyn Hypervisor,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
+        port: u16,
+        payload: u64,
+    ) -> Result<()> {
         let mut func = self
             .0
             .try_lock()
             .map_err(|e| new_error!("Error locking at {}:{}: {}", file!(), line!(), e))?;
-        func(port, payload)
+        func(
+            #[cfg(feature = "trace_guest")]
+            hv,
+            #[cfg(feature = "trace_guest")]
+            trace_info,
+            port,
+            payload,
+        )
     }
 }
 

src/hyperlight_host/src/hypervisor/hyperv_linux.rs

@@ -37,6 +37,8 @@ use crate::hypervisor::hypervisor_handler::HypervisorHandler;
 use crate::hypervisor::HyperlightExit;
 use crate::mem::memory_region::{MemoryRegion, MemoryRegionFlags};
 use crate::mem::ptr::{GuestPtr, RawPtr};
+#[cfg(feature = "trace_guest")]
+use crate::sandbox::TraceInfo;
 use crate::{log_then_return, new_error, Result};
 
 /// Determine whether the HyperV for Linux hypervisor API is present
@@ -173,6 +175,7 @@ impl Hypervisor for HypervLinuxDriver {
         outb_hdl: OutBHandlerWrapper,
         mem_access_hdl: MemAccessHandlerWrapper,
         hv_handler: Option<HypervisorHandler>,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
     ) -> Result<()> {
         let regs = StandardRegisters {
             rip: self.entrypoint,
@@ -194,6 +197,8 @@ impl Hypervisor for HypervLinuxDriver {
             hv_handler,
             outb_hdl,
             mem_access_hdl,
+            #[cfg(feature = "trace_guest")]
+            trace_info,
         )?;
 
         // reset RSP to what it was before initialise
@@ -212,6 +217,7 @@ impl Hypervisor for HypervLinuxDriver {
         outb_handle_fn: OutBHandlerWrapper,
         mem_access_fn: MemAccessHandlerWrapper,
         hv_handler: Option<HypervisorHandler>,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
     ) -> Result<()> {
         // Reset general purpose registers except RSP, then set RIP
         let rsp_before = self.vcpu_fd.get_regs()?.rsp;
@@ -238,6 +244,8 @@ impl Hypervisor for HypervLinuxDriver {
             hv_handler,
             outb_handle_fn,
             mem_access_fn,
+            #[cfg(feature = "trace_guest")]
+            trace_info,
         )?;
 
         // reset RSP to what it was before function call
@@ -257,12 +265,20 @@ impl Hypervisor for HypervLinuxDriver {
         rip: u64,
         instruction_length: u64,
         outb_handle_fn: OutBHandlerWrapper,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
     ) -> Result<()> {
         let payload = data[..8].try_into()?;
         outb_handle_fn
             .try_lock()
             .map_err(|e| new_error!("Error locking at {}:{}: {}", file!(), line!(), e))?
-            .call(port, u64::from_le_bytes(payload))?;
+            .call(
+                #[cfg(feature = "trace_guest")]
+                self,
+                #[cfg(feature = "trace_guest")]
+                trace_info,
+                port,
+                u64::from_le_bytes(payload),
+            )?;
 
         // update rip
         self.vcpu_fd.set_reg(&[hv_register_assoc {

src/hyperlight_host/src/hypervisor/hyperv_windows.rs

@@ -44,6 +44,8 @@ use crate::hypervisor::hypervisor_handler::HypervisorHandler;
 use crate::hypervisor::wrappers::WHvGeneralRegisters;
 use crate::mem::memory_region::{MemoryRegion, MemoryRegionFlags};
 use crate::mem::ptr::{GuestPtr, RawPtr};
+#[cfg(feature = "trace_guest")]
+use crate::sandbox::TraceInfo;
 use crate::HyperlightError::{NoHypervisorFound, WindowsAPIError};
 use crate::{debug, log_then_return, new_error, Result};
 
@@ -311,6 +313,7 @@ impl Hypervisor for HypervWindowsDriver {
         outb_hdl: OutBHandlerWrapper,
         mem_access_hdl: MemAccessHandlerWrapper,
         hv_handler: Option<HypervisorHandler>,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
     ) -> Result<()> {
         let regs = WHvGeneralRegisters {
             rip: self.entrypoint,
@@ -332,6 +335,8 @@ impl Hypervisor for HypervWindowsDriver {
             hv_handler,
             outb_hdl,
             mem_access_hdl,
+            #[cfg(feature = "trace_guest")]
+            trace_info,
         )?;
 
         // reset RSP to what it was before initialise
@@ -350,6 +355,7 @@ impl Hypervisor for HypervWindowsDriver {
         outb_hdl: OutBHandlerWrapper,
         mem_access_hdl: MemAccessHandlerWrapper,
         hv_handler: Option<HypervisorHandler>,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
     ) -> Result<()> {
         // Reset general purpose registers except RSP, then set RIP
         let rsp_before = self.processor.get_regs()?.rsp;
@@ -374,6 +380,8 @@ impl Hypervisor for HypervWindowsDriver {
             hv_handler,
             outb_hdl,
             mem_access_hdl,
+            #[cfg(feature = "trace_guest")]
+            trace_info,
         )?;
 
         // reset RSP to what it was before function call
@@ -393,12 +401,20 @@ impl Hypervisor for HypervWindowsDriver {
         rip: u64,
         instruction_length: u64,
         outb_handle_fn: OutBHandlerWrapper,
+        #[cfg(feature = "trace_guest")] trace_info: TraceInfo,
     ) -> Result<()> {
         let payload = data[..8].try_into()?;
         outb_handle_fn
             .try_lock()
             .map_err(|e| new_error!("Error locking at {}:{}: {}", file!(), line!(), e))?
-            .call(port, u64::from_le_bytes(payload))?;
+            .call(
+                #[cfg(feature = "trace_guest")]
+                self,
+                #[cfg(feature = "trace_guest")]
+                trace_info,
+                port,
+                u64::from_le_bytes(payload),
+            )?;
 
         let mut regs = self.processor.get_regs()?;
         regs.rip = rip + instruction_length;
@@ -548,16 +564,21 @@ pub mod tests {
 
     use serial_test::serial;
 
-    use crate::hypervisor::handlers::{MemAccessHandler, OutBHandler};
+    use crate::hypervisor::handlers::{MemAccessHandler, OutBHandler, OutBHandlerFunction};
     use crate::hypervisor::tests::test_initialise;
     use crate::Result;
 
     #[test]
     #[serial]
     fn test_init() {
         let outb_handler = {
-            let func: Box<dyn FnMut(u16, u64) -> Result<()> + Send> =
-                Box::new(|_, _| -> Result<()> { Ok(()) });
+            let func: OutBHandlerFunction = Box::new(
+                |#[cfg(feature = "trace_guest")] _,
+                 #[cfg(feature = "trace_guest")] _,
+                 _,
+                 _|
+                 -> Result<()> { Ok(()) },
+            );
             Arc::new(Mutex::new(OutBHandler::from(func)))
         };
         let mem_access_handler = {

src/hyperlight_host/src/hypervisor/hypervisor_handler.rs

@@ -47,6 +47,8 @@ use crate::mem::shared_mem::{GuestSharedMemory, HostSharedMemory, SharedMemory};
 use crate::sandbox::hypervisor::{get_available_hypervisor, HypervisorType};
 #[cfg(feature = "function_call_metrics")]
 use crate::sandbox::metrics::SandboxMetric::GuestFunctionCallDurationMicroseconds;
+#[cfg(feature = "trace_guest")]
+use crate::sandbox::TraceInfo;
 #[cfg(target_os = "linux")]
 use crate::signal_handlers::setup_signal_handlers;
 use crate::HyperlightError::{
@@ -183,6 +185,8 @@ pub(crate) struct HvHandlerConfig {
     pub(crate) outb_handler: OutBHandlerWrapper,
     pub(crate) mem_access_handler: MemAccessHandlerWrapper,
     pub(crate) max_wait_for_cancellation: Duration,
+    #[cfg(feature = "trace_guest")]
+    pub(crate) trace_info: TraceInfo,
 }
 
 impl HypervisorHandler {
@@ -338,6 +342,8 @@ impl HypervisorHandler {
                                     configuration.outb_handler.clone(),
                                     configuration.mem_access_handler.clone(),
                                     Some(hv_handler_clone.clone()),
+                                    #[cfg(feature = "trace_guest")]
+                                    configuration.trace_info.clone(),
                                 );
                                 drop(mem_lock_guard);
                                 drop(evar_lock_guard);
@@ -417,6 +423,7 @@ impl HypervisorHandler {
                                             configuration.outb_handler.clone(),
                                             configuration.mem_access_handler.clone(),
                                             Some(hv_handler_clone.clone()),
+                                            #[cfg(feature = "trace_guest")] configuration.trace_info.clone(),
                                         );
                                         histogram_vec_observe!(
                                             &GuestFunctionCallDurationMicroseconds,
@@ -432,6 +439,7 @@ impl HypervisorHandler {
                                         configuration.outb_handler.clone(),
                                         configuration.mem_access_handler.clone(),
                                         Some(hv_handler_clone.clone()),
+                                        #[cfg(feature = "trace_guest")] configuration.trace_info.clone(),
                                     )
                                 };
                                 drop(mem_lock_guard);

src/hyperlight_host/src/hypervisor/inprocess.rs

@@ -21,6 +21,8 @@ use super::{HyperlightExit, Hypervisor};
 #[cfg(crashdump)]
 use crate::mem::memory_region::MemoryRegion;
 use crate::sandbox::leaked_outb::LeakedOutBWrapper;
+#[cfg(feature = "trace_guest")]
+use crate::sandbox::TraceInfo;
 use crate::Result;
 
 /// Arguments passed to inprocess driver
@@ -73,6 +75,7 @@ impl<'a> Hypervisor for InprocessDriver<'a> {
         _outb_handle_fn: super::handlers::OutBHandlerWrapper,
         _mem_access_fn: super::handlers::MemAccessHandlerWrapper,
         _hv_handler: Option<super::hypervisor_handler::HypervisorHandler>,
+        #[cfg(feature = "trace_guest")] _trace_info: TraceInfo,
     ) -> crate::Result<()> {
         let entrypoint_fn: extern "win64" fn(u64, u64, u64, u64) =
             unsafe { std::mem::transmute(self.args.entrypoint_raw as *const c_void) };
@@ -93,6 +96,7 @@ impl<'a> Hypervisor for InprocessDriver<'a> {
         _outb_handle_fn: super::handlers::OutBHandlerWrapper,
         _mem_access_fn: super::handlers::MemAccessHandlerWrapper,
         _hv_handler: Option<super::hypervisor_handler::HypervisorHandler>,
+        #[cfg(feature = "trace_guest")] _trace_info: TraceInfo,
     ) -> crate::Result<()> {
         let ptr: u64 = dispatch_func_addr.into();
         let dispatch_func: extern "win64" fn() =
@@ -109,6 +113,7 @@ impl<'a> Hypervisor for InprocessDriver<'a> {
         _rip: u64,
         _instruction_length: u64,
         _outb_handle_fn: super::handlers::OutBHandlerWrapper,
+        #[cfg(feature = "trace_guest")] _trace_info: TraceInfo,
     ) -> crate::Result<()> {
         unimplemented!("handle_io should not be needed since we are in in-process mode")
     }