browser-chrome: browser_600545.js (and _601955.js) intermittently times out

RESOLVED FIXED in Firefox 6

Status

()

defect
RESOLVED FIXED
9 years ago
7 years ago

People

(Reporter: cmtalbert, Assigned: ttaubert)

Tracking

({intermittent-failure})

Trunk
Firefox 6
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(status2.0 ?)

Details

Attachments

(3 attachments, 4 obsolete attachments)

Reporter

Description

9 years ago
The browser chrome test browser_600545.js intermittently times out and then causes a few other errors afterward saying "found a tab after previous test timed out"

Zpao was saying that it might be a listener being removed too late when a tab is closing. The test was found to be flaky in running solo mode as well on bug 600545.

also there are some odd warnings scattered about the logs: "NetworkPrioritizer.jsm, line 117: reference to undefined property aBrowser.webNavigation" too, which may not be related.  Filing a separate bug on that too.

                aBrowser.webNavigation" 
Log: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1291939684.1291942553.22646.gz&fulltext=1#err0

Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/12/09 16:08:04

s: talos-r3-leopard-008
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/sessionstore/test/browser/browser_600545.js | Test timed out
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/sessionstore/test/browser/browser_600545.js | Found a tab after previous test timed out: http://example.com/#2
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/sessionstore/test/browser/browser_600545.js | Found a tab after previous test timed out: http://example.com/#1
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/sessionstore/test/browser/browser_600545.js | Found a browser window after previous test timed out
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/sessionstore/test/browser/browser_600545.js | Number of tabs in retreived session data, matches number of tabs set. - Got 1, expected 7
Reporter

Comment 1

