add more tracing entries

Cargo.lock

@@ -1271,6 +1271,7 @@ dependencies = [
  "serde_derive",
  "serde_json",
  "toml 0.5.11",
+ "tracing",
 ]
 
 [[package]]
@@ -2555,6 +2556,7 @@ dependencies = [
  "marine-wasm-backend-traits",
  "multimap",
  "paste",
+ "tracing",
  "wasmer-interface-types-fl 0.26.1",
  "wasmtime",
  "wasmtime-wasi",

core/src/host_imports/imports.rs

@@ -58,7 +58,7 @@ pub(crate) fn create_host_import_func<WB: WasmBackend>(
         func,
     )
 }
-
+#[tracing::instrument(level = "trace", skip_all)]
 fn call_host_import<WB: WasmBackend>(
     mut caller: <WB as WasmBackend>::ImportCallContext<'_>,
     inputs: &[WValue],
@@ -96,6 +96,7 @@ fn call_host_import<WB: WasmBackend>(
     lower_outputs::<WB>(&mut caller, memory, output)
 }
 
+#[tracing::instrument(level = "trace", skip_all)]
 fn lift_inputs<WB: WasmBackend>(
     caller: &mut <WB as WasmBackend>::ImportCallContext<'_>,
     memory: <WB as WasmBackend>::Memory,
@@ -114,6 +115,7 @@ fn lift_inputs<WB: WasmBackend>(
     )
 }
 
+#[tracing::instrument(level = "trace", skip_all)]
 fn lower_outputs<WB: WasmBackend>(
     caller: &mut <WB as WasmBackend>::ImportCallContext<'_>,
     memory: <WB as WasmBackend>::Memory,

core/src/module/exports.rs

@@ -63,6 +63,7 @@ impl wasm::structures::Export for ITExport {
         &self.outputs
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn call(&self, arguments: &[IValue]) -> Result<Vec<IValue>, ()> {
         (self.function)(arguments)
     }

core/src/module/marine_module.rs

@@ -159,6 +159,7 @@ impl<WB: WasmBackend> MModule<WB> {
         })
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     pub(crate) fn call(
         &mut self,
         store: &mut <WB as WasmBackend>::ContextMut<'_>,

core/src/module/wit_instance.rs

@@ -52,6 +52,7 @@ pub(super) struct ITInstance<WB: WasmBackend> {
 }
 
 impl<WB: WasmBackend> ITInstance<WB> {
+    #[tracing::instrument(level = "trace", skip_all)]
     pub(super) fn new(
         wasm_instance: &<WB as WasmBackend>::Instance,
         store: &mut <WB as WasmBackend>::Store,

crates/fluence-app-service/Cargo.toml

@@ -18,6 +18,7 @@ serde = "1.0.147"
 serde_derive = "1.0.147"
 serde_json = "1.0.89"
 toml = "0.5.9"
+tracing = "0.1.37"
 
 [features]
 raw-module-api = ["marine-runtime/raw-module-api"]

crates/fluence-app-service/src/service.rs

@@ -45,6 +45,7 @@ pub struct AppService {
 
 impl AppService {
     /// Create Service with given modules and service id.
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn new<C, S>(config: C, service_id: S, envs: HashMap<String, String>) -> Result<Self>
     where
         C: TryInto<AppServiceConfig>,
@@ -76,6 +77,7 @@ impl AppService {
     }
 
     /// Call a specified function of loaded module by its name with arguments in json format.
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn call(
         &mut self,
         func_name: impl AsRef<str>,
@@ -93,6 +95,7 @@ impl AppService {
     }
 
     /// Call a specified function of loaded module by its name with arguments in IValue format.
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn call_with_ivalues(
         &mut self,
         func_name: impl AsRef<str>,
@@ -185,6 +188,7 @@ impl AppService {
 // This API is intended for testing purposes (mostly in Marine REPL)
 #[cfg(feature = "raw-module-api")]
 impl AppService {
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn new_with_empty_facade<C, S>(
         config: C,
         service_id: S,
@@ -207,6 +211,7 @@ impl AppService {
         })
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn call_module(
         &mut self,
         module_name: impl AsRef<str>,
@@ -219,6 +224,7 @@ impl AppService {
             .map_err(Into::into)
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn load_module<C, S>(&mut self, name: S, wasm_bytes: &[u8], config: Option<C>) -> Result<()>
     where
         S: Into<String>,

crates/js-backend/src/function.rs

@@ -200,6 +200,7 @@ where
     F: for<'c> Fn(JsImportCallContext, &[WValue]) -> Vec<WValue> + Sync + Send + 'static,
 {
     let func = move |args: &js_sys::Array| -> js_sys::Array {
+        let _span = tracing::trace_span!("calling import function");
         log::debug!(
             "function produced by JsFunction:::new_with_caller call, signature: {:?}",
             signature
@@ -240,6 +241,7 @@ impl ExportFunction<JsWasmBackend> for WasmExportFunction {
         self.stored_mut(store.as_context_mut()).signature.clone()
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn call(
         &self,
         store: &mut impl AsContextMut<JsWasmBackend>,

crates/js-backend/src/memory.rs

@@ -121,6 +121,7 @@ impl it_memory_traits::MemoryReadable<DelayedContextLifetime<JsWasmBackend>> for
         result
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn read_vec(
         &self,
         _store: &mut <DelayedContextLifetime<JsWasmBackend> as it_memory_traits::Store>::ActualStore<

crates/js-backend/src/module.rs

@@ -44,9 +44,9 @@ impl Module<JsWasmBackend> for JsModule {
             WebAssembly::Module::new(&data_obj).map_err(|e| {
                 log::debug!("Module::new failed: {:?}", e);
                 ModuleCreationError::FailedToCompileWasm(anyhow!(format!(
-                "error compiling module: {:?}",
-                e
-            )))
+                    "error compiling module: {:?}",
+                    e
+                )))
             })?
         };
 
@@ -78,7 +78,8 @@ impl Module<JsWasmBackend> for JsModule {
         let imports_object = imports.build_import_object(store.as_context(), &self.inner);
 
         let instance = {
-            let span = tracing::span!(tracing::Level::TRACE, "WebAssembly::Instance::new").entered();
+            let span =
+                tracing::span!(tracing::Level::TRACE, "WebAssembly::Instance::new").entered();
             WebAssembly::Instance::new(&self.inner, &imports_object)
                 .map_err(|e| InstantiationError::Other(anyhow!("failed to instantiate: {:?}", e)))?
         };

crates/wasmtime-backend/Cargo.toml

@@ -18,3 +18,4 @@ multimap = "0.8.3"
 paste = "1.0.13"
 anyhow = "1.0.71"
 log = "0.4.19"
+tracing = "0.1.37"

crates/wasmtime-backend/src/function.rs

@@ -74,6 +74,7 @@ impl HostFunction<WasmtimeWasmBackend> for WasmtimeFunction {
                          args: &[wasmtime::Val],
                          results_out: &mut [wasmtime::Val]|
               -> Result<(), anyhow::Error> {
+            let _span = tracing::trace_span!("calling import function").entered();
             let caller = WasmtimeImportCallContext { inner: caller };
             let args = process_func_args(args).map_err(|e| anyhow!(e))?;
             let results = func(caller, &args);
@@ -103,6 +104,7 @@ impl ExportFunction<WasmtimeWasmBackend> for WasmtimeFunction {
         fn_ty_to_sig(&ty)
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn call<'c>(
         &self,
         store: &mut impl AsContextMut<WasmtimeWasmBackend>,

crates/wasmtime-backend/src/memory.rs

@@ -76,6 +76,7 @@ impl it_memory_traits::MemoryReadable<DelayedContextLifetime<WasmtimeWasmBackend
         value
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn read_vec(&self, store: &mut WasmtimeContextMut<'_>, offset: u32, size: u32) -> Vec<u8> {
         let mut value = vec![0u8; size as usize];
         self.memory

crates/wasmtime-backend/src/module.rs

@@ -31,6 +31,7 @@ pub struct WasmtimeModule {
 }
 
 impl Module<WasmtimeWasmBackend> for WasmtimeModule {
+    #[tracing::instrument(level = "trace", skip_all)]
     fn new(store: &mut WasmtimeStore, wasm: &[u8]) -> ModuleCreationResult<Self> {
         let module = wasmtime::Module::new(store.inner.engine(), wasm)
             .map_err(ModuleCreationError::FailedToCompileWasm)?;
@@ -44,6 +45,7 @@ impl Module<WasmtimeWasmBackend> for WasmtimeModule {
         })
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn custom_sections(&self, name: &str) -> &[Vec<u8>] {
         self.custom_sections
             .get_vec(name)
@@ -51,6 +53,7 @@ impl Module<WasmtimeWasmBackend> for WasmtimeModule {
             .unwrap_or_default()
     }
 
+    #[tracing::instrument(level = "trace", skip_all)]
     fn instantiate(
         &self,
         store: &mut WasmtimeStore,

marine-js/src/api.rs

@@ -150,7 +150,7 @@ pub fn register_module(
     modules: js_sys::Object,
     log_fn: js_sys::Function,
 ) -> Result<(), JsError> {
-    let _span = tracing::trace_span!( "register_module").entered();
+    let _span = tracing::trace_span!("register_module").entered();
     let mut config: ApiServiceConfig = serde_wasm_bindgen::from_value(config)?;
     let modules = extract_modules(modules)?;
 
@@ -204,7 +204,12 @@ pub fn call_module(
     args: &str,
     call_parameters: JsValue,
 ) -> Result<String, JsError> {
-    let _span = tracing::trace_span!( "call_module", module_name = module_name, function_name = function_name).entered();
+    let _span = tracing::trace_span!(
+        "call_module",
+        module_name = module_name,
+        function_name = function_name
+    )
+    .entered();
     let call_parameters = serde_wasm_bindgen::from_value(call_parameters)?;
 
     MARINE.with(|marine| {

marine-js/src/lib.rs

@@ -31,15 +31,13 @@ fn main() {
     init_tracing();
 }
 
-
 #[allow(dead_code)]
 pub fn init_tracing() {
     let config = tracing_wasm::WASMLayerConfigBuilder::new()
-            .set_max_level(tracing::Level::TRACE)
-            .set_report_logs_in_timings(true)
-            .set_console_config(tracing_wasm::ConsoleConfig::ReportWithoutConsoleColor)
-            .build();
+        .set_max_level(tracing::Level::TRACE)
+        .set_report_logs_in_timings(true)
+        .set_console_config(tracing_wasm::ConsoleConfig::ReportWithoutConsoleColor)
+        .build();
 
     tracing_wasm::set_as_global_default_with_config(config)
 }
-

marine/src/marine.rs

@@ -268,6 +268,7 @@ impl<WB: WasmBackend> Marine<WB> {
 // This API is intended for testing purposes (mostly in Marine REPL)
 #[cfg(feature = "raw-module-api")]
 impl<WB: WasmBackend> Marine<WB> {
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn load_module<C, S>(
         &mut self,
         name: S,

marine/src/module_loading/mod.rs

@@ -21,6 +21,7 @@ use std::collections::HashMap;
 use std::path::PathBuf;
 
 /// Loads modules from a directory at a given path. Non-recursive, ignores subdirectories.
+#[tracing::instrument(level = "trace", skip_all)]
 pub(crate) fn load_modules_from_fs(
     modules: &HashMap<String, PathBuf>,
 ) -> MarineResult<HashMap<String, Vec<u8>>> {