marcominetti / node-memwatch

A NodeJS library to keep an eye on your memory usage, and discover and isolate leaks.
775 stars 63 forks source link

how to trigger the 'leak' event? #14

Open zombieyang opened 8 years ago

zombieyang commented 8 years ago

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

droidenator commented 8 years ago

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.

marcominetti commented 8 years ago

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

buptwinux commented 8 years ago

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 commented 8 years ago

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

zombieyang commented 8 years ago
(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

joeytwiddle commented 7 years ago

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 commented 7 years ago

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' });
    }
});
marcominetti commented 7 years ago

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

egistli commented 7 years ago

@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.