Add timing instrumentation

crates/plugin_runtime/README.md

@@ -10,7 +10,7 @@ Wasm plugins can be run through `wasmtime`, with supported for sandboxed system
 ## ABI
 The interface between the host Rust runtime ('Runtime') and plugins implemented in Wasm ('Plugin') is pretty simple.
 
-`Buffer` is a pair of two 4-byte (`u32`) fields:
+`Buffer` is a pair of two 4-byte (`u32`) fields, encoded as a single `u64`.
 
 ```
 struct Buffer {
@@ -21,7 +21,7 @@ struct Buffer {
 
 All functions that Plugin exports must have the following properties:
 
-- Have the signature `fn(ptr: u32, len: u32) -> u32`, where the return type is a pointer to a `Buffer`, and the arguments are the component parts of a `Buffer`.
+- Have the signature `fn(ptr: u64) -> u64`, where both the argument and return types are a `Buffer`:
 
     - The input `Buffer` will contain the input arguments serialized to `bincode`.
     - The output `Buffer` will contain the output arguments serialized to `bincode`.

crates/plugin_runtime/src/plugin.rs

@@ -69,8 +69,12 @@ impl PluginBuilder {
         dbg!("new plugin");
         let mut config = Config::default();
         config.async_support(true);
+        dbg!("Creating engine");
+        let start = std::time::Instant::now();
         let engine = Engine::new(&config)?;
+        dbg!(start.elapsed());
         let linker = Linker::new(&engine);
+        dbg!(start.elapsed());
 
         Ok(PluginBuilder {
             // host_functions: HashMap::new(),
@@ -306,6 +310,8 @@ impl Plugin {
 
         // create a store, note that we can't initialize the allocator,
         // because we can't grab the functions until initialized.
+        dbg!("Creating store");
+        let start = std::time::Instant::now();
         let mut store: Store<WasiCtxAlloc> = Store::new(
             &engine,
             WasiCtxAlloc {
@@ -313,12 +319,20 @@ impl Plugin {
                 alloc: None,
             },
         );
-        let module = Module::new(&engine, module)?;
-        dbg!("created store");
+        dbg!(start.elapsed());
 
+        let module = Module::new(&engine, module)?;
         // load the provided module into the asynchronous runtime
         linker.module_async(&mut store, "", &module).await?;
+        dbg!("Instantiating module");
+        let start = std::time::Instant::now();
         let instance = linker.instantiate_async(&mut store, &module).await?;
+        let end = dbg!(start.elapsed());
+
+        dbg!("Instantiating second module");
+        let start = std::time::Instant::now();
+        let instance2 = linker.instantiate_async(&mut store, &module).await?;
+        let end = dbg!(start.elapsed());
 
         // now that the module is initialized,
         // we can initialize the store's allocator

crates/zed/src/languages/language_plugin.rs

@@ -15,19 +15,16 @@ use future_wrap::*;
 pub async fn new_json(executor: Arc<Background>) -> Result<PluginLspAdapter> {
     let plugin = PluginBuilder::new_with_default_ctx()?
         .host_function_async("command", |command: String| async move {
-            // TODO: actual thing
             dbg!(&command);
+
+            // TODO: actual thing
             let mut args = command.split(' ');
             let command = args.next().unwrap();
-            dbg!("Running command");
+
+            dbg!("Running external command");
+
+            let start = std::time::Instant::now();
             let future = smol::process::Command::new(command).args(args).output();
-            dbg!("Awaiting command");
-
-            #[no_mangle]
-            fn heck_point() {
-                dbg!("command awaited");
-            }
-
             let future = future.wrap(|fut, cx| {
                 dbg!("Poll command!");
 
@@ -35,12 +32,9 @@ pub async fn new_json(executor: Arc<Background>) -> Result<PluginLspAdapter> {
                 res
             });
             let future = future.await;
-            heck_point();
-            dbg!("blocked on future");
-            future.log_err().map(|output| {
-                dbg!("done running command");
-                output.stdout
-            })
+            dbg!(start.elapsed());
+
+            future.log_err().map(|output| output.stdout)
         })?
         .init(include_bytes!("../../../../plugins/bin/json_language.wasm"))
         .await?;
@@ -129,16 +123,17 @@ impl LspAdapter for PluginLspAdapter {
         // let versions: Result<Option<String>> = call_block!(self, "fetch_latest_server_version", ());
         let runtime = self.runtime.clone();
         let function = self.fetch_latest_server_version;
-        async move {
-            let mut runtime = runtime.lock().await;
-            let versions: Result<Option<String>> =
-                runtime.call::<_, Option<String>>(&function, ()).await;
-            versions
-                .map_err(|e| anyhow!("{}", e))?
-                .ok_or_else(|| anyhow!("Could not fetch latest server version"))
-                .map(|v| Box::new(v) as Box<_>)
-        }
-        .boxed()
+        self.executor
+            .spawn(async move {
+                let mut runtime = runtime.lock().await;
+                let versions: Result<Option<String>> =
+                    runtime.call::<_, Option<String>>(&function, ()).await;
+                versions
+                    .map_err(|e| anyhow!("{}", e))?
+                    .ok_or_else(|| anyhow!("Could not fetch latest server version"))
+                    .map(|v| Box::new(v) as Box<_>)
+            })
+            .boxed()
     }
 
     fn fetch_server_binary(
@@ -150,29 +145,31 @@ impl LspAdapter for PluginLspAdapter {
         let version = *version.downcast::<String>().unwrap();
         let runtime = self.runtime.clone();
         let function = self.fetch_server_binary;
-        async move {
-            let mut runtime = runtime.lock().await;
-            let handle = runtime.attach_path(&container_dir)?;
-            let result: Result<PathBuf, String> =
-                runtime.call(&function, (container_dir, version)).await?;
-            runtime.remove_resource(handle)?;
-            result.map_err(|e| anyhow!("{}", e))
-        }
-        .boxed()
+        self.executor
+            .spawn(async move {
+                let mut runtime = runtime.lock().await;
+                let handle = runtime.attach_path(&container_dir)?;
+                let result: Result<PathBuf, String> =
+                    runtime.call(&function, (container_dir, version)).await?;
+                runtime.remove_resource(handle)?;
+                result.map_err(|e| anyhow!("{}", e))
+            })
+            .boxed()
     }
 
     fn cached_server_binary(&self, container_dir: PathBuf) -> BoxFuture<'static, Option<PathBuf>> {
         let runtime = self.runtime.clone();
         let function = self.cached_server_binary;
 
-        async move {
-            let mut runtime = runtime.lock().await;
-            let handle = runtime.attach_path(&container_dir).ok()?;
-            let result: Option<PathBuf> = runtime.call(&function, container_dir).await.ok()?;
-            runtime.remove_resource(handle).ok()?;
-            result
-        }
-        .boxed()
+        self.executor
+            .spawn(async move {
+                let mut runtime = runtime.lock().await;
+                let handle = runtime.attach_path(&container_dir).ok()?;
+                let result: Option<PathBuf> = runtime.call(&function, container_dir).await.ok()?;
+                runtime.remove_resource(handle).ok()?;
+                result
+            })
+            .boxed()
     }
 
     fn process_diagnostics(&self, _: &mut lsp::PublishDiagnosticsParams) {}