Get Even More Visitors To Your Blog, Upgrade To A Business Listing >>

Node API taking 100% CPU, node-tick-processor output looks cryptic

Node API taking 100% CPU, node-tick-processor output looks cryptic

Problem

I have a node API which normally handles traffic quite well. However, in our peak times, it gets into this state where it starts using 100% CPU and needs to be restarted. After restarting, it returns to a regular state for the next few days.

Using a load testing site, I have been able to reproduce this issue. The request I am load testing is extremely simple, so I fear the problem is in a third-party library I'm using.

I'm new to debugging node and I'm not sure what to make of the following output from node-tick-processor. Can anyone decipher this?

Update: I'm running node v0.10.4

[Unknown]:
ticks  total  nonlib   name
   5    0.0%

[Shared libraries]:
ticks  total  nonlib   name
11943   49.1%    0.0%  /lib64/libc-2.12.so
10754   44.2%    0.0%  /usr/local/bin/node
  314    1.3%    0.0%  /lib64/libpthread-2.12.so
   50    0.2%    0.0%  7fff318b4000-7fff318b5000
    5    0.0%    0.0%  /lib64/libm-2.12.so
    3    0.0%    0.0%  /usr/lib64/libstdc++.so.6.0.17

[JavaScript]:
ticks  total  nonlib   name
 40    0.2%    3.2%  LazyCompile: ~read tls.js:397
 36    0.1%    2.8%  LazyCompile: *EventEmitter.addListener events.js:126
 29    0.1%    2.3%  LazyCompile: *Readable.read _stream_readable.js:226


[Bottom up (heavy) profile]:
Note: percentage shows a share of a particular caller in the total
amount of its parent calls.
Callers occupying less than 2.0% are not shown.

ticks parent  name
11943   49.1%  /lib64/libc-2.12.so
10754   44.2%  /usr/local/bin/node
 8270   76.9%    LazyCompile: *use tls.js:222
 5162   62.4%      LazyCompile: ~read tls.js:397
 5074   98.3%        LazyCompile: *Readable.read _stream_readable.js:226
 3396   66.9%          LazyCompile: ~write tls.js:315
 3396  100.0%            LazyCompile: *Writable.write _stream_writable.js:155
 1063   20.9%          LazyCompile: *write tls.js:315
 1063  100.0%            LazyCompile: *Writable.write _stream_writable.js:155
 370    7.3%          LazyCompile: *Writable.write _stream_writable.js:155
 370  100.0%            LazyCompile: ~write _stream_readable.js:546
 186    3.7%          LazyCompile: ~callback tls.js:753
 180   96.8%            LazyCompile: *onclienthello tls.js:748
 6    3.2%            LazyCompile: ~onclienthello tls.js:748
 2417   29.2%      LazyCompile: *read tls.js:397
 2417  100.0%        LazyCompile: *Readable.read _stream_readable.js:226
 2320   96.0%          LazyCompile: *Writable.write _stream_writable.js:155
 2315   99.8%            LazyCompile: ~write _stream_readable.js:546
   57    2.4%          LazyCompile: ~callback tls.js:753
   57  100.0%            LazyCompile: *onclienthello tls.js:748
  691    8.4%      LazyCompile: *Readable.read _stream_readable.js:226
  675   97.7%        LazyCompile: *write tls.js:315
  675  100.0%          LazyCompile: *Writable.write _stream_writable.js:155
  674   99.9%            LazyCompile: ~write _stream_readable.js:546
Problem courtesy of: thejav

Solution

For those still coming here, this was caused somewhere in the SSL-handling code in a system node module. I re-configured my stack to do SSL termination at nginx, and use basic HTTP handling at the node level, and this problem went away entirely.

Solution courtesy of: thejav

Discussion

View additional discussion.



This post first appeared on Node.js Recipes, please read the originial post: here

Share the post

Node API taking 100% CPU, node-tick-processor output looks cryptic

×

Subscribe to Node.js Recipes

Get updates delivered right to your inbox!

Thank you for your subscription

×