Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
pragma-git opened this issue Apr 29, 2021 · 24 comments
Closed

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

pragma-git opened this issue Apr 29, 2021 · 24 comments
Assignees
Labels

Comments

@pragma-git
Copy link

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
Copy link
Author

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

@rogerwang rogerwang self-assigned this Apr 29, 2021
@pragma-git
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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

@rogerwang
Copy link
Member

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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.

Screenshot profiler 0 50 3 to left 0 51 0 to right

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
Copy link
Author

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

@pragma-git
Copy link
Author

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
Copy link
Member

rogerwang commented Jan 18, 2022 via email

@pragma-git
Copy link
Author

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

@pragma-git
Copy link
Author

This could be a clue ?

electron/electron#26143

Is nwjs signed on MacOS from version 51.0 ?

@JanAxelsson
Copy link

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
Copy link
Author

Problem remains on MacOS nwjs SDK v0.64.0

@pragma-git
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

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 ( child_process.spawn is considerably slower in Electron 12+  electron/electron#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
Copy link

hubciorz commented Sep 21, 2022

@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
Copy link
Member

Will look into it soon. Thanks.

@hubciorz
Copy link

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

@pragma-git
Copy link
Author

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants