Performance issue related to increment operation in nested loops

[ShuyaoJiang]

Summary

Hi, I ran the attached case (C program, compiled to Wasm by Emscripten) in different Wasm runtimes, and found abnormal performance in Wasmtime compared with other runtimes. The execution time of this case (time interval from the start to the end of the execution of Wasm bytecode running command) on different runtimes is as follows:

• Wasmtime: 129ms
• WasmEdge (AOT): 15ms
• WAMR (AOT): 11ms

We found that in most other test cases, Wasmtime can achieve similar performance (1-2x) with the other two runtimes. However, in this case, Wasmtime is about 10x slower than the other two runtimes.

Emscripten

• emcc (Emscripten gcc/clang-like replacement + linker emulating GNU ld) 3.1.49 (04a0cad4d4c9f5d62876821274d78cd0a52427af) clang version 18.0.0 (https://github.com/llvm/llvm-project 269685545e439ad050b67740533c59f965cae955) Target: wasm32-unknown-emscripten Thread model: posix

Wasm Runtime Version

• Wasmtime: cli 15.0.0
• WasmEdge: 0.13.5
• WAMR: 1.2.3

Hardware & OS

• CPU: Intel(R) Xeon(R) E5-2686 v4 CPU @ 2.30GHz
• Memory: 16GB
• OS: Ubuntu 20.04.6 LTS

Additional details

The attached source program is synthesized by a Csmith seed and a code snippet from another program. The inserted code snippet is on lines 2386-2388 of the source program, which is an increment operation in nested loops. So, we think that this abnormal performance may be caused by this operation. Could you please check this situation? Thank you!

1702317926850.zip

[tschneidereit]

Hi @ShuyaoJiang, thank you for filing this and the other performance issues, much appreciated!

Would it be possible to also share (for this and the other issues you filed) the exact commands you used to compile the code, and also to execute the resulting .wasm file in all of the runtimes? That'd greatly help us in investigating what's going on.

[ShuyaoJiang]

Hi, here are the commands I used:

Compile

• Compile C to Wasm

  emcc -O2 -s WASM=1 -s TOTAL_MEMORY=512MB -I/home/ubuntu/csmith/include <C_PROGRAM> -o <WASM_TARGET>

• Build AOT targets for WasmEdge and WAMR

  /home/ubuntu/.wasmedge/bin/wasmedgec <WASM_TARGET> <WASMEDGE_AOT_TARGET(.wasm)>
  /home/ubuntu/wasm-micro-runtime/wamr-compiler/build/wamrc -o <WAMR_AOT_TARGET(.aot)> <WASM_TARGET>

Execute .wasm file (the execution time is collected in this phase)

• Wasmtime

  /home/ubuntu/.wasmtime/bin/wasmtime <WASM_TARGET>

• Wasmer

  /home/ubuntu/.wasmer/bin/wasmer run <WASM_TARGET>

• WasmEdge (AOT)

  /home/ubuntu/.wasmedge/bin/wasmedge <WASMEDGE_AOT_TARGET(.wasm)>

• WAMR (AOT)

  /home/ubuntu/wasm-micro-runtime/product-mini/platforms/linux/build/iwasm <WAMR_AOT_TARGET(.aot)> <WASM_TARGET>

[fitzgen]

This is measuring compilation time as well, you can separate the phases via

$ wasmtime compile foo.wasm
$ wasmtime run --allow-precompiled foo.cwasm

When you separate the compilation and execution phases are you still seeing Wasmtime as 10x slower?

[alexcrichton]

Ok I've dug into this in the same manner as https://github.com/bytecodealliance/wasmtime/issues/7732#issuecomment-1909132554 and I've at least locally confirmed that v8 takes ~2ms to execute this file and Wasmtime takes ~350us. In that sense I suspect that the 100ms+ times reported in the OP were probably including the compilation time for the module.

I'm hesitant to go ahead and close this to ensure you can confirm that when separating out the compilation phase you get expected timings, however.