Node: Sudden performance drop after multiple executions

[NeilFraser]

• Version: v8.2.1
• Platform: MacOS 10.12.6 and Debian 4.9.30

Node experiences a sudden and permanent drop in performance partway through executing the attached test. The test consists of running the same code eight times. After the first three times, the performance drops to one half (OS X) or one third (Debian) of its previous performance.
Memory usage remains at a constant 60 MB through the entire run. Forcing a GC between runs has no effect. When the same code is run in Chrome, there is no performance drop.

The test is purely algorithmic (computing Fibonacci sequences via a JavaScript interpreter). There is no disk access or network access. There are no dependencies beyond the included files. With the exception of using Sets and multi-line strings, all code is ES 5.1.

To recreate, unzip the attached file and execute node run.js. Expected output would be eight runs of approximately the same duration. Actual output is:

> node run.js
Run 0: 5075 ms
Run 1: 5174 ms
Run 2: 5156 ms
Run 3: 10888 ms
Run 4: 11022 ms
Run 5: 11244 ms
Run 6: 11196 ms
Run 7: 10742 ms

Also included is run.html which can be dropped into a browser. Chrome provides the following output which is consistent across all runs:

Run 0: 3902 ms
Run 1: 3923 ms
Run 2: 3982 ms
Run 3: 3923 ms
Run 4: 4189 ms
Run 5: 4135 ms
Run 6: 4105 ms
Run 7: 4094 ms

Speculation: Is V8 getting poisoned in some way that it can't optimize execution? Making insignificant changes in the code (like adding a busy loop that counts to 1000) can randomly move the performance cliff forwards or backwards.

nodeperf.zip

[bnoordhuis]

Is V8 getting poisoned in some way that it can't optimize execution?

Quite possible. --trace_opt --trace_deopt usually prints the what and why

[vsemozhetbyt]

@NeilFraser What Chrome version do you compare with? It may be that one of the old Crankshaft deopts is involved, as in Node.js canary (V8 6.1) or in Node.js nightly (V8 5.9). there are no significant degradations:

Node.js 8.2.1 (V8 5.8):

Run 0: 9520 ms
Run 1: 9597 ms
Run 2: 9617 ms
Run 3: 21471 ms
Run 4: 22012 ms
Run 5: 22426 ms
Run 6: 22274 ms
Run 7: 22179 ms

Node.js 9.0.0 canary (V8 6.1) (~ the same with Node.js nightly (V8 5.9)):

Run 0: 6590 ms
Run 1: 6726 ms
Run 2: 6991 ms
Run 3: 6761 ms
Run 4: 6757 ms
Run 5: 7729 ms
Run 6: 7301 ms
Run 7: 6871 ms

[vsemozhetbyt]

Output from the node --trace_opt --trace_deopt run.js > out.txt (Node.js 8.2.1 (V8 5.8); many various deopts in the dependencies).

[NeilFraser]

Thanks @vsemozhetbyt
I've refined your results and found the point at which the problem was resolved in Node. This version is the last to exhibit the cliff behaviour:
v9.0.0-nightly20170606b830c976b5/ 06-Jun-2017 19:35
And the next day there is no cliff:
v9.0.0-nightly20170607eef94a8bf8/ 07-Jun-2017 20:00

Looking at the logs I see that was the date when PR #13263 landed.

From my end, I'm completely satisfied. I'll run the nightlies until this becomes part of the next release. I'll leave it up to you as to whether to close this issue, or look into some form of back-port to 8.2.1.

[vsemozhetbyt]

@NeilFraser It seems we can have V8 6.0 in Node.js 8.x next week or a bit later: https://github.com/nodejs/CTC/issues/155

[bnoordhuis]

v8.3.0 has been released. I'll close this out, cheers.