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.

Sign up for GitHub

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

Jump to bottom

electron-nodejs (start.js) consuming 50% CPU constantly even when idle #2094

Closed
0xacx opened this issue Apr 19, 2024 · 8 comments
Closed

electron-nodejs (start.js) consuming 50% CPU constantly even when idle #2094

0xacx opened this issue Apr 19, 2024 · 8 comments

Comments

@0xacx
Copy link

0xacx commented Apr 19, 2024 •
edited

Type: Performance Issue

Start VS code and look at the Process Explorer for electron-nodejs (start.js) under extensionHost. It constantly consumes more than 50% CPU even when VS code is idle.

Extension version: 18.19.0
VS Code version: Code 1.88.1 (e170252f762678dec6ca2cc69aba1570769a5d39, 2024-04-10T17:42:52.765Z)
OS version: Darwin x64 21.6.0
Modes:

A/B Experiments 
vsliv368:30146709
vspor879:30202332
vspor708:30202333
vspor363:30204092
vscod805cf:30301675
binariesv615:30325510
vsaa593:30376534
py29gd2263:30899288
vscaac:30438847
c4g48928:30535728
azure-dev_surveyone:30548225
962ge761:30959799
pythongtdpath:30769146
welcomedialogc:30910334
pythonidxpt:30866567
pythonnoceb:30805159
asynctok:30898717
pythontestfixt:30902429
pythonregdiag2:30936856
pyreplss1:30897532
pythonmypyd1:30879173
pythoncet0:30885854
h48ei257:31000450
pythontbext0:30879054
accentitlementsc:30995553
dsvsc016:30899300
dsvsc017:30899301
dsvsc018:30899302
cppperfnew:31000557
d34g3935:30971562
fegfb526:30981948
bg6jg535:30979843
ccp2r3:30993541
dsvsc020:30976470
pythonait:31006305
jchc7451:30973076
gee8j676:31009558
dsvsc021:30996838
g316j359:31013175
pythoncenvptcf:31022791
@MaxKless
Copy link
Collaborator

Hi thanks for the report. Why do you think Nx Console is the issue?

Could you provide some logs? That will make it easier for us to fix the issue.

  • Go to Output -> Nx Console Client and paste what you see there.
  • Run Toggle Developer Tools and paste what you see there too
  • Finally, run nx daemon and provide the contents of the daemon.log file linked there

Thank you!

@0xacx
Copy link
Author

0xacx commented Apr 19, 2024 •
edited

I used the VS code tool Help: Start Extension Bisect which disables groups of extensions and asks if the issue is present until it finds the single extension that is causing the problem. It pointed that the Nx Console extension was causing the issue. When the extension is not enabled the start.js process, (which is consuming CPU) is not running.

Output:

Nx Language Server:


[Nxls] - 2024-04-19T14:25:18.900Z - Retrieving workspace configuration

[Nxls] - 2024-04-19T14:25:18.963Z - Using local Nx package at /Users/myproject/node_modules/nx/src/project-graph/project-graph.js

[Nxls] - 2024-04-19T14:25:18.965Z - Using local Nx package at /Users/myproject/node_modules/nx/src/project-graph/file-utils.js

[Nxls] - 2024-04-19T14:25:18.965Z - Using local Nx package at /Users/myproject/node_modules/nx/src/utils/output.js

[Nxls] - 2024-04-19T14:25:18.966Z - Using local Nx package at /Users/myproject/node_modules/nx/src/project-graph/file-map-utils.js

[Nxls] - 2024-04-19T14:25:18.966Z - Using local Nx package at /Users/myproject/node_modules/nx/src/daemon/client/client.js

[Nxls] - 2024-04-19T14:25:18.985Z - createProjectGraphAsync

[Nxls] - 2024-04-19T14:25:19.720Z - createProjectGraphAsync successful

[Nxls] - 2024-04-19T14:25:19.747Z - Resetting daemon client

[Nxls] - 2024-04-19T14:25:19.747Z - Retrieved workspace configuration in: 847.306702002883 ms

[Nxls] - 2024-04-19T14:25:20.282Z - Using local Nx package at /Users/myproject/node_modules/nx/src/daemon/client/client.js

[Nxls] - 2024-04-19T14:25:20.282Z - Initializing daemon watcher, retries 0

[Nxls] - 2024-04-19T14:25:20.282Z - project graph computation error during daemon watcher initialization, using native watcher.

Nx Console:

Telemetry: production
Graph - init

Developer tools console (filtered for nx):

