TypedArray performance - exploration

[naugtur]

Consider the following experiment setup:

import "ses";
import { hrtime } from "node:process";

const run = () => {
  const x = new Uint8Array(10000);
  for (let i = 0; i < x.length; i++) {
    x[i] = 1;
  }
};

// optionally, warm up typed array before lockdown
if (process.argv[2]) {
  run();
}

lockdown();

const runtime = 10000000000n;
const experiment = () => {
  const start = hrtime.bigint();
  let now = hrtime.bigint();
  let count = 0;
  // run for a fixed time, count how many runs
  while (now - start < runtime) {
    run();
    count++;
    now = hrtime.bigint();
  }
  console.log(count);
}

experiment();

Results:

naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs
20804
naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs giddyup
1016512

Looks like warming up the typed array before lockdown is helping prevent the performance drop. Let's explore the warmup.

• Is it because one instance gets created and something changes before lockdown happens?
• Is it because on the first ever assignment some optimization kicks in that would otherwise not kick in under lockdown?
• Is it a delayed optimization for the specific buffer size?

None of the above! :D

See the modified experiment

import "ses";
import { hrtime } from "node:process";

let count = 0;

const prerun = () => {
  // throw away the assumption that a specific buffer size is optimized by adding count
  const x = new Uint8Array(10000 + count);
  for (let i = 0; i < x.length; i++) {
    x[i] = 1;
  }
  count++;
};

const run = () => {
  // throw away the assumption that a specific buffer size is optimized by adding count
  const x = new Uint8Array(10000 + count);
  for (let i = 0; i < x.length; i++) {
    x[i] = 1;
  }
  count++;
};

let x;
switch (process.argv[2]) {
  case "warmup1":
    x = new Uint8Array(10000);
    break;
  case "warmup2":
    x = new Uint8Array(10000);
    x[0] = 1;
    break;
  case "warmup3":
    prerun();
    break;
  case "warmup4":
    run();
    break;
}

lockdown();


const runtime = 10000000000n;
const experiment = () => {
  const start = hrtime.bigint();
  let now = hrtime.bigint();
  // run for a fixed time, count how many runs
  while (now - start < runtime) {
    run();
    now = hrtime.bigint();
  }
};

experiment();
console.log(count);

naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs
15283
naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs warmup1
15252
naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs warmup2
15224
naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs warmup3
15129
naugtur@localhoist:~/repo/stuff/frozen-array [main]$ node index.mjs warmup4
134486

So it's beginning to look like using a frozen TypedArray in a function causes V8 to bail out of optimizing it, but if it's already been optimized, it's fine.

if I add --trace-opt --trace-deopt to node arguments, I get:

• fast warmed-up run:

