René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"tiered WebAssembly compilation broken","articleBody":"* **Version**: `v16.0.0-pre (903998aced7dbb964ec7567c4b5765888d16b18d)` \r\n* **Platform**: `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_64`\r\n* **Subsystem**: `embed_helpers.cc/SpinEventLoop`\r\n\r\nTrivia: V8 has two tiers of WASM compilation — `liftoff` and `turbofan`. Liftoff produces unoptimised code and completes fast. Once it's done, the promise returned from `WebAssembly.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.\r\n\r\nUse `--trace-wasm-compiler` flag to gain some visibility into the process.\r\n\r\n### What steps will reproduce the bug?\r\n\r\nGet a big WASM file (20MiB+). The following snippet assumes that the file is called `BIG.wasm`:\r\n\r\n```js\r\nconst fs = require(\"fs\")\r\nconst data = fs.readFileSync(\"BIG.wasm\")\r\nWebAssembly.compile(data).then(()=>console.log(\"module ready\"))\r\n\r\n```\r\n\r\n### How often does it reproduce? Is there a required condition?\r\n\r\nReproduces always if there's nothing registered with the event loop.\r\n\r\n### What is the expected behavior?\r\n\r\nWebAssembly module becomes available shortly while optimised compiler continues in the background.\r\n\r\nWorks as expected in interactive mode (`node --trace-wasm-compiler`):\r\n\r\n```\r\nWelcome to Node.js v16.0.0-pre.\r\nType \".help\" for more information.\r\n> const fs = require(\"fs\")\r\nundefined\r\n> const data = fs.readFileSync(\"BIG.wasm\")\r\nundefined\r\n> WebAssembly.compile(data).then(()=>console.log(\"module ready\"))\r\n(1) Decoding module...\r\nPromise { \u003cpending> }\r\n(2) Prepare and start compile...\r\nExecuteCompilationUnits (task id 0)\r\nCompiling wasm function 21088 with liftoff\r\nExecuteCompilationUnits (task id 1)\r\nCompiling wasm function 29541 with liftoff\r\nExecuteCompilationUnits (task id 2)\r\nCompiling wasm function 39979 with liftoff\r\nExecuteCompilationUnits (task id 3)\r\nCompiling wasm function 791 with liftoff\r\nCompiling wasm function 654 with liftoff\r\nCompiling wasm function 27451 with liftoff\r\nCompiling wasm function 24648 with liftoff\r\n...\r\n(3b) Compilation finished\r\n(4) Finish module...\r\nCompiling wasm function 791 with turbofan\r\nmodule ready\r\nCompiling wasm function 654 with turbofan\r\nCompiling wasm function 27451 with turbofan\r\nCompiling wasm function 24648 with turbofan\r\nCompiling wasm function 27700 with turbofan\r\n...\r\n```\r\n\r\n### What do you see instead?\r\n\r\nWebAssembly module doesn't become available until optimising compiler completes. The startup is rather slow.\r\n\r\n```\r\n(1) Decoding module...\r\n(2) Prepare and start compile...\r\nExecuteCompilationUnits (task id 0)\r\nCompiling wasm function 21088 with liftoff\r\nExecuteCompilationUnits (task id 1)\r\nCompiling wasm function 29541 with liftoff\r\nExecuteCompilationUnits (task id 2)\r\nCompiling wasm function 39979 with liftoff\r\nExecuteCompilationUnits (task id 3)\r\nCompiling wasm function 791 with liftoff\r\nCompiling wasm function 654 with liftoff\r\nCompiling wasm function 27451 with liftoff\r\nCompiling wasm function 24648 with liftoff\r\n...\r\nCompiling wasm function 21088 with turbofan\r\nCompiling wasm function 791 with turbofan\r\nCompiling wasm function 29541 with turbofan\r\nCompiling wasm function 39979 with turbofan\r\n...\r\n(3b) Compilation finished\r\n(4) Finish module...\r\nmodule ready\r\n```\r\n\r\n\r\n### Additional information\r\n\r\nMain thread is blocked in `node::WorkerThreadsTaskRunner::BlockingDrain`, waiting for compiler task. `BlockingDrain` doesn't run the event loop. Apparently there's an assumption that tasks don't communicate with the main thread.\r\n\r\nThat's wrong. WASM compiler notifies the main thread once baseline compilation is complete (see `AsyncCompileJob::CompilationStateCallback`, `CompilationEvent::kFinishedBaselineCompilation` case).\r\n\r\nThe message goes through `WorkerThreadsTaskRunner::DelayedTaskScheduler::PostDelayedTask` (`node_platform.cc`), calling `uv_async_send`. The later goes unnoticed since `BlockingDrain` doesn't run the event loop.\r\n\r\n```\r\n  * frame #0: 0x00007fff696fd882 libsystem_kernel.dylib`__psynch_cvwait + 10\r\n    frame #1: 0x00007fff697be425 libsystem_pthread.dylib`_pthread_cond_wait + 698\r\n    frame #2: 0x0000000101394c9d node`uv_cond_wait(cond=0x0000000107517f98, mutex=0x0000000107517f28) at thread.c:780:7\r\n    frame #3: 0x000000010014867d node`node::LibuvMutexTraits::cond_wait(cond=0x0000000107517f98, mutex=0x0000000107517f28) at node_mutex.h:156:5\r\n    frame #4: 0x0000000100148620 node`node::ConditionVariableBase\u003cnode::LibuvMutexTraits>::Wait(this=0x0000000107517f98, scoped_lock=0x00007ffeefbff430) at node_mutex.h:194:3\r\n    frame #5: 0x00000001002dfae7 node`node::TaskQueue\u003cv8::Task>::BlockingDrain(this=0x0000000107517f28) at node_platform.cc:603:20\r\n    frame #6: 0x00000001002dfa95 node`node::WorkerThreadsTaskRunner::BlockingDrain(this=0x0000000107517f28) at node_platform.cc:207:25\r\n    frame #7: 0x00000001002e2274 node`node::NodePlatform::DrainTasks(this=0x0000000108808d80, isolate=0x00000001073ec000) at node_platform.cc:441:33\r\n    frame #8: 0x00000001000087fe node`node::SpinEventLoop(env=0x000000010780f800) at embed_helpers.cc:38:17\r\n    frame #9: 0x000000010024cfb2 node`node::NodeMainInstance::Run(this=0x00007ffeefbff6a0, env_info=0x000000010491d6b8) at node_main_instance.cc:144:19\r\n    frame #10: 0x000000010012f28a node`node::Start(argc=3, argv=0x00007ffeefbff850) at node.cc:1078:38\r\n    frame #11: 0x0000000101d1215e node`main(argc=3, argv=0x00007ffeefbff850) at node_main.cc:127:10\r\n    frame #12: 0x00007fff695b9cc9 libdyld.dylib`start + 1\r\n```","author":{"url":"https://github.com/mejedi","@type":"Person","name":"mejedi"},"datePublished":"2020-12-24T06:20:27Z","url":"https://github.com/nodejs/node/issues/36616"}