Loop of console.log in nodejs

Question

My MCVE is the following

var i = 0;
for(;;)
    console.log(i++)

When I do this, at a certain moment, my nodejs just stops printing stuff, giving me an output that looks like this

[...]
684665
684666
684667

And then, I got this :

<--- Last few GCs --->

   69097 ms: Scavenge 1397.2 (1456.7) -> 1397.2 (1456.7) MB, 0.8 / 0 ms (+ 1.7 ms in 1 steps since last GC) [allocation failure] [incremental marking delaying mark-sweep].
   70462 ms: Mark-sweep 1397.2 (1456.7) -> 1396.0 (1456.7) MB, 1364.9 / 0 ms (+ 2.8 ms in 2 steps since start of marking, biggest step 1.7 ms) [last resort gc].
   71833 ms: Mark-sweep 1396.0 (1456.7) -> 1397.1 (1456.7) MB, 1370.2 / 0 ms [last resort gc].


<--- JS stacktrace --->

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

Security context: 0xcdf79d37399 <JS Object>
    1: formatPrimitive(aka formatPrimitive) [util.js:~411] [pc=0x634d9f4113f] (this=0xcdf79d04131 <undefined>,ctx=0x17b18f4d561 <an Object with map 0x32fd25043ef9>,value=16248021)
    2: formatValue(aka formatValue) [util.js:223] [pc=0x634d9f1fdbb] (this=0xcdf79d04131 <undefined>,ctx=0x17b18f4d561 <an Object with map 0x32fd25043ef9>,value=16248021,recurseTimes=2)
    3: inspect(aka inspect) [uti...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - process out of memory
[1]    19446 abort (core dumped)  node

I was wondering, what can console.log do that could lead to an out of memory error ?

Answer 1

After opening an issue on the nodejs repository, I got the following answer :

It's expected behavior: console.log is asynchronous, the memory associated with each call cannot be reclaimed until the next tick of the event loop. In your example that next tick never happens because of the infinite loop. If you rewrite your example to a callback-driven approach, it keeps running forever:

 let i = 0;
 const next = () => process.stdout.write(`${i++}\n`, next);
 next();

Answer 2

According to this discussion : https://groups.google.com/forum/#!topic/nodejs/KtONbpVV68U

Every time you call console.log (or an other logging method), the console object will allocate some memory. This memory will be free by the garbage collector on its next tick. But if you have a too big loop, the next tick never come.

But i tested this :

setInterval(function() {
    for (var i = 0; i < 100000; ++i) {
        console.log(i);
    }
}, 10000)

According to the google group discussion, between each interval, NodeJS garbage collector should free the allocated memory by the console.log. But it is not. Every time the loop is running, my process take more RAM.

I also tested this :

var fs = require('fs')
var output = fs.createWriteStream('./stdout.log');
var errorOutput = fs.createWriteStream('./stderr.log');
var logger = new console.Console(output, errorOutput);

var i = 0;
for (;;) {
    logger.log(i++);
}

The behavior is the same. The process take more and more RAM until it crash (because nore more RAM is available). And the file stdout.log is always empty.

Finally, i tested this :

var fs = require('fs')
var output = fs.createWriteStream('./stdout.log');
var errorOutput = fs.createWriteStream('./stderr.log');
var logger = new console.Console(output, errorOutput);

setInterval(function() {
    for (var i = 0; i < 100000; i++) {
        logger.log(i);
    }
}, 5000)

This example is interesting. Because between each interval, stdout.log is written (the lines are appended to the file) and the RAM reclaimed by the process doesn't grow. Between each interval the garbage collector do its works.

I think the console object does not handle well the buffer. But it is still weird. If you use the standard output (with just a console.log), it's look the console object keep in memory everthing printed so far. And it is never cleanse. And if you use a file ouput, everything works fine (except if you write it in an infinity loop, of course).

Maybe it's because of the NodeJS version, i'm working with a NodeJS 0.12.7