Strange memory leaks

[vitaly-t]

I'm using NodeJS 4.1.1, 64-bit on Windows 10.

In my simple application I'm calculating a sequence of primes and writing them into the console.

Here's the entire application:

function nextPrime(value) {
    if (value > 2) {
        var i, q;
        do {
            i = 3;
            value += 2;
            q = Math.floor(Math.sqrt(value));
            while (i <= q && value % i) {
                i += 2;
            }
        } while (i <= q);
        return value;
    }
    return value === 2 ? 3 : 2;
}

var value;
for (var i = 0; i < 1000000000; i++) {
    value = nextPrime(value);
    console.log(value);
}

However, when running it, the application starts eating up memory quite fast. I don't understand why, since I am making no memory allocation of any kind, it is just a plain calculation algorithm without any complexity.

After running it for about 5 mins, the app crashes as shown below, before it even gets to calculate the first 100m primes.

98857459
98857469
98857483
98857523
98857531
98857547

<--- Last few GCs --->

  287726 ms: Scavenge 1400.7 (1456.6) -> 1400.7 (1456.6) MB, 2.7 / 0 ms (+ 0.0 m
s in 1 steps since last GC) [allocation failure] [incremental marking delaying m
ark-sweep].
  288428 ms: Mark-sweep 1400.7 (1456.6) -> 1391.7 (1456.6) MB, 705.4 / 0 ms (+ 0
.0 ms in 2 steps since start of marking, biggest step 0.0 ms) [last resort gc].
  289131 ms: Mark-sweep 1391.7 (1456.6) -> 1391.9 (1456.6) MB, 706.8 / 0 ms [las
t resort gc].


<--- JS stacktrace --->

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

Security context: 0000025754B37349 <JS Object>
    1: formatPrimitive(aka formatPrimitive) [util.js:~386] [pc=000001A41133E1E3]
 (this=0000025754B04131 <undefined>,ctx=0000025754BFFE29 <an Object with map 000
000CA21A4B6F1>,value=98857573)
    2: formatValue(aka formatValue) [util.js:213] [pc=000001A4113219BB] (this=00
00025754B04131 <undefined>,ctx=0000025754BFFE29 <an Object with map 000000CA21A4
B6F1>,value=98857573,recurseTimes=2)
    3: ...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - process out of memory

[vitaly-t]

UPDATE

I can see now that this is all about the console output. If we write into the console fast, Node JS process quickly consumes over 1GB of memory and then crashes.

I did not expect that.

Turning off the console output stops the memory leak.

Is this a known problem and/or how to deal with such a problem?

[smartmouse]

Hi I played around with your sample in my environment.

A few comments.

node.js single threaded, you are looping it , this is not the "recommended" way to use node. The process will get into 100% CPU..

I trigger a core dump and checked the memory and found that

it has a large number functions and object type being allocated.

!jsobject 0x00001004b2f18b29 JS_FUNCTION_TYPE 8411788 5 length, name, arguments, caller, prototype
!jsobject 0x00001004b2f07be1 JS_OBJECT_TYPE 4205608 Object 2 callback, domain

[mscdex]

This is a known "issue" since writing to stdout in the case of a tty/console is async. So logging a lot of data very fast could very well cause a lot of writes to be buffered in memory if the tty/console cannot keep up.

Try writing to a file (synchronously) instead (e.g. fs.appendFileSync()) and that should work as well.

[ChALkeR]

Dupe of #1741.
See also #2970.

[ChALkeR]

Try redirecting the output to a file, it should help as a work-around.

[Qix-]

If this is literally all your script is doing, use setImmediate().

function nextPrime(value) {
    if (value > 2) {
        var i, q;
        do {
            i = 3;
            value += 2;
            q = Math.floor(Math.sqrt(value));
            while (i <= q && value % i) {
                i += 2;
            }
        } while (i <= q);
        return value;
    }
    return value === 2 ? 3 : 2;
}

var i = 0;
var value;
function doNextPrime() {
    if (i < 1000000000) {
        value = nextPrime(value);
        console.log(value);
        i++;

        setImmediate(doNextPrime);
    }
}

doNextPrime();

Node isn't built to do extensive primitive loops like what you're doing. In my opinion this is less Node's fault and more the misunderstanding of how Node's IO works.

What setImmediate() is doing is essentially what yield() is to lower level programs; it allows other async items in the pool to be collected and basically schedules a function to be executed after everything currently in the queue.

Running the modified program doesn't cause it to slow down as much and memory hovers around ~45M.

[ChALkeR]

@Qix- The example you provided does not work.

[Qix-]

@ChALkeR it does; had a typo in there. Fixed.

[ChALkeR]

@Qix- Ok, it works now after the fix. I'm still not sure why do you call setImmediate(doNextPrime); 1000000000 times from each doNextPrime, but whatever. Update: you don't, I overlooked that. Sorry.

Note that your answer is not correct, though. Using setImmediate would not help here in a general case — if the terminal processes the messages slower than your program fires them, the queue will eventually fill up and chew all the memory, and the process will crash.

Example:

var str = 'dssf'.repeat(100);

function next() {
  for (var i = 0; i < 100; i++) {
    console.log(str);
  }
  setImmediate(next);
}

next();

[Qix-]

@ChALkeR take a closer look at the example. The call to setImmediate() isn't in a loop. It's called exactly once per event loop iteration. It exactly solves the problem. 💃

[ChALkeR]

@Qix-

Edit Ah, sorry. It's not in the loop, I missed that.

[ChALkeR]

@Qix- Still it fixes things here only by making it piping slower, not by the means you described.

See the example in #3171 (comment).

[Qix-]

@ChALkeR What do you mean making piping slower?

[zhoujinhai]

@vitaly-t I have the same problem ,can you solved it?

<--- Last few GCs --->

[8368:0000024B6DC9E160]    48233 ms: Mark-sweep 1409.9 (1464.0) -> 1409.9 (1448.0) MB, 844.2 / 0.0 ms  (+ 0.0 ms in 0 steps since start of marking, biggest step 0.0 ms, walltime since start of marking 844 ms) last resort
[8368:0000024B6DC9E160]    49077 ms: Mark-sweep 1409.9 (1448.0) -> 1409.9 (1448.0) MB, 843.4 / 0.0 ms  last resort


<--- JS stacktrace --->

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

    2: arguments adaptor frame: 3->1
Security context: 0000019674029891 <JS Object>
    3: InnerArrayForEach(aka InnerArrayForEach) [native array.js:~776] [pc=00000268C83646D4](this=000003F21AB82311 <undefined>,bd=0000019903B1F7C9 <JS Function self.globalOnlyOptions.forEach.globalOnlyOption (SharedFunctionInfo 0000036F3E8A90F1)>,be=000003F21AB82311 <undefined>,p=0000004CA1DFFF29 <JS Array[6]>,q=6)
    4: forEach [native array.js:~794] [pc...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory

[vitaly-t]

@zhoujinhai
It was marked as a dupe, and the issue was explained along with the solution. See above.

[zhoujinhai]

@vitaly-t thanks