Enable Tracing for Guest-Side Debugging during Sweetests

When running sweettests, it is difficult to diagnose problems arising in guest-side code. The output of println's is not shown in the console.

Proposal

Following holochain practice of leveraging tokio's tracing utility by using

This involves:

instrumenting guest-side code with tracing macro calls (i.e., error!, warn!, info!, debug! or trace!) according do desired detail level .
inserting holochain_trace::test_run() at the start of a tests driver (e.g., dance_tests)
setting RUST_LOG to the desired client-side tracing level to include in output.
setting WASM_LOG to the desired guest-side tracing level to include in output.

In increasing level of detail: error, warn, info, debug, trace

Examples:

To show DEBUG level trace messages on the client-side and WARN level trace messages on the guest-side: export RUST_LOG=debug export WASM_LOG=warn
To show INFO level trace messages on the client-side and DEBUG level trace messages on the guest-side: export RUST_LOG=info export WASM_LOG=debug

This enhancement has been implemented and tested in PR#72 for the dance_tests. Some tracing messages have been inserted in both guest-side and client-side code.

tokio tracing includes the ability to dynamically control detail level (instead of via environment variables). So an approach like we tried with: https://github.com/evomimic/map-descriptors2/issues/25 may be possible. I played around with trying to add a "reloadable filter layer" using the following suggestion from ChatGPT:


// Create a reloadable filter
    let filter = EnvFilter::new("info");
    let (filter_layer, reload_handle) = reload::Layer::new(filter);

    // Ensure this layer is added to the existing global subscriber
    let subscriber = Registry::default()
        .with(filter_layer)
        .with(fmt::layer());

    // Set the subscriber as the global default
    // Note: This should be done before any other part of your framework sets a global subscriber
    tracing::subscriber::set_global_default(subscriber).expect("setting default subscriber failed");

    // Arc and Mutex for thread-safe shared access
    let reload_handle = Arc::new(Mutex::new(reload_handle));

    // Example log messages
    info!("This is an info message");

    // Function to dynamically update the filter
    update_filter(reload_handle.clone(), "debug");

    // Example log message after updating the filter
    info!("This is a debug message after reloading filter");

fn update_filter<S>(reload_handle: Arc<Mutex<reload::Handle<EnvFilter, S>>>, new_level: &str)
    where
        S: tracing::Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
{
    let new_filter = EnvFilter::new(new_level);
    let mut handle = reload_handle.lock().expect("Failed to lock reload_handle");
    handle.reload(new_filter).expect("Failed to reload filter");
}

But holochain is already setting a global default subscriber and so the above code fails.

I'm going to close this issue for now... perhaps introducing dynamic control later after talking with the holochain folks.

evomimic / map-holons

Enable Tracing for Guest-Side Debugging during Sweetests #81

Proposal