Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Why does this node.js loop run slowly after 112050 iterations?

I was playing around with node.js and I found that this simple program is running incredibly slowly, and I didn't even wait around to see how long it took after 3 minutes had passed.

var fs = require ('fs')
var s = fs.createWriteStream("test.txt");
for (i = 1; i <= 1000000; i++)
      s.write(i+"\n");
s.end()

I experimented using different values, and found that while 1-112050 takes 3 seconds, 1-112051 takes over a minute. This sudden dropoff is strange. The same program in python, or the equivalent shell script 'seq 1 112051` runs in a reasonable amount of time (0-2 seconds).

Note that this node.js app runs much faster:

var fs = require('fs')
     , s = []
for (var i = 1; i <= 1000000; i++) s.push(i.toString())
s.push('')
fs.writeFile('UIDs.txt', s.join('\n'), 'utf8')

Can anyone explain to me why node.js behaves this way, and why the dropoff is so sudden?

like image 253
Tony Biondo Avatar asked Jan 27 '13 23:01

Tony Biondo


2 Answers

This happens because for cycle is synchronous, but Writable.write() is not. For your example s.write creates one million chuncks queue. That causes more than one million function calls (like this) to process this queue. So, Writable.write is not designed for small chunks. You can check sources of Writable.write to get more info about it.

like image 102
Vadim Baryshev Avatar answered Oct 11 '22 07:10

Vadim Baryshev


It's a buffer that gets filled up. Each write will return true or false depending on the state of the kernel buffer.

If you start listen to the return code and use the drain event, it will at least be consistant in speed.

var fs = require ('fs') 

function runTest(stop) {
  var s = fs.createWriteStream("test.txt");
  var startTime = Date.now();
  var c = 1;
  function doIt() {
    while (++c <= stop) {
      if (!s.write(c+"\n")) {
        s.once('drain', doIt);
        return;
      }
    }

    s.end();
    var diffTime = Date.now() - startTime;
    console.log(stop+': took '+diffTime+'ms, per write: '+(diffTime/stop)+'ms')
  }

  doIt();
}

runTest(10000);
runTest(100000);
runTest(1000000);
runTest(10000000);
runTest(100000000);

Output:

$ node test.js
10000: took 717ms, per write: 0.0717ms
100000: took 5818ms, per write: 0.05818ms
1000000: took 42902ms, per write: 0.042902ms
10000000: took 331583ms, per write: 0.0331583ms
100000000: took 2542195ms, per write: 0.02542195ms
like image 36
vogonistic Avatar answered Oct 11 '22 09:10

vogonistic