node-memwatch icon indicating copy to clipboard operation
node-memwatch copied to clipboard

how to trigger the 'leak' event?

Open zombieyang opened this issue 8 years ago • 9 comments

I've run all of the example, but no one could trigger this event...

zombieyang avatar Mar 28 '16 03:03 zombieyang

I'm seeing the same thing. Stats event fires without issue and even though my usage_trend is like..22 and memory usage has grown over 5+ GCs, the leak event is never fired.

droidenator avatar Apr 07 '16 18:04 droidenator

@xosuperpig can you provide an example to generate a leak?

marcominetti avatar Apr 30 '16 10:04 marcominetti

I have also run all of example, but the "leak" event could not triggered... just like this:

var hd;
 memwatch.on('leak', function(info) {
     console.log("leak:\n");
     console.error(info);
     if (!hd) {
         hd = new memwatch.HeapDiff();
     } else {
         var diff = hd.end();
         console.error(util.inspect(diff, true, null));
         hd = null;
     }
    console.error('memory leak detected: ', info);
});

thank you very mach!

buptwinux avatar May 16 '16 03:05 buptwinux

@droidenator , did your problem keep on?how solve it?

buptwinux avatar May 16 '16 06:05 buptwinux

(function() {
    var i = 0;
    function run() {
        return new Promise(function(resolve) {
            if (i % 10000 === 0) console.log(process.memoryUsage());
            i++;
            setTimeout(function() {
                if(i === 10000 * 10) return resolve();
                resolve(run());
            }, 0);
        }).then(function() {});
    }
    run();
})();

this is a Promise leak example in node 4.2 lts @marcominetti

zombieyang avatar May 20 '16 13:05 zombieyang

I'm running node on a Mac Book Pro. I notice that garbage collection is sometimes running in pairs quite close together, and the second one reclaims a little bit of memory that the first did not.

As a result, my process never fulfils the "5 increases in a row" condition, despite the overall memory usage increasing!

Example log:

[log] (modules/debugTools.js:105:29)      naive:    111356664
[log] (modules/debugTools.js:105:29)      naive:    165723376
[log] (modules/debugTools.js:112:29)      postgc:   210520304   <--
[log] (modules/debugTools.js:105:29)      naive:    217459856
[log] (modules/debugTools.js:105:29)      naive:    246305776
[log] (modules/debugTools.js:112:29)      postgc:   261949272   <-- increase
[log] (modules/debugTools.js:105:29)      naive:    286845272
[log] (modules/debugTools.js:105:29)      naive:    322883080
[log] (modules/debugTools.js:105:29)      naive:    394269064
[log] (modules/debugTools.js:105:29)      naive:    430305896
[log] (modules/debugTools.js:105:29)      naive:    466342728
[log] (modules/debugTools.js:105:29)      naive:    555195016
[log] (modules/debugTools.js:105:29)      naive:    591238152
[log] (modules/debugTools.js:105:29)      naive:    621307808
[log] (modules/debugTools.js:105:29)      naive:    657373616
[log] (modules/debugTools.js:105:29)      naive:    772633808
[log] (modules/debugTools.js:112:29)      postgc:   765572840   <-- increase
[log] (modules/debugTools.js:105:29)      naive:    801502320
[log] (modules/debugTools.js:105:29)      naive:    837576568
[log] (modules/debugTools.js:112:29)      postgc:   752163536     <-- decrease
[log] (modules/debugTools.js:105:29)      naive:    778027472
[log] (modules/debugTools.js:105:29)      naive:    814065312
[log] (modules/debugTools.js:105:29)      naive:    850105616
[log] (modules/debugTools.js:105:29)      naive:    886142184
[log] (modules/debugTools.js:105:29)      naive:    1033814136
[log] (modules/debugTools.js:105:29)      naive:    1062652456
[log] (modules/debugTools.js:105:29)      naive:    1100131120
[log] (modules/debugTools.js:105:29)      naive:    1136174304
[log] (modules/debugTools.js:105:29)      naive:    1172210776
[log] (modules/debugTools.js:105:29)      naive:    1208247248
[log] (modules/debugTools.js:105:29)      naive:    1237084008
[log] (modules/debugTools.js:105:29)      naive:    1273126792
[log] (modules/debugTools.js:105:29)      naive:    1301980896
[log] (modules/debugTools.js:105:29)      naive:    1338017520
[log] (modules/debugTools.js:105:29)      naive:    1374053992
[log] (modules/debugTools.js:105:29)      naive:    1433063768
[log] (modules/debugTools.js:112:29)      postgc:   1563459896   <-- increase
[log] (modules/debugTools.js:112:29)      postgc:   1430329544   <-- decrease
[log] (modules/debugTools.js:105:29)      naive:    1462015280
[log] (modules/debugTools.js:112:29)      postgc:   1343619976   <--
[log] (modules/debugTools.js:112:29)      postgc:   1343478256   <-- decrease
[log] (modules/debugTools.js:105:29)      naive:    1354060952
[log] (modules/debugTools.js:105:29)      naive:    1390162888
[log] (modules/debugTools.js:105:29)      naive:    1426208992
[log] (modules/debugTools.js:105:29)      naive:    1455071568
FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - process out of memory

<--- Last few GCs --->

  204211 ms: Scavenge 1398.3 (1454.9) -> 1398.3 (1454.9) MB, 0.5 / 0 ms (+ 2.1 ms in 1 steps since last GC) [allocation failure] [incremental marking delaying mark-sweep].
  206404 ms: Mark-sweep 1398.3 (1454.9) -> 1396.5 (1454.9) MB, 2192.8 / 0 ms (+ 3.2 ms in 2 steps since start of marking, biggest step 2.1 ms) [last resort gc].
  208034 ms: Mark-sweep 1396.5 (1454.9) -> 1396.5 (1454.9) MB, 1630.2 / 0 ms [last resort gc].

The leak is detected fine when I use slightly_leaky.js with i < 100000. But the above is when I drop the same setInterval() into my app. (The app is supposed to be idle!) So I guess it's something else going on in my app that throws off the detection.

I wonder if we could use a different condition for detection. Perhaps something like "over threshold T after 5 consecutive GCs" where T can be set manually, or perhaps chosen as "10 x the memory usage one minute after startup".

Notably the problematic gc pairs do not occur when I reduce the speed at which the leak grows, so perhaps I am just being too aggressive/impatient with my tests.

joeytwiddle avatar Oct 26 '16 08:10 joeytwiddle

In the meantime, you can fake a 'leak' event like this...

memwatch.on('stats', function(d) {
    // If the app is using more than 3GB RAM
    if (d.current_base > 3000000000) {
        // Either call your leak handling function directly:
        // ...

        // or manually trigger a 'leak' event, for what it's worth:
        memwatch.emit('leak', { growth: d.current_base, reason: 'app using too much RAM lol' });
    }
});

joeytwiddle avatar Oct 26 '16 08:10 joeytwiddle

hi @joeytwiddle, i'll delve into this on monday... ;)

marcominetti avatar Oct 28 '16 06:10 marcominetti

@xosuperpig I modified the leaking http server in the example a bit and ran the http server for a while then memwatch did emit several leak events. What I modified is to reduce the interval of leaking from 1000 to 10.

egistli avatar May 03 '17 15:05 egistli