1290016 - tabs.executeScript in webRequest.onCompleted gives "Unchecked lastError value: Error: No matching message handler"

Status: REOPENED

(WebExtensions :: Request Handling, defect, P3)

Description

[Rob Wu [:robwu]]

Attachment: executeScript-at-webRequest.onCompleted.zip

When tabs.executeScript is called in the webRequest.onCompleted event, the script is not injected and the console shows an error.

Steps to reproduce:
1. Start Firefox with e10s.
2. Load the attached addon.
3. Open the global JS console (Ctrl-Shift-J)
4. Visit example.com.
5. Look at the global console and/or the tab's console.

Expected: "Script injected in http://example.com" to be logged.
Actual: Unchecked lastError value: Error: No matching message handlerExtensionUtils.jsm:305

When I step through with a debugger I see that getHandlers in MessageChannel.jsm returns an empty list because the innerWindowID of the message manager (handler.messageFilterStrict) differs from the innerWindowID of |recipient|.
E.g.:
handler.messageFilterStrict.innerWindowID  // = 2147483680
recipient.innerWindowID                    // = 2147483679

Firefox versions tested:
- Firefox 47.0.1 (without e10s only = works fine)
- Firefox Beta (48, 2016-07-25)
- Firefox Nightly (50.0a1, 2016-07-23, with and without e10s)

Comment 1

[Kris Maglione [:kmag]]

I'd generally expect the inner window ID of the browser to be updated long before onCompleted gets called for the main document request. But it's probably not guaranteed if the request happens very quickly.

I'm not sure if this is a bug, though, strictly speaking.

Comment 2

[Thomas Oberndörfer]

I’m also running into this issue when calling tabs.executeScript in the webRequest.onCompleted handler:

browser.webRequest.onCompleted.addListener(details => {
  browser.tabs.executeScript(details.tabId, {file: 'test.js', frameId: details.frameId})
}, {urls: matchPatterns, ['main_frame', 'sub_frame']});

This works reliable for sub_frames but for main_frames the executeScript will occasionally throw a "No matching message handler".
The issue is in general hard to reproduce, but I could significantly reduce the error rate by doing a setTimeout of 20ms before calling tabs.executeScript.

Still those errors occur. I'm experimenting with longer setTimeouts but is there maybe another work around? Could webNavigation.onCompleted be more reliable for injecting scripts into the main frame?

Comment 3

[Rob Wu [:robwu]]

(In reply to Thomas Oberndörfer from comment #2)
> Still those errors occur. I'm experimenting with longer setTimeouts but is
> there maybe another work around? Could webNavigation.onCompleted be more
> reliable for injecting scripts into the main frame?

There is no guarantee that a document is already shown when the request has finished.
If you want to be sure that the frame has switched, use webNavigation.onCommitted as the earliest event.

Comment 4

[Thomas Oberndörfer]

(In reply to Rob Wu [:robwu] from comment #3)
> There is no guarantee that a document is already shown when the request has
> finished.
> If you want to be sure that the frame has switched, use
> webNavigation.onCommitted as the earliest event.

Using webNavigation instead of webRequest solved our problem. Thanks!

Comment 5

[Andy McKay]

Marking as resolved based on last comment.

Comment 6

[Rob Wu [:robwu]]

Comment 4 does not say that the bug has been fixed, but that my suggested work-around worked for his case. However, based on comment 2 that says claims that the bug is rare, closing the bug is probably OK.

I tried the test case (e10s for all) in different Firefox
Firefox 55.0.2 - works* (build 20170816212843)
Firefox 56.0b5 - sometimes broken* (build 20170821193225)
Firefox 57.0a1 - always broken** (build 20170913100125)

*Not observing the error does not prove that the bug has been solved, because it is caused by a race condition:
- webRequest.onCompleted fires, with tabId
- Internally tabId is translated to a tab, and a tab is translated to a innerWindowID.
- While the message was transferred to the content process, the innerWindowID changes.
- The message is received in the content process, and no recipient with the given innerWindowID is found.
- -> error (as reported).

innerWindowID in source code: https://searchfox.org/mozilla-central/source/toolkit/components/extensions/ext-tabs-base.js#86-90


NOTE: The odds of triggering this bug would be even less if we switch from innerWindowID to outerWindowID. The latter is a more accurate representation of the tabId concept; tabId is not tied to "page at the time of API invocation", but "whatever is in the tab".
Using innerWindowID instead of outerWindowID reduces the risk of running scripts in the wrong page, but there is no guarantee, because it is possible for this to happen:

- browser process sends tab info to extension
- extension receives tab info, calls API with given tabId.
- meanwhile browser process observes that the page has navigated and maps the tabId to a new URL.
- browser process receives API call from extension and uses the new URL instead of the URL at the time that the extension received the tabId.




**In the case of Firefox 57.0a1, the tabId is -1, and the error is:
Unchecked lastError value: Error: Invalid tab ID: -1

I haven't checked whether this last thing is the same as this issue, or a regression.
I am 100% sure that the tab does exist at the time that the request completes, because I requested localhost in an already-open tab, used netcat to respond to the request, saw that the page switched to the response and only then ended the response (to trigger onCompleted). The result is still "Invalid tab ID: -1".
(^ TODO: investigate)


Re-opening because of NOTE. If we decide to stick to innerWindowID, then this incompatibility should be documented at https://developer.mozilla.org/en-US/Add-ons/WebExtensions/Chrome_incompatibilities

Comment 7

[Firefox Bug Husbandry Bot]

With Firefox 57 only WebExtensions are permitted and are, by default, e10s compatible.

Comment 8

[Shmuel Melamud]

Stumbled upon this bug when writing an extension for Firefox 64.

Source code: https://github.com/MoeraOrg/moera-browser-extension/tree/39915879809e6ded3a410c2291ff00aed7ddd10e

The problem is easily reproducible - navigation from the target page and back causes failure to inject a script with about 50% probability. The error message "Error: No matching message handler" can be seen in the background script debugging console.

The recommended workaround using webNavigation.onCommitted works perfectly.