Recent performance regressions

[mscdex]

Version

master

Platform

Linux foo 5.4.0-58-generic #64~18.04.1-Ubuntu SMP Wed Dec 9 17:11:11 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

stream

What steps will reproduce the bug?

No response

How often does it reproduce? Is there a required condition?

No response

What is the expected behavior?

No response

What do you see instead?

No response

Additional information

6cd12be for some reason is causing a noticeable performance regression for stream.Readable.

For example, before that commit:

$ ./node benchmark/streams/readable-bigunevenread.js n=2000

gives ~815 ops/s on my machine. With that commit I get ~640 ops/s. I don't quite entirely understand why stream.Readable is affected here as it's not being changed in that commit, so it could be something V8-related. I did notice in the profiler output with the commit shows a lot more GC activity than before the commit for some reason.

/cc @jasnell

[jasnell]

That's ... Bizarre. Are you able to post some repro code I can test locally? lol.. sorry, I just spotted that you're using one of our benchmarks :-) I'll see what I can find.

[mscdex]

Additionally, I noticed that the wpt url benchmarks are showing regressions as well, which is even more bizarre. For example this specific benchmark:

$ ./node benchmark/url/whatwg-url-properties.js e=13 prop="origin" type="wpt" withBase="false"

I used a larger e value here to let the process run longer to get more stable results. Before commit: ~25 million, after commit: ~23 million.

[jasnell]

O.o .... ooooh-kay. Just a thought, but maybe it's not impacting Readable or URL stuff directly... maybe it's impacting the benchmark runner itself? Specifically, since fs loads fs.promises automatically, and since this adds sme additional imports to fs.promises, maybe that's impacting things? I dunno, that's just a wild shot in the dark. The additional gc tho makes me think that's where the perf loss is coming from and that could be getting triggered by the fs.promises module include.

We can test that possibility by making the additional imports in fs/promises.js lazy.

[mscdex]

I'm wondering if it's something to do with the snapshot. I've tried to whittle the issue down by process of elimination and what I've found in one particular instance is that if I comment out:

const {
  ReadableStream,
  isReadableStream,
} = require('internal/webstreams/readablestream');

const {
  WritableStream,
  isWritableStream,
} = require('internal/webstreams/writablestream');

in internal/webstreams/adapters.js and comment out:

const {
  readableStreamCancel,
} = require('internal/webstreams/readablestream');

in internal/fs/promises.js and I have internal/webstreams/util.js only export at most 12 values, then the performance comes back. If I uncomment any of the lines in the previous files or I add any one extra export (it doesn't seem to matter which one) in internal/webstreams/util.js, the performance drops again.

[mscdex]

My hunch was right. If I compile without the snapshot, the performance bounces back (almost nearly). With the snapshot, I get the slow performance again.

I wonder if we're hitting some kind of snapshot size limit that causes built-in code to take a performance hit?

[mscdex]

/cc @joyeecheung maybe you can help shed some light on this as you've done some work on snapshots?

[joyeecheung]

Neither fs/promises.js nor the webstream modules are included in the snapshot (tips: use NODE_DEBUG_NATIVE=mksnapshot out/Release/node and look for the // -- native_modules begins -- section), so I suspect the commit introduces subtle changes to the timing at which the GC kicks in, and disabling snapshots probably did something similar. I wonder what would happen if the modules are included in the snapshot, or if the benchmarks are modified to do the work for a while to make sure things are in a steady state before measuring the performance.

[mscdex]

@joyeecheung Running the same loops before bench.start() does not seem to change anything from my testing.

[mscdex]

I can't test including fs/promises in the snapshot because it results in a syntax error at the close = () => in that module while running the doc tests. I don't understand why this is happening because this syntax is obviously supported in the master branch. I've even ran the failing command directly from my shell using the built binary to ensure it's not using the system/global binary but still no luck.

However, running the benchmark after simply adding require('fs/promises') to the bootstrap.js the performance does nearly bounce back to before the problematic commit.

[joyeecheung]

@mscdex That is a known bug being addressed in https://chromium-review.googlesource.com/c/v8/v8/+/2988830