Closed Bug 1379447 Opened 7 years ago Closed 7 years ago

Intermittent browser/base/content/test/general/browser_alltabslistener.js | {onStateChange,onStatusChange,onLocationChange} notification came from the correct browser -

Categories

(Firefox :: Tabbed Browser, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
Firefox 56
Tracking Status
firefox56 --- fixed

People

(Reporter: aryx, Assigned: Gijs)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed:timing])

Attachments

(1 file)

https://treeherder.mozilla.org/logviewer.html#?job_id=112796420&repo=mozilla-inbound

13:50:09     INFO - TEST-START | browser/base/content/test/general/browser_alltabslistener.js
13:50:09     INFO - GECKO(1680) | ++DOCSHELL 0x12498e800 == 2 [pid = 1682] [id = {e1aedad8-7faa-3f48-810e-5b45716a02a6}]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 9 (0x12499f800) [pid = 1682] [serial = 21] [outer = 0x0]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 10 (0x1249a8000) [pid = 1682] [serial = 22] [outer = 0x12499f800]
13:50:09     INFO - GECKO(1680) | ++DOCSHELL 0x126f1d800 == 4 [pid = 1683] [id = {02550372-c0ab-8242-83ce-442a8ef69b39}]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 15 (0x126f30800) [pid = 1683] [serial = 21] [outer = 0x0]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 16 (0x139c5d800) [pid = 1683] [serial = 22] [outer = 0x126f30800]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 11 (0x124ba9000) [pid = 1682] [serial = 23] [outer = 0x12499f800]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 17 (0x1281e8000) [pid = 1683] [serial = 23] [outer = 0x126f30800]
13:50:09     INFO - GECKO(1680) | [Child 1682] WARNING: site security information will not be persisted: file /home/worker/workspace/build/src/security/manager/ssl/nsSiteSecurityService.cpp, line 552
13:50:09     INFO - GECKO(1680) | [Parent 1680] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /home/worker/workspace/build/src/netwerk/base/nsChannelClassifier.cpp, line 316
13:50:09     INFO - GECKO(1680) | [Parent 1680] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /home/worker/workspace/build/src/netwerk/base/nsChannelClassifier.cpp, line 316
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 18 (0x1281ee800) [pid = 1683] [serial = 24] [outer = 0x126f30800]
13:50:09     INFO - GECKO(1680) | ++DOMWINDOW == 12 (0x1254e1000) [pid = 1682] [serial = 24] [outer = 0x12499f800]
13:50:09     INFO - GECKO(1680) | --DOMWINDOW == 11 (0x11be89000) [pid = 1682] [serial = 13] [outer = 0x0] [url = about:blank]
13:50:09     INFO - GECKO(1680) | --DOMWINDOW == 10 (0x1244f5800) [pid = 1682] [serial = 15] [outer = 0x0] [url = about:blank]
13:50:09     INFO - TEST-INFO | started process screencapture
13:50:10     INFO - TEST-INFO | screencapture: exit 0
13:50:10     INFO - Buffered messages logged at 13:50:09
13:50:10     INFO - Waiting for browser load
13:50:10     INFO - Waiting for browser load
13:50:10     INFO - Saw state f0001 and status 0
13:50:10     INFO - Saw state f0001 and status 0
13:50:10     INFO - Saw state c0010 and status 0
13:50:10     INFO - Browser loaded about:blank
13:50:10     INFO - Saw state c0010 and status 804b0002
13:50:10     INFO - Saw state f0001 and status 0
13:50:10     INFO - Saw state c0010 and status 0
13:50:10     INFO - Browser loaded http://example.org/browser/browser/base/content/test/general/dummy_page.html
13:50:10     INFO - 
13:50:10     INFO - Test 1
13:50:10     INFO - Buffered messages finished
13:50:10     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_alltabslistener.js | onStatusChange notification came from the correct browser - 
13:50:10     INFO - Stack trace:
13:50:10     INFO - chrome://mochitests/content/browser/browser/base/content/test/general/browser_alltabslistener.js:onStatusChange:68
13:50:10     INFO - resource://gre/modules/RemoteAddonsParent.jsm:wrapProgressListener/get/<:968
13:50:10     INFO - chrome://browser/content/tabbrowser.xml:callListeners:492
13:50:10     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:513
13:50:10     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:590
13:50:10     INFO - chrome://browser/content/tabbrowser.xml:onStatusChange:882
13:50:10     INFO - resource://gre/modules/RemoteWebProgress.jsm:_callProgressListeners:179
13:50:10     INFO - resource://gre/modules/RemoteWebProgress.jsm:receiveMessage:240
13:50:10     INFO - AllProgress: onStateChange 0xc0010
13:50:10     INFO - Not taking screenshot here: see the one that was previously logged
Summary: Intermittent browser/base/content/test/general/browser_alltabslistener.js | onStatusChange notification came from the correct browser - → Intermittent browser/base/content/test/general/browser_alltabslistener.js | {onStateChange,onStatusChange} notification came from the correct browser -
this had an instance on July 8th, then picked up on July 10th and has been failing quite frequently.  This is on osx and primarily opt with some debug failures mixed in.

