why does attempting to write a large file cause js heap to run out of memory

Question

this code

const file = require("fs").createWriteStream("./test.dat");
for(var i = 0; i < 1e7; i++){

    file.write("a");
}

gives this error message after running for about 30 seconds

<--- Last few GCs --->

[47234:0x103001400]    27539 ms: Mark-sweep 1406.1 (1458.4) -> 1406.1 (1458.4) MB, 2641.4 / 0.0 ms  allocation failure GC in old space requested
[47234:0x103001400]    29526 ms: Mark-sweep 1406.1 (1458.4) -> 1406.1 (1438.9) MB, 1986.8 / 0.0 ms  last resort GC in old spacerequested
[47234:0x103001400]    32154 ms: Mark-sweep 1406.1 (1438.9) -> 1406.1 (1438.9) MB, 2628.3 / 0.0 ms  last resort GC in old spacerequested


<--- JS stacktrace --->

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

Security context: 0x30f4a8e25ee1 <JSObject>
    1: /* anonymous */ [/Users/matthewschupack/dev/streamTests/1/write.js:~1] [pc=0x270efe213894](this=0x30f4e07ed2f1 <Object map = 0x30f4ede823b9>,exports=0x30f4e07ed2f1 <Object map = 0x30f4ede823b9>,require=0x30f4e07ed2a9 <JSFunction require (sfi = 0x30f493b410f1)>,module=0x30f4e07ed221 <Module map = 0x30f4edec1601>,__filename=0x30f493b47221 <String[49]: /Users/matthewschupack/dev/streamTests/...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [/usr/local/bin/node]
 2: node::FatalException(v8::Isolate*, v8::Local<v8::Value>, v8::Local<v8::Message>) [/usr/local/bin/node]
 3: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/usr/local/bin/node]
 4: v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [/usr/local/bin/node]
 5: v8::internal::Runtime_AllocateInTargetSpace(int, v8::internal::Object**, v8::internal::Isolate*) [/usr/local/bin/node]
 6: 0x270efe08463d
 7: 0x270efe213894
 8: 0x270efe174048
[1]    47234 abort      node write.js

whereas this code

const file = require("fs").createWriteStream("./test.dat");
for(var i = 0; i < 1e6; i++){

    file.write("aaaaaaaaaa");//ten a's
}

runs perfectly almost instantly and produces a 10MB file. As I understood it, the point of streams is that both versions should run in about the same amount of time since the data is identical. Even increasing the number of as to 100 or 1000 per iteration hardly increases the running time even and writes a 1GB file without any issues. Writing a single character per iteration at 1e6 iterations also works fine.

What's going on here?

Answer 1

The out of memory error happens because you're not waiting for the drain event to be emitted, without waiting Node.js will buffer all written chunks until maximum memory usage occurs.

.write will return false if the internal buffer is greater than highWaterMark which defaults to 16384 bytes (16kb). In your code, you're not handling the return value of .write, and so the buffer is never flushed.

This can be tested very easily using: tail -f test.dat

When executing your script, you will see that nothing is being written on test.dat until the script finishes.

For 1e7 the buffer should be cleared 610 times.

1e7 / 16384 = 610

---

A solution is to check for .write return value and if false is returned, use file.once('drain') wrapped in a promise to wait until drain event is emitted

NOTE: writable.writableHighWaterMark was added in node v9.3.0

const file = require("fs").createWriteStream("./test.dat");

(async() => {

    for(let i = 0; i < 1e7; i++) {
        if(!file.write('a')) {
            // Will pause every 16384 iterations until `drain` is emitted
            await new Promise(resolve => file.once('drain', resolve));
        }
    }
})();

Now if you dotail -f test.dat you will see how data is being written while the script is still running.

---

As of why you get memory issues with 1e7 and not 1e6 we have to take a look into how Node.Js does the buffering, that happen at the writeOrBuffer function.

This sample code will allow us to have a rough estimate of the memory usage:

const count = Number(process.argv[2]) || 1e6;
const state = {};

function nop() {}

const buffer = (data) => {
    const last = state.lastBufferedRequest;
    state.lastBufferedRequest = {
      chunk: Buffer.from(data),
      encoding: 'buffer',
      isBuf: true,
      callback: nop,
      next: null
    };

    if(last)
      last.next = state.lastBufferedRequest;
    else
      state.bufferedRequest = state.lastBufferedRequest;

    state.bufferedRequestCount += 1;
}

const start = process.memoryUsage().heapUsed;
for(let i = 0; i < count; i++) {
    buffer('a');
}
const used = (process.memoryUsage().heapUsed - start) / 1024 / 1024;
console.log(`${Math.round(used * 100) / 100} MB`);

When executed:

// node memory.js <count>
1e4: 1.98 MB
1e5: 16.75 MB
1e6: 160 MB
5e6: 801.74 MB
8e6: 1282.22 MB
9e6: 1442.22 MB - Out of memory
1e7: 1602.97 MB - Out of memory

So each object uses ~0.16 kb, and when doing 1e7 writes without waiting for drain event, you have 10 million of those objects in memory (To be fair it crashes before reaching 10M)

It doesn't matter if you use a single a or 1000, the memory increase from that is negligible.

---

You can increase the max memory used by node with --max_old_space_size={MB} flag (Of course this is not the solution, is just for checking the memory consumption without crashing the script):

node --max_old_space_size=4096 memory.js 1e7

UPDATE: I made a mistake on the memory snippet which led to a 30% increase on memory usage. I was creating a new callback for every .write, Node reuses nop callback.

---

UPDATE II

If you're writing always the same value (doubtful in a real scenario), you can reduce greatly the memory usage & execution time by passing the same buffer every time:

const buf = Buffer.from('a');
for(let i = 0; i < 1e7; i++) {
    if(!file.write(buf)) {
        // Will pause every 16384 iterations until `drain` is emitted
        await new Promise(resolve => file.once('drain', resolve));
    }
}