wasm files are very slow to load (C# PDK, Rust SDK)

[Somfic]

Hi!

New to WASM but excited to start. I am creating a plugin system for my application that’s written in Rust. I wrote a test plugin in C# and compiled it to a wasm file (~25mb for 1 import & 1 export). When I load the compiled wasm in my Rust application it takes ~45 seconds to load the wasm (M1 MacBook). Am I doing something wrong or is this expected performance?

C# plugin code:

public static class Plugin
{
	static void Log(string text)
	{
		using var block = Extism.Pdk.Allocate(text);
		wasm_Log(block.Offset);
	}

	[DllImport("extism", EntryPoint = "log")]
	static extern ulong wasm_Log(ulong offset);

	[UnmanagedCallersOnly(EntryPoint = "on_start")]
	static int OnStart()
	{
		Log("Hello from C#");
		return 0;
	}
}

Rust code:

#[derive(Debug)]
struct AppHandle {
    logs: Vec<String>,
}

impl AppHandle {
    pub fn new() -> Self {
        AppHandle { logs: vec![] }
    }

    pub fn log(&mut self, text: impl Into<String>) {
        self.logs.push(text.into());
    }
}

struct PluginManager {
    plugin_data: UserData<AppHandle>,
}

impl PluginManager {
	pub fn new(app_handle: AppHandle) -> Self {
        PluginManager {
            plugin_data: UserData::new(app_handle),
        }
    }

	fn load_plugin_from_file(&self, path: impl AsRef<std::path::Path>) -> Result<Plugin> {
	    let wasm = Wasm::file(path);
 	   self.load_plugin_from_wasm(wasm)
	}

	fn load_plugin_from_wasm(&self, wasm: Wasm) -> Result<Plugin> {
	    let manifest = Manifest::new([wasm]);
 	   PluginBuilder::new(manifest)
  	      .with_wasi(true)
  	      .with_function("log", [PTR], [PTR], self.plugin_data.clone(), log)
  	      .build()
   	    .context("Could not build plugin")
	}
}

My test case that loads the wasm generated by the plugin takes ~45 seconds to complete.

let path = "src/plugins/test.wasm";
let app_handle = AppHandle::new();
let plugin_manager = PluginManager::new(app_handle);

let mut plugin = plugin_manager.load_plugin_from_file(path)?; // This takes 45 seconds

I feel like something is not right. Is my compiled plugin bloated by C#? count_vowels.wasm is 1.7mb and is around the same complexity, but loads <1 sec.

[mhmd-azeez]

Hello @Somfic,

thanks for reporting the issue. I was able to reproduce it:

use extism::*;

host_fn!(log(userData: (), line: String) -> i64 {
  println!("log: {}", line);
  return Ok(0);
});

fn main() {
 // let file = Wasm::file("D:\\x\\dotnet\\readmeapp\\bin\\Debug\\net8.0\\wasi-wasm\\AppBundle\\readmeapp.wasm");
 let file = Wasm::file("D:\\x\\dotnet\\readmeapp\\bin\\Release\\net8.0\\wasi-wasm\\AppBundle\\readmeapp.wasm");
  let manifest = Manifest::new([file]);

  let x = UserData::new(());

  println!("{}: loading plugin", chrono::Utc::now());

  let plugin =  PluginBuilder::new(manifest)
    .with_wasi(true)
    .with_function("log", [PTR], [PTR], x, |plugin, inputs, outputs, user_data| {
      log(plugin, inputs, outputs, user_data)
    })
    .build();

    println!("{}: done", chrono::Utc::now());
}

This is the output:

2024-05-07 10:24:09.336664200 UTC: loading plugin
2024-05-07 10:24:21.305236100 UTC: done

This is not normal, I will take a deeper look

[mhmd-azeez]

A minimal repro:

use extism::*;

fn main() {
    let file = Wasm::file(
        "D:\\x\\dotnet\\readmeapp\\bin\\Release\\net8.0\\wasi-wasm\\AppBundle\\readmeapp.wasm",
    );
    
    let manifest = Manifest::new([file]);

    println!("{}: loading plugin", chrono::Utc::now());

    let _plugin = Plugin::new(manifest, [], true);

    println!("{}: done", chrono::Utc::now());
}

namespace MyPlugin;
public static class Plugin
{
    static void Main()
    {
        
    }
}

wazero: 406ms

PS D:\x\dotnet\readmeapp> dotnet publish
PS D:\x\dotnet\readmeapp> Measure-Command { extism call .\bin\Release\net8.0\wasi-wasm\AppBundle\readmeapp.wasm _start --wasi }

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 0
Milliseconds      : 406
Ticks             : 4068725
TotalDays         : 4.7091724537037E-06
TotalHours        : 0.000113020138888889
TotalMinutes      : 0.00678120833333333
TotalSeconds      : 0.4068725
TotalMilliseconds : 406.8725

Rust: ~12 seconds

PS D:\x\rust\rust-host> cargo run
warning: unused manifest key: depdendencies
   Compiling rust-host v0.1.0 (D:\x\rust\rust-host)
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 2.26s
     Running `target\debug\rust-host.exe`
2024-05-07 13:54:05.870944900 UTC: loading plugin
2024-05-07 13:54:17.159347400 UTC: done

cargo.toml

[package]
name = "rust-host"
version = "0.1.0"
edition = "2021"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[depdendencies]

[dependencies]
chrono = "0.4.38"
extism = "1.2.0"

compiled wasm:

repro.zip

[mhmd-azeez]

cc @zshipko

[zshipko]

Rust: ~12 seconds

@mhmd-azeez how does cargo run --release compare?

[mhmd-azeez]

@zshipko 2 notes:

1. subsequent runs are much faster, guessing it's the caching layer doing its job:

PS D:\x\rust\rust-host> cargo run
warning: unused manifest key: depdendencies
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.17s
     Running `target\debug\rust-host.exe`
2024-05-07 14:00:31.754239900 UTC: loading plugin
2024-05-07 14:00:44.102130 UTC: done
PS D:\x\rust\rust-host> cargo run
warning: unused manifest key: depdendencies
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.18s
     Running `target\debug\rust-host.exe`
2024-05-07 14:00:46.274649600 UTC: loading plugin
2024-05-07 14:00:46.529963 UTC: done

2. Release is faster, but still slower than wazero:

PS D:\x\rust\rust-host> cargo run --release  
warning: unused manifest key: depdendencies
    Finished `release` profile [optimized] target(s) in 0.19s
     Running `target\release\rust-host.exe`
2024-05-07 14:05:57.543549900 UTC: loading plugin
2024-05-07 14:05:58.283204300 UTC: done

[Somfic]

running with —release brings my loading time from ~45sec to ~200ms

[nilslice]

Going to close this as completed -- feel free to re-open if there are any further issues related to load time of a module though :)