36

We're having a problem where every once in a while one of our environments our node app runs on 100% CPU. The server isn't very active and usually runs on 0%-2% CPU. I was wondering what are the common issues that might cause this problem and what would be the best way to find out what causing this issue.

Server specs:

node version 0.8.14
ubuntu 11.10
Intel(R) Xeon(R) CPU E5645 @ 2.40GHz

Node packages used:

"express" : 2.5.x,
"log" : "1.2.x",
"redis" : "0.8.x",
"socket.io" : "0.9.x",
"mongodb": ">= 0.9.6-7",
"passport" : "0.x.x",
"passport-local" : "0.x.x",
Zanon
  • 29,231
  • 20
  • 113
  • 126
dortzur
  • 1,666
  • 2
  • 16
  • 21

5 Answers5

38

You can profile your app with node-tick.

  1. Install node-tick by npm -g install tick
  2. Run your app with enabled profile node --prof ./app.js
  3. After some time with CPU 100% usage stop your app
  4. You can see v8.log in your app directory, now you can read it with node-tick-processor
  5. Run node-tick-processor and explain results
dmon
  • 30,048
  • 8
  • 87
  • 96
Vadim Baryshev
  • 25,689
  • 4
  • 56
  • 48
  • Be careful about using npm as root (i.e. sudo npm.) Read the discussion here: http://stackoverflow.com/questions/16151018/npm-throws-error-without-sudo – Keith Jan 14 '16 at 19:46
  • Oh man, this helped me discover that I removed a module while also requiring it in a service. Good grief. – NetOperator Wibby Nov 02 '16 at 17:37
15

UPDATE 2019 !!

You better use the built in --prof-process to process v8 profiling data, the generated file is no longer v8.log and node-tick-processor won't help you much, so to profile your app and read the v8 profiling data you can proceed as follows:

node --prof your_script.js

Node will generate a file with a name like this isolate-0x103800000-v8.log in your current directory, now you use this file to generate a profiling report

node --prof-process isolate-0x103800000-v8.log > processed.txt

Simple profiling

ZEE
  • 5,669
  • 4
  • 35
  • 53
6

Constantly running at 100% CPU is typical for infinite loop. This is a real problem in singlethreaded nodejs but unfortunately there is a lack of info on it.

Eventually I have found the only useful article: How to track the deadloop in nodejs:

Connect to you server via SSH. Identify nodejs process id (let it be 4702, for example). Now, let’s tell the process to listen for debugging requests. Yes, we’re using a command called kill. No, we’re not killing the process. We’re sending it a different signal.

kill -SIGUSR1 4702

Once you do this, the process is open to a debugger connection. In fact, it will print a special URL to its console log, and you can open that URL in Chrome to debug the process! But, maybe you don’t want to drill a hole through a firewall and a container configuration just to make that connection. Yeah, me neither. So let’s debug at the command line instead:

node inspect -p 4702

You’ll see this prompt:

debug>

Then type:

pause

And you get back:

break in file:///somewhere/something.js:555
>555         for (prop in inputObject) {
510             if (hasOwnProp(inputObject, prop)) {
511                 normalizedProp = normalizeUnits(prop);

Yes! We have our first hint. The app was executing line 555 in file something.js. That might be enough to see the bug right away. But usually we need more information than that. You can type backtrace to get a complete stack trace:

#0 someFunctionName file:///somewhere/somefile.js:444:22
#1 someFunctionName file:///somewhere/somefile.js:555:33
#2 someFunctionName file:///somewhere/somefile.js:666:44

… And so on.

Dmitry Kochin
  • 3,830
  • 4
  • 22
  • 14
0

If you are using UI app with webpack, pay attention on watchOptions or watch For me, disabling poll solve the problem

watchOptions: {
   poll: false
}

https://webpack.js.org/configuration/watch/#watchoptionsignored

Antoine Thiry
  • 2,362
  • 4
  • 28
  • 42
akim lyubchenko
  • 247
  • 4
  • 8
  • That's the default. By default, polling is disabled in favor of Fs events. The issue is tied to Fs events somehow. – adi518 Jan 12 '22 at 15:14
  • Okay, I urge you to pay attention. Maybe your configuration already contains this option for some reason. – akim lyubchenko Jan 13 '22 at 16:05
-1

this is what i found:

    #!/usr/bin/env node

require(__dirname+"/processor-usage.js").startWatching();

var shouldRun = true;
var desiredLoadFactor = .5;

function blockCpuFor(ms) {
    var now = new Date().getTime();
    var result = 0
    while(shouldRun) {
        result += Math.random() * Math.random();
        if (new Date().getTime() > now +ms)
            return;
    }   
}

function start() {
    shouldRun = true;
    blockCpuFor(1000*desiredLoadFactor);
    setTimeout(start, 1000* (1 - desiredLoadFactor));
}

setInterval(function() {
    console.log("current process cpu usage: "+(global.processCpuUsage || 0)+"%");}
, 1000);

if (process.argv[2]) {
    var value = parseFloat(process.argv[2]);
    if (value < 0 || value > 1) {
        console.log("please give desired load value as a range [0..1]");
    process.exit(-1);
    } else {
        desiredLoadFactor = value;
    }
}
start();

on http://blackholethought.blogspot.de/2012/08/measuring-cpu-usage-of-nodejs-from.html

thegrunt
  • 1,054
  • 1
  • 11
  • 22