Closed Bug 494749 Opened 15 years ago Closed 15 years ago

mochitest-browser-chrome: browser_490040.js times out intermittently

Categories

(Firefox :: Session Restore, defect)

Product:
Firefox
Component:
Session Restore
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
VERIFIED FIXED
Milestone:
Firefox 3.6a1
Tracking Flags:
Tracking Status
status1.9.1 --- .3-fixed

People

(Reporter: ehsan.akhgari, Assigned: zpao)

References

(
URL
)

Details

(Keywords: intermittent-failure, verified1.9.1)

Attachments

(3 files, 2 obsolete files)

Patch v0.3 (for check-in) [Checkin: Comment 18 & 27]
2.56 KB, patch
Details | Diff | Splinter Review
experimental patch [Checkin: Comment 46]
5.78 KB, patch
dietrich
: review+
Details | Diff | Splinter Review
sync test on 1.9.1 [Checkin: Comment 51]
5.53 KB, patch
Details | Diff | Splinter Review 
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1243222356.1243229039.1215.gz
WINNT 5.2 mozilla-central unit test on 2009/05/24 20:32:36
Whiteboard: [orange]
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1243237063.1243244705.25953.gz
Linux mozilla-central unit test on 2009/05/25 00:37:43
OS: Windows XP → All
Hardware: x86 → All
}(In reply to comment #0)
> WINNT 5.2 mozilla-central unit test on 2009/05/24 20:32:36

{
Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js...
TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | That window should be restorable
TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | Timed out
Running chrome://mochikit/content/browser/browser/components/shell/test/browser_420786.js...
Running chrome://mochikit/content/browser/browser/fuel/test/browser_Application.js...
TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Application.js | Check global access to Application
}


(In reply to comment #1)
> Linux mozilla-central unit test on 2009/05/25 00:37:43

{
Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js...
TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | That window should be restorable
TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | That window should not be restorable
TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | Timed out
Running chrome://mochikit/content/browser/browser/components/shell/test/browser_420786.js...
TEST-PASS | chrome://mochikit/content/browser/browser/components/shell/test/browser_420786.js | Wallpaper was written to disk
}


{
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1243348533.1243352795.2017.gz
OS X 10.5.2 mozilla-central unit test on 2009/05/26 07:35:33

Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js...
TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | That window should be restorable
TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | That window should not be restorable
TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | That window should not be restorable
NEXT ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | Timed out
Running chrome://mochikit/content/browser/browser/components/shell/test/browser_420786.js...
Running chrome://mochikit/content/browser/browser/fuel/test/browser_Application.js...
TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Application.js | Check global access to Application
}
Summary: Intermittent failure of browser_490040.js (Timed Out) → mochitest-browser-chrome: browser_490040.js times out intermittently
This is happening very often!

Any plan to debug/fix/workaround?
(In reply to comment #4)
> This is happening very often!
> 
> Any plan to debug/fix/workaround?

Please !
From the offending patch:

>     theWin.addEventListener("load", function(aEvent) {
>       theWin.gBrowser.removeEventListener("load", arguments.callee, true);

This isn't causing the issue... still wrong, though.

>       theWin.gBrowser.addEventListener("load", function() {
>         theWin.gBrowser.removeEventListener("load", arguments.callee, true);
>         theWin.close();
>       }, true);

Most of the windows we're restoring are actually blank, so waiting for a load event is the wrong strategy. A simple executeSoon should do...

Paul: Would you mind uploading a patch for these to a tryserver to see if that makes it happier?
(In reply to comment #9)
> This isn't causing the issue... still wrong, though.
... 
> Most of the windows we're restoring are actually blank, so waiting for a load
> event is the wrong strategy. A simple executeSoon should do...

The first load event should always fire, right? Maybe just changing the second load event is a problem. Replacing both of these with executeSoon breaks ("'Illegal value' when calling method: [nsISessionStore::setWindowState]" - I guess it's not happy with theWin)

Replacing just the second load event with executeSoon consistently fails for the case where there's actual tab data to load, but passes for the 0 tabs case.

> Paul: Would you mind uploading a patch for these to a tryserver to see if that
> makes it happier?

When I get the tests to consistently pass locally, yes.
(In reply to comment #10)
> The first load event should always fire, right?

The one on the window, yes. It's only the load event on the content browser that's not being consistently fired (the second one).

> Replacing just the second load event with executeSoon consistently fails for
> the case where there's actual tab data to load, but passes for the 0 tabs case.

Sounds fixable. Lets hope that this actually is the issue to fix...
Attached patch Patch v0.1 (obsolete) — — Splinter Review 
A fix (I think). I couldn't make the test time out locally (~15 runs of sessionstore browser-chome tests) & it's building on the try server now.

I'm not entirely happy with the way the fix works (thus the long comment in there), but it seems to be working. I'll ask for review when after try server gives me some results. Though with it being an intermittent problem, the results could be deceiving...
Comment on attachment 382859 [details] [diff] [review]
Patch v0.1

Unfortunately, timeouts aren't really less fragile. Why not keep the event listener for states containing tabs and just use executeSoon for states that don't?
Attached patch Patch v0.2 (obsolete) — — Splinter Review 
(In reply to comment #13)
> Unfortunately, timeouts aren't really less fragile. Why not keep the event
> listener for states containing tabs and just use executeSoon for states that
> don't?

Done. Passing consistently locally. Just put it up on try server, will report back with results.
Attachment #382859 - Attachment is obsolete: true
Comment on attachment 382999 [details] [diff] [review]
Patch v0.2

Thanks for looking into this. Consider this r+=me'd and ready for check-in with the following to bits fixed:

>+      // Windows with a tab to load will fire a second load event. Other
>+      // windows won't, so just use executeSoon.

Nit: The second load event isn't from the window but from its content browser. Why not something along the line of "Close the window as soon as the first tab loads - or immediately if there are none"?

(In reply to comment #9)
> >     theWin.addEventListener("load", function(aEvent) {
> >       theWin.gBrowser.removeEventListener("load", arguments.callee, true);

While you're touching that file, please also change this bit (s/gBrowser\.//).
(In reply to comment #16)
Done & done.

Try-server seemed to like this, so hopefully this clears it up.
Assignee: nobody → paul
Attachment #382999 - Attachment is obsolete: true
http://hg.mozilla.org/mozilla-central/rev/acb26facb2c7 - I'll let you decide whether it's fixed now or not :)
Keywords: checkin-needed
Well, it looks like failure frequency is down, but the test did fail once since the patch got checked in, so not closing yet.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1245072480.1245080463.23898.gz
Linux mozilla-central unit test on 2009/06/15 06:28:00
(In reply to comment #19)
> http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1245072480.1245080463.23898.gz
> Linux mozilla-central unit test on 2009/06/15 06:28:00

This occurrence is a little different as it seems the test failed to start:
{
Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js...
TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_490040.js | Timed out
}
whereas previous reports (before the patch) reported 1-3 passed checks first.
Attachment #383068 - Attachment description: Patch v0.3 (for check-in) → Patch v0.3 (for check-in) [Checkin: Comment 18]
(In reply to comment #21)
> http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1245361861.1245363801.19734.gz&fulltext=1
> Linux mozilla-central test everythingelse on 2009/06/18 14:51:01

{
Running ...
TEST-PASS | ... | That window should be restorable
TEST-PASS | ... | That window should not be restorable
TEST-PASS | ... | That window should not be restorable
TEST-UNEXPECTED-FAIL | ... | Timed out
}
Status: NEW → ASSIGNED
{
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5/1245457934.1245462125.8540.gz
OS X 10.5.2 mozilla-1.9.1 unit test on 2009/06/19 17:32:14

Running ...
TEST-PASS | ... | That window should be restorable
TEST-PASS | ... | That window should not be restorable
TEST-UNEXPECTED-FAIL | ... | Timed out
}
URL: http://mxr.mozilla.org/mozilla-centra...
Flags: in-testsuite+
Keywords: checkin-needed
Whiteboard: [orange] → [needs 1.9.1 landing] [orange]
Target Milestone: --- → Firefox 3.6a1
Comment on attachment 383068 [details] [diff] [review]
Patch v0.3 (for check-in)
[Checkin: Comment 18 & 27]


http://hg.mozilla.org/releases/mozilla-1.9.1/rev/bfd37302fae9
Attachment #383068 - Attachment description: Patch v0.3 (for check-in) [Checkin: Comment 18] → Patch v0.3 (for check-in) [Checkin: Comment 18 & 27]
Keywords: checkin-needed → fixed1.9.1
Whiteboard: [needs 1.9.1 landing] [orange] → [fixed1.9.1rc3+] [orange]
Whiteboard: [fixed1.9.1rc3+] [orange] → [fixed1.9.1rc3+] [orange] [not really fixed]
Still fails on mozilla-central, too:
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1245948855.1245954957.3239.gz
WINNT 5.2 mozilla-central unit test on 2009/06/25 09:54:15
Flags: wanted-firefox3.6?
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1246895031.1246904571.6404.gz
OS X 10.5.2 mozilla-central unit test on 2009/07/06 08:43:51
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1246911367.1246917245.22724.gz
OS X 10.5.2 mozilla-central unit test on 2009/07/06 13:16:07
unless you have something against that, i'd like to try this small refactoring. Just using window watcher and exchanging some listener creation with actions. Also removes need for callbacks making the code more readable/expandable (imo).
dunno if this will make any difference, but maybe worth a try seeing the rate this failure hits.
Attachment #391316 - Flags: review?(paul)
Attachment #391316 - Flags: review?(paul) → review?(dietrich)
Comment on attachment 391316 [details] [diff] [review]
experimental patch
[Checkin: Comment 46]

much cleaner anyway, r=me.
Attachment #391316 - Flags: review?(dietrich) → review+
experimental patch on m-c
http://hg.mozilla.org/mozilla-central/rev/0b14d703b74e
Whiteboard: [fixed1.9.1rc3+] [orange] [not really fixed] → [fixed1.9.1rc3+] [orange] [new patch on m-c]
resolving since i've not seen failures in the last 3 days, and that's pretty "strange" (or encouraging).
Please reopen immediately if you catch a failure on mozilla-central, otherwise will sync the test on 1.9.1 in a few days
Status: ASSIGNED → RESOLVED
Closed: 15 years ago
Resolution: --- → FIXED
Just happened here:

OS X 10.5.2 mozilla-1.9.1 test everythingelse on 2009/08/05 08:29:10

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5-Unittest/1249486150.1249487343.1698.gz
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attachment #391316 - Attachment description: experimental patch → experimental patch [Checkin: Comment 46]
(In reply to comment #48)

m-1.9.1 doesn't have the fix yet...
Status: REOPENED → RESOLVED
Closed: 15 years ago → 15 years ago
status1.9.1: --- → ?
Flags: wanted-firefox3.6?
Resolution: --- → FIXED
http://hg.mozilla.org/releases/mozilla-1.9.1/rev/689c752309d6
Whiteboard: [fixed1.9.1rc3+] [orange] [new patch on m-c] → [orange]
Attachment #392767 - Attachment description: sync test on 1.9.1 → sync test on 1.9.1 [Checkin: Comment 51]
Looks like we are fine on trunk and 1.9.1 branch. Marking as verified.
Status: RESOLVED → VERIFIED
Keywords: fixed1.9.1 → verified1.9.1
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: