The test in the URL field uses setTimeout extensively. That's bogus, and can cause random failures as shown here: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1223284948.1223288480.11938.gz

Other occurrences, when it fails alone: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1223835200.1223838730.11008.gz Linux mozilla-central moz2-linux-slave07 dep unit test on 2008/10/12 11:13:20 { TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Checking 'BrowserTab.uri' after opening - Got about:blank, expected chrome://mochikit/content/browser/browser/fuel/test/ContentA.html TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Checking 'BrowserTab.uri' after opening - Got about:blank, expected chrome://mochikit/content/browser/browser/fuel/test/ContentB.html TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Checking existence of element in content DOM TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Timed out } and http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1223843077.1223846634.32407.gz Linux mozilla-central moz2-linux-slave08 dep unit test on 2008/10/12 13:24:37

This patch switches "setTimeout" to "executeSoon". The tests pass on my local machine. I do wonder if the pages will load fast enough on tinderboxen. This patch also enables two simple tests in browser_Extensions.js, so we get even basic coverage on that code.

I'm not sure I understand the motivation here. executeSoon's advantage over timeouts is really only just that it's more explicit about why the delay is needed (one spin through the event queue). If 1 second timeouts are causing problems, switching to executeSoon is unlikely to help and would probably even hurt.

what you probably want here is to wait for a load event, then use executeSoon

This patch is the same as the previous except I dropped the "executeSoon" used to wait for the pages to load. Instead, I use sequential page "load" events, then use "executeSoon" for other hand-off situations, but not page loads. [this was based on feedback from gavin and shawn on IRC]

Comment on attachment 346120 [details] [diff] [review] v2 - uses "load" events for intial pages > // use a setTimeout so the pageloadwithframes Change the comment?

browser_Browser.js is currently failing intermittently on tinderbox when I don't recall seeing that happen before. Should this be backed out?

(In reply to comment #8) > browser_Browser.js is currently failing intermittently on tinderbox when I > don't recall seeing that happen before. See comment 0 and comment 1 !?

Ok the problem here is that you are racing two page loads. When one page completes it triggers the test to finish. You rely on the other page loading first. Is loading both at the same time necessary?

(In reply to comment #9) > (In reply to comment #8) > > browser_Browser.js is currently failing intermittently on tinderbox when I > > don't recall seeing that happen before. > > See comment 0 and comment 1 !? I don't see how that answers my question. Presumably if I haven't seen it before it is failing more than previously.

This changes the loads to be one after the other. Use a web progress listener to verify the load of page B is completed before checking how many times the load event fired.

(In reply to comment #11) > I don't see how that answers my question. It is not supposed to answer your question about a backout. > Presumably if I haven't seen it before it is failing more than previously. More often, maybe, I don't know. I was only commenting that if you have never seen it before, others have.

Comment on attachment 346867 [details] [diff] [review] patch Test code only so I think I can r+ this. After Dave explained the issues with me on IRC, I understand why the webprogresslistener is a better choice for monitoring page loads when frames are involved.

http://hg.mozilla.org/mozilla-central/rev/750eb47b3b91 Thanks Dave!

Still timing out occasionally: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1227112647.1227116502.18267.gz I don't know what's busted.

(In reply to comment #16) > Still timing out occasionally: > http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1227112647.1227116502.18267.gz > > I don't know what's busted. Suggests the progress listener is never seeing a state change with STATE_IS_WINDOW + STATE_IS_NETWORK + STATE_STOP. Seems strange

(In reply to comment #17) > Suggests the progress listener is never seeing a state change with > STATE_IS_WINDOW + STATE_IS_NETWORK + STATE_STOP. Seems strange Perhaps someone who knows network code can help here.

Or rather it might be seeing it before the corresponding onload, no? I'm not entirely convinced the ordering of those two is guaranteed, but that's only my best guess as to what's going on here.

Er, nevermind. It's timing out, not failing the onload test. Pretty odd.

No, as soon as the progress listener sees STATE_IS_WINDOW + STATE_IS_NETWORK + STATE_STOP it calls onPageBLoadComplete which does a test which would show up in the log. If the load events fire after the progress listener sees that then we'd just see a test failure.

I can't see what might be going on here and won't have time to work on it further for now.

This test sporadically timed out today, FWIW: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1236643575.1236654665.5773.gz

Another failure: <http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1238213126.1238220828.20006.gz>

I disabled the test: http://hg.mozilla.org/mozilla-central/rev/e95463a6c47d

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1238954020.1238962539.5163.gz&fulltext=1 Linux mozilla-central unit test on 2009/04/05 10:53:40 (which was before comment 25)

From my debugging, I can see a bit of non-determinism by watching the state flags that are coming through the web progress listener: = All Failed Tests Have This Signature = TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 983041 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 720897 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 720897 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onPageBLoadWithFrames was called TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Timed out = Passing Tests on Windows Have = TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 983041 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 720897 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 720897 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 131088 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 524304 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 131088 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 524304 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 131088 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onPageBLoadWithFrames was called TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 786448 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ___debugging: onPageBLoadComplete is Called = Passing Tests on Linux and Mac have = TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 983041 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 720897 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 720897 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65537 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 196612 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 131088 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 524304 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 65552 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 131088 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 524304 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 131088 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onPageBLoadWithFrames was called TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ____debugging: onStateChage the stateFlags are: 786448 TEST-PASS | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | ___debugging: onPageBLoadComplete is Called The difference is in the 196612 (0x30004), 65552 (0x10010), 65552 (0x10010), 131088 (0x20010) pattern. This is where the timeout occurs. For passing tests on windows we get three 0x10010 states, and on mac and linux we get two. On a failing test, it always times out after the first 0x10010 after the 0x30004. bitwise AND'ing these states to all possible values of the state flag produces the following results: = 196612 (0x30004) = STATE_TRANSFERRING STATE_IS_REQUEST STATE_IS_DOCUMENT = 65552 (0x10010) = STATE_STOP STATE_IS_REQUEST = 131088 (0x20010) = STATE_STOP STATE_IS_DOCUMENT This honestly doesn't tell me a whole lot, but I'm posting it to see if it spurs any thoughts. I'm wondering if we're in some kind of race condition with the onPageBLoadWithFrames listener. I'm going to kick off some runs with that commented out and see what happens.

Still fails with the event listener commented out, but now it does two 0x10010's before timing out in the same place. So I've affected it slightly, but not enough to make the test pass. Will try to get the debug HTTP logging turned on and see what that says.

The test was disabled on m-c, but not on 1.9.1, and it's failing on that branch. http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5/1239451805.1239457218.28818.gz I'm going to disable this test on 1.9.1 as well.

(In reply to comment #29) > I'm going to disable this test on 1.9.1 as well. http://hg.mozilla.org/releases/mozilla-1.9.1/rev/bccb7ddf780c

I think the issue with this test is that there can be multiple browser windows open, and then Application.activeWindow isn't necessarily the one that the test lives in. There's no straightforward way to get the fuelWindow for the current window, which is a FUEL design flaw.

This was also an issue with browser_discovery.js on 1.9.1, btw. I fixed that by using the tabbrowser and DOM APIs instead of FUEL, a solution we obviously wouldn't want here: http://hg.mozilla.org/mozilla-central/rev/d53e256b5cb6

(In reply to comment #31) > Created an attachment (id=393455) [details] > patch > > I think the issue with this test is that there can be multiple browser windows > open, and then Application.activeWindow isn't necessarily the one that the test > lives in. There's no straightforward way to get the fuelWindow for the current > window, which is a FUEL design flaw. If the problem is that there can be multiple browser windows open then doesn't this change make the test fail in that case? Where are the multiple browser windows coming from? Is a previous test not cleaning up properly?

(In reply to comment #33) > If the problem is that there can be multiple browser windows open then doesn't > this change make the test fail in that case? My assumption is that if the window re-gained focused, the other window is closed. > Where are the multiple browser > windows coming from? Is a previous test not cleaning up properly? They must come from previous tests, but usually they try their best to clean up. I think the problem is that window.close isn't completely synchronous, at least on Linux.

Another case where the issue turned out to be another window is bug 498704.

Comment on attachment 393455 [details] [diff] [review] patch (In reply to comment #34) > (In reply to comment #33) > > If the problem is that there can be multiple browser windows open then doesn't > > this change make the test fail in that case? > > My assumption is that if the window re-gained focused, the other window is > closed. Fair enough. > > Where are the multiple browser > > windows coming from? Is a previous test not cleaning up properly? > > They must come from previous tests, but usually they try their best to clean > up. I think the problem is that window.close isn't completely synchronous, at > least on Linux. It's true that window.close isn't synchronous, but there are ways to listen for when a window finally closes. We should probably try to file bugs on tests that don't do this and fix them, or maybe we can do something in the test harness to wait for additional windows to close before running the next tests.

http://hg.mozilla.org/mozilla-central/rev/d9742d839d7d Crossing fingers and resolving...

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1250624369.1250629992.8552.gz WINNT 5.2 mozilla-central unit test on 2009/08/18 12:39:29 { TEST-PASS | ... | Checking event handler for tab move TEST-UNEXPECTED-FAIL | ... | Timed out }

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1251850954.1251852981.14132.gz Linux mozilla-central test everythingelse on 2009/09/01 17:22:34

OS X 10.5.2 mozilla-central unit test http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1252607559.1252614046.5200.gz&fulltext=1

OS X 10.5.2 mozilla-central test everythingelse [testfailed] Started 14:32, finished 15:04 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1252618334.1252620227.9661.gz&fulltext=1

WINNT 5.2 mozilla-central unit test [testfailed] Started 12:49, finished 15:00 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1252612181.1252619957.6668.gz&fulltext=1

OS X 10.5.2 mozilla-central unit test http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1252658079.1252662317.21054.gz

Linux mozilla-central test everythingelse on 2009/09/25 11:41:09 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1253904069.1253906465.15283.gz

Linux mozilla-central test opt everythingelse on 2009/10/16 13:33:57 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255725237.1255727590.21947.gz

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255968870.1255971283.18560.gz Linux mozilla-central test everythingelse on 2009/10/19 09:14:30

WINNT 5.2 mozilla-central test everythingelse [testfailed] Started 14:42, finished 15:22 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256247755.1256250100.12422.gz&fulltext=1

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256880024.1256882205.22809.gz WINNT 5.2 mozilla-central test everythingelse on 2009/10/29 22:20:24

i have been able to reproduce one hang locally in an optimized build. onStateChange is not hit (so we don't go further onPageBLoadWithFrames: 1, but everything looks fine in the browser window. and there are no other windows or popups open.

i also have to point out that reproducing these failures in a VM with multiple virtual cpus and low memory values (256MB or less, i'll try with 128) makes these failures more easily reproduceable.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257158235.1257163261.26458.gz Linux mozilla-central test debug everythingelse on 2009/11/02 02:37:15

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257287386.1257291227.611.gz#err0 Linux mozilla-central test opt everythingelse on 2009/11/03 14:29:46

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257695397.1257699334.32472.gz Linux mozilla-central debug test everythingelse on 2009/11/08 07:49:57

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257789298.1257793801.21853.gz Linux mozilla-central debug test everythingelse on 2009/11/09 09:54:58

(In reply to comment #52) > i also have to point out that reproducing these failures in a VM with multiple > virtual cpus and low memory values (256MB or less, i'll try with 128) makes > these failures more easily reproduceable. If this is easily reproducible in a VM, could someone try it in a record-and-replay VM?

One problem is that virtual machine record-and-replay simply does not work with multiple virtual CPUs due to fundamental hardware limitations. Namely, with truly parallel execution on multiple cores, different cores can have races in shared memory, and it's impossible for the virtual machine monitor to detect and reproduce those interactions. The only way to record and replay genuinely parallel races in shared memory with existing hardware is to instrument instructions that access shared memory, and that's certain to be high overhead. Low-overhead solutions require hardware support (e.g. Bodik et al.'s "Flight Data Recorder") which doesn't exist.

Ah, bummer. :-(

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258425987.1258436698.29117.gz Linux mozilla-central debug test everythingelse on 2009/11/16 18:46:27 s: moz2-linux-slave19 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Timed out

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258796143.1258802246.14380.gz Linux mozilla-central debug test everythingelse on 2009/11/21 01:35:43 s: moz2-linux-slave26

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258964061.1258970996.27993.gz WINNT 5.2 mozilla-central debug test everythingelse

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258974176.1258979238.26233.gz Linux mozilla-central debug test everythingelse

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259070195.1259075768.1188.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/24 05:43:15 "s: moz2-win32-slave39" TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Timed out

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259768587.1259775876.16367.gz&fulltext=1 WINNT 5.2 mozilla-central debug test everythingelse 2009/12/02 Started 07:43, finished 09:45

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259803883.1259810848.26289.gz&fulltext=1 WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/02 17:31:23

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260187184.1260194786.13490.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/07 03:59:44 s: moz2-win32-slave20

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260472914.1260480279.31864.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/10 11:21:54 s: win32-slave01

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260488011.1260495939.12442.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/10 15:33:31 s: win32-slave10

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260556294.1260563382.10836.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/11 10:31:34 s: win32-slave24 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/fuel/test/browser_Browser.js | Timed out

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260582483.1260588375.28158.gz Linux mozilla-central debug test everythingelse on 2009/12/11 17:48:03 s: moz2-linux-slave26

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260579911.1260588142.25593.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/11 17:05:11 s: win32-slave05

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260597873.1260604879.12449.gz#err0 WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/11 22:04:33 s: win32-slave43

I still plan to look into this again, but as others should feel free to do so as well, I'm unassigning this from me...

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1261001956.1261010172.20914.gz Linux mozilla-central debug test everythingelse on 2009/12/16 14:19:16 s: moz2-linux-slave18

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1261169169.1261175015.28939.gz Linux mozilla-central debug test everythingelse on 2009/12/18 12:46:09 s: moz2-linux-slave23

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1261201678.1261207138.21488.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/18 21:47:58 s: win32-slave39

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1261435761.1261441234.13867.gz Linux mozilla-central opt test everythingelse on 2009/12/21 14:49:21 s: moz2-linux-slave23

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1262166709.1262172164.3001.gz WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/30 01:51:49 s: win32-slave27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1262246595.1262252085.20109.gz Linux mozilla-central debug test everythingelse on 2009/12/31 00:03:15 s: moz2-linux-slave27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1263250138.1263254133.12833.gz Linux mozilla-central opt test everythingelse on 2010/01/11 14:48:58 s: moz2-linux-slave11

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264194503.1264195721.31922.gz Linux mozilla-central opt test mochitest-other on 2010/01/22 13:08:23 s: moz2-linux-slave24

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264431716.1264433065.29492.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/01/25 07:01:56 s: moz2-darwin9-slave15

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264434046.1264435116.21166.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/01/25 07:40:46 s: moz2-darwin9-slave14

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264711157.1264712704.19893.gz Linux mozilla-central opt test mochitest-other on 2010/01/28 12:39:17 s: moz2-linux-slave22

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1266001548.1266003385.17804.gz Linux mozilla-central opt test mochitest-other on 2010/02/12 11:05:48 s: moz2-linux-slave13

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1266519404.1266520475.11175.gz Linux mozilla-central opt test mochitest-other on 2010/02/18 10:56:44 s: moz2-linux-slave41

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267056419.1267058618.5961.gz Linux mozilla-central opt test mochitest-other on 2010/02/24 16:06:59 s: moz2-linux-slave09

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267633074.1267634491.22760.gz Linux mozilla-central opt test mochitest-other on 2010/03/03 08:17:54 s: moz2-linux-slave13

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267825299.1267827524.16837.gz Linux mozilla-central opt test mochitest-other on 2010/03/05 13:41:39 s: moz2-linux-slave13

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268187597.1268190056.13410.gz Linux mozilla-central opt test mochitest-other on 2010/03/09 18:19:57 s: moz2-linux-slave05

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268449339.1268450825.10595.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/03/12 19:02:19 s: moz2-darwin9-slave05

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268554972.1268556332.23206.gz Linux mozilla-central opt test mochitest-other on 2010/03/14 00:22:52 s: moz2-linux-slave11

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268616411.1268617523.21680.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/03/14 18:26:51 s: moz2-darwin9-slave11

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1268950617.1268951422.5505.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/03/18 15:16:57 s: moz2-darwin9-slave42

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269650329.1269651094.9923.gz WINNT 5.2 mozilla-central opt test mochitest-other on 2010/03/26 17:38:49 s: mw32-ix-slave08

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269821268.1269822044.12803.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/03/28 17:07:48 s: moz2-darwin9-slave42

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1269958601.1269959375.23878.gz WINNT 5.2 mozilla-central opt test mochitest-other on 2010/03/30 07:16:41 s: mw32-ix-slave08

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270167502.1270168278.13953.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/04/01 17:18:22 s: moz2-darwin9-slave40

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270191419.1270192177.3906.gz OS X 10.5.2 mozilla-central opt test mochitest-other on 2010/04/01 23:56:59 s: moz2-darwin9-slave42

Let's disable this test, IMO. It was disabled for a while, until Dao thought he had a fix for it, and we should just go back to that state if we can't figure it out. dtownsend: is there a bug on auditing the tests with multiple windows to make sure that they wait for the close to finish? I think that sounds like a promising direction, might help other tests as well.

Note the details and the patterns, though. It started up again on May 2nd, only because the 10.6 debug mochitest-other was unhidden on May 1st, and for whatever reason, it has failed all along more on 10.6 debug than anywhere else. Then suddenly on May 11th, we picked up a few non-Mac fails, then in a separate sudden, after the releng downtime this morning, and then the failure to realize for a while that we weren't getting sendchange on 10.5 after the downtime, every single 10.5 debug mochitest-other has failed. _That_, unlike all the other randomness, makes me think the test has caught something, either in one of the things we pushed while we didn't realize we weren't running Mac tests, or in a change from the downtime. nthomas was kind enough to trigger builds for the missed changesets, and a few extra tests for the changeset from before the downtime, which I hope will be enough to tell us whether we landed a regression today, or we still haven't noticed all the brokenness from the downtime (or, I guess, whether we just hit a really bad run of luck with those seven runs in a row).

And while the builds for the missing chunk of pushes are still going, the extra tests against 6a71deda9822 (the last changeset from before the downtime, which was the last one to have a 10.5 Mdoth not hit this) both did hit this, pointing an inexplicable finger at something from the downtime as being the reason this test is now apparently permaorange on 10.5 debug.

I was looking at the logs, actually when we browser.addProgressListener, we would expect browser to be waiting for us, really looking at the log it is loading a bunch of pages, or at least many are open: about:blank, http://example.com/#randomnumber#, about:config, http://example.com/, about:mozilla All of these pages seem to come from sessionstore/test/browser/browser_522545.js that runs not much before this test... I think disabling this test won't bring anything useful, we should look at tests that run before this one, or, as a workardound, this test should ensure status of the browser on startup and wait for eventual pages that are still loading.

hm, or those tabs/windows are just being destroyed... btw the fact "onStateChange:" is called as soon as we add the progressListener is bad, since something loading is removing the listener before we use it.

sigh, nvm previous comments. The only problem is that onStateChange does never receive complete. this is what we get in the last log: STATE_IS_NETWORK + STATE_IS_WINDOW + STATE_IS_DOCUMENT + STATE_IS_REQUEST + STATE_START STATE_IS_REQUEST + STATE_START STATE_IS_DOCUMENT + STATE_IS_REQUEST + STATE_TRANSFERRING STATE_IS_REQUEST + STATE_STOP STATE_IS_WINDOW + STATE_IS_DOCUMENT + STATE_IS_REQUEST + STATE_START STATE_IS_WINDOW + STATE_IS_DOCUMENT + STATE_IS_REQUEST + STATE_START STATE_IS_REQUEST + STATE_START STATE_IS_DOCUMENT + STATE_IS_REQUEST + STATE_TRANSFERRING STATE_IS_REQUEST + STATE_STOP STATE_IS_REQUEST + STATE_STOP what we expect STATE_IS_WINDOW + STATE_IS_NETWORK + STATE_STOP

Assigning to Mark for investigation; please reassign (but not to nobody@) if there's a better owner to be found.

I landed this: http://hg.mozilla.org/mozilla-central/rev/8e48c8fb8299 NeilAway: dao1: yeah, it would make a difference, given that weak references are broken on trunk

(In reply to comment #154) > NeilAway: dao1: yeah, it would make a difference, given that weak references > are broken on trunk NeilAway: see bug 533290 comment 11 in particular

What you did is compatible with what i was observing, the progresslistener was stopping at random positions, and the windows from previous tests were being collected, thus I guess GC was running and collecting the listener... good catch.

(In reply to comment #143) > And while the builds for the missing chunk of pushes are still going, the extra > tests against 6a71deda9822 (the last changeset from before the downtime, which > was the last one to have a 10.5 Mdoth not hit this) both did hit this, pointing > an inexplicable finger at something from the downtime as being the reason this > test is now apparently permaorange on 10.5 debug. Is it possible that the installation of the resistors onto the Rev3 Leopard machines (bug 563836) affected this? I went over all of the downtime bugs and I can't see anything else that could've.

I think/hope we're done here. Obviously the underlying problem still needs fixing in bug 533290. Landed on 1.9.2: http://hg.mozilla.org/releases/mozilla-1.9.2/rev/61a692b7799f