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

Leaking async ops when running tests using Puppeteer #27775

Open
harvestcore opened this issue Jan 22, 2025 · 8 comments
Open

Leaking async ops when running tests using Puppeteer #27775

harvestcore opened this issue Jan 22, 2025 · 8 comments

Comments

@harvestcore
Copy link

Setup:

  • Deno 2.1.5
  • Puppeteer Core 24.0.0 (npm:puppeteer-core@24.0.0)
  • Puppeteer Browsers 2.7.0 (npm:@puppeteer/browsers@2.7.0)

The bug

When running tests that make use of a Puppeteer browser Deno complains about leaks detected:

>> deno test -A ./test.ts --trace-leaks
running 1 test from ./test.ts
A ...
  B ... ok (0ms)
A ... FAILED (844ms)

 ERRORS 

A => ./test.ts:5:6
error: Leaks detected:
  - A child process stderr was opened during the test, but not closed during the test. Close the child process stderr by calling `proc.stderr.close()` or `await child.stderr.cancel()`.
  - An async call to op_read was started in this test, but never completed. The operation was started here:
    at Object.op_read (ext:core/00_infra.js:270:13)
    at Object.pull (ext:deno_web/06_streams.js:995:30)
    at Module.invokeCallbackFunction (ext:deno_webidl/00_webidl.js:1105:16)
    at ReadableByteStreamController.pullAlgorithm (ext:deno_web/06_streams.js:3566:14)
    at readableByteStreamControllerCallPullIfNeeded (ext:deno_web/06_streams.js:1241:49)
    at ReadableByteStreamController.[[[PullSteps]]] (ext:deno_web/06_streams.js:5958:5)
    at readableStreamDefaultReaderRead (ext:deno_web/06_streams.js:2516:36)
    at ReadableStreamDefaultReader.read (ext:deno_web/06_streams.js:5455:5)
    at Readable.read [as _read] (ext:deno_node/_stream.mjs:5368:14)
    at Readable.read (ext:deno_node/_stream.mjs:2561:16)

 FAILURES 

A => ./test.ts:5:6

FAILED | 0 passed (1 step) | 1 failed (847ms)

How to reproduce?

  1. Run the code below.
  2. See the error.
import puppeteer from 'npm:puppeteer-core@24.0.0';
import { Browser, getInstalledBrowsers, install } from 'npm:@puppeteer/browsers@2.7.0';
import { dirname, fromFileUrl, join } from 'jsr:@std/path@1.0.8';

const CHROME_VERSION: string = '131.0.6778.264';
const BROWSER = Browser.CHROME;

const CACHE_DIR = join(dirname(fromFileUrl(import.meta.url)), 'browser-cache');

async function installBrowser() {
	const installedBrowsers = await getInstalledBrowsers({
		cacheDir: CACHE_DIR,
	});

	const foundBrowser = installedBrowsers.length
		? installedBrowsers.find(
				(installed) =>
					installed.browser === BROWSER &&
					installed.buildId === CHROME_VERSION
		  )
		: null;

	if (!installedBrowsers.length || !!foundBrowser) {
		try {
			const result = await install({
				cacheDir: CACHE_DIR,
				browser: BROWSER,
				buildId: CHROME_VERSION,
				unpack: true,
				installDeps: false,
			});

			if (!result) {
				throw new Error('Booo');
			}

			return result.executablePath;
		} catch (error) {
			console.log(error);
		}
	}

	return foundBrowser!.executablePath;
}

Deno.test('A', async (t) => {
	const browser = await puppeteer.launch({
		executablePath: await installBrowser(),
		headless: true,
	});

	await t.step('B', async () => {});

	await browser.close();
});

Extra info

  • The leak is still reproducible in Deno 2.1.7
@Lightning00Blade
Copy link

Lightning00Blade commented Jan 27, 2025

Hey, would it be possible to scope down the repo example. What I mean by that is. Can you see if the issue is reproducible by only calling installBrowser? Or if you don't call installBrowser but provide string with the path to the executable directly?
Just trying to narrow down where this may come from on Puppeteer end.
And maybe someone can point out how to get better stack traces for that point to the part of code and not internal Deno files.

