puppeteer: [Bug]: Unable to execute Chrome Extension APIs that require opening Chrome Dev Tools on the Browser

Minimal, reproducible example

Run this command  run nataletoscano/reproducible-puppeteer-bug:v1

Please note that you may have to run it multiple times since the issue is intermittent.

When the bug is not reproduced, you will see this message show up in the log: "EXTENSION IS ONLINE!"

When the bug is successfully reproduced, you will NOT see "EXTENSION IS ONLINE!" Instead, the stack trace will look like this:

[64:128:1129/222535.989995:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.008805:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.017256:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.017359:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.025163:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.025247:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.028006:VERBOSE1:tls_handshaker.cc(100)] TlsClient: Continuing handshake
[64:128:1129/222536.028491:VERBOSE1:tls_client_handshaker.cc(519)] Client: handshake finished


Repo: https://github.com/Vorelli/reproducible-puppeteer-bug

Error string

no error

Bug behavior

Flaky
PDF

Background

At my company’s enterprise application, we use puppeteer to spin up Chrome browsers and have extensions that rely on dev-tools to gather necessary data.

E2E tests began failing intermittently on the latest version of puppeteer. We realized that this is might be due to the puppeteer browser not reliably opening dev-tools on our extensions. As a result, we are unable to execute this Chrome Extension API on our extension chrome.devtools.network.getHAR

The last stable version of puppeteer when we did not face this issue is v21.3.8 and issues began from v21.4.0.

Perhaps the dependency update of @puppeteer/browsers from 1.7.1 to 1.8.0 introduced in v21.4.0 introduced the issue?

These tests run in a docker container with the following specifications: Server Version: 20.10.17 API Version: 1.41 Operating System: Ubuntu 20.04.4 LTS

We use puppeteer in conjunction with these packages: puppeteer-extra v3.3.6 puppeteer-extra-plugin-stealth v2.11.2

Log Trace on Successful Runs:


 37:57:1128/005843.804159:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: file:///chrome-engine/extension/networking/devtools.html
notice: App:v1.0.5186 | chrome-engines|AuditClient | driver 2023-11-28T00:58:43.852Z: Chrome launched: version Chrome/119.0.6045.105 {"incoming_queue":"data"}
[37:73:1128/005844.186392:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log
[37:73:1128/005844.186814:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/status
[37:73:1128/005844.192308:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log
[37:73:1128/005844.192585:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log
[360:360:1128/005844.334759:VERBOSE1:script_context.cc(144)] Created context:
  extension id:           dummy_data
  frame:                   dummy_data
  URL:                    
  context_type:           BLESSED_EXTENSION
  effective extension id:  dummy_data
  effective context type: BLESSED_EXTENSION
[360:360:1128/005844.335709:VERBOSE1:script_context.cc(144)] Created context:
  extension id:           (none)
  frame:                  (nil)
  URL:                    
  context_type:           UNSPECIFIED
  effective extension id: (none)
  effective context type: UNSPECIFIED
[360:360:1128/005844.337123:VERBOSE1:dispatcher.cc(456)] Num tracked contexts: 1
[37:57:1128/005844.349454:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: file:///path-to-extension-file.js
[37:57:1128/005844.352787:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: file:///path-to-extension-file.js
[37:57:1128/005844.354280:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: file:///path-to-extension-file.js
[37:57:1128/005844.355747:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: ffile:///path-to-extension-file.js
[37:57:1128/005844.356539:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: ffile:///path-to-extension-file.js
[37:73:1128/005844.360969:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log

Log stack trace on Failed Runs:


[37:57:1128/005701.934712:VERBOSE1:file_url_loader_factory.cc(453)] FileURLLoader::Start: file:///chrome-engine/extension/networking/devtools.html
notice: App:v1.0.5186 | chrome-engines|WebJourneyClient | driver 2023-11-28T00:57:02.225Z: Chrome launched: version Chrome/119.0.6045.105 {"data"}
**[37:73:1128/005702.457349:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log**
[37:73:1128/005702.457552:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/status
[37:73:1128/005702.462358:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log
[37:73:1128/005702.462486:VERBOSE1:network_delegate.cc(35)] NetworkDelegate::NotifyBeforeURLRequest: http://localhost:7980/log
[105:105:1128/005702.735057:VERBOSE1:script_context.cc(144)] Created context:
  extension id:           (none)
  frame:                  0x27a7001ee208
  URL:                    
  context_type:           UNSPECIFIED
  effective extension id: (none)
  effective context type: UNSPECIFIED
[105:105:1128/005702.735160:VERBOSE1:script_context.cc(144)] Created context:
  extension id:           (none)
  frame:                  (nil)
  URL:                    
  context_type:           UNSPECIFIED
  effective extension id: (none)
  effective context type: UNSPECIFIED

Notice how the extension files load in the successful scenario (v21.3.8), but did not load in the failed case (v21.5.2).

Expectation

The Chrome browser should always open dev-tools reliably, without failing intermittently and we should be able to execute this Chrome Extension API chrome.devtools.network.getHAR consistently in a puppeteer browser spun up by our extension.

The expectation is for this to work in puppeteer’s “new” mode.

Docker specifications: Server Version: 20.10.17 API Version: 1.41 Operating System: Ubuntu 20.04.4 LTS

Reality

The dev-tools window may not always be consistently opening on the browser loaded by an extension as there is an inability to execute this Chrome Extension API chrome.devtools.network.getHAR

Puppeteer configuration file (if used)

No response

Puppeteer version

21.5.2

Node version

16.14.2

Package manager

npm

Package manager version

8.3.1

Operating system

Linux

About this issue

Original URL
State: open
Created 7 months ago
Comments: 19

Most upvoted comments

<del>I have noticed that the error only seems to happen with the regular Chrome. And it seems to always work with the bundled Chrome for Testing version. Remove the env var PUPPETEER_SKIP_DOWNLOAD and do not provide the custom executable path. Perhaps it’s related to some of the Chrome policies. </del>

This is wrong. I simply forgot to comment out an explicit creation of a new page. In that case, it works.

OrKoN on Dec 5, 2023

I meant something like https://gist.github.com/OrKoN/03379638045d25d0147aa8ec11dd7043 I have tested that and unfortunately the problem seems to be related specifically to Puppeteer or perhaps delays caused by Puppeteer.

OrKoN on Dec 5, 2023

but is it possible that puppeteer setting the devtools binary in Chrome is part of the race condition?

https://github.com/puppeteer/puppeteer/blob/main/packages/puppeteer-core/src/node/ChromeLauncher.ts#L262 the devtools flag only sets the args when launching.

Or maybe some other update that was introduced in v21.4.0 like the dependency update of @puppeteer/browsers from 1.7.1 to 1.8.0.

I don’t see anything that would break this specifically. Need to investigate maybe the extension targets get blocked somehow.

OrKoN on Dec 1, 2023