1395287 - document_end content scripts run before document_start content scripts when extension starts up

Status: VERIFIED FIXED

(WebExtensions :: Untriaged, defect, P1)

Description

[Hubert Figuiere [:hub]]

This is with Nightly 2017-08-30.

In some circumstances, content_script "document_end" runs after the content_script "document_start". For us this mean that some of the things initialised in the document_start aren't when the document_end is run.

This happen often when installing or reloading the add-on.

I'm trying to come up with a simplified reproducible test case.

Comment 1

[Hubert Figuiere [:hub]]

This happen in combination to bug 1369841 which is about the background script.

Comment 2

[Wladimir Palant]

In the description, it should say: "document_end content script runs *before* document_start content script" of course. This is an issue because document_end scripts can usually rely on variables defined by document_start scripts.

Comment 3

[Wladimir Palant]

Attachment: Minimal extension to reproduce the issue

I was able to reproduce the issue reliably in Firefox 57.0a1 nightly (2017-08-30). Steps to reproduce:

1. Download attached extension.
2. Make sure exactly one website is loaded, e.g. http://example.com/
3. Open about:debugging in a new tab, click "Load Temporary Add-on" and select the downloaded extension.
4. Press Ctrl-Shift-J (Cmd-Shift-J on Mac) to open Browser Console and inspect the messages.

Expected results:

You first get the messages "Initializing content.js" and "Finished initializing content.js" (produced by the document_start content script), then "Initializing content-post.js" and "Finished initializing content-post.js" (produced by the document_end content script). The document_end script can always rely on variables defined by the document_start script. This is the behavior seen in Chrome.

Actual results:

The messages "Initializing content-post.js" and "Finished initializing content-post.js" got first, so the document_end content script loads before the document_start content script. There is an error message "content.js not yet initialized!" because required variable is missing. The order seems to be determined by I/O delays, for me it only reproduces reliably if I make the document_start script very large (73 kB, mostly padding comments).

Comment 4

[Tomislav Jovanovic :zombie]

This is happening because the script reading and "compilation" is done async, so it may end up

Comment 5

[Manish Jethani]

For what it's worth, Chrome seems to avoid this problem entirely by not running the content scripts at all upon installation.

Comment 6

[Manish Jethani]

I should add that this is not a problem only on installation. It also happens on browser startup. To see this behavior on startup, set your browser's home page to https://mozilla.org, then restart the browser and look at the messages in the console. You'll see the error "content.js not yet initialized!".

Comment 7

[Tomislav Jovanovic :zombie]

Attachment: Bug 1395287 - Order and chain content_scripts injection on startup

Review commit: https://reviewboard.mozilla.org/r/178096/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/178096/

Comment 8

[Kris Maglione [:kmag]]

Comment on attachment 8906383 [details]
Bug 1395287 - Order and chain content_scripts injection on startup

https://reviewboard.mozilla.org/r/178096/#review183038

Nice. Thanks!

::: toolkit/components/extensions/extension-process-script.js:204
(Diff revision 1)
> -          contentScripts.get(script).injectInto(window);
> +          runAt[script.runAt].push(script);
>          }
>        }
> +
> +      let inject = matcher => contentScripts.get(matcher).injectInto(window);
> +      let allDone = matchers => Promise.all(matchers.map(inject));

Nit: Maybe call this something like `injectAll`? `allDone` sounds like we're just waiting for scripts that are already injected to finish, which wouldn't make sense here.

::: toolkit/components/extensions/extension-process-script.js:208
(Diff revision 1)
> +      allDone(runAt.document_start)
> +        .then(() => allDone(runAt.document_end))
> +        .then(() => allDone(runAt.document_idle));

I'm fine with this, but you could also do something like:

    (async () => {
      await injectAll(document_start);
      await injectAll(document_end);
      await injectAll(document_idle);
    })();
    
Not that the last `await` is strictly necessary. It's probably also not strictly necessary to wait for `document_end` scripts to finish before running the `document_idle` ones, but it probably doesn't matter much either way.

Comment 9

[Tomislav Jovanovic :zombie]

Comment on attachment 8906383 [details]
Bug 1395287 - Order and chain content_scripts injection on startup

https://reviewboard.mozilla.org/r/178096/#review183038

> I'm fine with this, but you could also do something like:
> 
>     (async () => {
>       await injectAll(document_start);
>       await injectAll(document_end);
>       await injectAll(document_idle);
>     })();
>     
> Not that the last `await` is strictly necessary. It's probably also not strictly necessary to wait for `document_end` scripts to finish before running the `document_idle` ones, but it probably doesn't matter much either way.

Fair, though I like the explicitness of `.then` where blocking makes a difference (`await` is too easy to ignore and pretend it's not there ;)

Comment 10

[Tomislav Jovanovic :zombie]

Comment on attachment 8906383 [details]
Bug 1395287 - Order and chain content_scripts injection on startup

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/178096/diff/1-2/

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ce17d1d232f1
Order and chain content_scripts injection on startup r=kmag

Comment 12

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/ce17d1d232f1

Comment 13

[Victor Carciu]

Verified as fixed in Build identifier: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0 with steps from Comment #3. Please see postfix screenshot attached.

Comment 14

[Victor Carciu]

Attachment: Postfix screenshot - FF56 vs FF57 consoles