Openssl 3 with NODE_EXTRA_CA_CERTS slows down node.js v17 startup #40524

nassau-t · 2021-10-19T19:33:08Z

Version

v17.0.0

Platform

Microsoft Windows NT 10.0.19042.0 x64

Subsystem

openssl 3

What steps will reproduce the bug?

Create an empty file a.js
Have a certificate.pem file with 1 certificate.

>SET NODE_EXTRA_CA_CERTS=

>timethis node a.js

TimeThis :  Command Line :  node a.js
TimeThis :    Start Time :  Tue Oct 19 21:19:06 2021


TimeThis :  Command Line :  node a.js
TimeThis :    Start Time :  Tue Oct 19 21:19:06 2021
TimeThis :      End Time :  Tue Oct 19 21:19:07 2021
TimeThis :  Elapsed Time :  00:00:00.110

>SET NODE_EXTRA_CA_CERTS=certificate.pem

>timethis node a.js

TimeThis :  Command Line :  node a.js
TimeThis :    Start Time :  Tue Oct 19 21:20:51 2021


TimeThis :  Command Line :  node a.js
TimeThis :    Start Time :  Tue Oct 19 21:20:51 2021
TimeThis :      End Time :  Tue Oct 19 21:20:51 2021
TimeThis :  Elapsed Time :  00:00:00.215

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

You must set a value for NODE_EXTRA_CA_CERTS

What is the expected behavior?

>node -v
v16.11.1

>timethis node a.js

TimeThis :  Command Line :  node a.js
TimeThis :    Start Time :  Tue Oct 19 21:22:16 2021


TimeThis :  Command Line :  node a.js
TimeThis :    Start Time :  Tue Oct 19 21:22:16 2021
TimeThis :      End Time :  Tue Oct 19 21:22:17 2021
TimeThis :  Elapsed Time :  00:00:00.115

What do you see instead?

It seems that openssl 3 slows down node.js startup.
With this empty script is 86% slower than node.js v16. With a big script, it is around 46% slower.
I don't know if this is expected, so this is a normal beaviour of openssl 3... It's strange that it only happens with EXTRA_CA_CERTS.

Additional information

No response

The text was updated successfully, but these errors were encountered:

nassau-t · 2021-10-20T14:09:02Z

In fact, certificate.pem can also be empty. It has the same slow down.

mhdawson · 2021-10-20T14:32:43Z

@danbev do you remember any changes related to EXTRA_CA_CERTS with the update to OpenSSL 3 that might be related?

mhdawson · 2021-10-20T14:55:30Z

this is in src/node.cc

    {
      std::string extra_ca_certs;
      if (credentials::SafeGetenv("NODE_EXTRA_CA_CERTS", &extra_ca_certs))
        crypto::UseExtraCaCerts(extra_ca_certs);
    }

And the code in UseExtraCaCerts does not seem to be changed as part of the update to v3 -

node/src/crypto/crypto_context.cc

Line 1327 in 7ed303b

void UseExtraCaCerts(const std::string& file) {

danbev · 2021-10-20T14:55:42Z

do you remember any changes related to EXTRA_CA_CERTS with the update to OpenSSL 3 that might be related?

Nothing that I can think unfortunately specifically related to EXTRA_CA_CERTS with regard to the changes in Node.js related to OpenSSL 3.0.

mhdawson · 2021-10-20T15:09:20Z

It also seems to reproduce on linux as well. For 16.x adding EXTRA_CA_CERTS does not seems to have much of an effect, where as it is noticeable in 17.x

It varies a bit but these are two comparisions:

Default

[midawson@midawson testextra]$ time node test.js

real	0m0.031s
user	0m0.022s
sys	0m0.009s

With NODE_EXTRA_CA_CERTS set

midawson@midawson testextra]$ time node test.js

real	0m0.071s
user	0m0.067s
sys	0m0.005s

nassau-t · 2021-10-20T15:14:58Z

Excuse me. Correcting title.

mhdawson · 2021-10-20T15:33:20Z

Additional time is in this method:

node/src/crypto/crypto_context.cc

Line 192 in 7ed303b

