Extension Error from running Lighthouse on a github page

[Jeremip11]

Lighthouse Version: 3.0.3
Lighthouse Commit: d1cae24
Chrome Version: 70.0.3510.2
Initial URL: Jeremip11/thimble.mozilla.org#4
Error Message: Cannot attach to this target.
Stack Trace:

Error: Cannot attach to this target.
    at Object.chrome.debugger.attach [as callback] (chrome-extension://blipmdconlkpinefehnmjammfjpmpbjk/scripts/lighthouse-ext-background.js:17315:15)
    at safeCallbackApply (extensions::uncaught_exception_handler:27:15)
    at handleResponse (extensions::sendRequest:67:7)

[brendankenny]

I'm not certain what this bug is exactly. Cannot attach to this target should only come from Chrome if trying to run lighthouse on a privileged page (e.g. a file:///...).

However, can anyone else run the extension on github pages? (e.g. this page) They run fine in the CLI (master) and devtools (3.0.3) for me, but in the extension they're failing with

Error in event handler for debugger.onDetach: Error: Lighthouse detached from browser: target_closed
    at ExtensionConnection._onUnexpectedDetach (chrome-extension://blipmdconlkpinefehnmjammfjpmpbjk/scripts/lighthouse-ext-background.js:17284:7)

The driver then times out and I get ExtensionConnection:error No tabId set for sendCommand for subsequent commands, all ending with a sad ExtensionConnection:warn disconnect() was called without an established connection.

[justinribeiro]

@brendankenny Spot checked some github pages with extension, wasn't able to duplicate.

[brendankenny]

thanks for checking! @wardpeet mentioned it may be new behavior in Chrome 69+, but haven't verified

[justinribeiro]

@wardpeet is spot on; I can duplicate that with M69+ and the extension.

[wardpeet]

Ok so I did a lot of investigation here. The problem lies with Chrome detaching the debugger when a Chrome page is shown (offline dinosaur, chrome:// page, ...). When a website is ran without offline support we hit the Chrome offline page. This moment the extension detaches from the protocol (this wasn't happening before 69). We can fix this by trying to reattach each second until we move back to online mode in the next pass.

_onUnexpectedDetach(source, detachReason) {
    log.warn('ExtensionConnection', `Lighthouse detached from browser: ${detachReason}`);
    if (this._disconnectRetry-- > 0) {
      log.log('ExtensionConnection', 'retry debugger attachment');
      chrome.debugger.attach({ tabId: this._tabId}, '1.1', () => {
        if (chrome.runtime.lastError) {
          const errMessage = chrome.runtime.lastError.message;
          setTimeout(() => this._onUnexpectedDetach(null, errMessage), 1000);
        }
      });
    } else {
      log.log('ExtensionConnection', `cleaning up`);
      this._detachCleanup();
    }
  }

Another idea I had but not sure if it will work is to try using the intercept api of the protocol to intercept the page and always respond with a valid page, this only works if the Service Worker logic will still be executed even when we intercept. I could try this with an example page and puppeteer.

@paulirish could you maybe try to make a crbug out of this?

This is the tricky part, why does paulirish.com work without a service worker and github doesn't? Well paulirish.com is served from the network disk cache and github is not. I believe this happens because of the Cache-Control header. When looking at the extension logs I see the following:

paulirish.com:
look at the fromDiskCache: true value

lighthouse-ext-background.js:69284 <= Network.responseReceived +9ms 
frameId: "E72B0FA4DFE5F219F9B1265BD028ABDD"
loaderId: "2B7B5F64F5F4750718737FD0D0D907E8"
requestId: "2B7B5F64F5F4750718737FD0D0D907E8"
response: {connectionId: 0, connectionReused: false, encodedDataLength: 0, fromDiskCache: true, fromServiceWorker: false, …}
timestamp: 1372.156995
type: "Document"

The reason why we don't die here is that paulirish serves a valid 200 page. In our audit we explicit check for the fromServiceWorker field which still marks the audit as false.

github.com:

lighthouse-ext-background.js:69284 <= Network.loadingFailed +5ms 
canceled: false
errorText: "net::ERR_INTERNET_DISCONNECTED"
requestId: "2FB7BC22D6F91F7D217F0C50C8C77F28"
timestamp: 1124.141853
type: "Document"

Here we don't get any response back which is why we detach.

we can make paulirish.com fail with the same message if we remove the isPerfRun check in gatherer-runner.js#224

// Clear disk & memory cache if it's a perf run
if (isPerfRun) await driver.cleanBrowserCaches();

[patrickhulce]

Thanks for investigating @wardpeet this sounds sticky! This definitely sounds crbug worthy, especially if re-attaching works, and it wasn't some blanket security concern that prompted the no debugger on chrome:// pages.

[wardpeet]

reattaching only works when we go back online and load a page. This behaviour is new in chrome 69 but not sure how to actually explain this in a crbug honestly.

[patrickhulce]

Wait how are we able to send commands to go back online while we're detached 🤔

[wardpeet]

Why we go online I have no idea but could it be when we detach unexpectedly chrome tries to get back online? When network changes, chrome refreshes. You can test yourself using devtools and offline checkbox

[paulirish]

@wardpeet can you make a reduced repro extension with chrome.debugger.sendCommand so we can circulate with extension/devtools people? (and bisect)

[brendankenny]

Looking at the extension debugger API changes from this year, the only really relevant ones I see are

• https://chromium.googlesource.com/chromium/src/+/4dafc317b6e614bdd86ea3e2f5c2fc2e8518a877%5E%21/
• https://chromium.googlesource.com/chromium/src/+/a81e00522e161fd7f9c495ac1ea4792aef3f3eee%5E%21/

[Jeremip11]

Thank you everyone for the help and support,

[wardpeet]

I've created a repro extension which we might use for other bugs later on.
https://github.com/wardpeet/lh-extension-bug-repro

[paulirish]

https://chromium-review.googlesource.com/c/chromium/src/+/1217599 is going to land which will resolve this. im asking to merge back to 69.

• we should change our extension-test to use google.com or github.com where the cache-control header is present

@wardpeet you wanna take these?

---

update: looks like we wont do the extension ID safelisting, so no need to do this key/id thing. :)

[wardpeet]

@paulirish I missed this thanks, will take this one

[paulirish]

update: https://chromium-review.googlesource.com/c/chromium/src/+/1217599 has landed and we'll merge to 70.

69 is stable and hypothetically should have this bug, however me and @dgozman were unable to reproduce it yesterday. (we could reproduce fine in 70) However the 3 issues i just duped into here were all on 69.

Can anyone repro this problem on 69?

LH repro steps:

1. LH chrome extension installed
2. go to a site that has cache-control:no-cache on. github.com is one. also: https://drive.google.com/drive/my-drive and https://inleggo.io/login
3. start LH. perf and PWA cats

Or the more isolated repro:

1. install this unpacked extension https://github.com/wardpeet/lh-extension-bug-repro
2. go to any site. http://example.com is fine.
3. open the extension's popup.
4. click its button once to attach
5. click its button again to trigger a reload

In both cases, the extension should disconnect when the "your page is offline" error page comes up. the root issue is that chrome.debugger API isn't being given permission to inspect error pages as they are isolated in their own process.

[wardpeet]

@paulirish this is weird, it works again but it was definitely broken in 69.

I just tested lighthouse and my extension on Version 69.0.3497.100. And both work fine

[paulirish]

update: https://chromium-review.googlesource.com/1240865 landed and fixes the second half of the chromium bug that was a problem.

we're trying to get them merged to 70 now. not sure about 69.

[paulirish]

This is fixed in m70+; https://bugs.chromium.org/p/chromium/issues/detail?id=882589#c21

sorry 69.