Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Why does this JavaScript code run slower after Node.js optimization

I was creating a solution to an ICPC problem using JavaScript and Node.js when I ran into an interesting issue: under certain circumstances my program would run twice as slow on the same data set.

I stripped it down until I got to this minimal example that demonstrates the behavior:

function solve(arr) {
  const total = arr.reduce((a, c) => a + c, 0);
  const count = arr.length;
  for (let i = 0; i < total; i++) {
    for (let j = 0; j < count; j++) {
      // calculate some stuff
    }
  }
}

for (let i = 0; i < 10; i++) {
  // generate some sample data (array of 5000 random numbers 1-10)
  const data = [];
  for (let i = 0; i < 5000; i++) {
    data.push(Math.floor(Math.random() * 10) + 1);
  }

  const start = new Date();
  solve(data);  // run solve on the data
  console.log(`${i + 1}: ${new Date() - start}ms`);
}

This is the output of running node --trace-opt code.js using Node v10.15.1:

[marking 0x005062b82521 <JSFunction solve (sfi = 000001DA56AD8CD9)> for optimized recompilation, reason: small function, ICs with typeinfo: 5/7 (71%), generic ICs: 0/7 (0%)]
[compiling method 0x005062b82521 <JSFunction solve (sfi = 000001DA56AD8CD9)> using TurboFan OSR]
[optimizing 0x005062b82521 <JSFunction solve (sfi = 000001DA56AD8CD9)> - took 1.453, 0.702, 0.082 ms]
1: 86ms
[marking 0x005062b82581 <JSFunction (sfi = 000001DA56AD8BD9)> for optimized recompilation, reason: hot and stable, ICs with typeinfo: 22/23 (95%), generic ICs: 1/23 (4%)]
[compiling method 0x005062b82521 <JSFunction solve (sfi = 000001DA56AD8CD9)> using TurboFan]
[optimizing 0x005062b82521 <JSFunction solve (sfi = 000001DA56AD8CD9)> - took 0.159, 0.632, 0.096 ms]
2: 82ms
3: 80ms
[compiling method 0x005062b82581 <JSFunction (sfi = 000001DA56AD8BD9)> using TurboFan OSR]
[optimizing 0x005062b82581 <JSFunction (sfi = 000001DA56AD8BD9)> - took 0.592, 2.312, 0.154 ms]
4: 245ms
5: 243ms
6: 236ms
7: 237ms
8: 240ms
9: 246ms
10: 239ms

During the first three iterations the run time is around 80ms, but just before the fourth iteration Node recompiles and optimizes a method and from that point on the code runs about 3 times slower.

Typically when Node does runtime analysis, recompilation, and optimization everything runs faster.

Can anyone explain why Node optimization makes things so much worse in this case?


Note that if the example code is changed to calculate total by iterating instead of using reduce the optimization improves performance as expected (run time drops to around 60ms):

let total = 0;
for (let v of arr) total += v;
like image 937
Brian Adams Avatar asked Feb 27 '19 15:02

Brian Adams


1 Answers

I filed a bug report and got the following response from a Chromium dev:

Some array builtins used branch hints for loop bounds checks, causing all code after the inlined builtin to become deferred code. This is detrimental for performance.

So it turns out this is a known issue with the TurboFan compiler and a fix has been created and is currently being tested:

This CL removes the hints, which improves code scheduling a lot, on the micro benchmark from the linked bug by 3x.

like image 189
Brian Adams Avatar answered Oct 14 '22 20:10

Brian Adams