X509_STORE* NewRootCertStore() {

mhdawson · 2021-10-20T16:03:53Z

Difference seems to be in this part of the code:

if (root_certs_vector.empty() &&
      per_process::cli_options->ssl_openssl_cert_store == false) {
    for (size_t i = 0; i < arraysize(root_certs); i++) {
      X509* x509 =
          PEM_read_bio_X509(NodeBIO::NewFixed(root_certs[i],
                                              strlen(root_certs[i])).get(),
                            nullptr,   // no re-use of X509 structure
                            NoPasswordCallback,
                            nullptr);  // no callback data

      // Parse errors from the built-in roots are fatal.
      CHECK_NOT_NULL(x509);

      root_certs_vector.push_back(x509);
    }
  }

I checked 16.x and 17.x and arraysize(root_certs) is 131 in both cases so looks like the extra time is in PEM_read_bio_X509

mhdawson · 2021-10-20T16:14:20Z

The extra time seems be proportional to the number of root_certs. ie if I truncate to 1/2 the size it seems to add 1/2 the overhead. This would indicate that PEM_read_bio_X509 is doing more work than before for each certificate.

mhdawson · 2021-10-20T16:28:10Z

Adding OPENSSL_NO_CHAIN_VERIFY to node.gyp does not seem to have any effect. Trying OPENSSL_NO_X509_VERIFY

mhdawson · 2021-10-20T16:28:50Z

Actually looks like those might be removed, need to look at equivalents

nassau-t · 2021-10-20T17:11:14Z

It seems very old, to affect now on v17 and not in v16.

Changes between 1.0.2h and 1.1.0 [25 Aug 2016]

Clean up OPENSSL_NO_xxx #define's

    Use setbuf() and remove OPENSSL_NO_SETVBUF_IONBF
    Rename OPENSSL_SYSNAME_xxx to OPENSSL_SYS_xxx
    OPENSSL_NO_EC{DH,DSA} merged into OPENSSL_NO_EC
    OPENSSL_NO_RIPEMD160, OPENSSL_NO_RIPEMD merged into OPENSSL_NO_RMD160
    OPENSSL_NO_FP_API merged into OPENSSL_NO_STDIO
    Remove OPENSSL_NO_BIO OPENSSL_NO_BUFFER OPENSSL_NO_CHAIN_VERIFY OPENSSL_NO_EVP OPENSSL_NO_FIPS_ERR OPENSSL_NO_HASH_COMP OPENSSL_NO_LHASH OPENSSL_NO_OBJECT OPENSSL_NO_SPEED OPENSSL_NO_STACK OPENSSL_NO_X509 OPENSSL_NO_X509_VERIFY
    Remove MS_STATIC; it's a relic from platforms <32 bits.

Rich Salz

nassau-t · 2021-10-20T17:16:40Z

In fact, it's very strange that it affects only when new certificates are added througth NODE_EXTRA_CA_CERTS and not with the node default certificates.

mhdawson · 2021-10-20T19:29:28Z

I created the bug report in the openssl repository to see if it is expected or not - openssl/openssl#16871. I did search for issues in the repo but could not find anything that discussed/suggested it was a known issue.

mhdawson · 2021-10-20T19:40:35Z

@nassau-t I must have searched wrong as I see no the OPENSSL_NO_X509_VERIFY is not in the OpenSSL v3 release notes, I was just looking for something that might disable new validating being done.

nassau-t · 2021-10-20T20:45:33Z

@nassau-t I must have searched wrong as I see no the OPENSSL_NO_X509_VERIFY is not in the OpenSSL v3 release notes, I was just looking for something that might disable new validating being done.

From what I read, It seems that "Remove ... OPENSSL_NO_X509_VERIFY" was done in the openssl log "Changes between 1.0.2h and 1.1.0 [25 Aug 2016]"

mhdawson · 2021-10-20T20:46:55Z

@nassau-t that is what I was trying to say. I thought it was part of the OpenSSL release notes earlier when when I first searched, but later saw that I got that wrong.

nassau-t · 2021-10-20T20:49:16Z

Ok, let's see if they say something in the openssl issue...

It's very strange that even with an empty certificate.pem, it is so slow. Perhaps it checks the default node certificates before to check the new one's (I don't know how it works).

mhdawson · 2021-10-21T17:20:22Z

@nassau-t it sounds like this is a known issue on OpenSSL v3 from the comment on the issue I opened. For your use case are the extra certificates used every time you run Node.js or just in some subset of the cases. I'm not sure if its even possible but wondering if a lazy loading scheme would add any value?

nassau-t · 2021-10-21T18:35:46Z

@mhdawson Well, I think I must go forward with node v17.x and 100 or 150 ms more are not critical in my case (in fact I have measured again (perhaps timethis is not very exact on windows) and now I get 62 ms more, so in my case is a 57% more startup time. In node v16 it's practically the same with or without added certificates).
But anyway it's important to have an opened openssl v3 issue because they known the problem. In a more general case a 10x slow down speed it's a lot (openssl/openssl#16878), and I hope they fix it. Thank you.

ebickle · 2022-08-23T19:04:20Z

@nassau-t The reason why the slowdown is noticeable only when NODE_EXTRA_CA_CERTS is set is because that environment variable triggers a call to NewRootCertStore() at startup. When the environment variable is not set, then NewRootCertStore() is called the first time a secure context is created (e.g. outbound TLS connection).

Either way, the performance penalty is likely the same - just in a different location.

Store loaded NODE_EXTRA_CA_CERTS into root_certs_vector, allowing them to be added to secure contexts when NewRootCertStore() is called. When NODE_EXTRA_CA_CERTS is specified, the bundled root certificates will no longer be preloaded at startup. This improves Node.js startup time and makes the behavior of NODE_EXTRA_CA_CERTS consistent with the default behavior when NODE_EXTRA_CA_CERTS is ommitted. Fixes: nodejs#32010 Refs: nodejs#40524

Store loaded NODE_EXTRA_CA_CERTS into root_certs_vector, allowing them to be added to secure contexts when NewRootCertStore() is called. When NODE_EXTRA_CA_CERTS is specified, the root certificates (both bundled and extra) will no longer be preloaded at startup. This improves Node.js startup time and makes the behavior of NODE_EXTRA_CA_CERTS consistent with the default behavior when NODE_EXTRA_CA_CERTS is omitted. The original reason NODE_EXTRA_CA_CERTS were loaded at startup (issues nodejs#20432, nodejs#20434) was to prevent the environment variable from being changed at runtime. This change preserves the runtime consistency without actually having to load the certs at startup. Fixes: nodejs#32010 Refs: nodejs#40524 Refs: nodejs#23354

Store loaded NODE_EXTRA_CA_CERTS into root_certs_vector, allowing them to be added to secure contexts when NewRootCertStore() is called, rather than losing them when unrelated options are provided. When NODE_EXTRA_CA_CERTS is specified, the root certificates (both bundled and extra) will no longer be preloaded at startup. This improves Node.js startup time and makes the behavior of NODE_EXTRA_CA_CERTS consistent with the default behavior when NODE_EXTRA_CA_CERTS is omitted. The original reason NODE_EXTRA_CA_CERTS were loaded at startup (issues #20432, #20434) was to prevent the environment variable from being changed at runtime. This change preserves the runtime consistency without actually having to load the certs at startup. Fixes: #32010 Refs: #40524 Refs: #23354 PR-URL: #44529 Reviewed-By: Tim Perry <[email protected]>

Mesteery added the openssl Issues and PRs related to the OpenSSL dependency. label Oct 19, 2021

nassau-t changed the title ~~Openssl 3 with EXTRA_CA_CERTS slows down node.js v17 startup~~ Openssl 3 with NODE_EXTRA_CA_CERTS slows down node.js v17 startup Oct 20, 2021

ebickle mentioned this issue Aug 30, 2022

crypto: add NODE_EXTRA_CA_CERTS to modified cert stores #44448

Closed

ebickle mentioned this issue Sep 6, 2022

crypto: add extra CA certs to all secure contexts #44529

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Openssl 3 with NODE_EXTRA_CA_CERTS slows down node.js v17 startup #40524

Openssl 3 with NODE_EXTRA_CA_CERTS slows down node.js v17 startup #40524

nassau-t commented Oct 19, 2021 •

edited

Loading

nassau-t commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

danbev commented Oct 20, 2021

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021

nassau-t commented Oct 20, 2021 •

edited

Loading

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021 •

edited

Loading

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021 •

edited

Loading

mhdawson commented Oct 21, 2021

nassau-t commented Oct 21, 2021 •

edited

Loading

ebickle commented Aug 23, 2022

Openssl 3 with NODE_EXTRA_CA_CERTS slows down node.js v17 startup #40524

Openssl 3 with NODE_EXTRA_CA_CERTS slows down node.js v17 startup #40524

Comments

nassau-t commented Oct 19, 2021 • edited Loading

Version

Platform

Subsystem

What steps will reproduce the bug?

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

What is the expected behavior?

What do you see instead?

Additional information

nassau-t commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

danbev commented Oct 20, 2021

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021

nassau-t commented Oct 20, 2021 • edited Loading

mhdawson commented Oct 20, 2021

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021 • edited Loading

mhdawson commented Oct 20, 2021

nassau-t commented Oct 20, 2021 • edited Loading

mhdawson commented Oct 21, 2021

nassau-t commented Oct 21, 2021 • edited Loading

ebickle commented Aug 23, 2022

nassau-t commented Oct 19, 2021 •

edited

Loading

nassau-t commented Oct 20, 2021 •

edited

Loading

nassau-t commented Oct 20, 2021 •

edited

Loading

nassau-t commented Oct 20, 2021 •

edited

Loading

nassau-t commented Oct 21, 2021 •

edited

Loading