Repository navigation
tiered WebAssembly compilation broken #36616
Description
Activity
Attaching a large WASM file.
clang-11.wasm.zipIs this a bug in V8 or in Node.js?
@targos
This is a Node.js bug. If there's anything registered with the event loop, it works as expected. It works in the interactive mode. Also works in non-interactive mode when there is a pending timer (setTimeout).See Additional information in the bug report for some additional info.
There are further oddities related to
WebAssembly.compile. Piggybacking on the existing issue since these shortcomings are closely related.const fs = require('fs'); // Workaround #36616 const timerId = setInterval(() => {}, 60000); process.on('exit', () => { console.log(new Date(), 'process exit'); }); process.on('beforeExit', () => { console.log(new Date(), 'process beforeExit'); }); WebAssembly.compile(fs.readFileSync('BIG.wasm')).then(() => { console.log(new Date(), 'compiled (liftoff)'); clearInterval(timerId); if (process.env.EXPLICIT_EXIT) process.exit(); }); console.log(new Date(), 'WebAssembly.compile()');
Without
EXPLICIT_EXITPending
WebAssembly.compileshould keep event loop running. Once the promise is resolved, event loop should stop (assuming that there's no other ongoing activity).% time ./out/Release/node bug.js 2021-01-11T12:39:00.828Z WebAssembly.compile() 2021-01-11T12:39:01.369Z compiled (liftoff) 2021-01-11T12:39:12.717Z process beforeExit 2021-01-11T12:39:12.718Z process exit ./out/Release/node bug.js 45.90s user 1.17s system 389% cpu 12.092 total
Event loop keeps going for another ~11 seconds until the module is fully optimised.
With
EXPLICIT_EXITNode should terminate promptly when
process.exit()is called.% time EXPLICIT_EXIT=1 ./out/Release/node bug.js 2021-01-11T12:43:53.213Z WebAssembly.compile() 2021-01-11T12:43:53.761Z compiled (liftoff) 2021-01-11T12:43:53.762Z process exit EXPLICIT_EXIT=1 ./out/Release/node bug.js 45.71s user 1.14s system 395% cpu 11.840 total
It took ~11 seconds for
process.exit()to be honoured.Reacted by Nate Moore- changed the title
[-]tiered WebAssembly compilation broken (node TaskQueue problem)[/-][+]tiered WebAssembly compilation broken[/+]on Jan 11, 2021 I'm working on esbuild and have also encountered this issue, and I believe swc has as well. I think I have a hacky workaround. I'm describing the workaround here in case it's useful to anyone:
-
Compile the following C code into a shared library for each platform you want to support:
#include <unistd.h> void* napi_register_module_v1(void* a, void* b) { _exit(0); }
-
Include all compiled shared libraries in your module, then invoke the shared library for the current platform as a native module:
process.on('exit', () => require('./exit0-darwin.node'))
Manually compiling the module like this avoids the complexity of
node-gypand should make the shared libraries really small, so it should be reasonable to just include precompiled versions for each supported platform in your package. FWIW.Reacted by Zxilly-
Sorry, I don't know much about the different queues, especially in node. It looks wrong though to have the main task blocked if there is foreground work to be executed. That work can indeed be triggered by background compilation, in which case the main thread should pick it up as soon as possible.
@gahaas anything to add here?
It seems to me that
BlockingDrainshould only execute a single task, not all tasks. As far as I understand, the purpose ofDrainTaskis to make the main thread help the worker threads while it does not have any work, not to do all the background work. The loop condition should be(per_isolate->FlushForegroundTasksInternal() || Isolate::HasPendingBackgroundTasks()), so that still all background work is done that could potentially spawn foreground work.Regarding the issue explained here #36616 (comment) where the node process does not terminate until WASM optimization has fully completed:
Is the issue that the WASM compilation task should be aborted instead of completed? I don't know v8 or node internals so I don't know if that theory makes sense or not. Is there a way that tasks are classified as either necessary or unnecessary to complete, so that unnecessary ones are aborted on
process.exit()?Or is the problem that
process.on('exit'handlers cannot be invoked as long as the event loop is blocked byBlockingDrain?I think the problem is still what I wrote in the comment above. V8 has foreground tasks and background tasks. Typically background tasks could be ignored completely, they just exist to make V8 faster. For example, the optimizing compiler can be executed on a background task, but if this task is not executed, then V8 can still execute the baseline code. Similarly the garbage collector can be executed on a background task, but if the background task is not executed, then V8 will just stop the main thread and do garbage collection on the main thread. This means also, that when all foreground tasks have finished and only background tasks are left, you can just terminate the node without any issue.
The only case where background tasks are important, and where node should wait for background tasks, is asynchronous compilation of WebAssembly modules. In that case the WebAssembly module gets compiled completely on background tasks, and the last background task will then spawn a foreground task to continue execution on the main thread. This means that if node terminates when no foreground task is available anymore, it would not wait for WebAssembly compilation to finish, and not would potentially not execute an important part of a script.
V8 introduced the API function
Isolate::HasPendingBackgroundTasks()to tell the embedder if there is background work that will spawn a foreground task or not. IfIsolate::HasPendingBackgroundTasks()returns false, then node can just terminate. But ifIsolate::HasPendingBackgroundTasks()returns true, node should also wait for background tasks to finish.Thank you for the detailed explanation. I was looking at the code to hopefully make a PR based on your recommendation.
Is the following scenario a potential risk? Again, I'm coming in blind so I don't know if this makes sense.
- 2x background tasks exist, one that will take 5 seconds and one that will take 0.1 seconds.
Isolate::HasPendingBackgroundTasksreturns true because the 0.1 second task must be completed. (the 5 second task is not important)- Main thread picks up the 5 second task instead of the 0.1 second task.
The main thread is stuck for 5 seconds executing work that is not strictly necessary. Is this possible? Is there a correct way to avoid it?
11 remaining items
I'm making progress.
I've tweaked
NodePlatform::DrainTasksto use this loop, and nowbeforeExitandexitare calling immediately.while(true) { while(per_isolate->FlushForegroundTasksInternal()) {} if(!per_isolate->HasPendingBackgroundTasks()) break; uv_sleep(10); // TODO replace with appropriate `Wait` for foreground task to be posted }However, the node process is still taking a while to exit because
Isolate::Dispose()is taking a long time.Line 93 in 8de858b
node/src/node_main_instance.cc
Line 124 in 8de858b
My informal testing is loading
@swc/wasmand synchronously invoking it 1000 times. Either@swc/wasmgenerates some resources or garbage that take a long time to cleanup, v8's WASM stuff generates resources that take a long time to dispose, orIsolate::Dispose()is still trying to flush all those background tasks. I'm not sure yet.Reacted by Niklas Mischkulnig and DanielI've tracked the slowness down to
OptimizingCompileDispatcher::Stop():node/deps/v8/src/compiler-dispatcher/optimizing-compile-dispatcher.cc
Lines 194 to 200 in 8de858b
I'm going to wait for an expert to reply because I suspect they can offer guidance which will be far more productive than me spinning my wheels in the interim.
I wonder if the issue in the
OptimizingCompileDispatcherwould be worth a separate issue, maybe even on the V8 bug tracker. For the problem with WebAssembly compilation we have a solution now, don't we?Attaching a large WASM file.
clang-11.wasm.zip@mejedi how was this file created? I think I'll need to recreate it if we're going to write automated tests for this bugfix.
In case @mejedi in not reachable, you could also try Solidity binaries which have the same problem, as mentioned above by @ekpyron.
You can build it by checking out https://github.com/ethereum/solidity/ and launching
./scripts/build_emscripten.sh, which will pull a docker image with all dependencies and compile it.Reacted by Andrew BradleyI wonder if the issue in the
OptimizingCompileDispatcherwould be worth a separate issue, maybe even on the V8 bug tracker. For the problem with WebAssembly compilation we have a solution now, don't we?To be honest, I'm not really sure. I haven't had a chance to figure out what
OptimizingCompileDispatcheris doing.I've modified node's logic elsewhere so that it does not wait for turbofan tasks to finish. But is
OptimizingCompileDispatcherwaiting for them anyway? I'm not sure.I've posted my work in progress here: cspotcode#1
The
OptimizingCompileDispatchermanages the optimization of JavaScript code. I guess in your benchmark you are executing some JavaScript code often enough so that it gets hot, and V8 decides to optimize it. But then optimization is still happening when the benchmark wants to exit. The background work of theOptimizingCompileDispatcherwould not setIsolate::HasPendingBackgroundTasks()to true, so the node platform would not have to wait for it.As you also wrote above, it's not node.js that is waiting for the
OptimizingCompileDispatcher, it is V8 itself. So if this is really something that needs to be fixed, it should be fixed in V8 and not in node.js. That's why I suggested to file a V8 bug.It looks like this may have actually been fixed? The first node release that doesn't have this problem is version 18.3.0:
Node version Time to run esbuild --versionwith WebAssembly in nodev14.21.1 3.27s v16.18.1 2.51s v18.0.0 1.89s v18.2.0 1.90s v18.3.0 0.32s ← The problem was fixed here v18.5.0 0.31s v18.12.1 0.31s I didn't see any relevant changes in node itself for that release other than V8 version bumps. So I searched back in V8's history from version 10.2.154 (the version of V8 that node v18.3.0 uses) and found this commit that seems relevant: dynamic tiering for WebAssembly was enabled by default. I'm guessing that was what fixed it.
It's still not as fast as it could be (with the
_exit(0)hack mentioned aboveesbuild --versiontakes 0.15s instead of 0.31s). But least node no longer takes multiple seconds to exit, which I'd consider good enough for me.Reacted by Dominic Elm and Nate Moore- added 2 commits that reference this issue
on Dec 7, 2022 - added a commit that references this issue
on Dec 7, 2022 - added a commit that references this issue
on Dec 15, 2022 Re: #36616 (comment) - yes, I do believe this is fixed in v18.x and newer. v16.x is almost EOL and won't get any big updates anymore so I'll go ahead and close this.
v16.0.0-pre (903998aced7dbb964ec7567c4b5765888d16b18d)Darwin DEU0917.local 19.6.0 Darwin Kernel Version 19.6.0: Thu Oct 29 22:56:45 PDT 2020; root:xnu-6153.141.2.2~1/RELEASE_X86_64 x86_64embed_helpers.cc/SpinEventLoopTrivia: V8 has two tiers of WASM compilation —
liftoffandturbofan. Liftoff produces unoptimised code and completes fast. Once it's done, the promise returned fromWebAssembly.compile(...)is resolved and the module is ready to run. In meantime, Turbofan continues in the background. It will transparently replace the compiled module code with an optimised version.Use
--trace-wasm-compilerflag to gain some visibility into the process.What steps will reproduce the bug?
Get a big WASM file (20MiB+). The following snippet assumes that the file is called
BIG.wasm:How often does it reproduce? Is there a required condition?
Reproduces always if there's nothing registered with the event loop.
What is the expected behavior?
WebAssembly module becomes available shortly while optimised compiler continues in the background.
Works as expected in interactive mode (
node --trace-wasm-compiler):What do you see instead?
WebAssembly module doesn't become available until optimising compiler completes. The startup is rather slow.
Additional information
Main thread is blocked in
node::WorkerThreadsTaskRunner::BlockingDrain, waiting for compiler task.BlockingDraindoesn't run the event loop. Apparently there's an assumption that tasks don't communicate with the main thread.That's wrong. WASM compiler notifies the main thread once baseline compilation is complete (see
AsyncCompileJob::CompilationStateCallback,CompilationEvent::kFinishedBaselineCompilationcase).The message goes through
WorkerThreadsTaskRunner::DelayedTaskScheduler::PostDelayedTask(node_platform.cc), callinguv_async_send. The later goes unnoticed sinceBlockingDraindoesn't run the event loop.