Scenario with very slow function execution in Wasmer on Windows compared to other runtimes and a native app

[dsherret]

Describe the bug

Usually wasmer is pretty quick, but I have a scenario where it's way way slower than browsers and a native rust app.

• wasmer 1.0.2 (cranelift)
• rustc 1.51.0 (2fd73fabe 2021-03-23)
• x86_64
• Edit: Windows 10 (19042.928) -- I haven't been able to reproduce on linux or mac.

Steps to reproduce

Reproduction steps available in https://github.com/dsherret/slow-wasm-example

Expected behavior

Would at least expect it to execute somewhere close to chrome (I would hope it would be close to wasmtime though).

Actual behavior

On my machine:

• Native - ~700ms
• Wasmer (cranelift) - 145s
• Wasmtime - 711ms
• Chrome - 5s
• Firefox - 705ms

This may be because the code is doing many allocations via bumpalo, but usually it's pretty quick...

[k-nasa]

I couldn't reproduce it in my environment...

Enviroment

❯ echo "`wasmer -V` | `rustc -V` | `uname -m`"
wasmer 1.0.2 | rustc 1.53.0-nightly (42816d61e 2021-04-24) | x86_64

Results

• native 667ms
• wasmtime 655ms
• wasmer 969ms
• chorme 1539ms
• firefox 686ms

native

~/lab/oss/sandbox/slow-wasm-example/native-app main*
❯ cargo run --release
    Finished release [optimized] target(s) in 0.01s
     Running `target/release/native-app`
1317605
Finished in 667ms...

wasmtime

~/lab/oss/sandbox/slow-wasm-example/wasmtime-app main*
❯ cargo run --release
    Finished release [optimized] target(s) in 0.08s
     Running `target/release/wasmtime-app`
Finished in 655ms...
Result: 1317605

wasmer

~/lab/oss/sandbox/slow-wasm-example/wasmer-app main*
❯ cargo run --release
    Finished release [optimized] target(s) in 0.07s
     Running `target/release/app`
Starting...
Finished in 969ms...
Result: I32(1317605)

Chrome

Firefox

[dsherret]

@k-nasa interesting! Maybe it only occurs on Windows (I will try out on other OS later). I'm on Windows 10 (19042.928)

[dsherret]

Yes, it only seems to occur on windows. I just tried on linux, mac, and two different windows machines. I've updated the description and title.

[k-nasa]

I want to try this problem, but I don't have windows machine...

[syrusakbary]

I believe the latest PR refactoring traps (#2216) and Cranelift fix (#2224) will fix the issue. Although we need to merge #2250 (in progress) #2272 (in progress) first.

I'll keep the issue updated with the progress!

[ptitSeb]

I reproduce the issue, even with current wasmer codebase.

I made some profiling, and it seems the cause is an excessive amount of memcpy beeing called. Mostly from core::intrinsics::copy_nonoverlapping<u8>
Those calls seems to be done from the JIT'd code for the most part, with memory_grow beeing the culprit

[syrusakbary]

I believe this might be causing the issue:
https://github.com/wasmerio/wasmer/blob/master/lib/api/src/sys/tunables.rs#L53-L68

[dsherret]

Thanks a lot! I can confirm it is fixed and super fast now in 2.1.