Does setting any of this to bigger number help with the size of the stacks:

  --stack-size (default size of stack region v8 is allowed to use (in kBytes))
        type: int  default: 984
  --max-stack-trace-source-length (maximum length of function source code printed in a stack trace.)
        type: int  default: 300

@harvestcore
Copy link
Author

Hey @Lightning00Blade, thanks for taking a look at this!

Can you see if the issue is reproducible by only calling installBrowser?

No, that function just installs the browser. If I only run that function inside a test I'm unable to reproduce the leak. The installBrowser is optional.

Or if you don't call installBrowser but provide string with the path to the executable directly?

You can skip the installBrowser call and just set an string there. The issue is still reproducible.

Also, I get the same output even when using the flags you mention (also, the following output is not using the installBrowser function).

>> deno test -A ./test.ts --trace-leaks --v8-flags="--stack-size=4096,--max-stack-trace-source-length=1000"
running 1 test from ./test.ts
A ...
  B ... ok (0ms)
A ... FAILED (457ms)

 ERRORS 

A => ./test.ts:50:6
error: Leaks detected:
  - A child process stderr was opened during the test, but not closed during the test. Close the child process stderr by calling `proc.stderr.close()` or `await child.stderr.cancel()`.
  - An async call to op_read was started in this test, but never completed. The operation was started here:
    at Object.op_read (ext:core/00_infra.js:293:13)
    at Object.pull (ext:deno_web/06_streams.js:995:30)
    at Module.invokeCallbackFunction (ext:deno_webidl/00_webidl.js:1105:16)
    at ReadableByteStreamController.pullAlgorithm (ext:deno_web/06_streams.js:3566:14)
    at readableByteStreamControllerCallPullIfNeeded (ext:deno_web/06_streams.js:1241:49)
    at ReadableByteStreamController.[[[PullSteps]]] (ext:deno_web/06_streams.js:5958:5)
    at readableStreamDefaultReaderRead (ext:deno_web/06_streams.js:2516:36)
    at ReadableStreamDefaultReader.read (ext:deno_web/06_streams.js:5455:5)
    at Readable.read [as _read] (ext:deno_node/_stream.mjs:5368:14)
    at Readable.read (ext:deno_node/_stream.mjs:2561:16)

 FAILURES 

A => ./test.ts:50:6

FAILED | 0 passed (1 step) | 1 failed (459ms)

error: Test failed

@Lightning00Blade
Copy link

Lightning00Blade commented Jan 27, 2025

I found a place that this may be coming from - puppeteer/puppeteer#13558
But no plans yet to make a release with this fix.
If you could test with local build of Puppeteer (from main) that would be helpful.

@luiisgallego
Copy link

Hello @Lightning00Blade . Thanks for your fix, what steps do we have to follow to be able to set up/use Puppeteer locally?

@Lightning00Blade
Copy link

You can read here - https://pptr.dev/contributing#getting-started
It should a as simple as clone the repo and run npm install && npm run build. (Change is already laned)
Hopefully that Deno won't need anything special besides including the local files.
In npm there is the npm link to link local packages, I don't know of a Deno equivalent.

@Lightning00Blade
Copy link

We just release v24.2.0 - https://github.com/puppeteer/puppeteer/releases/tag/puppeteer-v24.2.0
This has the fix for the suspected issue. If someone can verify this fixed the issue that would be great.

@harvestcore
Copy link
Author

Hey @Lightning00Blade, thanks for the update.

