Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug?]: Performance impact of process.report.getReport() is undesirable #5167

Closed
1 task done
oliversalzburg opened this issue Jan 2, 2023 · 12 comments
Closed
1 task done
Labels
bug Something isn't working external bug This issue highlights a bug in another project waiting for feedback Will autoclose in a while unless more data are provided

Comments

@oliversalzburg
Copy link
Contributor

Self-service

  • I'd be willing to implement a fix

Describe the bug

Yarn calls process.report.getReport internally to retrieve a list of loaded shared libraries to determine the C library in use. This can be seen following the code path at

// Doing these calls early is important: it seems calling it after we've started the resolution incurs very high
// performance penalty on WSL, with the Gatsby benchmark jumping from ~28s to ~130s. It's possible this is due to
// the number of async tasks being listed in the report, although it's strange this doesn't occur on other systems.
. The comment highlighted here already hints at the larger issue.

Yarn will grab this report and to generate the report, Node will go through all open handles in UV and retrieve information about them. Most importantly here, it will query information about all open socket handles. There handles are processed with https://github.com/nodejs/node/blob/9eb363a3e00dbba572756c7ed314273f17ea8e2e/src/node_report_utils.cc#L12.

  • This function will try to resolve the name for at least the local IP address used on the socket (as I observed).
  • This process is applied for all socket handles in series.
  • This can potentially take minutes to fully generate.

As the above quoted comment implies, there is a larger issue on WSL. From my observations, WSL will, by default, register a very poor DNS resolver into the Linux distribution. This resolver is not only extremely slow, it also responds to all queries with an answer with a TTL of 0. I expect that this causes the RDNS request for every single socket to go through the entire stack every single time.

While this behavior is generally prevented in yarn by calling out to the report generator early, when using plugins like upgrade-interactive, a lot of sockets have been opened from the resolution process and this causes a very long hang when the report is being generated. This approach seems unreliable. Determination of platform specifics should not be hindered by DNS performance.

To reproduce

const https = require("node:https");

const SOCKET_COUNT = 10;
const sockets = [];
let allResolved = false;

const keepAliveAgent = new https.Agent({ keepAlive: true });

const performRequest = () => {
  const socketPromise = new Promise((resolve) => {
    https
      .get(
        {
          agent: keepAliveAgent,
          hostname: "registry.npmjs.org",
        },
        () => {
          process.stdout.write(".");
          resolve();
        }
      )
      .on("error", (error) => {
        console.error(error);
        resolve();
      });
  });
  sockets.push(socketPromise);
};

process.stdout.write(`${new Date().toISOString()} opening ${SOCKET_COUNT} sockets`);
for (let loops = 0; loops < SOCKET_COUNT; ++loops) {
  performRequest();
}

Promise.all(sockets).then(() => {
  allResolved = true;
  console.log(
    `\n${new Date().toISOString()} all sockets created. requesting report...`
  );
  process.report.getReport();

  console.log(`${new Date().toISOString()} destroying client`);
  keepAliveAgent.destroy();

  console.log(`${new Date().toISOString()} end`);
});

const check = () => {
  if (!allResolved) {
    setTimeout(check, 200);
    return;
  }
};

check();

Environment

System:
    OS: Linux 5.10 Ubuntu 20.04.3 LTS (Focal Fossa)
    CPU: (12) x64 Intel(R) Core(TM) i7-6850K CPU @ 3.60GHz
  Binaries:
    Node: 18.12.0 - /tmp/xfs-ec34c936/node
    Yarn: 1.22.19 - /tmp/xfs-ec34c936/yarn
    npm: 8.19.2 - /usr/local/bin/npm

Additional context

This problem is amplified by poor WSL default behavior, but the underlying issue should apply generally.

@oliversalzburg oliversalzburg added the bug Something isn't working label Jan 2, 2023
@merceyz merceyz added the upholded Real issues without formal reproduction label Jan 3, 2023
@arcanis arcanis added the external bug This issue highlights a bug in another project label Jan 3, 2023
@arcanis
Copy link
Member

arcanis commented Jan 3, 2023

Very interesting investigation. I'm marking it as an external bug since I don't see a lot we can do on Yarn's side - ideally Node should provide a simpler API.

@oliversalzburg
Copy link
Contributor Author

I also reported this on the Node side here: nodejs/node#46060 and for WSL here microsoft/WSL#9423

@edoardo-bluframe
Copy link

As @arty-name reported this bug is causing #4327 which is making yarn berry really difficult to use for a few of us. Over 2m - for some more - every time we install packages! Just FYI 😄

@tadayosi
Copy link

Is there any workaround until the fix is provided? Since yarn install is the most essential part of the tool ☹️

@lpic10
Copy link

lpic10 commented Nov 13, 2023

maybe this can help: nodejs/node#46060 (comment)

@oliversalzburg
Copy link
Contributor Author

@tadayosi You can work around the issue in WSL by disabling resolv.conf generation (see https://learn.microsoft.com/en-us/windows/wsl/wsl-config#network-settings), and writing your own DNS server address into that file. Although Microsoft says this problem has potentially already been solved.

For other platforms, you'd still want to mitigate this issue at the DNS resolver level most likely.

If there are other performance implications in report.getReport(), then I still guess it would be best to have an alternate way in Node to retrieve the piece of information we actually require for yarn. IIRC only the C runtime name is what is being taken from this report. But it seems like there was an active decision to not do that, and only supply the information through the report: nodejs/node#41338

There is also https://github.com/lovell/detect-libc/tree/main, but I'm not sure if that's an option.

@arcanis
Copy link
Member

arcanis commented Nov 14, 2023

Can you try the 4.0.2 (literally just released)? It includes a workaround to avoid paying the getReport cost.

@arcanis arcanis added waiting for feedback Will autoclose in a while unless more data are provided and removed upholded Real issues without formal reproduction labels Nov 14, 2023
@arty-name
Copy link

Yes! Yarn is fast again! 😍

@arty-name
Copy link

arty-name commented Nov 14, 2023

Uhm, in case the overt emotions in my previous comment obscure its meaning, let me state that I have tested yarn 4.0.2 and the workaround in ffc9f8a has resolved the issue for me. Thank you @arcanis!

@oliversalzburg
Copy link
Contributor Author

From my side, I feel like this issue has been resolved on the WSL distribution/platform level. The performance is as expected, even with the WSL-internal DNS resolver and even with pre-4.0.2.

Thus, I'd like to close this issue. Non-WSL-related performance issues with getReport should likely go into separate issues.

That being said, nice to see that the report is no longer required 😊

@tadayosi
Copy link

Thanks. I tried 4.0.2 but unfortunately this doesn't solve my problem of yarn install slowness. Probably mine is a different problem from the original one.

@Tofandel
Copy link

Tofandel commented Oct 30, 2024

You need to set process.report.excludeNetwork = true before getReport to fix the speed issue of get report which is not just WSL specific

const report: any = process.report?.getReport() ?? {};

See lovell/detect-libc#21

Though that will only really fix the issue when nodejs/node#55602 lands

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working external bug This issue highlights a bug in another project waiting for feedback Will autoclose in a while unless more data are provided
Projects
None yet
Development

No branches or pull requests

8 participants