[marking 0x2871101dca61 <JSFunction run (sfi = 0xef1bbeb6c9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: small function]
[compiling method 0x2871101dca61 <JSFunction run (sfi = 0xef1bbeb6c9)> (target TURBOFAN) using Turbofan]
[optimizing 0x2871101dca61 <JSFunction run (sfi = 0xef1bbeb6c9)> (target TURBOFAN) - took 0.011, 1.426, 0.028 ms]
[completed optimizing 0x2871101dca61 <JSFunction run (sfi = 0xef1bbeb6c9)> (target TURBOFAN)]

• slow run:

[marking 0x3015cfaa4411 <JSFunction run (sfi = 0x2cb7510eb6c9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: small function]
[compiling method 0x3015cfaa4411 <JSFunction run (sfi = 0x2cb7510eb6c9)> (target TURBOFAN) using Turbofan OSR]
[optimizing 0x3015cfaa4411 <JSFunction run (sfi = 0x2cb7510eb6c9)> (target TURBOFAN) - took 0.015, 0.843, 0.016 ms]
[compiling method 0x3015cfaa4411 <JSFunction run (sfi = 0x2cb7510eb6c9)> (target TURBOFAN) using Turbofan]
[optimizing 0x3015cfaa4411 <JSFunction run (sfi = 0x2cb7510eb6c9)> (target TURBOFAN) - took 0.004, 0.652, 0.014 ms]

We can see 2 failed attempts to optimize the run function.
Note that the first attempt in the second run is using Turbofan OSR - a different kind of compilation attempt.

This is a minimal sample that triggers a repro in node.js

const run = () => {
  const x = new Uint8Array(10000);
  for (let i = 0; i < x.length; i++) {
    x[i] = 1;
  }
};

run(); // comment out one of these
Object.freeze(Uint8Array.prototype);
run(); // comment out one of these

run();
run();
run();

setTimeout(()=>{
},10000)

I've generated 1MB of TurboFan trace output for the 2 variants and am trying to find any hints as to how V8 decides what to do.

To be continued.

[erights]

Quite a mystery!

@syg Could you help us figure this out? Thanks.

[kumavis]

played around with d8 but i dont really know what im doing

logs and source here d8-logs.zip

tested against source:

if (arguments[0] === 'freeze') {
  console.log('freezing')
  Object.freeze(Uint8Array.prototype);
  console.log('frozen')
}

console.log('start')

let count = 0;

const run = () => {
  // throw away the assumption that a specific buffer size is optimized by adding count
  const x = new Uint8Array(10000 + count);
  for (let i = 0; i < x.length; i++) {
    x[i] = 1;
  }
  count++;
};

const runtime = 10 * 1000;
const experiment = () => {
  const start = Date.now();
  let now = Date.now();
  // run for a fixed time, count how many runs
  while (now - start < runtime) {
    run();
    now = Date.now();
  }
};

experiment();
console.log(count);

console.log('done')

theres some key differences in the pretty graphs but I don't know what to do with that information 🐈

[naugtur]

I have reported the behavior here: https://bugs.chromium.org/p/chromium/issues/detail?id=1463387

Also, fresh Node.js v20 shows different opt logs

Fast case:

[marking 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: small function]
[compiling method 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN) OSR, mode: ConcurrencyMode::kConcurrent]
[compiling method 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN), mode: ConcurrencyMode::kConcurrent]
[aborted optimizing 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN) OSR because: Bailed out due to dependency change - took 0.009, 0.867, 0.016 ms]
[completed compiling 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN) - took 0.010, 0.802, 0.012 ms]
[completed optimizing 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN)]
[compiling method 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN) OSR, mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN) OSR - took 0.004, 0.725, 0.007 ms]
[completed optimizing 0x1c7e6cddf031 <JSFunction run (sfi = 0x18cf35c610c9)> (target TURBOFAN) OSR]

Slow case:

[marking 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: small function]
[compiling method 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> (target TURBOFAN) OSR, mode: ConcurrencyMode::kConcurrent]
[compiling method 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> (target TURBOFAN), mode: ConcurrencyMode::kConcurrent]
[completed compiling 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> (target TURBOFAN) OSR - took 0.008, 0.825, 0.010 ms]
[completed optimizing 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> (target TURBOFAN) OSR]
[completed compiling 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> (target TURBOFAN) - took 0.014, 0.832, 0.007 ms]
[completed optimizing 0x158162edf031 <JSFunction run (sfi = 0x2b52090e10c9)> (target TURBOFAN)]

[kriskowal]

@naugtur If we conclude that using a Proxy over all TypedArrays is a net win for performance, it would make sense for SES to tame all the TypedArrays in this way, at least within compartments, and also implement Object.freeze on these proxies such that we can adopt copy-on-write semantics over immutable contents. That would solve problems at the marshaling layer. cc @mhofman @gibson042 @erights

[naugtur]

@kriskowal I removed my comment before you replied because upon further investigation I was not successful with a proxy. The only times when I got any improvements from using the proxy were ones where I broke something and got length to default to zero.
Wrapping typed array with something that gets precompiled is possible but you'd need to invoke a separate API to get the real reference and pass out to wasm or wherever you needed it.
I'll try some more now that I know what doesn't work. But I got no interesting results for now despite what I initially thought.

[erights]

If this did work, it would have made things much better on v8 but much worse everywhere else. Thus, if we did make this into a SES repair, it should be conditional on the target being v8. We already make some of our Error taming conditional on v8, so this would not be a new precedent. The key thing is that the observable semantics after repair be as similar as possible across platforms, where performance differences are not considered observable.

[naugtur]

At this point, having tried a few things, I would not recommend putting it in SES because I can't see a way around the problem without tradeoffs in logic or semantics. It could work as a vetted shim for specific usecases, where it could override DataView to return an Array or Array based proxy and internally map the changes onto a typed array.

I think we may get a fix from chromium this time - now that we were able to pinpoint the exact misbehavior labeling a function that uses a frozen typed array as megamorphic.