Pipe/stream performance regression after v2.5.0

[mhart]

(extracting from #3429)

Not sure if this is something that's well known and/or being worked on, but just in case it's not flagged somewhere: certain streams (pipes?) still appear (as of v4.2.1) to be at only 70% of the performance they were in v2.5.0 and prior.

Here's how the performance looks for different node.js versions reading from the stdout of a spawned cat process on a 2GB file (the results are similar for reading from stdin):

Generated using bench.sh (after npm install -g nave):

#!/bin/bash

VERSIONS="4.2.1 0.12.7 0.10.40 2.5.0 3.0.0 3.1.0"

fallocate -l 2000000000 file.dat

for i in 0 1 2 3 4 5; do
  for v in $VERSIONS; do
    nave use $v node spawn.js
  done
done

spawn.js:

var spawn = require('child_process').spawn

var FILE = process.argv[2] || 'file.dat'
var SIZE_MB = 2000

spawnPipe(function(err, time) {
  if (err) return console.error(err.stack || err)
  console.log([process.version, time].join(','))
})

function spawnPipe(cb) {
  var bytesRead = 0
  var time = process.hrtime()
  var cat = spawn('cat', [FILE], {stdio: ['ignore', 'pipe', 'ignore']})

  cat.stdout.on('data', function(data) {
    bytesRead += data.length
  })
  cat.on('error', cb)
  cat.on('close', function(code) {
    if (code !== 0) return cb(new Error('cat exited with: ' + code))
    if (bytesRead != SIZE_MB * 1000 * 1000) return cb(new Error('Incorrect bytes read: ' + bytesRead))
    var diff = process.hrtime(time)
    cb(null, SIZE_MB / (diff[0] + diff[1] / 1e9))
  })
}

[mhart]

Actually it's similar on OS X for these versions too (excluding v0.10.40 which is much faster due to whatever caused #3475)

So v4.2.1 is at about 60% of the performance of v2.5.0 here

[silverwind]

v2.5.0...v3.0.0

[mscdex]

If I had to guess, it would be the v8 changes that affected the Buffer implementation.

[mhart]

Yeah, figured something like that. Obviously the work that went into v3.1.0 mitigated the drop in v3.0.0 somewhat (on Linux anyway), but as of v4.2.1 still not back near v2.5.0 performance.

[jasnell]

is this still an issue?

[mhart]

I put a fair bit of work into creating a reproducible case there to be honest – can you not reproduce this?

[Trott]

@mhart I added some more recent versions of Node.js, and (on OS X) I got the same results as you with nothing significant changing in more recent versions.

So, yeah, @jasnell and anyone else interested: Still a problem. :-/

[addaleax]

I narrowed it down using bisecting (that was a lot harder than thought), and I’m pretty certain for the v0.12 -> v3 jump the Buffer -> Uint8Array changes are, as already suggested, responsible.

For the second jump from v3 to v4, that is the result of #2352, which fixed a memory leak and unnecessary copying here.

[Fishrock123]

I'm gona close this then, we can re-open if more progress is made but I think @trevnorris already squeezed about as much basic buffer perf out of V8 as was reasonably attainable at the time of the change(es). :/

Let's nail this to "a V8 limitation"...

[mhart]

So @Fishrock123 what's the limitation?

This doesn't seem to have had much research besides narrowing down the commit

Seems kinda lame that we can't progress in performance over v2.5.0!

[mhart]

I also thought one of the main purposes of the benchmarking group was to:

avoid performance regressions between releases

Has the benchmarking group looked at this at all?

[trevnorris]

I'm showing a slight performance regression, but not as large a gap as you've shown.

v0.12.9    3180 MB/sec
v4.4.7     2701 MB/sec
v7.0.0-pre 2832 MB/sec

Though, let's make a slight adjustment to the example script and run the test again:

   var bytesRead = 0
   var time = process.hrtime()
   var cat = spawn('cat', [FILE], {stdio: ['ignore', 'pipe', 'ignore']})
+  var cntr = 0

   cat.stdout.on('data', function(data) {
+    if (++cntr > 100) {
+      gc(true)
+      cntr = 0
+    }
     bytesRead += data.length
   })
   cat.on('error', cb)

Results:

v0.12.9    3516 MB/sec
v4.4.7     3515 MB/sec
v7.0.0-pre 3527 MB/sec

The additional impact GC has on node because of the switch to using typed arrays is known (issue #1671).

[mhart]

Ooh, nice. So you think it's probably a GC issue?

[mhart]

(if so, all good – it certainly looks like it considering you can eliminate the regression by gc'ing – so happy with this being closed as a specific case of #1671 👍 – thanks for the research @trevnorris!)