RE: [nodejs] nodejs 100% cpu randomly

1,684 views
Skip to first unread message

Chad Engler

unread,
Nov 14, 2012, 10:49:37 AM11/14/12
to nod...@googlegroups.com

Hehe, gems…

 

Sounds like garbage collection. Do you create large objects or buffers temporarily?

 

-Chad

 

From: nod...@googlegroups.com [mailto:nod...@googlegroups.com] On Behalf Of Dor Tzur
Sent: Wednesday, November 14, 2012 4:08 AM
To: nod...@googlegroups.com
Subject: [nodejs] nodejs 100% cpu randomly

 

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.

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

gems 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",

 

--
Job Board: http://jobs.nodejs.org/
Posting guidelines: https://github.com/joyent/node/wiki/Mailing-List-Posting-Guidelines
You received this message because you are subscribed to the Google
Groups "nodejs" group.
To post to this group, send email to nod...@googlegroups.com
To unsubscribe from this group, send email to
nodejs+un...@googlegroups.com
For more options, visit this group at
http://groups.google.com/group/nodejs?hl=en?hl=en

Anand George

unread,
Nov 14, 2012, 11:01:53 AM11/14/12
to nod...@googlegroups.com
Are you using a service like forever? Had an API server running using forever. Running without forever showed a CPU usage of about 5%. Running with forever, the CPU usage would go to 100% on the first few calls. Using another tool solved the issue. 

Adam Crabtree

unread,
Nov 14, 2012, 11:40:05 AM11/14/12
to nod...@googlegroups.com
On the note of forever running at 100%, that likes to happen when your process fails to start and forever attempts to restart it as fast as it can die.
Better a little with righteousness
       than much gain with injustice.
Proverbs 16:8

Michael Schoonmaker

unread,
Nov 14, 2012, 11:44:48 AM11/14/12
to nod...@googlegroups.com
... which is easily diagnosed with `forever list`, and can be assuaged
with forever's "spinning" parameters, "minUptime" and "spinSleepTime".

Other than Adam's reason, I've never seen CPU spikes because of
forever. Let's not have any straw men here.

Anand George

unread,
Nov 14, 2012, 11:48:36 AM11/14/12
to nod...@googlegroups.com
The app has no issues running without forever... so not sure why forever wants to restart the process. The app has been running for about 6 weeks now using nohup with supervisor on AWS, have had at least six code changes and have never faced this issue.

Jimb Esser

unread,
Nov 14, 2012, 12:50:53 PM11/14/12
to nod...@googlegroups.com
If it spikes to 100%, and then goes back down, I'd agree that sounds like garbage collection.

Either way, the best way to know what is going on is to profile it!  I think on current versions of node, node-webkit-agent[1] is currently the best (only?) way to get a JavaScript CPU profile.  If it reports all of the time in "(program)", then you may need a lower-level CPU profile to know what's going on.


  Jimb Esser

Dor Tzur

unread,
Nov 15, 2012, 3:41:36 AM11/15/12
to nod...@googlegroups.com
A. We are not using forever so it's not relevant  to this case, thanks for the input though.

B. We tried using nodetime but it couldn't profile the cpu when it's at 100%. Do you think node-web-kit has a better chance?

C. We've been using MongoDB without defining safe mode and with auto-reconnect turned on. do you think one of these options might cause this?

Anton Whalley

unread,
Nov 15, 2012, 4:41:09 AM11/15/12
to nod...@googlegroups.com
Can you put it on an illumOS based system temporarily and get DTracing?
At the very least this would tell you if its infrastructure or application.

Spin up a Joyent SmartOS or do a local install of OpenIndiana. 
Then install your app 

This d script will show you when garbage collection is starting and how long it takes. 

node*:::gc-start
{
    self->ts = timestamp;
}
    
node*:::gc-done
{
    printf("Garbage Collection - [%Y] - %d",
              walltimestamp,
              timestamp - self->ts);
              self->ts = 0
}

Anton

Ben Noordhuis

unread,
Nov 15, 2012, 9:42:31 AM11/15/12
to nod...@googlegroups.com
On Thu, Nov 15, 2012 at 10:41 AM, Anton Whalley
<anton....@nearform.com> wrote:
> Can you put it on an illumOS based system temporarily and get DTracing?
> At the very least this would tell you if its infrastructure or application.
>
> Spin up a Joyent SmartOS or do a local install of OpenIndiana.
> Then install your app
>
> This d script will show you when garbage collection is starting and how long
> it takes.
>
>
> node*:::gc-start
> {
> self->ts = timestamp;
> }
>
> node*:::gc-done
> {
> printf("Garbage Collection - [%Y] - %d",
> walltimestamp,
> timestamp - self->ts);
> self->ts = 0
> }

In that vein, if you're on a semi-recent RHEL-based system (CentOS,
Fedora), you can use this systemtap script. It prints aggregated GC
statistics every 5 seconds and at program exit. Run with `sudo stap
gc.stp -c 'node script.js'`.

Note that systemtap support currently only exists in master.
Debian/Ubuntu probably won't work, the systemtap in the official
repositories is too old.

#!/usr/bin/env stap

global samples
global all_samples
global timestamp

probe process("node").mark("gc__start")
{
timestamp = gettimeofday_us()
}

probe process("node").mark("gc__done")
{
sample = gettimeofday_us() - timestamp
samples <<< sample
all_samples <<< sample
}

probe timer.s(5)
{
print(@hist_log(samples))
printf("min:%d avg:%d max:%d count:%d\n",
@min(samples), @avg(samples),
@max(samples), @count(samples))
delete samples
}

probe end
{
print(@hist_log(all_samples))
printf("min:%d avg:%d max:%d count:%d\n",
@min(all_samples), @avg(all_samples),
@max(all_samples), @count(all_samples))
}

As a gist: https://gist.github.com/4078925

darcy

unread,
Nov 15, 2012, 9:33:34 PM11/15/12
to nod...@googlegroups.com
node-webkit-agent is a good tool.
if you just want to know whether it's caused by gc, the easiest way is run your program by "node --trace_gc myapp.js", and you can see GC time like this:

  785292 ms: Mark-sweep 9.5 (46.0) -> 9.4 (46.0) MB, 14 ms ...

where '14ms' means busy doing GC with CPU usage of nearly 100%.

Murvin Lai

unread,
Nov 16, 2012, 5:51:31 PM11/16/12
to nod...@googlegroups.com
For your server, how many RAM u have?   it may be related to memory.   
try either increase your physical memory, or run node with extra memory allocated.  (default is 1GB)




Reply all
Reply to author
Forward
0 new messages