Nodejs randomly hitting 100% CPU

763 views
Skip to first unread message

Karim Tarek

unread,
Dec 17, 2014, 5:03:22 AM12/17/14
to nod...@googlegroups.com
We are facing a problem with our Node js (v0.10.33) application with CLUSTER module on ubuntu amazon EC2 (c3.large) instance that nearly everyday we get a 100% cpu spike (on the workers) suddenly and it never goes down until we restart our application the problem is that these spikes happens randomly and at weird times (at 3AM) when the traffic is minimal, when i looked at the logs i found that the logs and any APMs stopped recording any requests probably because the node js app stopped working, what i did based on what i read so far is that i did a strace on the process which was at 100% and here is a part of the output of my stack trace (full strace attached): 

gettimeofday({1418314214, 491214}, NULL) = 0
gettimeofday({1418314214, 491327}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1418314214, 619975}, NULL) = 0
gettimeofday({1418314214, 620055}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b000000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b000000
mprotect(0xfcc3b005000, 4096, PROT_NONE) = 0
mmap(0xfcc3b006000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b006000
mprotect(0xfcc3b0ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3b100000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b100000
mprotect(0xfcc3b105000, 4096, PROT_NONE) = 0
mmap(0xfcc3b106000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b106000
mprotect(0xfcc3b1ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314214, 731602}, NULL) = 0
gettimeofday({1418314214, 731682}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b200000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b200000
mprotect(0xfcc3b205000, 4096, PROT_NONE) = 0
mmap(0xfcc3b206000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b206000
mprotect(0xfcc3b2ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314214, 835071}, NULL) = 0
gettimeofday({1418314214, 835154}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b300000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b300000
mprotect(0xfcc3b305000, 4096, PROT_NONE) = 0
mmap(0xfcc3b306000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b306000
mprotect(0xfcc3b3ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3b400000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b400000
mprotect(0xfcc3b405000, 4096, PROT_NONE) = 0
mmap(0xfcc3b406000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b406000
mprotect(0xfcc3b4ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314214, 938991}, NULL) = 0
gettimeofday({1418314214, 939072}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b500000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b500000
mprotect(0xfcc3b505000, 4096, PROT_NONE) = 0
mmap(0xfcc3b506000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b506000
mprotect(0xfcc3b5ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 41662}, NULL) = 0
gettimeofday({1418314215, 41744}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b600000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b600000
mprotect(0xfcc3b605000, 4096, PROT_NONE) = 0
mmap(0xfcc3b606000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b606000
mprotect(0xfcc3b6ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 161306}, NULL) = 0
gettimeofday({1418314215, 161408}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b700000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b700000
mprotect(0xfcc3b705000, 4096, PROT_NONE) = 0
mmap(0xfcc3b706000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b706000
mprotect(0xfcc3b7ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3b800000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b800000
mprotect(0xfcc3b805000, 4096, PROT_NONE) = 0
mmap(0xfcc3b806000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b806000
mprotect(0xfcc3b8ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 287996}, NULL) = 0
gettimeofday({1418314215, 288120}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3b900000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b900000
mprotect(0xfcc3b905000, 4096, PROT_NONE) = 0
mmap(0xfcc3b906000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3b906000
mprotect(0xfcc3b9ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 472947}, NULL) = 0
gettimeofday({1418314215, 473040}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3ba00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3ba00000
mprotect(0xfcc3ba05000, 4096, PROT_NONE) = 0
mmap(0xfcc3ba06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3ba06000
mprotect(0xfcc3baff000, 4096, PROT_NONE) = 0
mmap(0xfcc3bb00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bb00000
mprotect(0xfcc3bb05000, 4096, PROT_NONE) = 0
mmap(0xfcc3bb06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bb06000
mprotect(0xfcc3bbff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 593480}, NULL) = 0
gettimeofday({1418314215, 593565}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3bc00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bc00000
mprotect(0xfcc3bc05000, 4096, PROT_NONE) = 0
mmap(0xfcc3bc06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bc06000
mprotect(0xfcc3bcff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 696233}, NULL) = 0
gettimeofday({1418314215, 696315}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3bd00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bd00000
mprotect(0xfcc3bd05000, 4096, PROT_NONE) = 0
mmap(0xfcc3bd06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bd06000
mprotect(0xfcc3bdff000, 4096, PROT_NONE) = 0
mmap(0xfcc3be00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3be00000
mprotect(0xfcc3be05000, 4096, PROT_NONE) = 0
mmap(0xfcc3be06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3be06000
mprotect(0xfcc3beff000, 4096, PROT_NONE) = 0
gettimeofday({1418314215, 875801}, NULL) = 0
gettimeofday({1418314215, 875898}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3bf00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bf00000
mprotect(0xfcc3bf05000, 4096, PROT_NONE) = 0
mmap(0xfcc3bf06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3bf06000
mprotect(0xfcc3bfff000, 4096, PROT_NONE) = 0
gettimeofday({1418314216, 38282}, NULL) = 0
gettimeofday({1418314216, 38365}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c000000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c000000
mprotect(0xfcc3c005000, 4096, PROT_NONE) = 0
mmap(0xfcc3c006000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c006000
mprotect(0xfcc3c0ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314216, 255472}, NULL) = 0
gettimeofday({1418314216, 255552}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c100000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c100000
mprotect(0xfcc3c105000, 4096, PROT_NONE) = 0
mmap(0xfcc3c106000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c106000
mprotect(0xfcc3c1ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3c200000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c200000
mprotect(0xfcc3c205000, 4096, PROT_NONE) = 0
mmap(0xfcc3c206000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c206000
mprotect(0xfcc3c2ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314216, 390157}, NULL) = 0
gettimeofday({1418314216, 390240}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c300000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c300000
mprotect(0xfcc3c305000, 4096, PROT_NONE) = 0
mmap(0xfcc3c306000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c306000
mprotect(0xfcc3c3ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314216, 532144}, NULL) = 0
gettimeofday({1418314216, 532225}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c400000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c400000
mprotect(0xfcc3c405000, 4096, PROT_NONE) = 0
mmap(0xfcc3c406000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c406000
mprotect(0xfcc3c4ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3c500000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c500000
mprotect(0xfcc3c505000, 4096, PROT_NONE) = 0
mmap(0xfcc3c506000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c506000
mprotect(0xfcc3c5ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314216, 676703}, NULL) = 0
gettimeofday({1418314216, 676786}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c600000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c600000
mprotect(0xfcc3c605000, 4096, PROT_NONE) = 0
mmap(0xfcc3c606000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c606000
mprotect(0xfcc3c6ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314216, 832680}, NULL) = 0
gettimeofday({1418314216, 845863}, NULL) = 0
gettimeofday({1418314216, 855742}, NULL) = 0
mmap(0xfcc3c600000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c600000
mmap(0xfcc3c500000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c500000
mmap(0xfcc3c400000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c400000
mmap(0xfcc3c300000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c300000
mmap(0xfcc3c200000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c200000
mmap(0xfcc3c100000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c100000
mmap(0xfcc3c000000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3c000000
mmap(0xfcc3bf00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3bf00000
mmap(0xfcc3be00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3be00000
mmap(0xfcc3bd00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3bd00000
mmap(0xfcc3bc00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3bc00000
mmap(0xfcc3bb00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3bb00000
mmap(0xfcc3ba00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3ba00000
mmap(0xfcc3b900000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b900000
mmap(0xfcc3b800000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b800000
mmap(0xfcc3b700000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b700000
mmap(0xfcc3b600000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b600000
mmap(0xfcc3b500000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b500000
mmap(0xfcc3b400000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b400000
mmap(0xfcc3b300000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b300000
mmap(0xfcc3b200000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b200000
mmap(0xfcc3b100000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b100000
mmap(0xfcc3b000000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3b000000
gettimeofday({1418314216, 872832}, NULL) = 0
gettimeofday({1418314216, 878758}, NULL) = 0
gettimeofday({1418314216, 878857}, NULL) = 0
gettimeofday({1418314216, 878928}, NULL) = 0
gettimeofday({1418314216, 878996}, NULL) = 0
gettimeofday({1418314216, 879065}, NULL) = 0
gettimeofday({1418314216, 879154}, NULL) = 0
gettimeofday({1418314216, 879648}, NULL) = 0
gettimeofday({1418314216, 879718}, NULL) = 0
gettimeofday({1418314216, 880313}, NULL) = 0
gettimeofday({1418314216, 880383}, NULL) = 0
gettimeofday({1418314216, 880452}, NULL) = 0
gettimeofday({1418314216, 880521}, NULL) = 0
gettimeofday({1418314216, 880590}, NULL) = 0
gettimeofday({1418314216, 880658}, NULL) = 0
gettimeofday({1418314216, 885737}, NULL) = 0
gettimeofday({1418314216, 887874}, NULL) = 0
gettimeofday({1418314216, 887965}, NULL) = 0
gettimeofday({1418314216, 888056}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1418314217, 8997}, NULL)  = 0
gettimeofday({1418314217, 9096}, NULL)  = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1418314217, 115505}, NULL) = 0
gettimeofday({1418314217, 115588}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1418314217, 217206}, NULL) = 0
gettimeofday({1418314217, 217287}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1418314217, 315058}, NULL) = 0
gettimeofday({1418314217, 315137}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1418314217, 412213}, NULL) = 0
gettimeofday({1418314217, 412294}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c700000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c700000
mprotect(0xfcc3c705000, 4096, PROT_NONE) = 0
mmap(0xfcc3c706000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c706000
mprotect(0xfcc3c7ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3c800000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c800000
mprotect(0xfcc3c805000, 4096, PROT_NONE) = 0
mmap(0xfcc3c806000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c806000
mprotect(0xfcc3c8ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314217, 519206}, NULL) = 0
gettimeofday({1418314217, 519289}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3c900000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c900000
mprotect(0xfcc3c905000, 4096, PROT_NONE) = 0
mmap(0xfcc3c906000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3c906000
mprotect(0xfcc3c9ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314217, 653545}, NULL) = 0
gettimeofday({1418314217, 653624}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3ca00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3ca00000
mprotect(0xfcc3ca05000, 4096, PROT_NONE) = 0
mmap(0xfcc3ca06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3ca06000
mprotect(0xfcc3caff000, 4096, PROT_NONE) = 0
mmap(0xfcc3cb00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cb00000
mprotect(0xfcc3cb05000, 4096, PROT_NONE) = 0
mmap(0xfcc3cb06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cb06000
mprotect(0xfcc3cbff000, 4096, PROT_NONE) = 0
gettimeofday({1418314217, 757446}, NULL) = 0
gettimeofday({1418314217, 757530}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3cc00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cc00000
mprotect(0xfcc3cc05000, 4096, PROT_NONE) = 0
mmap(0xfcc3cc06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cc06000
mprotect(0xfcc3ccff000, 4096, PROT_NONE) = 0
gettimeofday({1418314217, 880698}, NULL) = 0
gettimeofday({1418314217, 880777}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3cd00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cd00000
mprotect(0xfcc3cd05000, 4096, PROT_NONE) = 0
mmap(0xfcc3cd06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cd06000
mprotect(0xfcc3cdff000, 4096, PROT_NONE) = 0
gettimeofday({1418314217, 996985}, NULL) = 0
gettimeofday({1418314217, 997063}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3ce00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3ce00000
mprotect(0xfcc3ce05000, 4096, PROT_NONE) = 0
mmap(0xfcc3ce06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3ce06000
mprotect(0xfcc3ceff000, 4096, PROT_NONE) = 0
mmap(0xfcc3cf00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cf00000
mprotect(0xfcc3cf05000, 4096, PROT_NONE) = 0
mmap(0xfcc3cf06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3cf06000
mprotect(0xfcc3cfff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 156422}, NULL) = 0
gettimeofday({1418314218, 156512}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d000000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d000000
mprotect(0xfcc3d005000, 4096, PROT_NONE) = 0
mmap(0xfcc3d006000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d006000
mprotect(0xfcc3d0ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 331075}, NULL) = 0
gettimeofday({1418314218, 331155}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d100000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d100000
mprotect(0xfcc3d105000, 4096, PROT_NONE) = 0
mmap(0xfcc3d106000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d106000
mprotect(0xfcc3d1ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3d200000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d200000
mprotect(0xfcc3d205000, 4096, PROT_NONE) = 0
mmap(0xfcc3d206000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d206000
mprotect(0xfcc3d2ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 469695}, NULL) = 0
gettimeofday({1418314218, 469779}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d300000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d300000
mprotect(0xfcc3d305000, 4096, PROT_NONE) = 0
mmap(0xfcc3d306000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d306000
mprotect(0xfcc3d3ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 572096}, NULL) = 0
gettimeofday({1418314218, 572177}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d400000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d400000
mprotect(0xfcc3d405000, 4096, PROT_NONE) = 0
mmap(0xfcc3d406000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d406000
mprotect(0xfcc3d4ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3d500000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d500000
mprotect(0xfcc3d505000, 4096, PROT_NONE) = 0
mmap(0xfcc3d506000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d506000
mprotect(0xfcc3d5ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 710743}, NULL) = 0
gettimeofday({1418314218, 710827}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d600000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d600000
mprotect(0xfcc3d605000, 4096, PROT_NONE) = 0
mmap(0xfcc3d606000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d606000
mprotect(0xfcc3d6ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 844711}, NULL) = 0
gettimeofday({1418314218, 844795}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d700000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d700000
mprotect(0xfcc3d705000, 4096, PROT_NONE) = 0
mmap(0xfcc3d706000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d706000
mprotect(0xfcc3d7ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314218, 979663}, NULL) = 0
gettimeofday({1418314218, 979743}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3d800000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d800000
mprotect(0xfcc3d805000, 4096, PROT_NONE) = 0
mmap(0xfcc3d806000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d806000
mprotect(0xfcc3d8ff000, 4096, PROT_NONE) = 0
mmap(0xfcc3d900000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d900000
mprotect(0xfcc3d905000, 4096, PROT_NONE) = 0
mmap(0xfcc3d906000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3d906000
mprotect(0xfcc3d9ff000, 4096, PROT_NONE) = 0
gettimeofday({1418314219, 128634}, NULL) = 0
gettimeofday({1418314219, 128719}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3da00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3da00000
mprotect(0xfcc3da05000, 4096, PROT_NONE) = 0
mmap(0xfcc3da06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3da06000
mprotect(0xfcc3daff000, 4096, PROT_NONE) = 0
gettimeofday({1418314219, 264543}, NULL) = 0
gettimeofday({1418314219, 264626}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3db00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3db00000
mprotect(0xfcc3db05000, 4096, PROT_NONE) = 0
mmap(0xfcc3db06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3db06000
mprotect(0xfcc3dbff000, 4096, PROT_NONE) = 0
mmap(0xfcc3dc00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3dc00000
mprotect(0xfcc3dc05000, 4096, PROT_NONE) = 0
mmap(0xfcc3dc06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3dc06000
mprotect(0xfcc3dcff000, 4096, PROT_NONE) = 0
gettimeofday({1418314219, 400804}, NULL) = 0
gettimeofday({1418314219, 400886}, NULL) = 0
futex(0x7faad80008c8, FUTEX_WAKE_PRIVATE, 1) = 1
mmap(0xfcc3dd00000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3dd00000
mprotect(0xfcc3dd05000, 4096, PROT_NONE) = 0
mmap(0xfcc3dd06000, 1019904, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xfcc3dd06000
mprotect(0xfcc3ddff000, 4096, PROT_NONE) = 0
gettimeofday({1418314219, 584835}, NULL) = 0
gettimeofday({1418314219, 612381}, NULL) = 0
gettimeofday({1418314219, 625079}, NULL) = 0
mmap(0xfcc3dd00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3dd00000
mmap(0xfcc3dc00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3dc00000
mmap(0xfcc3db00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3db00000
mmap(0xfcc3da00000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3da00000
mmap(0xfcc3d900000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3d900000
mmap(0xfcc3d800000, 1048576, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xfcc3d800000


Also i performed lsof command on the process and that was the output:


 as you can see there are some (CLOST_WAIT) in the output while the other process(worker) which was working fine at the time had no (CLOSE_WAIT).

I am new to node so i don't really understand what is going wrong with my application so if anyone has any idea of what is going on, or can explain for me the output of strace and lsof please help!
straceOut.txt

Fedor Indutny

unread,
Dec 17, 2014, 8:55:03 AM12/17/14
to nod...@googlegroups.com
Hello Karim,

I'd suggest profiling the application during such spikes. It seems that the app is spinning in JS and doing lots of allocations (because of mmap() calls in strace output).

Cheers,
Fedor.



--
Job board: http://jobs.nodejs.org/
New group rules: https://gist.github.com/othiym23/9886289#file-moderation-policy-md
Old group rules: 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 unsubscribe from this group and stop receiving emails from it, send an email to nodejs+un...@googlegroups.com.
To post to this group, send email to nod...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/nodejs/02001bf2-c2d2-4c8f-a09a-932e2b158030%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Karim Tarek

unread,
Dec 17, 2014, 9:09:23 AM12/17/14
to nod...@googlegroups.com, fe...@indutny.com
Hi Fedor!

Thanks for the reply! i wanted to tell you that i already tried profiling and started node with the --prof parameter but what happened is the following a log file was created for each process and it kept increasing in size like crazy in like 4 hours the file size reached 1.9GB so is there any way to profile the node app at the spike time only in order to be able to process it via the node-tick-processor ? because when i tried to read the 1.9GB file it ran out of memory while reading it and i tried to split but the context was lost so any suggestions? 
...

Fedor Indutny

unread,
Dec 17, 2014, 9:26:42 AM12/17/14
to Karim Tarek, nod...@googlegroups.com
Please consider using some module like: https://www.npmjs.com/package/v8-profiler , to enable and disable profiling in runtime, without logging everything.

So just wait for the 100% CPU peak and turn on profiler for a couple of seconds.

Karim Tarek

unread,
Dec 17, 2014, 9:38:32 AM12/17/14
to nod...@googlegroups.com, karim.tarek...@gmail.com, fe...@indutny.com
The problem is that @ 100% cpu anything installed like node or via npm like new relic doesn't even respond/report during the 100% cpu time. Its like the application froze, nothing working inside of node i tried using the usage module to try to restart node but it didn't work! any other suggestions ? and concerning the npm v8 profiler how would i start profiling from outside node i mean from the cmd because as i just said the node app is not responding during the 100% cpu time
...

Alain

unread,
Dec 17, 2014, 10:23:52 AM12/17/14
to nod...@googlegroups.com

Maybe if you run node with nice (in Linux) you could run some other higher priority command...

Enviado através do AquaMail para Android
http://www.aqua-mail.com

--
Job board: http://jobs.nodejs.org/
New group rules: https://gist.github.com/othiym23/9886289#file-moderation-policy-md
Old group rules: 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 unsubscribe from this group and stop receiving emails from it, send an email to nodejs+un...@googlegroups.com.
To post to this group, send email to nod...@googlegroups.com.

Ben Noordhuis

unread,
Dec 18, 2014, 8:49:38 AM12/18/14
to nod...@googlegroups.com
On Wed, Dec 17, 2014 at 3:09 PM, Karim Tarek
<karim.tarek...@gmail.com> wrote:
> is there any way to profile the node app at the spike time only in order to
> be able to process it via the node-tick-processor ?

We (StrongLoop) recently added a new paid feature to our
strong-agent[0] product that profiles selectively during event loop
stalls; it profiles only when a script takes too long to complete and
it also works when the script is otherwise unresponsive; for example,
when the program is stuck in an infinite loop.

The easiest way to use it is with slc[1][2]: slc runctl cpu-start
$process_id $threshold_in_ms

Caveat emptor: it's Linux-only for now but OS X support is on the way.
If people are interested in support for other platforms, they should
get in touch with us: call...@strongloop.com or b...@strongloop.com if
you want to reach me personally.

[0] https://npmjs.org/package/strong-agent
[1] https://npmjs.org/package/strong-cli
[2] http://docs.strongloop.com/display/SLC/StrongLoop+Controller

Karim Tarek

unread,
Dec 18, 2014, 8:54:17 AM12/18/14
to nod...@googlegroups.com
Thank you very much Ben for your reply i will have a look and perhaps its our only way to know what is going on with our node app thanks!

zladuric

unread,
Dec 19, 2014, 4:21:01 AM12/19/14
to nod...@googlegroups.com
Also, do you at least know where in the code is this happening?

100% CPU suggests there might be a blocking bit of code. There are very simple modules, things like [blocked](https://www.npmjs.com/package/blocked), that might help you locate the critical part, if not already, so you might to observe and test this code?
...

Karim Tarek

unread,
Dec 20, 2014, 12:33:57 PM12/20/14
to nod...@googlegroups.com
Unfortunately no i dont! and i am not sure as i am not that experienced how to spot the piece of code which has the problem :S
...
Reply all
Reply to author
Forward
0 new messages