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] puppeteer-extra-plugin:user-data-dir.onClose called twice and causes Error. Also possible memory leak with Plugins #559

Closed
stupidpr opened this issue Sep 20, 2021 · 10 comments
Labels
issue: bug report A bug has been reported needs triage

Comments

@stupidpr
Copy link

Describe the bug

Running puppeteer extra with user-agent-plugin causes error "Error: ENOENT: no such file or directory, stat '/tmp/puppeteer_dev_profile-6fIz4i'" visible only in DEBUG mode. Look like "puppeteer-extra-plugin:user-data-dir.onClose" called twice,

Run snippet with "DEBUG=puppeteer-extra,puppeteer-extra-plugin:* ./node_modules/.bin/ts-node ./test/script/double-close-crash.ts "

Code Snippet

import {addExtra} from "puppeteer-extra";

let puppeteer = require('puppeteer');
puppeteer = addExtra(puppeteer);
const UserAgentOverride = require("puppeteer-extra-plugin-stealth/evasions/user-agent-override");
puppeteer.use(UserAgentOverride());

(async function main() {
	const browser = await puppeteer.launch({headless: true});
	console.log('Start');
	await browser.close();
	console.log('Done');
})();

Run: DEBUG=puppeteer-extra,puppeteer-extra-plugin:* ./node_modules/.bin/ts-node ./test/script/double-close-crash.ts

 puppeteer-extra-plugin:base:stealth/evasions/user-agent-override Initialized. +0ms
  puppeteer-extra plugin registered stealth/evasions/user-agent-override +0ms
  puppeteer-extra dependencies missing Set(1) { 'user-preferences' } +1ms
  puppeteer-extra-plugin:base:user-preferences Initialized. +0ms
  puppeteer-extra plugin registered user-preferences +3ms
  puppeteer-extra dependencies missing Set(1) { 'user-data-dir' } +1ms
  puppeteer-extra-plugin:base:user-data-dir Initialized. +0ms
  puppeteer-extra-plugin:user-data-dir initialized {
  deleteTemporary: true,
  deleteExisting: false,
  files: [],
  folderPath: '/tmp',
  folderPrefix: 'puppeteer_dev_profile-'
} +0ms
  puppeteer-extra plugin registered user-data-dir +35ms
  puppeteer-extra orderPlugins:before [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +1ms
  puppeteer-extra orderPlugins:after [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +0ms
  puppeteer-extra-plugin:user-preferences _userPrefsFromPlugins { intl: { accept_languages: 'en-US,en' } } +0ms
  puppeteer-extra-plugin:user-data-dir created custom dir /tmp/puppeteer_dev_profile-6fIz4i +4ms
  puppeteer-extra-plugin:user-data-dir Wrote file /tmp/puppeteer_dev_profile-6fIz4i/Default/Preferences +6ms
Start
  puppeteer-extra-plugin:user-data-dir onClose +219ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +0ms
(node:507333) [DEP0147] DeprecationWarning: In future versions of Node.js, fs.rmdir(path, { recursive: true }) will be removed. Use fs.rm(path, { recursive: true }) instead
(Use `node --trace-deprecation ...` to show where the warning was created)
Done
  puppeteer-extra-plugin:user-data-dir onClose +28ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +0ms
  puppeteer-extra-plugin:user-data-dir Error: ENOENT: no such file or directory, stat '/tmp/puppeteer_dev_profile-6fIz4i'
  puppeteer-extra-plugin:user-data-dir     at Object.statSync (node:fs:1536:3)
  puppeteer-extra-plugin:user-data-dir     at __node_internal_ (node:internal/fs/utils:793:8)
  puppeteer-extra-plugin:user-data-dir     at Object.rmdirSync (node:fs:1156:15)
  puppeteer-extra-plugin:user-data-dir     at Plugin.deleteUserDataDir (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:72:11)
  puppeteer-extra-plugin:user-data-dir     at Plugin.onClose (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:114:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:events:394:28)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:domain:475:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (/var/www/projects/svb-bot/node_modules/@cspotcode/source-map-support/source-map-support.js:527:35) +0ms

Versions

├── puppeteer-afp@1.0.1
├── puppeteer-extra-plugin-adblocker@2.11.11
├── puppeteer-extra-plugin-block-resources@2.2.9
├── puppeteer-extra-plugin-proxy@1.0.2
├── puppeteer-extra-plugin-stealth@2.7.8
├── puppeteer-extra@3.1.18
├── puppeteer@10.2.0

@stupidpr stupidpr added issue: bug report A bug has been reported needs triage labels Sep 20, 2021
@stupidpr
Copy link
Author

stupidpr commented Sep 20, 2021

Also considering running in a row launch/close all the errors are reported at the end of whole script. It looks like something (Plugin instances at least) are not released until the end of script and probably can be a reason of memory issues.

UPDATE and as you can find all the latest calls are for the same latest folder! It is overall correct that "puppeteer-extra-plugin:user-data-dir" contains properties like "_userDataDir", "_isTemporary"?

UPDATE see next comment with updated code snippet

import {addExtra} from "puppeteer-extra";

let puppeteer = require('puppeteer');
puppeteer = addExtra(puppeteer);
const UserAgentOverride = require("puppeteer-extra-plugin-stealth/evasions/user-agent-override");
puppeteer.use(UserAgentOverride());

async function runOne() {
    const browser = await puppeteer.launch({headless: true});
    console.log('Start');
    await browser.close();
    console.log('Done');
}
(async function main() {
    await runOne();
    await runOne();
    await runOne();
    await new Promise(resolve => setTimeout(resolve, 5000));
    console.log('DONE WAIT');
})();
 puppeteer-extra-plugin:base:stealth/evasions/user-agent-override Initialized. +0ms
  puppeteer-extra plugin registered stealth/evasions/user-agent-override +0ms
  puppeteer-extra dependencies missing Set(1) { 'user-preferences' } +2ms
  puppeteer-extra-plugin:base:user-preferences Initialized. +0ms
  puppeteer-extra plugin registered user-preferences +4ms
  puppeteer-extra dependencies missing Set(1) { 'user-data-dir' } +1ms
  puppeteer-extra-plugin:base:user-data-dir Initialized. +0ms
  puppeteer-extra-plugin:user-data-dir initialized {
  deleteTemporary: true,
  deleteExisting: false,
  files: [],
  folderPath: '/tmp',
  folderPrefix: 'puppeteer_dev_profile-'
} +0ms
  puppeteer-extra plugin registered user-data-dir +35ms
  puppeteer-extra orderPlugins:before [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +0ms
  puppeteer-extra orderPlugins:after [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +1ms
  puppeteer-extra-plugin:user-preferences _userPrefsFromPlugins { intl: { accept_languages: 'en-US,en' } } +0ms
  puppeteer-extra-plugin:user-data-dir created custom dir /tmp/puppeteer_dev_profile-7AUxTK +5ms
  puppeteer-extra-plugin:user-data-dir Wrote file /tmp/puppeteer_dev_profile-7AUxTK/Default/Preferences +10ms
Start
  puppeteer-extra-plugin:user-data-dir onClose +282ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +0ms
(node:508780) [DEP0147] DeprecationWarning: In future versions of Node.js, fs.rmdir(path, { recursive: true }) will be removed. Use fs.rm(path, { recursive: true }) instead
(Use `node --trace-deprecation ...` to show where the warning was created)
Done
  puppeteer-extra no dependencies are missing +304ms
  puppeteer-extra orderPlugins:before [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +0ms
  puppeteer-extra orderPlugins:after [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +1ms
  puppeteer-extra-plugin:user-preferences _userPrefsFromPlugins { intl: { accept_languages: 'en-US,en' } } +0ms
  puppeteer-extra-plugin:user-data-dir created custom dir /tmp/puppeteer_dev_profile-XZMNIJ +11ms
  puppeteer-extra-plugin:user-data-dir Wrote file /tmp/puppeteer_dev_profile-XZMNIJ/Default/Preferences +1ms
Start
  puppeteer-extra-plugin:user-data-dir onClose +262ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +0ms
Done
  puppeteer-extra no dependencies are missing +282ms
  puppeteer-extra orderPlugins:before [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +0ms
  puppeteer-extra orderPlugins:after [
  'stealth/evasions/user-agent-override',
  'user-preferences',
  'user-data-dir'
] +0ms
  puppeteer-extra-plugin:user-preferences _userPrefsFromPlugins { intl: { accept_languages: 'en-US,en' } } +0ms
  puppeteer-extra-plugin:user-data-dir created custom dir /tmp/puppeteer_dev_profile-AcWeuM +21ms
  puppeteer-extra-plugin:user-data-dir Wrote file /tmp/puppeteer_dev_profile-AcWeuM/Default/Preferences +19ms
Start
  puppeteer-extra-plugin:user-data-dir onClose +221ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +1ms
Done
DONE WAIT
  puppeteer-extra-plugin:user-data-dir onClose +5s
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +0ms
  puppeteer-extra-plugin:user-data-dir Error: ENOENT: no such file or directory, stat '/tmp/puppeteer_dev_profile-AcWeuM'
  puppeteer-extra-plugin:user-data-dir     at Object.statSync (node:fs:1536:3)
  puppeteer-extra-plugin:user-data-dir     at __node_internal_ (node:internal/fs/utils:793:8)
  puppeteer-extra-plugin:user-data-dir     at Object.rmdirSync (node:fs:1156:15)
  puppeteer-extra-plugin:user-data-dir     at Plugin.deleteUserDataDir (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:72:11)
  puppeteer-extra-plugin:user-data-dir     at Plugin.onClose (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:114:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:events:406:35)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:domain:475:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (/var/www/projects/svb-bot/node_modules/@cspotcode/source-map-support/source-map-support.js:527:35) +0ms
  puppeteer-extra-plugin:user-data-dir onClose +5ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +0ms
  puppeteer-extra-plugin:user-data-dir Error: ENOENT: no such file or directory, stat '/tmp/puppeteer_dev_profile-AcWeuM'
  puppeteer-extra-plugin:user-data-dir     at Object.statSync (node:fs:1536:3)
  puppeteer-extra-plugin:user-data-dir     at __node_internal_ (node:internal/fs/utils:793:8)
  puppeteer-extra-plugin:user-data-dir     at Object.rmdirSync (node:fs:1156:15)
  puppeteer-extra-plugin:user-data-dir     at Plugin.deleteUserDataDir (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:72:11)
  puppeteer-extra-plugin:user-data-dir     at Plugin.onClose (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:114:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:events:406:35)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:domain:475:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (/var/www/projects/svb-bot/node_modules/@cspotcode/source-map-support/source-map-support.js:527:35) +0ms
  puppeteer-extra-plugin:user-data-dir onClose +1ms
  puppeteer-extra-plugin:user-data-dir removeUserDataDir +1ms
  puppeteer-extra-plugin:user-data-dir Error: ENOENT: no such file or directory, stat '/tmp/puppeteer_dev_profile-AcWeuM'
  puppeteer-extra-plugin:user-data-dir     at Object.statSync (node:fs:1536:3)
  puppeteer-extra-plugin:user-data-dir     at __node_internal_ (node:internal/fs/utils:793:8)
  puppeteer-extra-plugin:user-data-dir     at Object.rmdirSync (node:fs:1156:15)
  puppeteer-extra-plugin:user-data-dir     at Plugin.deleteUserDataDir (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:72:11)
  puppeteer-extra-plugin:user-data-dir     at Plugin.onClose (/var/www/projects/svb-bot/node_modules/puppeteer-extra-plugin-user-data-dir/index.js:114:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:events:406:35)
  puppeteer-extra-plugin:user-data-dir     at process.emit (node:domain:475:12)
  puppeteer-extra-plugin:user-data-dir     at process.emit (/var/www/projects/svb-bot/node_modules/@cspotcode/source-map-support/source-map-support.js:527:35) +0ms


@stupidpr
Copy link
Author

Probably properProbably proper test case tht solves issue with same folder name. Main issue is still here

import {addExtra} from "puppeteer-extra";

const puppeteerCore = require('puppeteer');

async function runOne() {

    let puppeteer = addExtra(puppeteerCore);
    const UserAgentOverride = require("puppeteer-extra-plugin-stealth/evasions/user-agent-override");
    puppeteer.use(UserAgentOverride());

    const browser = await puppeteer.launch({headless: true} as any);
    console.log('Start');
    await browser.close();
    console.log('Done');
}
(async function main() {
    await runOne();
    await runOne();
    await runOne();
    await new Promise(resolve => setTimeout(resolve, 5000));
    console.log('DONE WAIT');
})();

@stupidpr
Copy link
Author

stupidpr commented Sep 20, 2021

Looks like because of PuppeteerExtraPlugin._bindBrowserEvents :

[skipped]
if (this.onClose) {
                process.on('exit', this.onClose.bind(this));
                browser.on('disconnected', this.onClose.bind(this));
                if (opts.options.handleSIGINT !== false) {
                    process.on('SIGINT', this.onClose.bind(this));
                }
                if (opts.options.handleSIGTERM !== false) {
                    process.on('SIGTERM', this.onClose.bind(this));
                }
                if (opts.options.handleSIGHUP !== false) {
                    process.on('SIGHUP', this.onClose.bind(this));
                }
            }
[skipped]

All the plugin instances with "onClose" are not released on browser close, stays in memory until end of the script and cause memory leak in case of long run. Do I miss something?

@stupidpr stupidpr changed the title [Bug] puppeteer-extra-plugin:user-data-dir.onClose called twice and causes Error [Bug] puppeteer-extra-plugin:user-data-dir.onClose called twice and causes Error. Also possible memory leak with Plugins Sep 20, 2021
@berstend
Copy link
Owner

berstend commented Sep 20, 2021

@stupidpr are you using the latest version of the plugin? we just switched from onClose to onDisconnected in #530

@stupidpr
Copy link
Author

stupidpr commented Sep 20, 2021

@stupidpr are you using the latest version of the plugin? we just switched from onClose to onDisconnected in #530

I use 3.1.18. But in master I still see

process.on('exit', this.onClose.bind(this))

That prevents proper release Plugin instances on browser close and keep them in memory until process end.

@berstend
Copy link
Owner

I use 3.1.18.

I meant the plugins:

Successfully published:
 - puppeteer-extra-plugin-stealth@2.7.9
 - puppeteer-extra-plugin-user-data-dir@2.2.13
 - puppeteer-extra-plugin-user-preferences@2.2.13

onClose has been deprecated for a while, we could however add e.g. if (this._hasChildClassMember('onClose')) { this.onClose() }, then the event would only be registered when a plugin actually defines a onClose method.

In addition we could "debounce" the onClose event to only be emitted once per (browser-) session 🤔

@berstend
Copy link
Owner

But yeah, it seems like you're not using the latest stealth/user-data-dir plugin version, as onClose has been removed and we switched to onDisconnected which should not have these issues.

@stupidpr
Copy link
Author

stupidpr commented Sep 20, 2021

But yeah, it seems like you're not using the latest stealth/user-data-dir plugin version, as onClose has been removed and we switched to onDisconnected which should not have these issues.

Yeah, thank you, I see what you mean now. Will try it tomorrow.
I wonder if continue supporting onClose in PuppeteerExtraPlugin makes sense as it still lead to hidden memory issue in any custom outdated Plugins

@stupidpr
Copy link
Author

Confirm with latest issue was resolved

 - puppeteer-extra@3.1.18
 - puppeteer-extra-plugin-stealth@2.7.9
 - puppeteer-extra-plugin-user-data-dir@2.2.13
 - puppeteer-extra-plugin-user-preferences@2.2.13

@andrewcartwright1
Copy link

andrewcartwright1 commented Oct 20, 2021

Hi,

I raised this on the discord (https://discord.com/channels/737009125862408274/737010875960918058/900444366248763462) - but my local appears to still be hanging at this point.

      } else {
        // Deprecated since node >= v14.14.0
        console.log('deleting profile');
        fs.rmdirSync(this._userDataDir, {
          recursive: true,
          maxRetries: 3
        })
        console.log('deleted profile');
      }

to mitigate this I have followed the advice here: #421 (comment) which seems to work.

"puppeteer-extra-plugin-stealth":  "version": "2.9.0",
"puppeteer-extra-plugin-user-data-dir":  "version": "2.3.1",
"puppeteer-extra-plugin-user-preferences": "version": "2.3.1",

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
issue: bug report A bug has been reported needs triage
Projects
None yet
Development

No branches or pull requests

3 participants