Here is a recent osx debug failure:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=114407408&lineNumber=2507

and a related screenshot:
https://public-artifacts.taskcluster.net/Y4pA3xCYQXWozLKeqv_aRg/0/public/test_info/mozilla-test-fail-screenshot_bEAjyh.png

here is data from the log file:
09:21:38     INFO - TEST-START | browser/base/content/test/general/browser_alltabslistener.js
09:21:38     INFO - GECKO(1687) | ++DOCSHELL 0x128cd0000 == 3 [pid = 1689] [id = {78b36d34-eb2d-3841-b52c-404dbf6b1b35}]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 8 (0x128cd5800) [pid = 1689] [serial = 21] [outer = 0x0]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 9 (0x129122000) [pid = 1689] [serial = 22] [outer = 0x128cd5800]
09:21:38     INFO - GECKO(1687) | ++DOCSHELL 0x121698800 == 3 [pid = 1690] [id = {bde85101-941e-af4c-b553-516a8047232e}]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 16 (0x124bba800) [pid = 1690] [serial = 21] [outer = 0x0]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 17 (0x124ef5800) [pid = 1690] [serial = 22] [outer = 0x124bba800]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 10 (0x12911b000) [pid = 1689] [serial = 23] [outer = 0x128cd5800]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 18 (0x128939800) [pid = 1690] [serial = 23] [outer = 0x124bba800]
09:21:38     INFO - GECKO(1687) | [Child 1689] WARNING: site security information will not be persisted: file /home/worker/workspace/build/src/security/manager/ssl/nsSiteSecurityService.cpp, line 552
09:21:38     INFO - GECKO(1687) | [Parent 1687] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /home/worker/workspace/build/src/netwerk/base/nsChannelClassifier.cpp, line 316
09:21:38     INFO - GECKO(1687) | [Parent 1687] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /home/worker/workspace/build/src/netwerk/base/nsChannelClassifier.cpp, line 316
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 11 (0x12951d800) [pid = 1689] [serial = 24] [outer = 0x128cd5800]
09:21:38     INFO - GECKO(1687) | ++DOMWINDOW == 19 (0x128940000) [pid = 1690] [serial = 24] [outer = 0x124bba800]
09:21:38     INFO - TEST-INFO | started process screencapture
09:21:38     INFO - TEST-INFO | screencapture: exit 0
09:21:38     INFO - Buffered messages logged at 09:21:38
09:21:38     INFO - Waiting for browser load
09:21:38     INFO - Waiting for browser load
09:21:38     INFO - Saw state f0001 and status 0
09:21:38     INFO - Saw state f0001 and status 0
09:21:38     INFO - Saw state c0010 and status 0
09:21:38     INFO - Browser loaded about:blank
09:21:38     INFO - Saw state c0010 and status 804b0002
09:21:38     INFO - Saw state f0001 and status 0
09:21:38     INFO - Saw state c0010 and status 0
09:21:38     INFO - Browser loaded http://example.org/browser/browser/base/content/test/general/dummy_page.html
09:21:38     INFO - 
09:21:38     INFO - Test 1
09:21:38     INFO - Buffered messages finished
09:21:38     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_alltabslistener.js | onStatusChange notification came from the correct browser - 
09:21:38     INFO - Stack trace:
09:21:38     INFO - chrome://mochitests/content/browser/browser/base/content/test/general/browser_alltabslistener.js:onStatusChange:68
09:21:38     INFO - resource://gre/modules/RemoteAddonsParent.jsm:wrapProgressListener/get/<:968
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:callListeners:492
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:513
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:590
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:onStatusChange:882
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:_callProgressListeners:179
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:receiveMessage:240
09:21:38     INFO - AllProgress: onStateChange 0xc0010
09:21:38     INFO - Not taking screenshot here: see the one that was previously logged
09:21:38     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_alltabslistener.js | onStateChange notification came from the correct browser - 
09:21:38     INFO - Stack trace:
09:21:38     INFO - chrome://mochitests/content/browser/browser/base/content/test/general/browser_alltabslistener.js:onStateChange:44
09:21:38     INFO - resource://gre/modules/RemoteAddonsParent.jsm:wrapProgressListener/get/<:968
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:callListeners:492
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:513
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:590
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:onStateChange:778
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:_callProgressListeners:179
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:receiveMessage:240
09:21:38     INFO - TEST-PASS | browser/base/content/test/general/browser_alltabslistener.js | Got an expected notification for the all notifications listener - 
09:21:38     INFO - TEST-PASS | browser/base/content/test/general/browser_alltabslistener.js | Got a notification for the all notifications listener - 
09:21:38     INFO - Not taking screenshot here: see the one that was previously logged
09:21:38     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_alltabslistener.js | Saw the expected number of notifications - 
09:21:38     INFO - Stack trace:
09:21:38     INFO - chrome://mochitests/content/browser/browser/base/content/test/general/browser_alltabslistener.js:onStateChange:50
09:21:38     INFO - resource://gre/modules/RemoteAddonsParent.jsm:wrapProgressListener/get/<:968
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:callListeners:492
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:513
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:590
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:onStateChange:778
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:_callProgressListeners:179
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:receiveMessage:240
09:21:38     INFO - Not taking screenshot here: see the one that was previously logged
09:21:38     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_alltabslistener.js | Saw the expected number of frontnotifications - 
09:21:38     INFO - Stack trace:
09:21:38     INFO - chrome://mochitests/content/browser/browser/base/content/test/general/browser_alltabslistener.js:onStateChange:51
09:21:38     INFO - resource://gre/modules/RemoteAddonsParent.jsm:wrapProgressListener/get/<:968
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:callListeners:492
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:513
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:590
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:onStateChange:778
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:_callProgressListeners:179
09:21:38     INFO - resource://gre/modules/RemoteWebProgress.jsm:receiveMessage:240
09:21:38     INFO - FrontProgress: onStateChange 0xf0001
09:21:38     I
NFO - TEST-PASS | browser/base/content/test/general/browser_alltabslistener.js | Got an expected notification for the front notifications listener - 
09:21:38     INFO - TEST-PASS | browser/base/content/test/general/browser_alltabslistener.js | Got a notification for the front notifications listener - 
09:21:38     INFO - AllProgress: onStateChange 0xf0001
09:21:38     INFO - TEST-PASS | browser/base/content/test/general/browser_alltabslistener.js | onStateChange notification came from the correct browser - 
09:21:38     INFO - TEST-PASS | browser/base/content/test/general/browser_alltabslistener.js | Got an expected notification for the all notifications listener - 
09:21:38     INFO - Not taking screenshot here: see the one that was previously logged
09:21:38     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/general/browser_alltabslistener.js | Got a notification for the all notifications listener - Got onStateChange, expected onLocationChange
09:21:38     INFO - Stack trace:
09:21:38     INFO - chrome://mochikit/content/browser-test.js:test_is:967
09:21:38     INFO - chrome://mochitests/content/browser/browser/base/content/test/general/browser_alltabslistener.js:onStateChange:46
09:21:38     INFO - resource://gre/modules/RemoteAddonsParent.jsm:wrapProgressListener/get/<:968
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:callListeners:492
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:513
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:_callProgressListeners:590
09:21:38     INFO - chrome://browser/content/tabbrowser.xml:onStateChange:778
...


