chore: add more logging

runtime/src/memory.rs

@@ -31,6 +31,7 @@ impl PluginMemory {
     }
 
     pub(crate) fn store_u8(&mut self, offs: usize, data: u8) -> Result<(), MemoryAccessError> {
+        trace!("store_u8: {data:x} at offset {offs}");
         if offs >= self.size() {
             // This should raise MemoryAccessError
             let buf = &mut [0];
@@ -43,6 +44,7 @@ impl PluginMemory {
 
     /// Read from memory
     pub(crate) fn load_u8(&self, offs: usize) -> Result<u8, MemoryAccessError> {
+        trace!("load_u8: offset {offs}");
         if offs >= self.size() {
             // This should raise MemoryAccessError
             let buf = &mut [0];
@@ -53,6 +55,7 @@ impl PluginMemory {
     }
 
     pub(crate) fn store_u32(&mut self, offs: usize, data: u32) -> Result<(), MemoryAccessError> {
+        trace!("store_u32: {data:x} at offset {offs}");
         let handle = MemoryBlock {
             offset: offs,
             length: 4,
@@ -63,6 +66,7 @@ impl PluginMemory {
 
     /// Read from memory
     pub(crate) fn load_u32(&self, offs: usize) -> Result<u32, MemoryAccessError> {
+        trace!("load_u32: offset {offs}");
         let mut buf = [0; 4];
 
         let handle = MemoryBlock {
@@ -74,6 +78,7 @@ impl PluginMemory {
     }
 
     pub(crate) fn store_u64(&mut self, offs: usize, data: u64) -> Result<(), MemoryAccessError> {
+        trace!("store_u64: {data:x} at offset {offs}");
         let handle = MemoryBlock {
             offset: offs,
             length: 8,
@@ -83,6 +88,7 @@ impl PluginMemory {
     }
 
     pub(crate) fn load_u64(&self, offs: usize) -> Result<u64, MemoryAccessError> {
+        trace!("load_u64: offset {offs}");
         let mut buf = [0; 8];
         let handle = MemoryBlock {
             offset: offs,

runtime/src/plugin.rs

@@ -152,6 +152,7 @@ impl Plugin {
 
     /// Set `last_error` field
     pub fn set_error(&mut self, e: impl std::fmt::Debug) {
+        debug!("Set error: {:?}", e);
         let x = format!("{:?}", e).into_bytes();
         let x = if x[0] == b'"' && x[x.len() - 1] == b'"' {
             x[1..x.len() - 1].to_vec()

runtime/src/plugin_ref.rs

@@ -2,12 +2,17 @@ use crate::*;
 
 // PluginRef is used to access a plugin from the global plugin registry
 pub struct PluginRef<'a> {
+    pub id: PluginIndex,
     pub plugins: std::sync::MutexGuard<'a, Vec<Plugin>>,
     plugin: *mut Plugin,
 }
 
 impl<'a> PluginRef<'a> {
     pub fn init(mut self) -> Self {
+        trace!(
+            "Resetting memory and clearing error message for plugin {}",
+            self.id,
+        );
         // Initialize
         self.as_mut().clear_error();
         self.as_mut().memory.reset();
@@ -17,20 +22,26 @@ impl<'a> PluginRef<'a> {
     /// # Safety
     ///
     /// This function is used to access the static `PLUGINS` registry
-    pub unsafe fn new(plugin: PluginIndex) -> Self {
+    pub unsafe fn new(plugin_id: PluginIndex) -> Self {
         let mut plugins = match PLUGINS.lock() {
             Ok(p) => p,
             Err(e) => e.into_inner(),
         };
 
-        if plugin < 0 || plugin as usize >= plugins.len() {
+        trace!("Loading plugin {plugin_id}");
+
+        if plugin_id < 0 || plugin_id as usize >= plugins.len() {
             drop(plugins);
-            panic!("Invalid PluginIndex {plugin}");
+            panic!("Invalid PluginIndex {plugin_id}");
         }
 
-        let plugin = plugins.get_unchecked_mut(plugin as usize) as *mut _;
+        let plugin = plugins.get_unchecked_mut(plugin_id as usize) as *mut _;
 
-        PluginRef { plugins, plugin }
+        PluginRef {
+            id: plugin_id,
+            plugins,
+            plugin,
+        }
     }
 }
 
@@ -48,6 +59,7 @@ impl<'a> AsMut<Plugin> for PluginRef<'a> {
 
 impl<'a> Drop for PluginRef<'a> {
     fn drop(&mut self) {
+        trace!("Dropping plugin {}", self.id);
         // Cleanup?
     }
 }

runtime/src/sdk.rs

@@ -11,6 +11,10 @@ pub unsafe extern "C" fn extism_plugin_register(
     wasm_size: Size,
     with_wasi: bool,
 ) -> PluginIndex {
+    trace!(
+        "Call to extism_plugin_register with wasm pointer {:?}",
+        wasm
+    );
     let data = std::slice::from_raw_parts(wasm, wasm_size as usize);
     let plugin = match Plugin::new(data, with_wasi) {
         Ok(x) => x,
@@ -40,6 +44,12 @@ pub unsafe extern "C" fn extism_plugin_config(
 ) -> bool {
     let mut plugin = PluginRef::new(plugin);
 
+    trace!(
+        "Call to extism_plugin_config for {} with json pointer {:?}",
+        plugin.id,
+        json
+    );
+
     let data = std::slice::from_raw_parts(json, json_size as usize);
     let json: std::collections::BTreeMap<String, String> = match serde_json::from_slice(data) {
         Ok(x) => x,
@@ -53,6 +63,7 @@ pub unsafe extern "C" fn extism_plugin_config(
     let wasi = &mut plugin.memory.store.data_mut().wasi;
     let config = &mut plugin.manifest.as_mut().config;
     for (k, v) in json.into_iter() {
+        trace!("Config, adding {k}");
         let _ = wasi.push_env(&k, &v);
         config.insert(k, v);
     }
@@ -131,22 +142,31 @@ pub unsafe extern "C" fn extism_call(
 
 #[no_mangle]
 pub unsafe extern "C" fn extism_error(plugin: PluginIndex) -> *const c_char {
+    trace!("Call to extism_error for plugin {plugin}");
     let plugin = PluginRef::new(plugin);
     match &plugin.as_ref().last_error {
         Some(e) => e.as_ptr() as *const _,
-        None => std::ptr::null(),
+        None => {
+            trace!("Error is NULL");
+            std::ptr::null()
+        }
     }
 }
 
 #[no_mangle]
 pub unsafe extern "C" fn extism_output_length(plugin: PluginIndex) -> Size {
+    trace!("Call to extism_output_length for plugin {plugin}");
     let plugin = PluginRef::new(plugin);
 
-    plugin.as_ref().memory.store.data().output_length as Size
+    let len = plugin.as_ref().memory.store.data().output_length as Size;
+    trace!("Output length: {len}");
+    len
 }
 
 #[no_mangle]
 pub unsafe extern "C" fn extism_output_get(plugin: PluginIndex, buf: *mut u8, len: Size) {
+    trace!("Call to extism_output_get for plugin {plugin}, length {len}");
+
     let plugin = PluginRef::new(plugin);
     let data = plugin.as_ref().memory.store.data();
 
@@ -221,7 +241,7 @@ pub unsafe extern "C" fn extism_log_file(
     let config = match Config::builder()
         .appender(Appender::builder().build("logfile", logfile))
         .logger(Logger::builder().appender("logfile").build("extism", level))
-        .build(Root::builder().appender("logfile").build(LevelFilter::Off))
+        .build(Root::builder().build(LevelFilter::Off))
     {
         Ok(x) => x,
         Err(_) => {