We tried the local setup with no luck, so we decided to wait until the official release. I just did some testing (after upgrading to Puppeteer 24.2.0 and Puppeteer/Browsers 2.7.1) and the example in the initial comment (#27775 (comment)) works well, no leaks detected in that case. That is good news, but when running our complete suite of tests we can still see some leaks.

Test 1 => https://jsr.io/@std/testing/1.0.9/_test_suite.ts:256:10
error: Leaks detected:
  - A timer was started in this test, but never completed. This is often caused by not calling `clearTimeout`. The operation was started here:
    at Object.queueUserTimer (ext:core/01_core.js:786:9)
    at setTimeout (ext:deno_web/02_timers.js:64:15)
    at Timeout.<computed> (ext:deno_node/internal/timers.mjs:68:7)
    at new Timeout (ext:deno_node/internal/timers.mjs:55:37)
    at setTimeout (node:timers:14:10)
    at new Deferred (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/util/Deferred.js:58:31)
    at Function.create (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/util/Deferred.js:18:16)
    at FrameManager.#onClientDisconnect (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/cdp/FrameManager.js:80:34)
    at file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/cdp/FrameManager.js:64:37
    at onceHandler (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/common/EventEmitter.js:88:13)

Test 2 => https://jsr.io/@std/testing/1.0.9/_test_suite.ts:256:10
error: Leaks detected:
  - "fetchUpgradedStream" was created during the test, but not cleaned up during the test. Close the resource before the end of the test.
  - 3 async calls to op_read were started in this test, but never completed. The operation were started here:
    at Object.op_read (ext:core/00_infra.js:270:13)
    at Object.pull (ext:deno_web/06_streams.js:995:30)
    at Module.invokeCallbackFunction (ext:deno_webidl/00_webidl.js:1105:16)
    at ReadableByteStreamController.pullAlgorithm (ext:deno_web/06_streams.js:3566:14)
    at readableByteStreamControllerCallPullIfNeeded (ext:deno_web/06_streams.js:1241:49)
    at ReadableByteStreamController.[[[PullSteps]]] (ext:deno_web/06_streams.js:5958:5)
    at readableStreamDefaultReaderRead (ext:deno_web/06_streams.js:2516:36)
    at ReadableStreamDefaultReader.read (ext:deno_web/06_streams.js:5455:5)
    at Readable.read [as _read] (ext:deno_node/_stream.mjs:5368:14)
    at Readable.read (ext:deno_node/_stream.mjs:2561:16)
  - 3 async calls to op_read were started in this test, but never completed. The operation were started here:
    at Object.op_read (ext:core/00_infra.js:270:13)
    at UpgradedConn.read (ext:deno_net/01_net.js:130:26)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:228:44)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:257:17)
    at eventLoopTick (ext:core/01_core.js:177:7)
  - 3 async operations to wait for a subprocess to exit were started in this test, but never completed. This is often caused by not awaiting the result of a `Deno.Process#status` call. The operation were started here:
    at op_spawn_wait (ext:core/00_infra.js:250:13)
    at new ChildProcess (ext:deno_process/40_process.js:302:25)
    at spawnChildInner (ext:deno_process/40_process.js:201:10)
    at spawnChild (ext:deno_process/40_process.js:208:10)
    at Command.spawn (ext:deno_process/40_process.js:483:12)
    at new ChildProcess (ext:deno_node/internal/child_process.ts:189:10)
    at Object.spawn (node:child_process:120:10)
    at new Process (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:144:45)
    at launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:49:12)
    at ChromeLauncher.launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/node/BrowserLauncher.js:66:32)
  - A child process stderr was opened during the test, but not closed during the test. Close the child process stderr by calling `proc.stderr.close()` or `await child.stderr.cancel()`.
  - A child process stdin was opened during the test, but not closed during the test. Close the child process stdin by calling `proc.stdin.close()`.
  - A child process was started during the test, but not closed during the test. Close the child process by calling `proc.kill()` or `proc.close()`.
  - A signal listener was created during the test, but not fired/cleared during the test. Clear the signal listener by calling `Deno.removeSignalListener`.
  - An async operation to get the next signal was started in this test, but never completed. This is often caused by not un-registering a OS signal handler. The operation was started here:
    at op_signal_poll (ext:core/00_infra.js:250:13)
    at pollSignal (ext:deno_os/40_signals.js:18:19)
    at loop (ext:deno_os/40_signals.js:73:15)
    at Object.addSignalListener (ext:deno_os/40_signals.js:55:5)
    at Process.on (node:process:379:12)
    at subscribeToProcessEvent (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:85:17)
    at new Process (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:156:13)
    at launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:49:12)
    at ChromeLauncher.launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/node/BrowserLauncher.js:66:32)
    at eventLoopTick (ext:core/01_core.js:177:7)