9 years ago
(In reply to comment #0)
> also there are some odd warnings scattered about the logs:
> "NetworkPrioritizer.jsm, line 117: reference to undefined property
> aBrowser.webNavigation" too, which may not be related.  Filing a separate bug
> on that too.
That's covered in bug 618193.
(In reply to comment #0)
> Zpao was saying that it might be a listener being removed too late when a tab
> is closing.

I think I intended this for the NetworkPrioritizer warnings in bug 618193
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Summary: browser-chrome: browser_600545.js intermittently times out → browser-chrome: browser_600545.js (and browser_601955.js) intermittently times out
Version: unspecified → Trunk
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Summary: browser-chrome: browser_600545.js (and browser_601955.js) intermittently times out → browser-chrome: browser_600545.js (and _601955.js) intermittently times out
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
OS: Mac OS X → All
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Depends on: 618470
Assignee: nobody → tim.taubert
Status: NEW → ASSIGNED
Posted patch patch v1 (obsolete) — Splinter Review
Attachment #528291 - Flags: review?(paul)
Blocks: 651643
Comment on attachment 528291 [details] [diff] [review]
patch v1

Review of attachment 528291 [details] [diff] [review]:

let is the new var! Otherwise that should be fine.
Attachment #528291 - Flags: review?(paul) → review+
Posted patch patch for checkin (obsolete) — Splinter Review
(In reply to comment #181)
> let is the new var! Otherwise that should be fine.

Of course, damn copy'n'paste :)
Attachment #528291 - Attachment is obsolete: true
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Keywords: checkin-needed
Whiteboard: [orange] → [fixed in cedar]
Pushed:
https://bugzilla.mozilla.org/show_bug.cgi?id=618188
Status: ASSIGNED → RESOLVED
Last Resolved: 8 years ago
Flags: in-litmus+
Resolution: --- → FIXED
Whiteboard: [fixed in cedar]
Target Milestone: --- → Firefox 6
Whiteboard: [orange]
Comment hidden (Legacy TBPL/Treeherder Robot)
Still seems to be timing out
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
It timed out while waiting for the session state to be saved:

>  waitForBrowserState(state, function() {
>    waitForSaveState(function () {

Paul: As waitForBrowserState() uses executeSoon() to execute the callback, is it possible that the state has been saved already by "sessionstore.interval" or something equivalent?
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Posted patch patch v2 (obsolete) — Splinter Review
(In reply to comment #189)
> It timed out while waiting for the session state to be saved:
> 
> >  waitForBrowserState(state, function() {
> >    waitForSaveState(function () {
> 
> Paul: As waitForBrowserState() uses executeSoon() to execute the callback, is
> it possible that the state has been saved already by "sessionstore.interval" or
> something equivalent?

sessionstore.interval decreased to 2000ms.
Attachment #528410 - Attachment is obsolete: true
Attachment #529805 - Flags: review?(paul)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment on attachment 529805 [details] [diff] [review]
patch v2

>+  Services.prefs.setIntPref("browser.sessionstore.interval", 2000);

I don't think this is going to help. If the problem is that we're saving before waitForSaveState, then making the timer shorter would actually just exacerbate the problem (I think).

Really we want something like I just proposed in bug 656147.

But until that happens, we can work around this more scientifically than just grasping at straws:
* In waitForSaveState, look up sessionstore.interval, then add 1000 (just to be sure, give time for JSON crap, writing to disk since that happens after the interval timer)
* create a one shot timer which would just call aSaveStateCallback (and remove the observer), then start it
* in the observer callback, cancel the timer
* keep sessionstore.interval to something small like you have.

This *should* make sure that we never just get stuck waiting for a notification that's not coming (and it doesn't matter that it's not coming because it's already happened)

Tim: Do you still want to own this bug and take the above on?
Attachment #529805 - Flags: review?(paul) → review-
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Posted patch patch v3 (obsolete) — Splinter Review
Attachment #529805 - Attachment is obsolete: true
Attachment #531904 - Flags: review?(paul)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment on attachment 531904 [details] [diff] [review]
patch v3

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

::: browser/components/sessionstore/test/browser/head.js
@@ +126,3 @@
>    function observer(aSubject, aTopic, aData) {
>      Services.obs.removeObserver(observer, topic, false);
> +    clearTimeout(timeout);

Let's make this
> timeout = clearTimeout(timeout);

@@ +133,4 @@
>    registerCleanupFunction(function() {
>      if (observing) {
>        Services.obs.removeObserver(observer, topic, false);
>      }

And that way here we can say
> if (timeout) clearTimeout...
just to make sure that we don't accidentally call that when we shouldn't
Attachment #531904 - Flags: review?(paul) → review+
Comment hidden (Legacy TBPL/Treeherder Robot)
(In reply to comment #213)
> Let's make this
> > timeout = clearTimeout(timeout);
> 
> And that way here we can say
> > if (timeout) clearTimeout...
> just to make sure that we don't accidentally call that when we shouldn't

Fixed.
Attachment #531904 - Attachment is obsolete: true
Flags: in-litmus+
Keywords: checkin-needed
Hardware: x86 → All
Whiteboard: [orange] → [orange][fixed in cedar]
Comment hidden (Legacy TBPL/Treeherder Robot)
Pushed:
http://hg.mozilla.org/mozilla-central/rev/fff184536887
Status: REOPENED → RESOLVED
Last Resolved: 8 years ago8 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Whiteboard: [orange][fixed in cedar] → [orange]
Just saw this random orange. Starring now.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Comment hidden (Legacy TBPL/Treeherder Robot)
Actually, this is different than the timeout. It looks to be related to the new patch. Should I open a new bug?
Quick guess, it looks like the observer can get removed twice in this test. Which might perhaps trigger the assertion in the log?
Posted patch Possible fixSplinter Review
(In reply to comment #221)
> Quick guess, it looks like the observer can get removed twice in this test.
> Which might perhaps trigger the assertion in the log?

I think so, but I have no idea how could it be happened yet.
Attachment #533512 - Flags: review?(paul)
Hmm, perhaps somehow the test finishes before the timeout? In any case that patch looks like it should prevent such a problem.
(In reply to comment #222)
> I think so, but I have no idea how could it be happened yet.

The setTimeout callback doesn't set "observing = false". So in case we trigger the actual timeout which was intermittent before we now fail because we try to remove the observer a second time when cleaning up. Damn :/

Your patch looks good and should solve that!
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment on attachment 533512 [details] [diff] [review]
Possible fix

Ah, good catch. Thanks!
Attachment #533512 - Flags: review?(paul) → review+
Status: REOPENED → RESOLVED
Last Resolved: 8 years ago8 years ago
Resolution: --- → FIXED
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)