High load on node library when CPU profiling

nLassimonneAdveez commented 1 month ago

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: https://github.com/nodejs/help/issues/4422

Thanks.

Minimal Reproduction

No response

Output

processed.txt

Before You Submit

[X] I have looked for issues that already exist before submitting this
[X] 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 commented 1 month ago

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 commented 1 month ago

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

RedYetiDev commented 1 month ago

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

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 commented 1 month ago

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 commented 6 days ago

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!

nodejs / help