I am not familiar with the test, but it would be nice if we could fix this while it is fresh!

::dao, I see you are the triage owner for the firefox::tabbed browser component, can you find someone from the tabbed browser team to look into this failure sometime in the next week or two?
Flags: needinfo?(dao+bmo)
Whiteboard: [stockwell needswork]
Summary: Intermittent browser/base/content/test/general/browser_alltabslistener.js | {onStateChange,onStatusChange} notification came from the correct browser - → Intermittent browser/base/content/test/general/browser_alltabslistener.js | {onStateChange,onStatusChange,onLocationChange} notification came from the correct browser -
(In reply to Joel Maher ( :jmaher) (UTC-8) from comment #2)
> ::dao, I see you are the triage owner for the firefox::tabbed browser
> component, can you find someone from the tabbed browser team to look into
> this failure sometime in the next week or two?

Unlikely... There is no tabbed browser team. Redirecting NI to mossop (module owner).
Flags: needinfo?(dao+bmo) → needinfo?(dtownsend)
See Also: → 951680
Dao's right -- there's no tabbed browser team, but we're the closest there is. :(

Could one of you (Gijs/Dao) look into at least starting adding some debugging to help figure out what's happening, so we get a sense of how important an issue this is (real bug vs timing vs whatever)? And then we can figure out how to prioritize fixing it, if it's not easy/obvious from there.

The logs in comment 0 indicate it's getting a notification from an unexpected browser, so maybe this can be as simple as logging what that browser/page is? The test looks pretty simple, so maybe it's just something dumb happening?
Flags: needinfo?(gijskruitbosch+bugs)
Flags: needinfo?(dtownsend)
Flags: needinfo?(dao+bmo)
Looks to me like the clue is right in comment #0. Specifically, the code does this before the test starts:


  // We must wait until a page has completed loading before
  // starting tests or we get notifications from that
  let promises = [
    waitForDocLoadComplete(gBackgroundBrowser),
    waitForDocLoadComplete(gForegroundBrowser)
  ];
  gBackgroundBrowser.loadURI(kBasePage);
  gForegroundBrowser.loadURI(kBasePage);
  Promise.all(promises).then(startTest1);


waitForDocLoadComplete effectively waits for a load to, err, complete, in that browser. It has helpful info() logging: https://dxr.mozilla.org/mozilla-central/source/browser/base/content/test/general/head.js#461 .

What it doesn't do is discriminate between loads. The log in comment #0 is:


13:50:10     INFO - Buffered messages logged at 13:50:09
13:50:10     INFO - Waiting for browser load
13:50:10     INFO - Waiting for browser load
13:50:10     INFO - Saw state f0001 and status 0
13:50:10     INFO - Saw state f0001 and status 0
13:50:10     INFO - Saw state c0010 and status 0
13:50:10     INFO - Browser loaded about:blank
13:50:10     INFO - Saw state c0010 and status 804b0002
13:50:10     INFO - Saw state f0001 and status 0
13:50:10     INFO - Saw state c0010 and status 0
13:50:10     INFO - Browser loaded http://example.org/browser/browser/base/content/test/general/dummy_page.html
13:50:10     INFO - 
13:50:10     INFO - Test 1

if I run this locally on a debug build and it passes, it looks like this:

3 INFO Waiting for browser load
4 INFO Waiting for browser load
5 INFO Saw state f0001 and status 0
6 INFO Saw state c0010 and status 804b0002
7 INFO Saw state f0001 and status 0
8 INFO Saw state c0010 and status 0
9 INFO Browser loaded http://example.org/browser/browser/base/content/test/general/dummy_page.html
10 INFO Saw state f0001 and status 0
11 INFO Saw state c0010 and status 804b0002
12 INFO Saw state f0001 and status 0
13 INFO Saw state c0010 and status 0
14 INFO Browser loaded http://example.org/browser/browser/base/content/test/general/dummy_page.html



Conclusion: one of the tabs loads about:blank, and then we start testing, and it then loads the requested dummy URL, throwing off the listeners because it's getting events for the 'wrong' tab.
Assignee: nobody → gijskruitbosch+bugs
Status: NEW → ASSIGNED
Flags: needinfo?(gijskruitbosch+bugs)
Flags: needinfo?(dao+bmo)
Mike, does the timeline where this started failing match with some of your (or someone else's?) changes to about:blank loading in remote browsers?
Flags: needinfo?(mconley)
Comment on attachment 8888078 [details]
Bug 1379447 - fix intermittent failure in browser_alltabslistener caused by tab hitting about:blank when waiting for page stops,

https://reviewboard.mozilla.org/r/158976/#review164544

::: browser/base/content/test/general/browser_alltabslistener.js:100
(Diff revision 1)
>  
>    // We must wait until a page has completed loading before
>    // starting tests or we get notifications from that
>    let promises = [
> -    waitForDocLoadComplete(gBackgroundBrowser),
> -    waitForDocLoadComplete(gForegroundBrowser)
> +    waitForDocLoadComplete(gBackgroundBrowser, kBasePage),
> +    waitForDocLoadComplete(gForegroundBrowser, kBasePage)

Can this use BrowserTestUtils.browserLoaded instead?
(In reply to Dão Gottwald [::dao] from comment #9)
> Comment on attachment 8888078 [details]
> Bug 1379447 - fix intermittent failure in browser_alltabslistener caused by
> tab hitting about:blank when waiting for page stops,
> 
> https://reviewboard.mozilla.org/r/158976/#review164544
> 
> ::: browser/base/content/test/general/browser_alltabslistener.js:100
> (Diff revision 1)
> >  
> >    // We must wait until a page has completed loading before
> >    // starting tests or we get notifications from that
> >    let promises = [
> > -    waitForDocLoadComplete(gBackgroundBrowser),
> > -    waitForDocLoadComplete(gForegroundBrowser)
> > +    waitForDocLoadComplete(gBackgroundBrowser, kBasePage),
> > +    waitForDocLoadComplete(gForegroundBrowser, kBasePage)
> 
> Can this use BrowserTestUtils.browserLoaded instead?

I think network stop happens after the load event, so I think that would leave room for a race (ie the load event would fire, we would continue with this code, and a bit later network stop would fire and we would still get notifications for the "wrong" tab in the listener).

There's also BrowserTestUtils.browserStopped, but that (like waitForDocLoadComplete pre-patch) doesn't currently allow filtering by URI. If you prefer, I could switch to browserStopped, and update it to have similar checks and info() statements as waitForDocLoadComplete, switch over the few other consumers in browser/base/content/test/general/ as well and remove the head.js waitForDocLoadComplete, to do a bit of cleanup, if you prefer?
Flags: needinfo?(dao+bmo)
(In reply to :Gijs from comment #10)
> There's also BrowserTestUtils.browserStopped, but that (like
> waitForDocLoadComplete pre-patch) doesn't currently allow filtering by URI.
> If you prefer, I could switch to browserStopped, and update it to have
> similar checks and info() statements as waitForDocLoadComplete, switch over
> the few other consumers in browser/base/content/test/general/ as well and
> remove the head.js waitForDocLoadComplete, to do a bit of cleanup, if you
> prefer?

That sounds reasonable.
Flags: needinfo?(dao+bmo)
Blocks: 1382616
Blocks: 951680
See Also: 951680
Comment on attachment 8888078 [details]
Bug 1379447 - fix intermittent failure in browser_alltabslistener caused by tab hitting about:blank when waiting for page stops,

https://reviewboard.mozilla.org/r/158976/#review164732

::: testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm:341
(Diff revision 2)
>      return new Promise(resolve => {
> +      const kDocStopFlags = Ci.nsIWebProgressListener.STATE_IS_NETWORK |
> +                            Ci.nsIWebProgressListener.STATE_STOP;
>        let wpl = {
>          onStateChange(aWebProgress, aRequest, aStateFlags, aStatus) {
> -          if (aStateFlags & Ci.nsIWebProgressListener.STATE_STOP &&
> +          dump("Saw state " + aStateFlags.toString(16) + " and status " + aStatus.toString(16) + "\n");

Use info()? Using dump in tests seems rather unusual.

::: testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm:342
(Diff revision 2)
> +      const kDocStopFlags = Ci.nsIWebProgressListener.STATE_IS_NETWORK |
> +                            Ci.nsIWebProgressListener.STATE_STOP;
>        let wpl = {
>          onStateChange(aWebProgress, aRequest, aStateFlags, aStatus) {
> -          if (aStateFlags & Ci.nsIWebProgressListener.STATE_STOP &&
> -              aWebProgress.isTopLevel) {
> +          dump("Saw state " + aStateFlags.toString(16) + " and status " + aStatus.toString(16) + "\n");
> +          if ((aStateFlags & kDocStopFlags) == kDocStopFlags &&

aStateFlags & Ci.nsIWebProgressListener.STATE_STOP &&
aStateFlags & Ci.nsIWebProgressListener.STATE_IS_NETWORK

::: testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm:343
(Diff revision 2)
> +                            Ci.nsIWebProgressListener.STATE_STOP;
>        let wpl = {
>          onStateChange(aWebProgress, aRequest, aStateFlags, aStatus) {
> -          if (aStateFlags & Ci.nsIWebProgressListener.STATE_STOP &&
> -              aWebProgress.isTopLevel) {
> -            browser.webProgress.removeProgressListener(filter);
> +          dump("Saw state " + aStateFlags.toString(16) + " and status " + aStatus.toString(16) + "\n");
> +          if ((aStateFlags & kDocStopFlags) == kDocStopFlags &&
> +              aWebProgress.isTopLevel && aStatus != Cr.NS_BINDING_ABORTED) {

nit: \n after && once you've started doing this in an expression, so that it can be scanned more constently.

::: testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm:359
(Diff revision 2)
>          onStatusChange() {},
>          onLocationChange() {},
>          QueryInterface: XPCOMUtils.generateQI([
>            Ci.nsIWebProgressListener,
>            Ci.nsIWebProgressListener2,
> +          Ci.nsISupportsWeakReference,

Why? I assume this is the only reason you introduced _webProgressListeners. Seems like not making this a weak reference could simplify things.
Comment on attachment 8888078 [details]
Bug 1379447 - fix intermittent failure in browser_alltabslistener caused by tab hitting about:blank when waiting for page stops,

https://reviewboard.mozilla.org/r/158976/#review164732

> Use info()? Using dump in tests seems rather unusual.

`info()` is not available in the JSM scope, so I can't.

> Why? I assume this is the only reason you introduced _webProgressListeners. Seems like not making this a weak reference could simplify things.

That's not possible because nsIWebProgress enforces that the listener can be weak-referenced, see the note in the docstring comment here: https://dxr.mozilla.org/mozilla-central/source/uriloader/base/nsIWebProgress.idl#98-114 .

This is only a problem in non-e10s because the JS re-implementation of `RemoteWeb*` doesn't enforce this constraint, but tests do fail in non-e10s without this.
Looks like, as written, this breaks  browser/base/content/test/urlbar/browser_urlbar_stop_pending.js . I'll have to have another look, I guess. :-\

Should we go with a more minimal patch in the meantime to shut up the intermittent?
FWIW, the new patch addresses your 2 other comments, and fixes the urlbar_stop_pending issue for me locally (I had to add an option to "allow" NS_ERROR_BINDING_ABORTED as a reason for the stop, as the test calls BrowserStop() and that's what that comes through as).
(In reply to :Gijs from comment #7)
> Mike, does the timeline where this started failing match with some of your
> (or someone else's?) changes to about:blank loading in remote browsers?

Unless I'm very mistaken, I think you're referring to bug 1261842? That landed last year, and so does not fall in the timeline in question.

Or are you referring to some other work?
Flags: needinfo?(mconley) → needinfo?(gijskruitbosch+bugs)
(In reply to Mike Conley (:mconley) - Buried in needinfo / review backlog, eating my way out from comment #22)
> (In reply to :Gijs from comment #7)
> > Mike, does the timeline where this started failing match with some of your
> > (or someone else's?) changes to about:blank loading in remote browsers?
> 
> Unless I'm very mistaken, I think you're referring to bug 1261842? That
> landed last year, and so does not fall in the timeline in question.
> 
> Or are you referring to some other work?

I don't know. I thought there must be something more recent, but maybe there wasn't.

I'm happy with the fix, I think, but I don't like it when I don't understand what's set off a latent bug, even if I know what the bug is. :-)
Flags: needinfo?(gijskruitbosch+bugs)
Comment on attachment 8888078 [details]
Bug 1379447 - fix intermittent failure in browser_alltabslistener caused by tab hitting about:blank when waiting for page stops,

https://reviewboard.mozilla.org/r/158976/#review166630

::: browser/base/content/test/urlbar/browser_urlbar_stop_pending.js:77
(Diff revision 3)
>    await BrowserTestUtils.synthesizeMouseAtCenter("#clickme", { button: 1 }, tab.linkedBrowser);
>    // get new tab, switch to it
>    let newTab = (await newTabPromise).target;
>    await BrowserTestUtils.switchTab(gBrowser, newTab);
>    is(gURLBar.value, SLOW_HOST, "Should have slow page in URL bar");
> -  let browserStoppedPromise = BrowserTestUtils.browserStopped(newTab.linkedBrowser);
> +  let browserStoppedPromise = BrowserTestUtils.browserStopped(newTab.linkedBrowser, "", false);

nit: null rather than ""

::: testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm:338
(Diff revision 3)
> +   *        (e.g. caused by the stop button or equivalent APIs)
>     *
>     * @return {Promise}
>     * @resolves When STATE_STOP reaches the tab's progress listener
>     */
> -  browserStopped(browser) {
> +  browserStopped(browser, expectedURI, ignoreAborts=true) {

I think I'd reverse the logic here, e.g. checkAborts=false
Attachment #8888078 - Flags: review?(dao+bmo) → review+
Pushed by gijskruitbosch@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/a9de37a148b7
fix intermittent failure in browser_alltabslistener caused by tab hitting about:blank when waiting for page stops, r=dao
https://hg.mozilla.org/mozilla-central/rev/a9de37a148b7
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 56
Whiteboard: [stockwell needswork] → [stockwell fixed:timing]
You need to log in before you can comment on or make changes to this bug.