Test 3 => https://jsr.io/@std/testing/1.0.9/_test_suite.ts:256:10
error: Leaks detected:
  - "fetchUpgradedStream" was created during the test, but not cleaned up during the test. Close the resource before the end of the test.
  - 4 async calls to op_read were started in this test, but never completed. The operation were started here:
    at Object.op_read (ext:core/00_infra.js:270:13)
    at Object.pull (ext:deno_web/06_streams.js:995:30)
    at Module.invokeCallbackFunction (ext:deno_webidl/00_webidl.js:1105:16)
    at ReadableByteStreamController.pullAlgorithm (ext:deno_web/06_streams.js:3566:14)
    at readableByteStreamControllerCallPullIfNeeded (ext:deno_web/06_streams.js:1241:49)
    at ReadableByteStreamController.[[[PullSteps]]] (ext:deno_web/06_streams.js:5958:5)
    at readableStreamDefaultReaderRead (ext:deno_web/06_streams.js:2516:36)
    at ReadableStreamDefaultReader.read (ext:deno_web/06_streams.js:5455:5)
    at Readable.read [as _read] (ext:deno_node/_stream.mjs:5368:14)
    at Readable.read (ext:deno_node/_stream.mjs:2561:16)
  - 4 async calls to op_read were started in this test, but never completed. The operation were started here:
    at Object.op_read (ext:core/00_infra.js:270:13)
    at UpgradedConn.read (ext:deno_net/01_net.js:130:26)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:228:44)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:257:17)
    at eventLoopTick (ext:core/01_core.js:177:7)
  - 4 async operations to wait for a subprocess to exit were started in this test, but never completed. This is often caused by not awaiting the result of a `Deno.Process#status` call. The operation were started here:
    at op_spawn_wait (ext:core/00_infra.js:250:13)
    at new ChildProcess (ext:deno_process/40_process.js:302:25)
    at spawnChildInner (ext:deno_process/40_process.js:201:10)
    at spawnChild (ext:deno_process/40_process.js:208:10)
    at Command.spawn (ext:deno_process/40_process.js:483:12)
    at new ChildProcess (ext:deno_node/internal/child_process.ts:189:10)
    at Object.spawn (node:child_process:120:10)
    at new Process (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:144:45)
    at launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:49:12)
    at ChromeLauncher.launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/node/BrowserLauncher.js:66:32)
  - A child process stderr was opened during the test, but not closed during the test. Close the child process stderr by calling `proc.stderr.close()` or `await child.stderr.cancel()`.
  - A child process stdin was opened during the test, but not closed during the test. Close the child process stdin by calling `proc.stdin.close()`.
  - A child process was started during the test, but not closed during the test. Close the child process by calling `proc.kill()` or `proc.close()`.
  - A signal listener was created during the test, but not fired/cleared during the test. Clear the signal listener by calling `Deno.removeSignalListener`.
  - An async operation to get the next signal was started in this test, but never completed. This is often caused by not un-registering a OS signal handler. The operation was started here:
    at op_signal_poll (ext:core/00_infra.js:250:13)
    at pollSignal (ext:deno_os/40_signals.js:18:19)
    at loop (ext:deno_os/40_signals.js:73:15)
    at Object.addSignalListener (ext:deno_os/40_signals.js:55:5)
    at Process.on (node:process:379:12)
    at subscribeToProcessEvent (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:85:17)
    at new Process (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:156:13)
    at launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/@puppeteer/browsers/2.7.1/lib/esm/launch.js:49:12)
    at ChromeLauncher.launch (file:///Users/foobarbaz/Library/Caches/deno/npm/registry.npmjs.org/puppeteer-core/24.2.0/lib/esm/puppeteer/node/BrowserLauncher.js:66:32)
    at eventLoopTick (ext:core/01_core.js:177:7)

Thanks for taking a look at this issue!

@Lightning00Blade
Copy link

Lightning00Blade commented Feb 5, 2025

If you could provide more info on what the test that fails with A timer was started in this test, but never completed.
as I looked at the code and it should either call clearTimeout or the setTimeout callback will be called, and that specific timeout is rather short 100ms.

As for the other I will try to see if I can find what the issue is - very likely that Node vs Deno handle process.on/off differently and/or the way the we kill the process. If someone has idea here is were we implement the killing of the process, and all the browser spawning parts.
https://github.com/puppeteer/puppeteer/blob/main/packages/browsers/src/launch.ts#L407

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants