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

High load on node library when CPU profiling #4450

Open
2 tasks done
nLassimonneAdveez opened this issue Jul 23, 2024 · 5 comments
Open
2 tasks done

High load on node library when CPU profiling #4450

nLassimonneAdveez opened this issue Jul 23, 2024 · 5 comments

Comments

@nLassimonneAdveez
Copy link

Node.js Version

v18.9.0

NPM Version

v10.7.0

Operating System

Ubuntu 20.04 Linux 5.4.0-92-generic

Subsystem

inspector

Description

Hello,

I have an app that is basically subscribing to MQTT channels and sending HTTP request.
I have a high RAM and CPU load on my app and I am trying to find out the culprit.

I ran a node --prof to run a CPU profiling and here is the result.
My report indicates node library using 61.4% :

   ticks  total  nonlib   name
  100357   61.4%          /usr/local/nvm/versions/node/v18.9.0/bin/node

What does that mean ?

I found the following issue that looks like my problem, but no solution has been found:
#4422

Thanks.

Minimal Reproduction

No response

Output

processed.txt

Before You Submit

  • I have looked for issues that already exist before submitting this
  • My issue follows the guidelines in the README file, and follows the 'How to ask a good question' guide at https://stackoverflow.com/help/how-to-ask
@RedYetiDev
Copy link
Member

RedYetiDev commented Jul 23, 2024

After that issue, I brushed up on my knowledge of profiling reports, but I'm still a bit rusty, but here's a go:

 [Shared libraries]:
   ticks  total  nonlib   name
  100357   61.4%          /usr/local/nvm/versions/node/v18.9.0/bin/node
  37636   23.0%          /usr/lib/x86_64-linux-gnu/libc-2.31.so
   4053    2.5%          /usr/lib/x86_64-linux-gnu/libpthread-2.31.so
    339    0.2%          /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.28
    130    0.1%          [vdso]

This section, at the top, refers to what parts are using how much CPU. As you can see, the CPP libraries are using some, as they are the backbone of Node.js.

Node itself is using a large portion of the CPU, typically in response to whatever code you are running.

Looking down at the report, elastic-apm-node (especially the http-apm-client files) appears to be using a decent amount of CPU, so maybe that's the bottleneck?


Additionally, there's also flamegraphs. These are human-visualizable graphs of CPU usage. They could also help you identify what parts of your script are using the most CPU (https://nodejs.org/en/learn/diagnostics/flame-graphs)

@nLassimonneAdveez
Copy link
Author

Thanks for your response. elastic-apm-node is a module I added to help me tracking down my performance issue 😕
I will try without this module.

@RedYetiDev
Copy link
Member

Thanks for your response. elastic-apm-node is a module I added to help me tracking down my performance issue 😕

I will try without this module.

Haha. Well, according to the profile report, it looks like knex is also using a lot of CPU. I highly recommend flamegraphs to determine what functions are using the most CPU.

@nLassimonneAdveez
Copy link
Author

I finally obtained a flamegraph, thanks to 0x. As I feared, it seems my high CPU is mostly coming from my HTTP sending, using axios. I will try using a Worker to avoid blocking my app.
FYI, what we were seeing on elastic-apm-node seems to only be a wrapper, hiding the real culprit.

Thanks.

@gireeshpunathil
Copy link
Member

here is how I would interpret the profile output. it looks at the CPU consumption of the process from three different perspectives (that corresponds to three different sections in the log):

  • shared libraries
  • components as seen by v8
  • raw dump

from the first two sections it is already obvious that node is taking a great share of samples. this is natural, and expected: a good running production with sufficient load should show CPU against his module. On the other hand if CPU were shown against components such gc, unaccounted etc, then it could be a concern.

now, in this case, I would look air the [Bottom up (heavy) profile] which shows raw consumption of CPU in the whole process. And as we can see, Client._encode /srv/yakapush/releases/145792-master#ae1937371a6c6567ad3612b307a36052c6ddfaf4/node_modules/elastic-apm-node/lib/apm-client/http-apm-client/index.js:689:37 is the dominant CPU eater. this being the APM, we should remove this, run the profiler again and see who is taking up the CPU next, and progress from thereon.

hope this helps!

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

No branches or pull requests

3 participants