Investigate: dependency on `lto="fat"` and `codegen-units=1`

[Robbepop]

Currently wasmi_v1 is performing pretty well compared to the old wasmi on the following profile:

[profile.release]
lto = "fat"
codegen-units = 1

However, for the default profile which is

[profile.release]
lto = false
codegen-units = 16

We can see a slow down of factor x4.21 which is pretty terrible.

For more information and stats see this GitHub Gist.

We need to investigate the reasons for this particularly bad slowdown under default profile configuration.
Usually you can see performance differences in the range of 10-15% but not in the range of 400-500%.

The Rust source files implementing the wasmi_v1 engine can be found here:

• The entry points and orchestration of the wasmi_v1 engine:
  • Source (.rs)
• The instruction execution of the wasmi_v1 engine:
  • Source (.rs)

[ggwpez]

I'm currently looking into the same flags for Substrate paritytech/substrate#10608.
Please let me know if you find something beyond lto=fat and cu=1.

Your tiny_keccak test seems to produce results much faster than the 8hr of Substrate benchmarks 😆

[Robbepop]

Glad I am not alone on this.
So far I have used cargo-flamegraph to get some flamegraph data and try to make some sense out of the information it brought to me. There is just one strange thing that I currently cannot explain but maybe that's just lack of knowledge about the tool itself.

Please also keep me updated if you find something!

Your tiny_keccak test seems to produce results much faster than the 8hr of Substrate benchmarks laughing

How bad are the slowdowns for Substrate without those flags?

[ggwpez]

Glad I am not alone on this.
So far I have used cargo-flamegraph to get some flamegraph data and try to make some sense out of the information it brought to me.

Yes great! Maybe we can share some more knowledge about this, since I am new to profiling in rust.

How bad are the slowdowns for Substrate without those flags?

In Substrate it is the other way around, we currently do not run the benchmarks with any flags 🙈
Relative speedup for the balances pallet is documented here.

Also looking at other pallets; 100% speedup (2x) is the highest that I saw consistently.
But these are benchmarks of just one function, so not that much room for improvement I guess.

PS: paritytech/polkadot#4311 claims 200-400% ish.

[Robbepop]

PS: paritytech/polkadot#4311 claims 200-400% ish.

Well that's absolutely the same that we see in wasmi_v1 ...

Looking forward to your updates. 😅

[Robbepop]

Slowdown concerning configurations without codegen-units=1 might be (partially) affected by rust-lang/rust#46139.

[ggwpez]

One more thing: Did you try RUSTFLAGS='-C target-cpu=native' yet?
It is only possible to define as env variable, not in the Cargo.toml AFAIK.

[Robbepop]

One more thing: Did you try RUSTFLAGS='-C target-cpu=native' yet?
It is only possible to define as env variable, not in the Cargo.toml AFAIK.

I just tried it out but there was no signifiant performance difference. A few benchmarks even showed slightly worse performance.

[Robbepop]

Demonstrates how bad it really is:
https://gist.github.com/Robbepop/ffa340bdfc306856a98e21597091f6f0

[Robbepop]

@athei Also ran the benchmarks on a different CPU and using the stable Rust compiler version 1.58.

Corei9-9900k@5GHZ
rustc 1.58-stable

Results

Default Profile

compile_and_validate/v1        time: [7.7698 ms 7.7948 ms 7.8208 ms]
instantiate/v1                 time: [144.96 us 147.68 us 150.42 us]
execute/tiny_keccak/v1         time: [3.4168 ms 3.4222 ms 3.4277 ms]
execute/rev_complement/v1      time: [4.4750 ms 4.4810 ms 4.4869 ms]
execute/regex_redux/v1         time: [4.2505 ms 4.2580 ms 4.2659 ms]
execute/count_until/v1         time: [4.5702 ms 4.5844 ms 4.5991 ms]
execute/factorial_recursive/v1 time: [3.5012 us 3.5085 us 3.5164 us]
execute/factorial_optimized/v1 time: [1.7917 us 1.8038 us 1.8161 us]
execute/recursive_ok/v1        time: [865.95 us 870.12 us 874.17 us]
execute/recursive_trap/v1      time: [74.352 us 74.633 us 74.977 us]
execute/host_calls/v1          time: [103.87 us 104.21 us 104.60 us]

Custom Profile

compile_and_validate/v1        time: [5.7856 ms 5.8243 ms 5.8628 ms]
instantiate/v1                 time: [127.04 us 130.94 us 134.55 us]
execute/tiny_keccak/v1         time: [741.29 us 745.45 us 749.46 us]
execute/rev_complement/v1      time: [925.63 us 929.02 us 932.65 us]
execute/regex_redux/v1         time: [1.0749 ms 1.0759 ms 1.0770 ms]
execute/count_until/v1         time: [1.2899 ms 1.2915 ms 1.2933 ms]
execute/factorial_recursive/v1 time: [1.2258 us 1.2276 us 1.2297 us]
execute/factorial_optimized/v1 time: [568.03 ns 568.82 ns 569.64 ns]
execute/recursive_ok/v1        time: [349.49 us 350.52 us 351.57 us]
execute/recursive_trap/v1      time: [30.064 us 30.093 us 30.125 us]
execute/host_calls/v1          time: [46.170 us 46.236 us 46.316 us]

We see more or less the same slowdowns between both profiles.
In conclusion Rust compiler version used and target CPU does not matter too much here.

[Robbepop]

I tried to use custom package Cargo profiles for our Wasm coremark benchmarks between wasmi_v0, wasmi_v1, Wasm3 and Wasmtime that can be found here.

On this profile

[profile.release]
lto = "fat"
codegen-units = 1

wasm_v1 achieved a score of over 500 on my CPU whereas on

[profile.release]
lto = "fat"

[profile.release.package.wasim_v1]
codegen-units = 1

We achieved only a score of roughly 300 which is the same score we achieve with this profile configuration:

[profile.release]
lto = "fat"

So it is as if Cargo's package specific profile settings are simply not applied.

[Robbepop]

Some cargo flamegraph execution runs show some very strange graphs for the slow case.

The fast run shows a flamegraph as it is to be expected by the developer of the new wasmi engine (me).
The slow run shows strange artifacts in the graph such as Engine::execute_func in the head of all lines above the first Engine::execute_func stack. I am confused as to how this actually even exists since there is no way how Engine::execute_func could call itself recursively. It may be some optimization artifacts but then again we do not see this (as expected) in the fast run.

Slow

[profile.bench]
lto = false
codegen-units = 16

Fast

[profile.bench]
lto = "fat"
codegen-units = 1

[ggwpez]

In conclusion Rust compiler version used and target CPU does not matter too much here.

Thanks for the check!

So it is as if Cargo's package specific profile settings are simply not applied.

I wondered if cargo is actually pushing all the config flags on its dependencies or if they all use their own release profile.
Something like:

[profile.release.package."*"]
lto = "fat"
codegen-units = 1

Hopefully makes no difference.