Re: Extremely slow startup time in Node environment
*node --liftoff --no-wasm-tier-up dhry2_node.js*
Runtime initialized after 49.4109835826 ms
вт, 2 мар. 2021 г. в 09:11, Александр Гурьянов :
> Yeah...
> ~/Загрузки/node-v14.16.0-linux-x64/bin/*node dhry2_node.js*
> Runtime initialized after 16328.0365122 ms
> dhry2: 1 181.949037 31.280845
> dhry2: 2 353.980880 32.157215
> dhry2: 4 720.280341 31.607247
> dhry2: 8 1366.479560 33.320774
> dhry2: 16 2578.543112 35.316188
> dhry2: 32 5049.154954 36.07
>
> ~/Загрузки/node-v14.16.0-linux-x64/bin/*node --liftoff --no-wasm-tier-up
> dhry2_node.js*
> dhry2: 1 236.612041 24.054227
> dhry2: 2 500.253110 22.754560
> dhry2: 4 900.747170 25.274660
> dhry2: 8 1808.096051 25.182377
> dhry2: 16 3842.752959 23.697676
>
>
> вт, 2 мар. 2021 г. в 02:43, Alon Zakai :
>
>> IMaybe node 12 did not yet have baseline compiler support for wasm. That
>> could explain the 30 seconds delay, as it fully optimizes all the code
>> before it runs. Asyncify can generate bigger code, which makes this worse.
>>
>> A newer node may not have the problem, and should run the baseline
>> compiler by default, like on the web. You can force a newer node to use the
>> optimizing compiler with --liftoff --no-wasm-tier-up and that should be
>> slow once more, as a test to verify this is the issue.
>>
>> On Sun, Feb 28, 2021 at 7:59 PM Александр Гурьянов
>> wrote:
>>
>>> I found something, this huge loading time only happens in -s ASYNCIFY=1
>>> and only if I add CPU_Core_Normal_Run to ASYNCIFY_WHITELIST, i think it
>>> happens
>>> because of function size.
>>>
>>> -s ASYNCIFY=1 +CPU_Core_Normal_Run
>>> Runtime initialized after 32175.474978000857 ms
>>> *(32 sec)*
>>> func: CPU_Core_Normal_Run\28\29
>>> [binary-bytes] : 245307 (*239kb*)
>>> [total]: 114037
>>> [vars] : 22
>>> Binary : 15203
>>> Block : 8136
>>> Break : 4471
>>> Call : 1250
>>> CallIndirect : 1120
>>> Const : 20921
>>> Drop : 1693
>>> GlobalGet : 7836
>>> GlobalSet : 2
>>> If :
>>> Load : 7368
>>> LocalGet : 17195
>>> LocalSet : 13046
>>> Loop : 6
>>> Return : 1
>>> Select : 1908
>>> Store : 3193
>>> Switch : 48
>>> Unary : 3968
>>> Unreachable: 6
>>>
>>> -s ASYNCIFY=1 -CPU_Core_Normal_Run
>>> Runtime initialized after 689.4367050006986 ms
>>> *(0.6 sec)*
>>> func: CPU_Core_Normal_Run\28\29
>>> [binary-bytes] : 157675 (*153k*)
>>> [total]: 64879
>>> [vars] : 14
>>> Binary : 10832
>>> Block : 3166
>>> Break : 2815
>>> Call : 1250
>>> CallIndirect : 1120
>>> Const : 13764
>>> Drop : 37
>>> GlobalGet : 1
>>> GlobalSet : 2
>>> If : 1803
>>> Load : 7342
>>> LocalGet : 11878
>>> LocalSet : 7304
>>> Loop : 6
>>> Select : 54
>>> Store : 3171
>>> Switch : 48
>>> Unary : 281
>>> Unreachable: 5
>>>
>>> Is it possible to do something automatically? Maybe split this function
>>> to chunks?
>>>
>>>
>>> пн, 8 февр. 2021 г. в 16:40, Александр Гурьянов :
>>>
Hi. I created a test program to estimate performance of my program. I
am trying to use it both in browser and node environment. Test program
works fine in both environments. However startups in node took up to
30 sec, while in browser it starts instantly. I don’t understand why.
I use an release build with -s ASYNCIFY = 1, my node.js script:
```
const { performance } = require('perf_hooks');
const dhry2 = require("./dhry2.js");
const startedAt = performance.now();
const Module = {
log: console.log,
performance,
onRuntimeInitialized: () => {
console.log("Runtime initialized after", performance.now() -
startedAt, "ms");
Module.callMain([]);
},
};
dhry2(Module);
```
And for browser:
```
Start
var stdout = document.getElementById("stdout");
function start() {
WDHRY2({
log: function(message) {
},
print: function(message) {
if (message.startsWith("dhry2")) {
console.log(message);
stdout.innerHTML = stdout.innerHTML + "
"
+ message;
}
},
}).then(function(m) {
m.callMain([]);
});
};
```
Node.js version starts in 30 sec, while browser versions starts
Re: Extremely slow startup time in Node environment
Yeah...
~/Загрузки/node-v14.16.0-linux-x64/bin/*node dhry2_node.js*
Runtime initialized after 16328.0365122 ms
dhry2: 1 181.949037 31.280845
dhry2: 2 353.980880 32.157215
dhry2: 4 720.280341 31.607247
dhry2: 8 1366.479560 33.320774
dhry2: 16 2578.543112 35.316188
dhry2: 32 5049.154954 36.07
~/Загрузки/node-v14.16.0-linux-x64/bin/*node --liftoff --no-wasm-tier-up
dhry2_node.js*
dhry2: 1 236.612041 24.054227
dhry2: 2 500.253110 22.754560
dhry2: 4 900.747170 25.274660
dhry2: 8 1808.096051 25.182377
dhry2: 16 3842.752959 23.697676
вт, 2 мар. 2021 г. в 02:43, Alon Zakai :
> IMaybe node 12 did not yet have baseline compiler support for wasm. That
> could explain the 30 seconds delay, as it fully optimizes all the code
> before it runs. Asyncify can generate bigger code, which makes this worse.
>
> A newer node may not have the problem, and should run the baseline
> compiler by default, like on the web. You can force a newer node to use the
> optimizing compiler with --liftoff --no-wasm-tier-up and that should be
> slow once more, as a test to verify this is the issue.
>
> On Sun, Feb 28, 2021 at 7:59 PM Александр Гурьянов
> wrote:
>
>> I found something, this huge loading time only happens in -s ASYNCIFY=1
>> and only if I add CPU_Core_Normal_Run to ASYNCIFY_WHITELIST, i think it
>> happens
>> because of function size.
>>
>> -s ASYNCIFY=1 +CPU_Core_Normal_Run
>> Runtime initialized after 32175.474978000857 ms
>> *(32 sec)*
>> func: CPU_Core_Normal_Run\28\29
>> [binary-bytes] : 245307 (*239kb*)
>> [total]: 114037
>> [vars] : 22
>> Binary : 15203
>> Block : 8136
>> Break : 4471
>> Call : 1250
>> CallIndirect : 1120
>> Const : 20921
>> Drop : 1693
>> GlobalGet : 7836
>> GlobalSet : 2
>> If :
>> Load : 7368
>> LocalGet : 17195
>> LocalSet : 13046
>> Loop : 6
>> Return : 1
>> Select : 1908
>> Store : 3193
>> Switch : 48
>> Unary : 3968
>> Unreachable: 6
>>
>> -s ASYNCIFY=1 -CPU_Core_Normal_Run
>> Runtime initialized after 689.4367050006986 ms
>> *(0.6 sec)*
>> func: CPU_Core_Normal_Run\28\29
>> [binary-bytes] : 157675 (*153k*)
>> [total]: 64879
>> [vars] : 14
>> Binary : 10832
>> Block : 3166
>> Break : 2815
>> Call : 1250
>> CallIndirect : 1120
>> Const : 13764
>> Drop : 37
>> GlobalGet : 1
>> GlobalSet : 2
>> If : 1803
>> Load : 7342
>> LocalGet : 11878
>> LocalSet : 7304
>> Loop : 6
>> Select : 54
>> Store : 3171
>> Switch : 48
>> Unary : 281
>> Unreachable: 5
>>
>> Is it possible to do something automatically? Maybe split this function
>> to chunks?
>>
>>
>> пн, 8 февр. 2021 г. в 16:40, Александр Гурьянов :
>>
>>> Hi. I created a test program to estimate performance of my program. I
>>> am trying to use it both in browser and node environment. Test program
>>> works fine in both environments. However startups in node took up to
>>> 30 sec, while in browser it starts instantly. I don’t understand why.
>>>
>>> I use an release build with -s ASYNCIFY = 1, my node.js script:
>>>
>>>
>>> ```
>>> const { performance } = require('perf_hooks');
>>> const dhry2 = require("./dhry2.js");
>>>
>>> const startedAt = performance.now();
>>> const Module = {
>>> log: console.log,
>>> performance,
>>> onRuntimeInitialized: () => {
>>>console.log("Runtime initialized after", performance.now() -
>>> startedAt, "ms");
>>>Module.callMain([]);
>>> },
>>> };
>>>
>>> dhry2(Module);
>>> ```
>>>
>>> And for browser:
>>> ```
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> Start
>>>
>>>
>>>
>>> var stdout = document.getElementById("stdout");
>>>
>>> function start() {
>>> WDHRY2({
>>> log: function(message) {
>>> },
>>> print: function(message) {
>>> if (message.startsWith("dhry2")) {
>>> console.log(message);
>>> stdout.innerHTML = stdout.innerHTML + "
"
>>> + message;
>>> }
>>> },
>>> }).then(function(m) {
>>> m.callMain([]);
>>> });
>>> };
>>>
>>>
>>>
>>> ```
>>>
>>> Node.js version starts in 30 sec, while browser versions starts
>>> immediately. Node hangs after leaving instantiateArrayBuffer and
>>> before entering receiveInstantiatedSource.
>>> I think it doing something, but I don't understand what. I profiled
>>> node but results is no obvious:
>>>
>>> ```
>>> Statistical profiling result from isolate-0x36df400-1353021-v8.log,
>>> (28109 ticks, 0
Re: Extremely slow startup time in Node environment
IMaybe node 12 did not yet have baseline compiler support for wasm. That
could explain the 30 seconds delay, as it fully optimizes all the code
before it runs. Asyncify can generate bigger code, which makes this worse.
A newer node may not have the problem, and should run the baseline compiler
by default, like on the web. You can force a newer node to use the
optimizing compiler with --liftoff --no-wasm-tier-up and that should be
slow once more, as a test to verify this is the issue.
On Sun, Feb 28, 2021 at 7:59 PM Александр Гурьянов
wrote:
> I found something, this huge loading time only happens in -s ASYNCIFY=1
> and only if I add CPU_Core_Normal_Run to ASYNCIFY_WHITELIST, i think it
> happens
> because of function size.
>
> -s ASYNCIFY=1 +CPU_Core_Normal_Run
> Runtime initialized after 32175.474978000857 ms
> *(32 sec)*
> func: CPU_Core_Normal_Run\28\29
> [binary-bytes] : 245307 (*239kb*)
> [total]: 114037
> [vars] : 22
> Binary : 15203
> Block : 8136
> Break : 4471
> Call : 1250
> CallIndirect : 1120
> Const : 20921
> Drop : 1693
> GlobalGet : 7836
> GlobalSet : 2
> If :
> Load : 7368
> LocalGet : 17195
> LocalSet : 13046
> Loop : 6
> Return : 1
> Select : 1908
> Store : 3193
> Switch : 48
> Unary : 3968
> Unreachable: 6
>
> -s ASYNCIFY=1 -CPU_Core_Normal_Run
> Runtime initialized after 689.4367050006986 ms
> *(0.6 sec)*
> func: CPU_Core_Normal_Run\28\29
> [binary-bytes] : 157675 (*153k*)
> [total]: 64879
> [vars] : 14
> Binary : 10832
> Block : 3166
> Break : 2815
> Call : 1250
> CallIndirect : 1120
> Const : 13764
> Drop : 37
> GlobalGet : 1
> GlobalSet : 2
> If : 1803
> Load : 7342
> LocalGet : 11878
> LocalSet : 7304
> Loop : 6
> Select : 54
> Store : 3171
> Switch : 48
> Unary : 281
> Unreachable: 5
>
> Is it possible to do something automatically? Maybe split this function to
> chunks?
>
>
> пн, 8 февр. 2021 г. в 16:40, Александр Гурьянов :
>
>> Hi. I created a test program to estimate performance of my program. I
>> am trying to use it both in browser and node environment. Test program
>> works fine in both environments. However startups in node took up to
>> 30 sec, while in browser it starts instantly. I don’t understand why.
>>
>> I use an release build with -s ASYNCIFY = 1, my node.js script:
>>
>>
>> ```
>> const { performance } = require('perf_hooks');
>> const dhry2 = require("./dhry2.js");
>>
>> const startedAt = performance.now();
>> const Module = {
>> log: console.log,
>> performance,
>> onRuntimeInitialized: () => {
>>console.log("Runtime initialized after", performance.now() -
>> startedAt, "ms");
>>Module.callMain([]);
>> },
>> };
>>
>> dhry2(Module);
>> ```
>>
>> And for browser:
>> ```
>>
>>
>>
>>
>>
>>
>>
>> Start
>>
>>
>>
>> var stdout = document.getElementById("stdout");
>>
>> function start() {
>> WDHRY2({
>> log: function(message) {
>> },
>> print: function(message) {
>> if (message.startsWith("dhry2")) {
>> console.log(message);
>> stdout.innerHTML = stdout.innerHTML + "
"
>> + message;
>> }
>> },
>> }).then(function(m) {
>> m.callMain([]);
>> });
>> };
>>
>>
>>
>> ```
>>
>> Node.js version starts in 30 sec, while browser versions starts
>> immediately. Node hangs after leaving instantiateArrayBuffer and
>> before entering receiveInstantiatedSource.
>> I think it doing something, but I don't understand what. I profiled
>> node but results is no obvious:
>>
>> ```
>> Statistical profiling result from isolate-0x36df400-1353021-v8.log,
>> (28109 ticks, 0 unaccounted, 0 excluded).
>>
>> [Shared libraries]:
>>ticks total nonlib name
>> 440.2%
>> /home/caiiiycuk/sdk/emsdk/node/12.18.1_64bit/bin/node
>> 50.0% /usr/lib/x86_64-linux-gnu/libc-2.31.so
>> 10.0% /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.28
>>
>> [JavaScript]:
>>ticks total nonlib name
>> 10.0%0.0% Function: *wasm-function[2219]
>>
>> [C++]:
>>ticks total nonlib name
>> 27974 99.5% 99.7% __pthread_cond_wait
>> 350.1%0.1%
>>
>> node::native_module::NativeModuleEnv::CompileFunction(v8::FunctionCallbackInfo
>> const&)
>> ...
>> [Summary]:
>>ticks total nonlib name
>> 10.0%0.0% JavaScript
>> 28058 99.8% 100.0% C++
>> ...
>> [C++ entry points]:
