Is there a way to get a detailed tracing/profiling from a linker?

[mere-human]

Problem: Linking an optimized wasm build takes a lot of time for my project.
I'd like to know if there's a way to get a detailed info.

I've tried some things such as building with EMCC_DEBUG=1 and I see that the block "wasm_opt" took most of the time.
I know that there could be problems with the project such as unused code.
But figuring out what exactly takes too long (like a specific static library or an object file) would be good.
Or a more fine-grained logging from wasm-opt.

Can anybody advise on that, please?

[sbc100]

A better way then EMCC_DEBUG is to use EMPROFILE=1 and EMPROFILE=2.

EMPROFILE=2 gives you summary information on stdout.

EMPROFILE=1 generates and html page with much more detailed profiling information which you can view interactively.

See https://emscripten.org/docs/optimizing/Profiling-Toolchain.html. (I notice that we still need to document EMPROFILE=2 there).

[sbc100]

EMCC_DEBUG can be bad because it also slows things down in some places by avoiding parallelism.

[mere-human]

@sbc100 Thanks! EMPROFILE=1 shows a very useful graph. EMPROFILE=2 writes useful info too.
However, it still lacks granularity. Both wasm_opt and binaryen took most of the time without much details.
Is there an existing way to see separate "phases" of those passes?

profiler:INFO:   block "link" took 3.578 seconds
profiler:INFO:   start block "post link"
profiler:INFO:     start block "emscript"
profiler:INFO:       start block "get_metadata"
profiler:INFO:       block "get_metadata" took 10.685 seconds
profiler:INFO:       start block "compile_javascript"
profiler:INFO:       block "compile_javascript" took 0.255 seconds
profiler:INFO:     block "emscript" took 11.108 seconds
profiler:INFO:     start block "binaryen"
profiler:INFO:       start block "wasm_opt"
profiler:INFO:       block "wasm_opt" took 174.496 seconds
profiler:INFO:       start block "use_unsigned_pointers_in_js"
profiler:INFO:       block "use_unsigned_pointers_in_js" took 0.972 seconds
profiler:INFO:       start block "minify_wasm"
profiler:INFO:       block "minify_wasm" took 1.019 seconds
profiler:INFO:     block "binaryen" took 176.487 seconds
profiler:INFO:     start block "final emitting"
profiler:INFO:     block "final emitting" took 0.754 seconds
profiler:INFO:   block "post link" took 188.349 seconds
profiler:INFO: block "main" took 192.053 seconds

[sbc100]

It looks like its pretty much all wasm-opt. (the binaryen block includes the wasm-opt block which is why it appears to take 176 seconds).

Is this a regression or was it always this slow?

How big is the original wasm binary that wasm-ld outputs? The fact that get_metadata makes me this it much be fairly large. Can you share the full link command line along with the size of the wasm-ld output (you can get this by building with EMCC_DEBUG).

[mere-human]

Is this a regression or was it always this slow?

This particular target usually took ~2.5m to build but then the time increased to more than ~3.5m. I reported that in #21521
We can continue the discussion there.

How big is the original wasm binary that wasm-ld outputs?

I'll provide that info later in the linked issue. Also, does it make sense to check with BINARYEN_PASS_DEBUG=1?
Thanks!

[sbc100]

Lets close this issue then and continue to discuss the regression in #21521