Performance regression on crypto createPublicKey and createPrivateKey APIs starting with node v17

[canova]

We were investigating a performance regression for the profiler-server repository that we have for the Firefox Profiler. The latest staging branch also includes node v16 to v18 upgrade. After some profiling we realized that the regression is caused by createPublicKey and createPrivateKey APIs starting with, and more specifically the init functions called inside these APIs.

Performance measurements

It looks like you've recently added a benchmark for these APIs, that helped me a lot to identify the issue. It also made me suspicious that maybe you are already aware of this issue, but I couldn't find a filed bug for it.

Here's the performance measurements of this benchmark on node v16 (76f9a7d) (this benchmark file doesn't exist in node v16 but I copy and pasted that file manually):

$ ./node benchmark/crypto/create-keyobject.js

crypto/create-keyobject.js n=1000 keyFormat="pkcs8" keyType="rsa": 87,062.20010881033
crypto/create-keyobject.js n=1000 keyFormat="spki" keyType="rsa": 158,704.96746548166
crypto/create-keyobject.js n=1000 keyFormat="der-pkcs8" keyType="rsa": 211,033.50705611636
crypto/create-keyobject.js n=1000 keyFormat="der-spki" keyType="rsa": 320,864.2285477396
crypto/create-keyobject.js n=1000 keyFormat="jwk-public" keyType="rsa": 323,458.8882135786
crypto/create-keyobject.js n=1000 keyFormat="jwk-private" keyType="rsa": 173,287.70090542824
crypto/create-keyobject.js n=1000 keyFormat="pkcs8" keyType="ec": 70,854.9851406468
crypto/create-keyobject.js n=1000 keyFormat="spki" keyType="ec": 74,614.33714488239
crypto/create-keyobject.js n=1000 keyFormat="der-pkcs8" keyType="ec": 76,651.35377021947
crypto/create-keyobject.js n=1000 keyFormat="der-spki" keyType="ec": 82,093.38122113905
crypto/create-keyobject.js n=1000 keyFormat="jwk-public" keyType="ec": 18,947.09442612292
crypto/create-keyobject.js n=1000 keyFormat="jwk-private" keyType="ec": 18,842.475454331183
crypto/create-keyobject.js n=1000 keyFormat="pkcs8" keyType="ed25519": 32,020.53617875503
crypto/create-keyobject.js n=1000 keyFormat="spki" keyType="ed25519": 274,898.3700725842
crypto/create-keyobject.js n=1000 keyFormat="der-pkcs8" keyType="ed25519": 33,281.65468932025
crypto/create-keyobject.js n=1000 keyFormat="der-spki" keyType="ed25519": 364,669.5054972105
crypto/create-keyobject.js n=1000 keyFormat="jwk-public" keyType="ed25519": 350,800.26310019736
crypto/create-keyobject.js n=1000 keyFormat="jwk-private" keyType="ed25519": 33,675.18359204967

And here's the same benchmark measurements on latest main branch (0fb5123):

$ ./node benchmark/crypto/create-keyobject.js

crypto/create-keyobject.js n=1000 keyFormat="pkcs8" keyType="rsa": 3,980.7933250567066
crypto/create-keyobject.js n=1000 keyFormat="spki" keyType="rsa": 12,610.70480611237
crypto/create-keyobject.js n=1000 keyFormat="der-pkcs8" keyType="rsa": 3,985.828387169419
crypto/create-keyobject.js n=1000 keyFormat="der-spki" keyType="rsa": 12,325.61807982795
crypto/create-keyobject.js n=1000 keyFormat="jwk-public" keyType="rsa": 340,865.5530816291
crypto/create-keyobject.js n=1000 keyFormat="jwk-private" keyType="rsa": 147,652.3425191793
crypto/create-keyobject.js n=1000 keyFormat="pkcs8" keyType="ec": 4,045.5283763474135
crypto/create-keyobject.js n=1000 keyFormat="spki" keyType="ec": 13,477.76265527882
crypto/create-keyobject.js n=1000 keyFormat="der-pkcs8" keyType="ec": 3,985.9051696879155
crypto/create-keyobject.js n=1000 keyFormat="der-spki" keyType="ec": 13,667.145900581954
crypto/create-keyobject.js n=1000 keyFormat="jwk-public" keyType="ec": 18,282.357519508965
crypto/create-keyobject.js n=1000 keyFormat="jwk-private" keyType="ec": 18,120.223259995593
crypto/create-keyobject.js n=1000 keyFormat="pkcs8" keyType="ed25519": 3,859.544118830917
crypto/create-keyobject.js n=1000 keyFormat="spki" keyType="ed25519": 19,712.78472653439
crypto/create-keyobject.js n=1000 keyFormat="der-pkcs8" keyType="ed25519": 3,842.351514208486
crypto/create-keyobject.js n=1000 keyFormat="der-spki" keyType="ed25519": 20,007.853082334816
crypto/create-keyobject.js n=1000 keyFormat="jwk-public" keyType="ed25519": 183,844.65126967712
crypto/create-keyobject.js n=1000 keyFormat="jwk-private" keyType="ed25519": 30,817.353251615987

As you can see here there is a huge difference between node v16 and node v18+

Preliminary performance profiles

I have captured some profiles both with Chrome's DevTool and also with samply

Profiles from Chrome DevTool with our loadtests:
v16 - v18
These profiles are captured from the profiler-server loadtests, but you can clearly see that createPublicKey and createPrivateKey are now taking a lot more time.

These profiles were the ones that made us aware that these APIs might have regression. Then we went ahead and looked for a more targeted test which we found create-keyobject.js benchmark.

Performance profiles with C++ stacks and STR

So after finding out that these APIs are the culprit I profiled the create-keyobject.js benchmarks with samply. You can see the profiles here:

v16.x branch - main branch

As you can see the duration of the test goes from 46ms to 265ms. And it looks like most of the time is spent on node::crypto::KeyObjectHandle::Init method (it had 8 samples before and now it has 248 samples). So I think we are calling this a lot, or this has started to take a lot more time. I don't know this codebase, so it would be great if a node crypto experts take a look at it.

STR for profiling yourself:

1. Install samply by running cargo install samply. (it requires rust)
2. Check out to the branch you want to test and build node.
3. If you don't have the benchmark/crypto/create-keyobject.js on that branch, manually add the file.
4. Run the benchmark tests with samply using this command: samply record ./node benchmark/crypto/create-keyobject.js
5. It will open up the Firefox Profiler UI in the browser after it's done.
6. Repeat it for the other branch.

Hope this helps identifying and fixing the problem!

I'm on macOS 14.0 with M1 Max CPU, but we observed the same issue on Linux as well, I believe it's platform agnostic.

[H4ad]

Probably related to nodejs/performance#72

[bnoordhuis]

Yes, it is. I'll take the liberty of closing this because it's a) a known issue, and b) not under our control (3p dep), but thanks for the excellent bug report.