Extremely slow after updating from v0.50.1 to v0.52.1 and later

[pragma-git]

NWJS Version : 0.52.1 and 0.53.0 Operating System : MacOS and probably others

Expected behavior

Same rendering speed as v0.50.1 and earlier.

Actual behavior

GUI rendering is at least a factor 10 slower than in v0.50.1.

How to reproduce

git clone https://github.com/pragma-git/pragma-git.git cd pragma-git git switch develop /Applications/nwjs.app/Contents/MacOS/nwjs . # On mac, use similar on other platforms You may also click the "question-mark icon" at the top left corner, or the "settings icon" at the lower right corner, to observe more of the slow rendering

I have also tried the following

--disable-features=nw2 flag in above run command removed "chromium-args": "--disable-gpu" in package.json

[pragma-git]

Added tag in above git repo : nw_issue_7715. Please check out that one, since develop may be changed

[pragma-git]

This very same issue reamins in v0.58.0. It is still at least 10 times slower than v0.50.1 -- which makes it totally impossible to upgrade past v0.50.1.

I am curious if I am the only one seeing this? Pragma-git is a pretty heavy application, but the startup is not where I would expect slowdowns. Anything I can do to aid?

[pragma-git]

NWJS Version : 0.52.1 ... 0.60.0 (as downloaded from https://nwjs.io/downloads/ ) Operating System : MacOS Big Suhr and Monteray (and others ?)

• The slowdown remains in v0.60.0. It is still at least 10 times (I would guess even more) slower than v0.50.1 -- which makes it totally impossible to upgrade past v0.50.1.

• I have now found that nwjs Helper (Renderer) uses 100% CPU.

• It appears that the redrawing I do every second now bogs down the system incredibly after 0.50.1. Is there anything after 0.50.1 which has changed in the underlying rendering mechanism? Any flags I can set?

I am willing to participate in finding the cause, but need some guidance on how. Please connect with me

[pragma-git]

The problem occurs exactly when switching from v0.50.3 (good) to v0.51.0 (bad)

[rogerwang]

Thanks for the program for reproducing. Could you shrink it down to some simpler sample? It would be helpful to fix the issue.

[pragma-git]

I wish I has an idea where to start!

With the 0.51.0 version the dev summary graph shows 99.9% "scripting", and no "idle" With the 0.50.3 version I get about 10-15% scripting, and the rest "idle".

I have two thoughts : Could spawning external processes be different (I run git commands via simple-git)? Could async function handling be different?

From your experience with what happened between the two versions, would you have any high-level idea on what to focus my search on?

[pragma-git]

I have now managed to make a micro-version that displays the problem.

https://github.com/pragma-git/issue7715.git (Tag = version2)

Instructions how to run are in the comments in the file frameless_window.js. You need the two versions 0.50.3 (or lower) and 0.51.0 (or higher) to reproduce. The difference is striking from about 20 ms to about 450 ms

[pragma-git]

Wow, getting closer. Now I have come down to exec a child process being the culprit. All timers, and function calls removed. I don't think it can become more clear than this.

https://github.com/pragma-git/issue7715.git (Tag = version3)

Same instructions as before :

Instructions how to run are in the comments in the file frameless_window.js. You need the two versions 0.50.3 (or lower) and 0.51.0 (or higher) to reproduce. The difference is striking from about 15 ms to about 450 ms

[pragma-git]

More information : Profiling with 0.50.3 to the left, and 0.51.0 to the right. If I understand it the node versions should be the same, which is a bit curious.

To be able to do this profiling, I made a timer call the same code multiple times (Tag = version 4). Thus, it is the same child-process call as used in (Tag = version 3), mentioned in previous comment.

[pragma-git]

Did I give you sufficient information to work on this issue?

[pragma-git]

Some timing information for version (51.0 and 50.3), running with debug flag /Applications/nwjs_v0.51.0.app/Contents/MacOS/nwjs --enable-logging=stderr --v=2 . and /Applications/nwjs_v0.50.3.app/Contents/MacOS/nwjs --enable-logging=stderr --v=2 .

The javascript simply prints time-output before and after the child_process.exec, whereas a bash date command prints the time from within the bash-shell (note that its using MacOS bash, so modify if running on other platform)

From below, the following can be deduced:

• Javascript clock and bash clock were very close in this experiment
• Child process in v51.0 executed after a long initial delay

See https://github.com/pragma-git/issue7715/tree/timing_info , Tag=timing_info

    
version 50.3   
------------
[80955:259:0118/190350.816905:INFO:CONSOLE(37)] " ", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (37)
[80955:259:0118/190350.817130:INFO:CONSOLE(40)] "1642529030816 (start time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (40)
--> NOTE + 18 ms   

[80955:259:0118/190350.835987:INFO:CONSOLE(49)] "1642529030835 (done time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (49)
[80955:259:0118/190350.847301:INFO:CONSOLE(43)] "1642529030100 (bash time)
--> NOTE : "bash time close to start time" => clocks are matching between shell and javascript

", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (43)
[80955:259:0118/190350.847503:INFO:CONSOLE(46)] "1642529030847 (child exit time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (46)

TOT = 30 ms



version 51.0 
------------
[80482:259:0118/190306.857709:INFO:CONSOLE(37)] " ", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (37)
[80482:259:0118/190306.857900:INFO:CONSOLE(40)] "1642528986857 (start time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (40)
--> NOTE +500 ms    

[80482:259:0118/190307.354109:INFO:CONSOLE(49)] "1642528987353 (done time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (49)
[80482:259:0118/190307.364911:INFO:CONSOLE(43)] "1642528987100 (bash time)
--> NOTE : "bash time close to exit time"

", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (43)
[80482:259:0118/190307.364990:INFO:CONSOLE(46)] "1642528987364 (child exit time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (46)
--> NOTE : "bash time close to child exit time"

TOT = 500 ms

[rogerwang]

Did it reproduce on Linux? Or it is Mac only.

On Tue, Jan 18, 2022, 11:22 AM pragma-git @.***> wrote:

Some timing information for version (51.0 and 50.3), running with debug flag /Applications/nwjs_v0.51.0.app/Contents/MacOS/nwjs --enable-logging=stderr --v=2 . and /Applications/nwjs_v0.50.3.app/Contents/MacOS/nwjs --enable-logging=stderr --v=2 .

The javascript simply prints time-output before and after the child_process.exec, whereas a bash date command prints the time from within the bash-shell (note that its using MacOS bash, so modify if running on other platform)

From below, the following can be deduced:

• Javascript clock and bash clock were very close in this experiment
• Child process in v51.0 executed after a long initial delay

See https://github.com/pragma-git/issue7715/tree/timing_info , Tag=timing_info

version 50.3

[80955:259:0118/190350.816905:INFO:CONSOLE(37)] " ", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (37) [80955:259:0118/190350.817130:INFO:CONSOLE(40)] "1642529030816 (start time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (40) --> NOTE + 18 ms

[80955:259:0118/190350.835987:INFO:CONSOLE(49)] "1642529030835 (done time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (49) [80955:259:0118/190350.847301:INFO:CONSOLE(43)] "1642529030100 (bash time) --> NOTE : "bash time close to start time" => clocks are matching between shell and javascript

", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (43) [80955:259:0118/190350.847503:INFO:CONSOLE(46)] "1642529030847 (child exit time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (46)

TOT = 30 ms

version 51.0

[80482:259:0118/190306.857709:INFO:CONSOLE(37)] " ", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (37) [80482:259:0118/190306.857900:INFO:CONSOLE(40)] "1642528986857 (start time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (40) --> NOTE +500 ms

[80482:259:0118/190307.354109:INFO:CONSOLE(49)] "1642528987353 (done time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (49) [80482:259:0118/190307.364911:INFO:CONSOLE(43)] "1642528987100 (bash time) --> NOTE : "bash time close to exit time"

", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (43) [80482:259:0118/190307.364990:INFO:CONSOLE(46)] "1642528987364 (child exit time)", source: chrome-extension://kmdapnfabpgbijhamipfegdgochkobfm/frameless_window.js (46) --> NOTE : "bash time close to child exit time"

TOT = 500 ms

— Reply to this email directly, view it on GitHub https://github.com/nwjs/nw.js/issues/7715#issuecomment-1015689036, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABIMGJOW3BPMKSVGGINEQLUWWVVZANCNFSM43ZQ3PNA . You are receiving this because you were assigned.Message ID: <nwjs/nw. @.***>

[pragma-git]

No, the test-code does not appear to be a problem under Linux.

[pragma-git]

This could be a clue ?

https://github.com/electron/electron/issues/26143

Is nwjs signed on MacOS from version 51.0 ?

[JanAxelsson]

Sorry to bother again. I am curious if there is some more information, or anything I can do. For me this is an issue prohibiting me from moving past nwjs version 50.3 on MacOS.

I really want to be on track with the newer nwjs releases, especially since other improvements and bug fixes are bound to come. It is not a good option to keep my software on different nwjs versions on Linux, Windows, and MacOS platforms.

[pragma-git]

Problem remains on MacOS nwjs SDK v0.64.0

[pragma-git]

I am not proficient enough to compile nwjs, but I would be happy to help by testing different versions.

I am willing to aid and test versions between 50.3 and 51.0 to isolate where the slow-down was introduced. Would that be helpful? Is it possible to let the build-bot create such versions for me to download and test?

It would be greatly appreciated if you could comment on if this would be a way forward, or if you maybe already know the cause of this problem and instead could hint on a possible time-line.

[pragma-git]

And since I cannot help looking for clues...

This is the difference in process.versions (patch formatted) in the console between 50.3 and 51.0 versions :

 ares: "1.17.1"
 brotli: "1.0.9"
-chromium: "87.0.4280.141"
-icu: "67.1"
+chromium: "88.0.4324.96"
+icu: "68.1"
 llhttp: "2.1.3"
 modules: "88"
 napi: "7"
 nghttp2: "1.41.0"
 node: "15.5.1"
-node-webkit: "0.50.3"
-nw: "0.50.3"
-nw-commit-id: "0789755-0ffab9c-050bd3e-49b68d6"
+node-webkit: "0.51.0"
+nw: "0.51.0"
+nw-commit-id: "7bffd8a-99315b5-488e31c-49b68d6"
 nw-flavor: "sdk"
 openssl: "1.1.1i"
 unicode: "13.0"
 uv: "1.40.0"
-v8: "8.7.220.31"
+v8: "8.8.278.14"
 zlib: "1.2.11"

[pragma-git]

The most minimal way to show this, is now to start the nwjs app on MacOS with remote-debugging, and paste code.

Requirements: Two versions 0.50.3 and 0.51.0 SDK versions for MacOS downloaded, and renamed from nwjs.app to nwjs_v0.50.3.app and nwjs_v0.51.0.app, respectively

Behavior : 50.3 version shows a very short time printed, and 51.0 a very long time printed to console

/**
 * This code shows the problem with issue #7715 on NWJS, but run inside dev-console of NWJS
 * 
 * Go into folder with package.json, and run below commands.  Time spend is shown in window.
 * 
 * In terminal : /Applications/nwjs_v0.50.3.app/Contents/MacOS/nwjs   --remote-debugging-port=9222
 *     or 
 *  In terminal : /Applications/nwjs_v0.51.0.app/Contents/MacOS/nwjs   --remote-debugging-port=9222
 * 
 * 1) In google chrome :  http://localhost:9222/
 * 2) click on one of the pages
 * 3) and then paste below code into console
 * 
 */




//
// HERE GOES MINIMAL CODE SHOWING NWJS ISSUE #7715 
//

function test(){

    var startTime = performance.now();

    const { exec } = require("child_process")
    let child = exec('echo "$(date +%s%100) (bash time)"', (error, stdout, stderr) => { 
            //console.log(stdout); 
        }
    );

    child.on('close', (code) => {
        console.log(`Close: ${ performance.now() - startTime} ms    code = ${code}`);
    });

}

test()

[pragma-git]

Would there be some way to fix the sudden slowdown on child_process.spawn for nwjs from version 0.51.0?

I have put years into a new git client (pragma-git) soon to be announced to the open source. It feels that it will one day break on MacOs if I cannot follow the nwjs releases. I mean, it is not unheard of that new MacOS releases break features, which could make nwjs 0.50.3 fail. Such feature would most likely be repaired in a later nwjs, but would render pragma-git incompatible because of the spawn slowdown-bug, which has remained in all versions post 0.50.3.

Therefore I have read a lot, and I wish to view a few of the things that I hope could inspire you guys who understands the inner parts of nwjs :

• There were reports on very similar slow-downs on Electron, and it seems like modifying libuv to use posix spawn was a solution ( https://github.com/electron/electron/issues/32480). Don't know if that applies here.

• Since the slowdown does only appear on later MacOS and only after NWJS 51.0 (worked great on 0.50.3), I start to wonder if something about libuv was updated at this time to match Big Suhr MacOS (about right time span), and that the integration of this new libuv into NWJS may have suffered some blow due to this change? It obviously doesn't affect old releases of nwjs, so it is not due to BigSuhr alone

• I read (https://github.com/nwjs/nw.js/issues/82) that there is a fallback in the integration of libuv into nwjs. Maybe the slowdown is this fallback kicking in?

I find it very annoying that I don't have the understanding and programming skills to fix this. Is this something I can hope somebody else knows how to do?

[hubciorz]

@pragma-git @rogerwang @JanAxelsson
We are experiencing the same issue in our app.

We could stick with 0.50.x but the problem is it's not working on macOS Ventura. So for now we have 2 choices and none of them is good tbh:

• stick with 0.50.x, but it won't run on macOS Ventura (it crashes at startup) or
• update to a later version (the newest one is working), but the app will be slow and clunky (but still runnable at all on macOS Ventura)

[rogerwang]

Will look into it soon. Thanks.

[hubciorz]

@rogerwang I can confirm that the fix included in the latest nightly build is working! Thanks! ♥️

[pragma-git]

I can confirm that it fixes the problem for pragma-git as well. Thanks a lot, you made my day! 💖