Garbage collection deadlock (0.8.22)

[mrjoes]

Hello,

We have application that runs on top of node.js 0.8.22 on Linux. There are three nodes in the cluster and we're seeing random freezes with 100% CPU usage once a day per node. Node becomes completely unresponsive.

First attempt to debug the issue was to attach node.js debugger using steps from this article: http://offthelip.org/?p=206
Debugger successfully attaches, but running "pause" or any other command will lock the debugger.

Second attempt was to attach gdb and get stack trace. Here's what in stacktrace:

(gdb) bt 
#0  0x000000000088a6ac in ?? () 
#1  0x000000000088a735 in v8::internal::FreeList::CountFreeListItems(v8::internal::Page*, v8::internal::FreeList::SizeStats*) () 
#2  0x00000000007bd0d2 in v8::internal::MarkCompactCollector::CollectEvacuationCandidates(v8::internal::PagedSpace*) () 
#3  0x00000000007bd1c3 in v8::internal::MarkCompactCollector::StartCompaction(v8::internal::MarkCompactCollector::CompactionMode) () 
#4  0x00000000007bda45 in v8::internal::MarkCompactCollector::Prepare(v8::internal::GCTracer*) () 
#5  0x00000000007402b8 in v8::internal::Heap::MarkCompact(v8::internal::GCTracer*) () 
#6  0x0000000000744113 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::internal::GCTracer*) () 
#7  0x00000000007444e3 in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollector, char const*, char const*) () 
#8  0x0000000000744bd0 in v8::internal::Heap::CollectAllGarbage(int, char const*) () 
#9  0x000000000074506c in v8::internal::Heap::IdleNotification(int) () 
#10 0x00000000005990a7 in ?? () 
#11 0x00000000005f1533 in uv__run_idle () 
#12 0x00000000005e4632 in ?? () 
#13 0x00000000005e4920 in uv_run () 
#14 0x000000000059c485 in node::Start(int, char**) () 
#15 0x00007fd553e53c8d in __libc_start_main () from /lib/libc.so.6 
#16 0x000000000059426d in _start ()

And it sits there forever.

Any hints are welcome.

[bnoordhuis]

Does --nouse_idle_notification remedy it? v0.8 tries to GC whenever there is nothing happening. In practice, that doesn't work out so great so we've removed that in v0.10.

[mrjoes]

OK, tried it.

Command line is: /usr/bin/nodejs --nouse_idle_notification /home/socket/bin/coffee bin/server.coffee 8080

Top shows: 4105 socket 20 0 2699m 2.0g 5832 R 100 13.6 56:47.80 nodejs

Overall, there are no deadlocks anymore, but this issue still happens. Server is "sort of" responsive, but it takes around 30 seconds to make response.

Here's new gdb stack trace:

#0  0x000000000088a6ac in ?? () 
#1  0x000000000088a78c in v8::internal::FreeList::CountFreeListItems(v8::internal::Page*, v8::internal::FreeList::SizeStats*) () 
#2  0x00000000007bceb7 in v8::internal::MarkCompactCollector::CollectEvacuationCandidates(v8::internal::PagedSpace*) () 
#3  0x00000000007bd1c3 in v8::internal::MarkCompactCollector::StartCompaction(v8::internal::MarkCompactCollector::CompactionMode) () 
#4  0x00000000007bda45 in v8::internal::MarkCompactCollector::Prepare(v8::internal::GCTracer*) () 
#5  0x00000000007402b8 in v8::internal::Heap::MarkCompact(v8::internal::GCTracer*) () 
#6  0x0000000000744113 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::internal::GCTracer*) () 
#7  0x00000000007444e3 in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollector, char const*, char const*) () 
#8  0x0000000000841d9b in v8::internal::Runtime::PerformGC(v8::internal::Object*) () 
#9  0x0000222219a063da in ?? () 
#10 0x0000222219a062c1 in ?? () 
#11 0x00007fff5186bef0 in ?? () 
#12 0x00007fff5186bf70 in ?? () 
#13 0x000022221a49df07 in ?? () 
#14 0x0000001800000000 in ?? () 
#15 0x000033a04cc04121 in ?? () 
#16 0x0000000000000000 in ?? () 
(gdb) ^Z

[mrjoes]

Also, looks like this issue: https://code.google.com/p/chromium/issues/detail?id=224201

At least stack trace is very similar.

[bnoordhuis]

This won't be fixed in the v0.8 series. The V8 that ships with v0.8 (3.11) is EOL'd and the v0.8 branch itself is in maintenance mode.

I might consider landing a fix if it's small enough that I can be sure it works without causing regressions elsewhere.

[mrjoes]

Updated to 0.10.7 and issue still exists, but stack trace is different.

0x0000000000810d26 in v8::internal::MarkCompactCollector::SweepSpace(v8::internal::PagedSpace*, v8::internal::MarkCompactCollector::SweeperType) () 
(gdb) bt 
#0  0x0000000000810d26 in v8::internal::MarkCompactCollector::SweepSpace(v8::internal::PagedSpace*, v8::internal::MarkCompactCollector::SweeperType) () 
#1  0x000000000081504a in v8::internal::MarkCompactCollector::SweepSpaces() () 
#2  0x0000000000818b42 in v8::internal::MarkCompactCollector::CollectGarbage() () 
#3  0x0000000000787c88 in v8::internal::Heap::MarkCompact(v8::internal::GCTracer*) () 
#4  0x000000000078a9cb in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::internal::GCTracer*) () 
#5  0x000000000078adc3 in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollector, char const*, char const*) () 
#6  0x000000000089464b in v8::internal::Runtime::PerformGC(v8::internal::Object*) ()

[bnoordhuis]

Do you have a test case or some way for me to reproduce the issue?

[mrjoes]

Unfortunately, no. It is live application and we started seeing this behavior starting from node 0.8.x.

Also, it does not happen immediately - only after process hits certain memory limit (appears to be 1 GB).

Will try to come up with test case.