console.ts:137 [Extension Host] rejected promise not handled within 1 second: Error: ENOENT: no such file or directory, stat 'extension-output-nrwl.angular-console-#1-Nx Console'
w @ console.ts:137
$logExtensionHostMessage @ mainThreadConsole.ts:39
S @ rpcProtocol.ts:458
Q @ rpcProtocol.ts:443
M @ rpcProtocol.ts:373
L @ rpcProtocol.ts:299
(anonymous) @ rpcProtocol.ts:161
y @ event.ts:1156
fire @ event.ts:1187
fire @ ipc.net.ts:650
q.onmessage @ localProcessExtensionHost.ts:376
console.ts:137 [Extension Host] stack trace: Error: ENOENT: no such file or directory, stat 'extension-output-nrwl.angular-console-#1-Nx Console'
    at statSync (node:fs:1692:3)
    at t.statSync (node:electron/js2c/node_init:2:5052)
    at Object.n.statSync (/Users/myuser/.vscode/extensions/esbenp.prettier-vscode-10.4.0/dist/extension.js:1:3435)
    at y._panelReadyCallback (/Users/myuser/.vscode/extensions/codium.codium-0.8.5/dist/extension.js:2:901963)
w @ console.ts:137
$logExtensionHostMessage @ mainThreadConsole.ts:39
S @ rpcProtocol.ts:458
Q @ rpcProtocol.ts:443
M @ rpcProtocol.ts:373
L @ rpcProtocol.ts:299
(anonymous) @ rpcProtocol.ts:161
y @ event.ts:1156
fire @ event.ts:1187
fire @ ipc.net.ts:650
q.onmessage @ localProcessExtensionHost.ts:376
mainThreadExtensionService.ts:81 [esbenp.prettier-vscode]ENOENT: no such file or directory, stat 'extension-output-nrwl.angular-console-#1-Nx Console'
$onExtensionRuntimeError @ mainThreadExtensionService.ts:81
S @ rpcProtocol.ts:458
Q @ rpcProtocol.ts:443
M @ rpcProtocol.ts:373
L @ rpcProtocol.ts:299
(anonymous) @ rpcProtocol.ts:161
y @ event.ts:1156
fire @ event.ts:1187
fire @ ipc.net.ts:650
q.onmessage @ localProcessExtensionHost.ts:376
mainThreadExtensionService.ts:82 Error: ENOENT: no such file or directory, stat 'extension-output-nrwl.angular-console-#1-Nx Console'
    at statSync (node:fs:1692:3)
    at t.statSync (node:electron/js2c/node_init:2:5052)
    at Object.n.statSync (/Users/myuser/.vscode/extensions/esbenp.prettier-vscode-10.4.0/dist/extension.js:1:3435)
    at y._panelReadyCallback (/Users/myuser/.vscode/extensions/codium.codium-0.8.5/dist/extension.js:2:901963)

daemon.log (this file is really long and just the same logs repeating, so I am pasting the beginning and the end )

[NX Daemon Server] - 2024-04-19T09:04:20.376Z - Started listening on: /var/folders/qd/lcqv4v7176104bd553b5bs1w0000gn/T/5d188e5d19291bfb84a4/d.sock
[NX Daemon Server] - 2024-04-19T09:04:20.424Z - [WATCHER]: Subscribed to changes within: /Users/myuser/myproject (native)
[NX Daemon Server] - 2024-04-19T09:04:20.532Z - Established a connection. Number of open connections: 1
[NX Daemon Server] - 2024-04-19T09:04:20.535Z - Established a connection. Number of open connections: 2
[NX Daemon Server] - 2024-04-19T09:04:20.540Z - [REQUEST]: Client Request for Project Graph Received
[NX Daemon Server] - 2024-04-19T09:04:20.767Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2024-04-19T09:04:20.767Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T09:04:20.768Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T09:04:21.348Z - [REQUEST]: Responding to the client. project-graph
[NX Daemon Server] - 2024-04-19T09:04:21.357Z - Time taken for 'total for creating and serializing project graph' 807.521482000011ms
[NX Daemon Server] - 2024-04-19T09:04:21.357Z - Closed a connection. Number of open connections: 1
[NX Daemon Server] - 2024-04-19T09:04:21.385Z - Done responding to the client project-graph
[NX Daemon Server] - 2024-04-19T09:04:21.385Z - Handled REQUEST_PROJECT_GRAPH. Handling time: 808. Response time: 37.
[NX Daemon Server] - 2024-04-19T09:04:21.408Z - [REQUEST]: Responding to the client. handleRequestFileData
[NX Daemon Server] - 2024-04-19T09:04:21.414Z - Done responding to the client handleRequestFileData
[NX Daemon Server] - 2024-04-19T09:04:21.414Z - Handled REQUEST_FILE_DATA. Handling time: 11. Response time: 6.
[NX Daemon Server] - 2024-04-19T09:04:21.429Z - Closed a connection. Number of open connections: 0
[NX Daemon Server] - 2024-04-19T09:04:21.448Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T09:04:21.457Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2024-04-19T09:04:21.655Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2024-04-19T09:04:21.655Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T09:04:21.655Z - [REQUEST]: .nx/cache/project-graph.json~d1b282bc,.nx/cache/file-map.json~d1b282bc
[NX Daemon Server] - 2024-04-19T09:04:21.965Z - Time taken for 'hash changed files from watcher' 67.67871500001638ms
[NX Daemon Server] - 2024-04-19T09:04:21.998Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2024-04-19T09:04:22.010Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T09:04:22.344Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2024-04-19T09:04:22.344Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T09:04:22.344Z - [REQUEST]: .nx/cache/project-graph.json~c3133fc2,.nx/cache/file-map.json~c3133fc2
[NX Daemon Server] - 2024-04-19T09:04:22.628Z - Time taken for 'hash changed files from watcher' 84.39149100001669ms
[NX Daemon Server] - 2024-04-19T09:04:22.664Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T09:04:22.673Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2024-04-19T09:04:22.933Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2024-04-19T09:04:22.933Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T09:04:22.933Z - [REQUEST]: .nx/cache/project-graph.json~f8c755d4,.nx/cache/file-map.json~f8c755d4
[NX Daemon Server] - 2024-04-19T09:04:23.090Z - Time taken for 'hash changed files from watcher' 106.09449699998368ms
[NX Daemon Server] - 2024-04-19T09:04:23.142Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T09:04:23.174Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2024-04-19T09:04:23.641Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...

