1304359 - Infinite spinner with print edit + shutdownhang

Status: RESOLVED FIXED

(Firefox :: Untriaged, defect)

Description

[Jonathan Howard]

e10s enabled.
Install Print Edit https://addons.mozilla.org/en-GB/firefox/addon/print-edit/
(Optional) Still happens without, install various others to add slowness, ublock, privacy badger, greasemonkey, stylish etc.)
(Optional, recommended) Customise -> Move Print Preview to toolbar.
Visit web page (http://www.bbc.co.uk/news/ one I found most likely to trigger but http://www.theguardian.com/uk also triggered it, likely others too.)
As soon as content first appears (i.e. not fully loaded),
Click Print Preview. (Print Edit seems not to trigger it.)
Chrome switches correctly.
Content shows spinner and never stops (Not the bug if spinner stops and page displays.)
CPU constantly active.
Close print preview and spinner remains on the page.
New tabs function but noticeably bad.
Closing Firefox gives a crash with various shutdownhang signatures.

Regression range 2016-09-17 good, 2016-09-18 bad. exception stopped run going into inbound.
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=b3aa1f62ce6862722d16004cfdb9da973517f352&tochange=eaf5eb6f8fa0d8e7a09f3774c0da53c0dd6dadd7
Most likely regressed by: bug 1279086

Print Edit developer added to CC, I think fix probably more likely to be change in Firefox but developer with knowledge of code better at determining.

Comment 1

[Ryan VanderMeulen [:RyanVM]]

Can you please try |mozregression --good c0021d576b3a --bad 4606672d8efe --repo mozilla-inbound| to see if you can confirm that culprit?

Comment 2

[dw-dev]

I am the developer of Print Edit.

I have done a brief test with Print Edit 17.2 and Nightly 52.0a1 (2016-09-21) (32-bit) on Windows 10, but I could not reproduce the problem with the BBC or Guardian web pages.

If File > Print Preview works without Print Edit installed, but hangs with Print Edit installed, then it seems most likely a timing or sequencing issue, or possibly a print preview progress listener issue.

Are we sure this problem doesn't happen without Print Edit installed?

Which operating system was this problem reproduced on?

Comment 3

[Jonathan Howard]

The very first time I triggered it was likely with the the page loaded (can't say if any XHR was active or not) but other tabs were still loading content (dirty profile, processcount high.) Later experimenting leads me to just triggering it with single tab (or extra idle tabs eg about:home) and pressing print preview soon after making request.

Confirmed regression is bug 1279086.
2016-09-22T10:02:56: INFO : Narrowed inbound regression window from [c6876f22, 7b707a4d] (3 revisions) to [c6876f22, ea326f6e] (2 revisions) (~1 steps left)
2016-09-22T10:02:56: DEBUG : Starting merge handling...
2016-09-22T10:02:56: DEBUG : Using url: https://hg.mozilla.org/integration/mozilla-inbound/json-pushes?changeset=ea326f6e7e6c485907fdb4e1739bcb2707f7c1bc&full=1
2016-09-22T10:03:02: DEBUG : Found commit message:
Bug 1303499 - Fix broken IPDL tests (r=me, NPOTB)
2016-09-22T10:03:02: INFO : The bisection is done.
2016-09-22T10:03:02: INFO : Stopped

I wouldn't be surprised if someone with a different computer could trigger it without print edit. For me it seems dependent on just print edit.
Debian main OS but also same for me on Windows 10 x64.

Unfortunately my computer is too old to run rr.

Any exiting (remote) open tabs also spin after closing print preview. Content process doesn't crash, new tabs open without spinner.

After triggering bug, browser toolbox always stops on;
https://dxr.mozilla.org/mozilla-central/rev/560b2c805bf7bebeb3ceebc495a81b2aa4c0c755/browser/base/content/tabbrowser.xml#3991

Had it now with default get firefox for android link. (Clean Nightly 20160921030221 just with print edit add-on.)
First tab home page second new tab which I click the thumbnail.
POST XHR & Cross-Origin Request Blocked first attempt which did not bug out.
Error try after. This time clicked print preview as soon as I saw tabs progress change from send to receive.

POST 
XHR 
https://www.google.com/_/og/promos/z [HTTP/2.0 400 Bad Request 138ms]
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://www.google.com/_/og/promos/z. (Reason: CORS header ‘Access-Control-Allow-Origin’ missing). (unknown)
Error: Assertion failure  tabbrowser.xml:3623:23
	_getSwitcher/switcher.assert chrome://browser/content/tabbrowser.xml:3623:23
	_getSwitcher/switcher.onLayersReady chrome://browser/content/tabbrowser.xml:3772:15
	_getSwitcher/switcher.handleEvent chrome://browser/content/tabbrowser.xml:3954:17
XML Parsing Error: no root element found
Location: https://play.google.com/jserror?script=https%3A%2F%2Fplay.google.com%2Fstore%2Fapps%2Fdetails%3Fid%3Dorg.mozilla.firefox%26referrer%3Dadjust_reftag%253Dc8LU4U0MppQxE%2526utm_source%253DProduct%252BMarketing%252B%252528not%252Bads%252529%2526utm_campaign%253Dtiles%2526utm_content%253Ddirectory%2526utm_term%253Dgeneral&error=PlayStorePurchaseFlowPayments%20script%20promise%20rejected%20with%20reason%3ACustomError%3A%20Jsloader%20error%20(code%20%231)%3A%20Timeout%20reached%20for%20loading%20script%20https%3A%2F%2Fpayments.google.com%2Fpayments%2Fv4%2Fjs%2Fintegrator.js%3Fss%3Dn&line=Not%20available
Line Number 1, Column 1:

Comment 4

[Justin [:JW_SoftvisionQA]]

I can confirm from Ryans Mozregression command above that this is being caused by 1279086.

Bill it looks like you fixed 1279086, could you look at this one?

Comment 5

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Attachment: workaround

The problem is that the print edit extension is doing this from a frame script:

chrome/content/printedit-framescript-edit.js:
>>>
    enterPrintEditFirst: function(message)
    {
        var uri;
        
        /* Make edit browser active */
        docShell.isActive = true;
<<<

Ideally the extension would call activateBrowserForPrintPreview/deactivatePrintPreviewBrowsers on gBrowser. That's the "right" way to do it, although there's no way for the developer to know that. I'm needinfoing the developer to see if this can be fixed.

Activating a docshell outside of tabbrowser's control causes the tabbrowser to lose track of  which browser elements are active, and so an assertion fires later because the state doesn't match what it expects:

Assertion failure
_getSwitcher/switcher.assert@chrome://browser/content/tabbrowser.xml:3622:46
_getSwitcher/switcher.onLayersReady@chrome://browser/content/tabbrowser.xml:3776:15

When the assertion fires, we throw an exception and leave the browser in a really bad state from which it can never recover. We probably shouldn't be breaking the user's browser so badly when a tabswitch assertion fails. That's something we can fix on our end, and that's what this patch does.

In this case, the assertion that's failing probably doesn't mean anything too bad is happening. We might show the spinner when we shouldn't, but it should get fixed up on the next switch if it weren't for the assertion.

Comment 6

[Mike Conley (:mconley) (:⚙️)]

Comment on attachment 8795464 [details] [diff] [review]
workaround

Review of attachment 8795464 [details] [diff] [review]:
-----------------------------------------------------------------

Sounds like the right call. Thanks, billm.

Comment 7

[dw-dev]

It is very simple to move "docShell.isActive = true;" from the frame script to become "printEdit.editBrowser.docShellIsActive = true;" in the parent process.

You should be aware that activateBrowserForPrintPreview/deactivatePrintPreviewBrowsers are also not used in PrintUtils.js:

   // Set the original window as an active window so any mozPrintCallbacks can
   // run without delayed setTimeouts.
   if (this._listener.activateBrowser) {
     this._listener.activateBrowser(this._sourceBrowser);
   } else {
     this._sourceBrowser.docShellIsActive = true;
   }

Comment 8

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

(In reply to dw-dev from comment #7)
> It is very simple to move "docShell.isActive = true;" from the frame script
> to become "printEdit.editBrowser.docShellIsActive = true;" in the parent
> process.

docShellIsActive is not sufficient. You need to use activateBrowserForPrintPreview instead.

> You should be aware that
> activateBrowserForPrintPreview/deactivatePrintPreviewBrowsers are also not
> used in PrintUtils.js:
> 
>    // Set the original window as an active window so any mozPrintCallbacks
> can
>    // run without delayed setTimeouts.
>    if (this._listener.activateBrowser) {
>      this._listener.activateBrowser(this._sourceBrowser);
>    } else {
>      this._sourceBrowser.docShellIsActive = true;
>    }

this._listener.activateBrowser calls activateBrowserForPrintPreview:
http://searchfox.org/mozilla-central/rev/767e1e9b118269f957ca1817138472146278a29e/browser/base/content/browser.js#3373

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/bcaf503c7f54
Don't break browser for tabswitch assertions (r=mconley)

Comment 10

[Carsten Book [:Tomcat]]

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

Comment 11

[Mike Conley (:mconley) (:⚙️)]

Comment on attachment 8795464 [details] [diff] [review]
workaround

Approval Request Comment
[Feature/regressing bug #]:

Bug 1279086

[User impact if declined]:

Users who use the Print Edit add-on with e10s enabled (currently I only believe this is possible without user intervention on Nightly and Aurora) can get into a state where switching tabs breaks after entering print preview. Switching tabs in that window will fail to work after hitting this error.

[Describe test coverage new/current, TreeHerder]:

I'm afraid there's no test coverage for this particular bug.

[Risks and why]: 

Low risk. Essentially, we're making assertion failures in the tab switcher non-fatal on non-debug builds. This Print Edit author has also indicated that they'll be updating their add-on, but this change also makes us more resilient / able to recover from add-ons that might do similar things.

[String/UUID change made/needed]:

None.

Comment 12

[dw-dev]

I have had a look at the latest code in printUtils.js, browser.js and tabbrowser.xml using DXR to fully understand what has changed recently.

To maintain compatibility with all versions of Firefox from 4.0 onwards, the fix for Print Edit will be to add the following code in the parent process:

    if (printEdit.ffVersion >= +"51.0") gBrowser.activateBrowserForPrintPreview(printEdit.editBrowser);
    else if (printEdit.ffVersion >= +"34.0") printEdit.editBrowser.docShellIsActive = true;
    else printEdit.editBrowser.docShell.isActive = true;

I expect to submit Print Edit 17.3 with this fix to Mozilla for review by the end of the week.

Comment 13

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Thanks, that looks perfect!

Comment 14

[Gerry Chang [:gchang]]

Comment on attachment 8795464 [details] [diff] [review]
workaround

Fix a regression related to Print Edit add-on. Take it in 51 aurora.

Comment 15

[dw-dev]

Print Edit 17.3 with fix has been submitted to Mozilla for review.

Comment 16

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/9fdbac8eb078