nodejs / node

Node.js JavaScript runtime ✨🐢🚀✨
https://nodejs.org
Other
107.38k stars 29.5k forks source link

Memory leak with debugger running. #28787

Open laino opened 5 years ago

laino commented 5 years ago

Edit: Removed information about https://github.com/nodejs/node/issues/28786 making this hard to debug, as it has been fixed in v12.7.0.

This bug might also be the same as, or related to, this bug, but because I'm unsure whether it's the same and because this one contains a minimal example, I've filed a separate issue.

Run this with node --inspect script.js and attach chrome:

// edit: simplified example

async function noop() {}

async function run() {
    while (true) {
        await noop();
    }
}

run();

You can see memory usage getting out of hand as soon as you attach google chrome:

5454 Before connecting with Chrome's debugger.

5455 A few seconds after connecting with Chrome's debugger.

This is what you see if you manage to grab a heapdump before it crashes: 5468

The eventual crash when it runs out of memory is in a comment below.

laino commented 5 years ago

Crash when OOM (second snippet):

<--- Last few GCs --->

[60458:0x5560095f1530]    45932 ms: Scavenge 566.8 (590.2) -> 558.2 (593.7) MB, 10.8 / 0.4 ms  (average mu = 0.908, current mu = 0.910) allocation failure 
[60458:0x5560095f1530]    46020 ms: Scavenge 570.2 (593.7) -> 561.6 (597.7) MB, 11.2 / 0.5 ms  (average mu = 0.908, current mu = 0.910) allocation failure 
[60458:0x5560095f1530]    46109 ms: Scavenge 573.7 (597.7) -> 565.0 (601.2) MB, 11.1 / 0.4 ms  (average mu = 0.908, current mu = 0.910) allocation failure 

<--- JS stacktrace --->

==== JS stack trace =========================================

    0: ExitFrame [pc: 0x31adef4cfc5d]
Security context: 0x1b8c2271d9f1 <JSObject>
    1: add [0x1b8c22710799](this=0x0cfffcab14c9 <Set map = 0x35009eb83d81>,16777221)
    2: emitInitNative [0x1785e2a84459] [internal/async_hooks.js:~126] [pc=0x31adef569587](this=0x1d0ff1195b01 <PromiseWrap map = 0x35009ebc67c1>,16777221,0x1b8c22724591 <String[7]: PROMISE>,16767983,0x1d0ff1195b01 <PromiseWrap map = 0x35009ebc67c1>)
    3: InternalFrame [pc:...

FATAL ERROR: invalid table size Allocation failed - JavaScript heap out of memory
 1: 0x55600854c761 node::Abort() [node]
 2: 0x55600854e255 node::OnFatalError(char const*, char const*) [node]
 3: 0x5560086f4002 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
 4: 0x5560086f425b v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
 5: 0x556008a8b573  [node]
 6: 0x556008bf3891 v8::internal::OrderedHashTable<v8::internal::OrderedHashSet, 1>::Allocate(v8::internal::Isolate*, int, v8::internal::PretenureFlag) [node]
 7: 0x556008bf6981 v8::internal::OrderedHashTable<v8::internal::OrderedHashSet, 1>::Rehash(v8::internal::Isolate*, v8::internal::Handle<v8::internal::OrderedHashSet>, int) [node]
 8: 0x556008cbd4f2 v8::internal::Runtime_SetGrow(int, v8::internal::Object**, v8::internal::Isolate*) [node]
 9: 0x31adef4cfc5d 
Aborted (core dumped)
alexkozy commented 5 years ago

It might be related to async stacks that inspector is capturing when debugger is enabled.

targos commented 3 years ago

Is it still relevant?

marcbachmann commented 2 years ago

Yes, it is... or again. As soon as chrome is connected, it leaks quite a lot. I'm seeing the issue on mac. with node v16.13.1

leak.js ```js const fastify = require('fastify')() fastify.get('/', async () => 'ok') fastify.listen(8000) ```
  1. execute node --inspect leak.js
  2. run autocannon http://localhost:8000 > no leak
  3. connect to the process using the inspector of chrome
  4. run autocannon http://localhost:8000 > leak

Just. after one autocannon run: image

With a gc() run before every process.memoryUsage() call:

setInterval(() => { gc(); console.log(process.memoryUsage())}, 5000)
{rss: 454283264, heapTotal: 19218432, heapUsed: 9223752, external: 850876, arrayBuffers: 32954}
{rss: 681766912, heapTotal: 31547392, heapUsed: 9528048, external: 850916, arrayBuffers: 32954}
{rss: 856518656, heapTotal: 31809536, heapUsed: 9558776, external: 850192, arrayBuffers: 32954}
{rss: 1048981504, heapTotal: 32333824, heapUsed: 9671536, external: 850192, arrayBuffers: 32954}
{rss: 1229918208, heapTotal: 32333824, heapUsed: 9656000, external: 850192, arrayBuffers: 32954}
{rss: 1429995520, heapTotal: 32595968, heapUsed: 9641936, external: 850192, arrayBuffers: 32954}
{rss: 1599672320, heapTotal: 32595968, heapUsed: 9663888, external: 850192, arrayBuffers: 32954}
{rss: 1710706688, heapTotal: 32858112, heapUsed: 9700616, external: 850192, arrayBuffers: 32954}
{rss: 1830445056, heapTotal: 49635328, heapUsed: 9669224, external: 850192, arrayBuffers: 32954}
{rss: 1911767040, heapTotal: 48324608, heapUsed: 9987640, external: 850192, arrayBuffers: 32954}
{rss: 1978179584, heapTotal: 49373184, heapUsed: 9655744, external: 850192, arrayBuffers: 32954}

The heap stays low here, so it might not be an issue.