[NX Daemon Server] - 2024-04-19T14:42:49.262Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T14:42:49.262Z - [REQUEST]: .nx/cache/file-map.json~ba156228,.nx/cache/project-graph.json~ba156228
[NX Daemon Server] - 2024-04-19T14:42:49.353Z - Time taken for 'hash changed files from watcher' 56.74431099742651ms
[NX Daemon Server] - 2024-04-19T14:42:49.402Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T14:42:49.403Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2024-04-19T14:42:49.555Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2024-04-19T14:42:49.556Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T14:42:49.556Z - [REQUEST]: .nx/cache/file-map.json~8e6779f5,.nx/cache/project-graph.json~8e6779f5
[NX Daemon Server] - 2024-04-19T14:42:49.649Z - Time taken for 'hash changed files from watcher' 23.88901099935174ms
[NX Daemon Server] - 2024-04-19T14:42:49.686Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2024-04-19T14:42:49.688Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T14:42:49.846Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2024-04-19T14:42:49.846Z - [REQUEST]: 
[NX Daemon Server] - 2024-04-19T14:42:49.846Z - [REQUEST]: .nx/cache/file-map.json~c655c9e4,.nx/cache/project-graph.json~c655c9e4
[NX Daemon Server] - 2024-04-19T14:42:49.945Z - Time taken for 'hash changed files from watcher' 30.313896000385284ms
[NX Daemon Server] - 2024-04-19T14:42:49.988Z - [WATCHER]: 2 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2024-04-19T14:42:49.988Z - [WATCHER]: Processing file changes in outputs

I hope this helps!

@MaxKless
Copy link
Collaborator

Thanks this is a great help! It looks like for some reason changes in .nx/cache are being picked up by the watcher which retriggers project graph calculation in an infinite loop.
Can you paste your nx report here as well? This shouldn't happen on the latest versions of nx...

@0xacx
Copy link
Author

0xacx commented Apr 29, 2024 •
edited

nx report:

   Node   : 21.7.1
   OS     : darwin-x64
   yarn   : 3.2.4
   
   nx                 : 16.10.0
   @nx/js             : 16.10.0
   @nx/jest           : 16.10.0
   @nx/linter         : 16.10.0
   @nx/workspace      : 16.10.0
   @nx/cypress        : 16.10.0
   @nx/devkit         : 16.10.0
   @nx/esbuild        : 16.10.0
   @nx/eslint-plugin  : 16.10.0
   @nx/express        : 16.10.0
   @nx/node           : 16.10.0
   @nx/react          : 16.10.0
   @nx/storybook      : 16.10.0
   @nrwl/tao          : 16.10.0
   @nx/web            : 16.10.0
   @nx/webpack        : 16.10.0
   nx-cloud           : 16.5.2
   typescript         : 5.4.2

I guess I should try updating the nx version.

@MaxKless
Copy link
Collaborator

I'm going to release a version which handles this on the nx console side as well but yes, updating the nx version would be great!

@MaxKless
Copy link
Collaborator

MaxKless commented May 3, 2024

Hey! Can you try on the latest version? :) I made some changes that should fix these issues.
If you could report back whether it still happens on 18.21.0/1.23.0 that would be amazing!

@MaxKless
Copy link
Collaborator

MaxKless commented May 8, 2024

I'm closing this as completed for now as we've released a fix.
If you still run into any issues, please let me know and I'll have another look :)

@MaxKless MaxKless closed this as completed May 8, 2024
@0xacx
Copy link
Author

0xacx commented May 8, 2024

Hey @MaxKless Thank you for the help. My issue was resolved when I migrated to nx 17 and the nx console VS code extension to 18.21.1. Big thanks for quick resolution! 🙏

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@MaxKless @0xacx