Fix StackOverflow produced by guest logging (#1067)

* Fix StackOverflow produced by guest logging

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

* [guest] Enable `log` feature for `tracing` crate in simpleguest

- The rationale for this change is to allow hyperlight core to test this
  scenario and catch potential issues early, not downstream.
- This makes all trace spans to be created as logs when there is no
  subscriber installed on the guest (when `trace_guest` not enabled)
- The `log_messages` integration test verifies that the guest correctly
  behaves when `RUST_LOG` enables guest logs.

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

---------

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

Author: dblnz

Justfile

@@ -166,7 +166,7 @@ test-integration guest target=default-target features="":
     @# run execute_on_heap test with feature "executable_heap" on and off
     {{if os() == "windows" { "$env:" } else { "" } }}GUEST="{{guest}}"{{if os() == "windows" { ";" } else { "" } }} {{ cargo-cmd }} test --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} --test integration_test execute_on_heap {{ if features =="" {" --features executable_heap"} else {"--features executable_heap," + features} }} -- --ignored
     {{if os() == "windows" { "$env:" } else { "" } }}GUEST="{{guest}}"{{if os() == "windows" { ";" } else { "" } }} {{ cargo-cmd }} test --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} --test integration_test execute_on_heap {{ if features =="" {""} else {"--features " + features} }} -- --ignored
-    
+
     @# run the rest of the integration tests
     @# skip interrupt_random_kill_stress_test and then run it explicitly so we can see the output more 
     {{if os() == "windows" { "$env:" } else { "" } }}GUEST="{{guest}}"{{if os() == "windows" { ";" } else { "" } }} {{ cargo-cmd }} test -p hyperlight-host {{ if features =="" {''} else if features=="no-default-features" {"--no-default-features" } else {"--no-default-features -F init-paging," + features } }} --profile={{ if target == "debug" { "dev" } else { target } }} {{ target-triple-flag }} --test '*' --  --skip interrupt_random_kill_stress_test

src/hyperlight_guest/src/guest_handle/io.rs

@@ -89,7 +89,6 @@ impl GuestHandle {
     }
 
     /// Pushes the given data onto the shared output data buffer.
-    #[instrument(skip_all, parent = Span::current(), level= "Trace")]
     pub fn push_shared_output_data(&self, data: &[u8]) -> Result<()> {
         let peb_ptr = self.peb().unwrap();
         let output_stack_size = unsafe { (*peb_ptr).output_stack.size as usize };

src/hyperlight_host/tests/integration_test.rs

@@ -727,8 +727,19 @@ fn recursive_stack_allocate_overflow() {
 #[test]
 #[ignore]
 fn log_message() {
-    // internal_dispatch_function does a log::trace! in debug mode, and we call it 6 times in `log_test_messages`
-    let num_fixed_trace_log = if cfg!(debug_assertions) { 6 } else { 0 };
+    // The magic numbers below represent the number of fixed log messages that are emitted as
+    // follows:
+    //  - internal_dispatch_function does a log::trace! in debug mode
+    //  - logs from trace level tracing spans created as logs because of the tracing `log` feature
+    //    - 6 from evolve call (hyperlight_main + halt)
+    //    - 16 from guest call (internal_dispatch_function + others)
+    // and are multiplied because we make 6 calls to `log_test_messages`
+    // NOTE: These numbers need to be updated if log messages or spans are added/removed
+    let num_fixed_trace_log = if cfg!(debug_assertions) {
+        (1 + 22) * 6
+    } else {
+        22 * 6
+    };
 
     let tests = vec![
         (LevelFilter::Trace, 5 + num_fixed_trace_log),

src/tests/rust_guests/simpleguest/Cargo.lock

@@ -9,7 +9,7 @@ hyperlight-guest-bin = { path = "../../../hyperlight_guest_bin" }
 hyperlight-common = { path = "../../../hyperlight_common", default-features = false }
 hyperlight-guest-tracing = { path = "../../../hyperlight_guest_tracing" }
 log = {version = "0.4", default-features = false }
-tracing = { version = "0.1.41", default-features = false, features = ["attributes"] }
+tracing = { version = "0.1.41", default-features = false, features = ["log", "attributes"] }
 
 [features]
 default = []