Closed Bug 1734208 Opened 2 months ago Closed 2 months ago

Puppeteer causes Firefox to freeze because stdout/stderr pipes are no longer processed

Categories

(Remote Protocol :: CDP, defect, P2)

defect
Points:
2

Tracking

(firefox95 fixed)

RESOLVED FIXED
95 Branch
Tracking Status
firefox95 --- fixed

People

(Reporter: whimboo, Assigned: whimboo)

References

()

Details

(Whiteboard: [bidi-m2-mvp])

Attachments

(2 files)

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:94.0) Gecko/20100101 Firefox/94.0 ID:20211003201113

For testing purposes I'm running the following Puppeteer script with a recent Firefox Nightly:

const puppeteer = require('puppeteer');

(async () => {
  const browser = await puppeteer.launch({
    'headless': false,
    'remote.log.level': 'trace',
  });

  const page = await browser.newPage();
  await page.goto('http://example.org/page1');
  await browser.close();
})();

It simply loads the given page, and then quits the browser. But closing the browser hangs, and Firefox never quits. Even the shutdown hang monitor doesn't kick in. The hang can reliably reproduced.

Note that when I do not call browser.close() also hangs with a beach ball.

Attached you can find a trace from the main process as recorded with Instruments during the shutdown request. I hope that it's helpful.

Markus, could you maybe have a look at? Thanks!

Flags: needinfo?(mstange.moz)

The problem here is happening already before the shutdown and causes the main thread to be blocked. As such also the shutdown is blocked.

To get this information Markus helped me to get the Gecko profile from the hung process. Here the profile: https://share.firefox.dev/3AiIbBf

By using the flame graph it's visible that when we are logging a trace entry for the network event http-on-modify-request, the call to fputs never returns. This can happen when a consumer has an open pipe to stdout/stderr and closes it too soon, or doesn't actually read anymore from it.

Puppeteer actually needs these pipes to get the DevTools address of the CDP WebSocket, which is expected on stderr and looks like:

DevTools listening on ws://localhost:52200/devtools/browser/184e6a9d-2285-9745-b9df-ceedd866e6b3

Maybe once this line has been received Puppeteer no longer cares about these pipes, and maybe closes them.

Component: General → CDP
Flags: needinfo?(mstange.moz)
Product: Core → Remote Protocol
Summary: Infinite hang during shutdown after running a Puppeteer script with Firefox → Puppeteer causes Firefox to freeze because stdout/stderr pipes are closed too early

Actually as Markus mentioned this should not be caused by early closing the pipes, because this might end-up in a crash of Firefox. But more due to missing processing of the stdout/stderr data.

Summary: Puppeteer causes Firefox to freeze because stdout/stderr pipes are closed too early → Puppeteer causes Firefox to freeze because stdout/stderr pipes are no longer processed

The freeze can actually be avoided when using dumpio: true as option for the call to puppeteer.launch(). Checking the Puppeteer code the related bits around setting up the pipe can be found at:

https://github.com/puppeteer/puppeteer/blob/18651c5fd80f79db745f47bf704c246e2aec34f9/src/node/BrowserRunner.ts#L89-L92

Here the child_process Node.js package is used to track the browser process running as child. By default a ['pipe', 'pipe', 'pipe'] configuration is passed into the child for stdio. And in case of dumpio both the stdout and stderr pipes are set to process.stdout or process.stderr.

The documentation for the Node.js package has a good description:

These pipes have limited (and platform-specific) capacity. If the subprocess writes to stdout in excess of that limit without the output being captured, the subprocess blocks waiting for the pipe buffer to accept more data. This is identical to the behavior of pipes in the shell. Use the { stdio: 'ignore' } option if the output will not be consumed

That perfectly explains why Firefox is blocked in fputs. I tried to fix it in Puppeteer's code and the following changes make it work for me:

diff --git a/src/node/BrowserRunner.ts b/src/node/BrowserRunner.ts
index beac06cf..7151aecf 100644
--- a/src/node/BrowserRunner.ts
+++ b/src/node/BrowserRunner.ts
@@ -64,10 +64,13 @@ export class BrowserRunner {
   start(options: LaunchOptions): void {
     const { handleSIGINT, handleSIGTERM, handleSIGHUP, dumpio, env, pipe } =
       options;
-    let stdio: Array<'ignore' | 'pipe'> = ['pipe', 'pipe', 'pipe'];
+    let stdio: Array<'ignore' | 'pipe'>;
     if (pipe) {
       if (dumpio) stdio = ['ignore', 'pipe', 'pipe', 'pipe', 'pipe'];
       else stdio = ['ignore', 'ignore', 'ignore', 'pipe', 'pipe'];
+    } else {
+      if (dumpio) stdio = ['ignore', 'pipe', 'pipe'];
+      else stdio = ['ignore', 'ignore', 'pipe'];
     }
     assert(!this.proc, 'This process has previously been started.');
     debugLauncher(

Tomorrow I'm going to test a bit more and if that works I will propose it as PR on the upstream repository.

Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Attachment #9244859 - Attachment description: Bug 1734208 - [remote] Ignore stdout in Puppeteer launcher if dumpio isn't used. → Bug 1734208 - [remote] Ignore stdout in Puppeteer if dumpio isn't used.
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c0f2a8744f8b
[remote] Ignore stdout in Puppeteer if dumpio isn't used. r=webdriver-reviewers,jdescottes
Status: ASSIGNED → RESOLVED
Closed: 2 months ago
Resolution: --- → FIXED
Target Milestone: --- → 95 Branch
Points: --- → 2
Priority: -- → P2
Whiteboard: [bidi-m2-mvp]
You need to log in before you can comment on or make changes to this bug.