Just seen on Firefox-Unittest tinderbox page: WINNT 5.2 mozilla-central test opt everythingelse on 2009/09/25 14:46:12 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1253915172.1253918100.15234.gz#err0 { Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js... TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js was removed command timed out: 1200 seconds without output program finished with exit code 1 } There were only two possibly-guilty changesets -- one was mac-only, and one was a fix in a different test: http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=213da42e5f65&tochange=8b4d2fc47ecf So, I'm calling this sporadic.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254517284.1254520123.21915.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/02 14:01:24

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254604259.1254607095.2327.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/03 14:10:59

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1254796986.1254799708.13328.gz OS X 10.5.2 mozilla-1.9.2 test everythingelse on 2009/10/05 19:43:06

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254934316.1254937006.2639.gz and http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254935828.1254938541.19708.gz

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255083586.1255086209.4141.gz#err0 WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/09 03:19:46 since problem is most likely the same as for browser_394759.js i'm going to fix it same way

Comment on attachment 405489 [details] [diff] [review] patch v1.0 r=zpao

at least seems to hit less. the only difference from browser_394759.js is the useCapture on the internal addEventListeners... but i'm not sure if that could make a difference, will take a deeper look

synced usecapture just to be sure, and added a couple info() to see where we fail http://hg.mozilla.org/mozilla-central/rev/607c935fde96

and http://hg.mozilla.org/mozilla-central/rev/607c935fde96 :(

i need a coffee http://hg.mozilla.org/mozilla-central/rev/28fa630e4669

ok, so looks like one of the external "load" event listener is never called or is added too late.

I can't tell offhand if this could help with the random failures, but there are a certain number of sessionstore browser tests that are not removing no more used event listeners. So i'd like to try cleaning them up.

(In reply to comment #19) > I can't tell offhand if this could help with the random failures, but there are > a certain number of sessionstore browser tests that are not removing no more > used event listeners. So i'd like to try cleaning them up. There's a bug for that (which Dão tried a partial fix for): bug 507784.

thanks moving there

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255411911.1255414470.3310.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/12 22:31:51

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255459159.1255461783.22408.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/13 11:39:19

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255486031.1255488696.24427.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/13 19:07:11

pushed experimental change http://hg.mozilla.org/mozilla-central/rev/af0ade2a9a1d will backout if nothing changes.

i will backout since not getting better, but thanks to the added info i know what is failing is the first load event. at that point we could consider to use windowmanager

backed out previous experiment http://hg.mozilla.org/mozilla-central/rev/6240e80d2c21 pushed new experiment (using windowwatcher) http://hg.mozilla.org/mozilla-central/rev/5ae7b09f730f if this should work i'll ask postreview directly on the test code.

>+ // Prevent VM timers issues, cache now and increment it manually. >+ const NOW = Date.now(); "increment it manually" isn't going to work, since it's a const. Is the cause of the failure understood? We should try to get to that point before implementing a different approach.

woops right, well it's not a big deal for now i can fix it later in case. I think we could try to set the load listener before the window is ready to get it (but i don't know windows opening code, for now), using the window watcher will ensure we set it when the window is ready. But if this works we can investigate deeper, backtracing code (other 2 ss tests are failing for the same cause i think). We use this ww+load method in various Places tests and they did never fail. so let's see if that helps for now. Rather then a new approach this really is just a cleanup with a windowwatcher notification added (so the new approach is basicly adding windowwatcher notification).

or otherwise we set it too late. btw i suspect the problem is time in adding load listener, indeed the failure is pretty visible in Optimized builds that are faster.

Are you talking about this pattern? let newWin = openDialog(location, "_blank", "chrome,all,dialog=no", testURL_A); newWin.addEventListener("load", function(aEvent) { I don't think the load event could be dispatched before the synchronous addEventListener call. We also don't seem to have a problem with that in other tests.

yes, i'm talking about that. We fail there, because we print the previous info() but we did not print the info() inside the load handler (that i added in the old experiment). Between that info and the dialog opening handlere there are only var definitions that i doubt can cause a timeout. So either: the dialog is not opened/load is not fired/load is dired too early or too late/we crash. i'm starting explorating the too early/too late, other ways are still open though.

oh, with windowatcher we can also discover if the problem is that the dialog is not opened for any reason.

You could easily verify your theory this way: let newWin = openDialog([...]); newWin.addEventListener("load", [...]); is(newWin.document.readyState, FOO, "..."); FOO should always be "uninitialized", I think, but never "complete".

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255793142.1255795845.4927.gz#err0 so, the dialog did open (we got openwindow event), but the load event handler was not added/called! crazy.

Ah, I see your trying to protect against adding the listener too early rather than too late. That doesn't make more sense to me, though. As soon as we have a window object, it should be ready to get the event listener. Any other idea why the event listener wouldn't be called? How about polling newWin.document.readyState and newWin.closed to figure out if the window ever finishes loading?

You could also use getListenerInfoFor from bug 448602 to verify that the listener has been added.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255897227.1255900215.11588.gz http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255912365.1255915107.9404.gz

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255950294.1255953229.504.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/19 04:04:54

i'm starting thinking this is a real hang in sessionstore, since it has a load listener that runs before ours. on next push i'll just add some more dump and move up clearing sessionstore interval pref earlier, maybe we are hanging on file access (this only hangs on Windows after all). The fact other ss tests are timing out in similar situations concerns me, but the fact that a lot of other tests actually use successfully the above pattern is confusing.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1255990320.1255993078.29753.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/19 15:12:00 With the exception of comment #5 (which isn't this test anyway), every failure has been on an opt build. Not sure if that's relevant, but it's a definite pattern. Marco, can you reproduce this locally with debug builds? It might be worth building an opt-test build to track it down. Do we have a list of bugs that are only failing on opt-builds? I'm marking this one [opt-orange] until we come up with some better way of tracking.

(In reply to comment #44) > With the exception of comment #5 (which isn't this test anyway), every failure > has been on an opt build. Not sure if that's relevant, but it's a definite > pattern. it is relevant for sure. And all failures on Windows. > Marco, can you reproduce this locally with debug builds? It might be worth > building an opt-test build to track it down. No, it's not reproduceable atm, i was able to reproduce failures before the same changes i did in browser_394759.js At this point i'll try if i can reproduce in an optimized build, but i've lost lot of time trying to fix this :( > Do we have a list of bugs that are only failing on opt-builds? I'm marking this > one [opt-orange] until we come up with some better way of tracking. bug 521889 and bug 521802, but probably they have also some failure in non optimized builds.

oh, this failed on Linux too today.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256053099.1256055776.17565.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/20 08:38:19

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256087154.1256089996.7969.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/20 18:05:54

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

WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 12:37:49 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256153869.1256156677.8850.gz#err0

WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 13:19:35 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256156375.1256159379.6067.gz

WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 15:18:29 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256163509.1256166539.20477.gz

And to fill in between the two of us, WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 09:49:36 WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 07:04:55 WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 06:55:48 WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 06:16:56 WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 03:12:43

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256128688.1256131900.15422.gz Linux mozilla-central test opt everythingelse on 2009/10/21 05:38:08

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256166307.1256169445.20067.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 16:05:07

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256169462.1256172372.19885.gz#err0 WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 16:57:42

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256174498.1256177447.11235.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 18:21:38 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256175309.1256178230.19576.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 18:35:09

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256180552.1256183364.10772.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 20:02:32 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256180964.1256183798.15417.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/21 20:09:24

I'm just going to disable this test on m-c in the morning if there are no objections. Unless Marco wants to keep looking at it, I'll carve out some time soon to look into why this is happening.

sorry i was unable to do anything for 2 days due to hardware failures, i'm still working to fix them. even if this is really annoying, disabling it won't help fixing it in any way, unit tests are still reliable, this is only(mostly) failing on windows optimized builds. Since fixing this could clarify the failure reasons for other optimized tests that are timing out, i'd rather stop losing time to report the failure and just ignore it, since actually reporting failures here does not help at all. If we are going to disable this we will disable a bunch of other tests, without solving a possible real issue. let me complete an optimized build and try to run tests on it, if i'll be able to reproduce locally then we can disable the test on central, but till then central is the only point where we can reproduce and fix the issue.

otherwise, if we want to disable the test, we should disable it with an ifdef DEBUG, since it only fails in optimized builds.

Linux mozilla-central test opt everythingelse on 2009/10/22 09:00:37 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256227237.1256230526.20198.gz&fulltext=1

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256255974.1256258796.11161.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/22 16:59:34

i've run mochitests on an optimized build multiple times in Vista, without seeing any timeout or hang :\

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256287344.1256290149.26140.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/23 01:42:24 This really hurts, because it aborts the test suite. Ehsan: can you help Marco out with debugging this failure?

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256303116.1256305818.13991.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/23 06:05:16

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256277041.1256279877.12519.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/22 22:50:41

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256339643.1256342848.22136.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/23 16:14:03

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256359122.1256361836.32189.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/23 21:38:42

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256436736.1256439467.21017.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/24 19:12:16

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256565537.1256568534.13853.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/26 06:58:57

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256553128.1256556233.27421.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/26 03:32:08

Couldn't waitForFocus be useful here? I think this type of failure is one that waitForFocus was designed to solve. Or am I missing something? BTW, Marco or anyone else, have you been able to reproduce this locally so far?

waitForFocus depends on the load event.

Is there any way to get a regression range on this?

no, because tests on optimized builds have been enabled recently

OK. I don't see anything particularly suspicious here, but maybe I've missed something in the large number of comments here. Marco, is there anything which would raise your suspicion here?

If i would have found something suspicious i'd have already tried to change it. I think we could early finish() in load event leaving in the info() call and comment out various parts of the sessionstore setup code. The main difference of this test from the previous ones is that code, if we discover it can cause an hang, then we could restrict the search.

(In reply to comment #78) > If i would have found something suspicious i'd have already tried to change it. > I think we could early finish() in load event leaving in the info() call and > comment out various parts of the sessionstore setup code. > The main difference of this test from the previous ones is that code, if we > discover it can cause an hang, then we could restrict the search. By previous ones, you mean the test before your changes, or before your last change? If someone can reproduce this locally, I think it's best to disable this on m-c and then try to figure out what the problem is.

(In reply to comment #79) > (In reply to comment #78) > By previous ones, you mean the test before your changes, or before your last > change? no i mean other tests using the same "load" pattern, for example browser_394759.js. My changes actually just ended up being a small cleanup and adding infos, did not change a bit of the issue unfortunatly (once this is sorted out we could get rid of the windowwatcher). I still have a really small cleanup patch around that fixes some minor thing and adds more infos. > If someone can reproduce this locally, I think it's best to disable this on m-c nobody can so far, that's why i prefer not disabling it, till someone can reproduce.

(In reply to comment #80) > > If someone can reproduce this locally, I think it's best to disable this on m-c > > nobody can so far, that's why i prefer not disabling it, till someone can > reproduce. In that case, I think that's what we should do. I don't know of any way to solve this issue off-hand.

let me push my new patch, i'll do as soon as i can, then we can still disable parts of the setup, to reduce the offending code.

added more dumps: http://hg.mozilla.org/mozilla-central/rev/fd21464eec80

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256746127.1256749019.24193.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/28 09:08:47 Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js... TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js was removed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Correctly set window count TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Opening new window TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window has been opened command timed out: 1200 seconds without output

(In reply to comment #84) > http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256746127.1256749019.24193.gz FWIW this is before my last push

With your push: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256752615.1256754801.26016.gz WINNT 5.2 mozilla-central test everythingelse on 2009/10/28 10:56:55 Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js... TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js was removed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Correctly set window count TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js has been recreated - Got false, expected true TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Opening new window TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window has been opened TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window has 1 listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window has load listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window does not have a capture listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window has been loaded TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window browser has been loaded TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window closed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | The closed window was added to the list TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | The closed window data was stored correctly TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | private browsing enabled TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Recently Closed Windows are removed when entering Private Browsing TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Recently Closed Windows data is cleared when entering Private Browsing TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Opening new window TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window has been opened TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window has 1 listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window has load listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window does not have a capture listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window has been loaded TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window browser has been loaded TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window closed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | The closed window was added to the list TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | The closed window data was stored correctly TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | private browsing disabled TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | The correct number of recently closed windows were restored when exiting PB mode TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | The data associated with the recently closed window was restored when exiting PB mode TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Console message:

pushed http://hg.mozilla.org/mozilla-central/rev/a812503aff1c to wait for sessionstore.js to be written, Windows is taking more time than others.

small followup http://hg.mozilla.org/mozilla-central/rev/c03e4d80991e

this is before the change in comment 87: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256763306.1256766598.31350.gz Running chrome://mochikit/content/browser/browser/components/sessionstore ... TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Opening new window TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | New window has been opened TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window has 1 listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window has load listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window does not have a capture listener TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window closed this is interesting, looks like we receive a DOMWindowclosed before load can fire.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256788472.1256791389.19659.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/28 20:54:32

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256793659.1256796772.13084.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/28 22:20:59

new push: http://hg.mozilla.org/mozilla-central/rev/40b3d440c5a9 since i got that the problem is the window closes before load can fire, i changed the test to detect that situation (And interrupt without timeout) and detect eventual spurious windows-restored notifications.

from this log: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256831010.1256834175.2248.gz Looks like sessionstore.js is not rewritten correctly on optimized Win, or at least, we don't receive "sessionstore-state-write-complete" notification.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256844076.1256847322.24652.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/29 12:21:16

changed the startup order based on other tests around that are not failing. The actual order makes more sense, also trying to avoid getting a bogus write of the sessionstore file. http://hg.mozilla.org/mozilla-central/rev/2df99504c1ec

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256926573.1256929475.14658.gz on that push

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256952859.1256955877.20308.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/30 18:34:19 [ Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js... TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js was removed command timed out: 1200 seconds without output ]

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256960901.1256963683.6762.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/30 20:48:21

So, it's pretty clear that AsyncCopy fails, probably because the file is held locked by the OS. We can probably listen on sessionstore-state-write and don't bother looking at the fact the state file has been effectively written or not. That should allow us to move on, but won't yet explain why a window is closed suddenly.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256978552.1256981292.2883.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/10/31 01:42:32

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257133794.1257136774.29552.gz#err2 WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/01 19:49:54

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257135708.1257138608.17242.gz#err2 WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/01 20:21:48

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257136913.1257140150.1323.gz#err2 Linux mozilla-central test opt everythingelse on 2009/11/01 20:41:53

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257142190.1257144969.20874.gz#err2 WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/01 22:09:50

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257144086.1257146862.8907.gz#err2 WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/01 22:41:26

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257154734.1257157741.30525.gz#err0 Linux mozilla-central test opt everythingelse on 2009/11/02 01:38:54

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257199534.1257202870.4117.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/02 14:05:34

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257206919.1257209865.18131.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/02 16:08:39

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257207672.1257210591.26294.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/02 16:21:12

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257236031.1257238778.8846.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/03 00:13:51

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257252023.1257255197.6124.gz#err1 WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/03 04:40:23

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257279498.1257283036.5161.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/03 12:18:18

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257295484.1257298708.19845.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/03 16:44:44

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257293950.1257297597.7620.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/03 16:19:10

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257291555.1257295506.16663.gz WINNT 5.2 mozilla-central test opt everythingelse on 2009/11/03 15:39:15

removed some check that was causing us to fail when checking sessionstore.js, or timing out while waiting for it to be written. http://hg.mozilla.org/mozilla-central/rev/df3198a37757 At this point i don't have new ideas, something is closing the window onLoad, with an handler that exists before our own. I suppose could be sessionstore or a previous uncleaned test, but i can't find a test part that could force that behavior.

(In reply to comment #117) > removed some check that was causing us to fail when checking sessionstore.js, > or timing out while waiting for it to be written. > http://hg.mozilla.org/mozilla-central/rev/df3198a37757 Is it clear that the timeout while waiting for sessionstore-state-write-complete is a testing quirk rather than a real failure that needs to be investigated? I also don't understand this change: - ok(sessionStoreJS.exists() == false, "sessionstore.js was removed"); + info("sessionstore.js was correctly removed: " + (!sessionStoreJS.exists()));

the file sometimes is held lock by the OS, so it's not correctly removed. actually we don't need it to be in place for this test, so i just info rather than failing.

this especially happens on Windows, i've seen other bugs caused by the fact Windows release of file locks is slooow.

Testing these things might not be the responsibility of this particular file, but my point is that if there are actual failures, they need to be investigated rather than not testing them anymore.

(In reply to comment #121) > Testing these things might not be the responsibility of this particular file, Though, maybe it is, as I could imagine that whether sessionstore.js gets written and removed correctly could be relevant for private browsing.

i want to know if the fact the file is locked is somehow related to the fact the window is closed. so i need to skip that check and let the test timeout on window load. That said, i think the fact on Windows FS files can be "in use" after some time you stop using them is pretty known, and i'm not sure what we should investigate about it. The only alternative possibility i could think of is that a previous test is writing a quite large sessionstore, and when we run it has not yet finished. Also consider the fact that this failure can only be reproduced on tinderboxes, i've found no way to reproduce locally (even in a VM), real machines have also pretty faster IO and less threading issues than VMs. Clearly if you have any idea to suggest, i'm open to accept them and try getting more debug infos.

(In reply to comment #122) > (In reply to comment #121) > > Testing these things might not be the responsibility of this particular file, > > Though, maybe it is, as I could imagine that whether sessionstore.js gets > written and removed correctly could be relevant for private browsing. i guess sessionstore does not even track changes while PB is active.

(In reply to comment #123) > That said, i think the fact on Windows FS files can be "in use" after some time > you stop using them is pretty known, and i'm not sure what we should > investigate about it. It needs to be made out whether there's a deficiency in session restore code or in the tools it uses that could hit users. At least to me, the answer to that isn't clear.

(In reply to comment #124) > (In reply to comment #122) > > (In reply to comment #121) > > > Testing these things might not be the responsibility of this particular file, > > > > Though, maybe it is, as I could imagine that whether sessionstore.js gets > > written and removed correctly could be relevant for private browsing. > > i guess sessionstore does not even track changes while PB is active. It shouldn't, and that is one of the main things that this test is supposed to ensure.

So, here it is some new data: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257409117.1257412155.29435.gz#err0 The test now does not timeout anymore, since i detect window close. The interesting thing is that now that this does not timeout, the test immediately after this, browser_408470.js, times out. it adds a tab and waits for load handler.

(In reply to comment #125) > (In reply to comment #123) > It needs to be made out whether there's a deficiency in session restore code or > in the tools it uses that could hit users. At least to me, the answer to that > isn't clear. SS does just asyncOpen and write its file, if the filesystem thinks the file is in use, it will silently fail. Since during PB the session data is not saved, i think the worst thing can happen is that on browser restart it will restore the session that was open BEFORE entering PB, that should not be a privacy concern. That said, i think that hitting a locked file is hard for real SS code since it uses a delay between writes, while in these tests we phisically remove the file and force a rewrite of it immediately, and that can cause fs headaches.

It looks like _writeFile actually knows about the failure. So maybe it should try again after some time? Or maybe it should send a sessionstore-state-write-failed notification? Otherwise, why don't we use a delay in the test? Would it have to be so long that the test would time out?

(In reply to comment #129) > It looks like _writeFile actually knows about the failure. So maybe it should > try again after some time? Or maybe it should send a > sessionstore-state-write-failed notification? true, we could detect errors in the asyncCopy callback, but i think sending a failed notification is over-engineering the thing, maybe a "retry sooner" solution is better. Still we are already retrying on the interval timer. So we could do that only if we feel that the file could be often locked and interval is too big. I think interval is good enough and having a not-so-small interval reduces the possibility of locking a lot. This is a guess but should be correct enough to consider this a minor problem. > Otherwise, why don't we use a delay in the test? Would it have to be so long > that the test would time out? i suspect so, in a previous change i added a 100ms delay and it was not enough, but actually we could try to set it to 500ms, and restore the write-complete check. Leaving this apart for a moment, any idea of what could happen with load handler, it's like as soon as this fails, all next tests will timeout. There is a possibility that the culprit is not this test, but the previous one the causes all next tests to timeout: browser_394759.js

pushed a cleanup of browser_394759.js previous tests are probably involved, especially that one and browser_354894.js http://hg.mozilla.org/mozilla-central/rev/fc4702c75a04

(In reply to comment #132) > pushed a cleanup of browser_394759.js > previous tests are probably involved, especially that one and browser_354894.js > http://hg.mozilla.org/mozilla-central/rev/fc4702c75a04 Reverted with http://hg.mozilla.org/mozilla-central/rev/f05767494de2 (didn't backout & merge because it wasn't worth the hassle here) since it seems to have caused bug 527074.

Paul, thank you for the backout, time was not good for me :( this is damn interesting, since the timeout in this bug disappeared(!) and that failure appeared. Unfortunatly there aren't many data available, but looks like touching browser_394759.js caused a failure shift. browser_526613 is the last test in sessionstore browser folder, if we can fix that failure we should be fine.

also notice there is also a green run, so the cleanup was correct, but something did open a second browser window in some runs... could even be this was fixed, and bug 527074 is a failure that previously was covered by the timeouts (actually same cause, but tests going on)

i compared messages in a successfull run against a failing run. the only difference is this TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Console message: [JavaScript Error: "[Exception... "'JavaScript component does not have a method named: "notify"' when calling method: [nsITimerCallback::notify]" nsresult: "0x80570030 (NS_ERROR_XPC_JSOBJECT_HAS_NO_FUNCTION_NAMED)" location: "<unknown>" data: no]"] in the failing run this message fires during browser_394759_privatebrowsing.js in the successfull run it fires during 394759.js

we could probably extract some interesting info from here.

Just occurred to me that since I stopped pasting logs in here, someone might think it's gone away - it hasn't.

bug 527074 could make this better providing a reliable notification of the end of SetBrowserState, i also think we have a blocker (iirc) about "zombie" tabs, so could be here we are seeing something similar (never loaded tabs). Btw we should wait for the former and then check the latter.

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

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258032267.1258035057.15566.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/12 05:24:27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258041559.1258045514.3806.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/12 07:59:19

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258041595.1258045792.7091.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/12 07:59:55

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258067676.1258070832.4188.gz#err0 WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/12 15:14:36 "s: moz2-win32-slave27"

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

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258129573.1258133228.3580.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/13 08:26:13 "s: moz2-win32-slave39"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258118289.1258121322.24539.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/13 05:18:09 "s: moz2-win32-slave15"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258135584.1258139195.7932.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/13 10:06:24 "s: moz2-win32-slave38" BTW, these timeouts are now coming after this failure: TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Window was closed before load could fire! (at least, the log here & in the last 4 comments all had that failure)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258137847.1258141167.31919.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/13 10:44:07 "s: moz2-win32-slave16"

(In reply to comment #148) > http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258135584.1258139195.7932.gz > WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/13 10:06:24 > "s: moz2-win32-slave38" > > BTW, these timeouts are now coming after this failure: > TEST-UNEXPECTED-FAIL | > chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js > | Window was closed before load could fire! yes it's due to my last changes, i'm waiting for a couple other ss tests and a possible test harness change that could interact with this.

Could bug 528440 have made a difference for this? Haven't seen a failure since that landed.

There have only been three Windows opt builds, though. Still, three is encouraging, since at least 50% of these kind of builds failed yesterday.

(In reply to comment #151) > Could bug 528440 have made a difference for this? Haven't seen a failure since > that landed. it could, but also zpao landed Bug 522545, that it's unclear if related. For sure having ss not taking in count wrong windows is a big win for tests.

I think we can close this if nothing shows up later today. There was a fourth Win opt build with a different failure (bug 521802) and another build is on the way. I'll also go through the other open orange bugs in Firefox/Session Restore and resolve them after some time, depending on how often the failures used to occur.

i agree, closing.

we can reopen bugs if new failures should show up, no reasons to wait for something, this failure was requent enough to show up in at least 1 run over 3.

sigh http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258201434.1258204315.24029.gz

I wonder if the previous runs were just lucky or if this is less frequent now. We'll see in the next few days...

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258210391.1258213328.776.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/14 06:53:11 "s: moz2-win32-slave15"

WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/15 10:10:32 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258308632.1258311732.15065.gz

doesn't seem to be frequent anymore

Marco, can you back out the window watcher stuff? It looks like that will incorrectly report a failure when an unrelated window gets destroyed.

I think that's the revision we want to go back to as far as the window watcher is concerned, i.e. without any window watcher dependency: http://hg.mozilla.org/mozilla-central/file/6240e80d2c21/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js

Alright, this was easy enough to do since the test didn't really depend on the window watcher stuff. http://hg.mozilla.org/mozilla-central/rev/74e3158a9fc5

yep, it was there just for logging open/close. thank you.

after <http://hg.mozilla.org/mozilla-central/rev/eb6ad91709a7>: TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | Only one browser window should be open eventually - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258566069.1258569909.1877.gz

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258597123.1258601028.1518.gz Linux mozilla-central opt test everythingelse on 2009/11/18 18:18:43 s: moz2-linux-slave23

(In reply to comment #168) > http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258597123.1258601028.1518.gz > Linux mozilla-central opt test everythingelse on 2009/11/18 18:18:43 > s: moz2-linux-slave23 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1

Linux mozilla-central opt test everythingelse on 2009/11/18 22:58:48 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258613928.1258618963.3822.gz TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output, killing pid 5433 If this bug is for these different errors could someone in the know update the summary so it is easier to find?

(In reply to comment #170) > If this bug is for these different errors could someone in the know update the > summary so it is easier to find? these errors are actual logging added to solve these failures

about:mozilla and about:buildconfig are from browser_354894.js

also see https://bugzilla.mozilla.org/show_bug.cgi?id=528776#c31

Yeah, this looks like a bug in _getCurrentState. The whole dependency on domwindowclosed is annyoing. That code should probably use the unload event instead.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258685600.1258689846.12154.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/19 18:53:20 "s: moz2-win32-slave35" TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258686058.1258690530.19552.gz Linux mozilla-central opt test everythingelse on 2009/11/19 19:00:58 s: moz2-linux-slave27 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output, killing pid 4201

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258746806.1258750221.29615.gz&fulltext=1 WINNT 5.2 mozilla-central opt test everythingelse

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258751197.1258754598.13164.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/20 13:06:37 "s: moz2-win32-slave37"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258761228.1258764675.29532.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/20 15:53:48 "s: moz2-win32-slave37" TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258769280.1258772283.15851.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/20 18:08:00 "s: moz2-win32-slave40"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258809969.1258815025.31032.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/21 05:26:09 "s: moz2-win32-slave15"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258815022.1258818153.3125.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/21 06:50:22 "s: moz2-win32-slave41"

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

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258946167.1258949185.15960.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/22 19:16:07

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

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258978147.1258981210.18588.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/23 04:09:07 "s: moz2-win32-slave36"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259000679.1259004015.24694.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/23 10:24:39 "s: moz2-win32-slave40"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259014149.1259017409.15051.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/23 14:09:09 "s: moz2-win32-slave34"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259072424.1259075576.31621.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/24 06:20:24 "s: moz2-win32-slave34" TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259078897.1259082325.12264.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/24 08:08:17 "s: moz2-win32-slave31" TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259106071.1259111572.23485.gz Linux mozilla-central opt test everythingelse on 2009/11/24 15:41:11 s: moz2-linux-slave25

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

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

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259212243.1259215303.2948.gz WINNT 5.2 mozilla-central opt

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259198027.1259200859.7004.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/25 17:13:47 "s: moz2-win32-slave16"

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259241772.1259244851.19633.gz http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259222040.1259225141.12754.gz

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1259292241.1259295063.2528.gz WINNT 5.2 mozilla-1.9.2 test everythingelse on 2009/11/26 19:24:01

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259623528.1259626889.31529.gz&fulltext=1 WINNT 5.2 mozilla-central opt test everythingelse on 2009/11/30 15:25:28

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259717570.1259720956.12155.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/01 17:32:50 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259726575.1259729468.7826.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/01 20:02:55

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

WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/03 18:12:36 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259892756.1259895845.5504.gz

WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/03 18:52:43 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259895163.1259898150.5293.gz At least the fourth time today... did something make this worse?

(In reply to comment #207) > At least the fourth time today... did something make this worse? doubt it, this is due to bug 528776, and can happen quite frequently

also bug 531519

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259957848.1259960748.15295.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/04 12:17:28 s: moz2-win32-slave25 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260528059.1260532279.5084.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/11 02:40:59 s: win32-slave30 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260562247.1260565234.30974.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/11 12:10:47 s: win32-slave25 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260585914.1260589103.3872.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/11 18:45:14 s: win32-slave39

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260594806.1260597950.2985.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/11 21:13:26 s: win32-slave38

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260579172.1260582396.26565.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/11 16:52:52 s: win32-slave39 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260563659.1260567912.28270.gz Linux mozilla-central opt test everythingelse on 2009/12/11 12:34:19 s: moz2-linux-slave19 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output, killing pid 11193

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260605170.1260608233.16072.gz#err0 WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/12 00:06:10 s: win32-slave26 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 3 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260618322.1260621498.4332.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/12 03:45:22 s: win32-slave26

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260609457.1260613256.6941.gz Linux mozilla-central opt test everythingelse on 2009/12/12 01:17:37 s: moz2-linux-slave23

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260646672.1260649858.1413.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/12 11:37:52 s: win32-slave32 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 2 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260648038.1260654261.17489.gz Linux mozilla-central opt test everythingelse on 2009/12/12 12:00:38 s: moz2-linux-slave18 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 2 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output, killing pid 17315

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260659487.1260664719.3516.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/12 15:11:27 s: win32-slave37

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260684869.1260687724.24165.gz#err0 WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/12 22:14:29 s: win32-slave16

Bug 531519 made one window go away, bug 528776 didn't make the other one go away. So there's still something weird going on. Bug 534489 might be related.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260736441.1260741847.1881.gz Linux mozilla-central opt test everythingelse on 2009/12/13 12:34:01 s: moz2-linux-slave25 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 2 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260738008.1260742354.8000.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/13 13:00:08 s: win32-slave28

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260760380.1260765070.28367.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/13 19:13:00 s: win32-slave27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260770208.1260773864.27923.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/13 21:56:48 s: win32-slave27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260769637.1260773197.20272.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/13 21:47:17 s: win32-slave32

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260773702.1260777882.7303.gz Linux mozilla-central opt test everythingelse on 2009/12/13 22:55:02 s: moz2-linux-slave27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260779067.1260781986.19291.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/14 00:24:27 s: win32-slave15

http://hg.mozilla.org/mozilla-central/rev/355d9819adba http://hg.mozilla.org/mozilla-central/rev/c961ea762a53

Linux mozilla-central opt test http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260791741.1260796420.23057.gz TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_354894.js | browser windows after testOpenCloseRestoreFromPopup (getBrowserState) - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_354894.js | browser windows after testNotificationCount (getBrowserState) - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 2 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1 buildbot.slave.commands.TimeoutError: command timed out: 1200 seconds without output, killing pid 5336

Apparently the first '_closedWindows' entry here equals the last 'windows' entry in the previous attachment.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1260839410.1260842377.24615.gz WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/14 17:10:10 s: win32-slave27 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_354894.js | browser windows after testOpenCloseRestoreFromPopup (getBrowserState) - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_354894.js | browser windows after testNotificationCount (getBrowserState) - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | oldState in test_purge has 2 windows instead of 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_purge - Got 2, expected 1 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially - Got 2, expected 1

(Oh, and a crapload of others - hard though it is to believe, I finally got tired of pasting log links in here, so just figure that its failing five or ten times a day.)

Do we need more data here? I think I've got this in a recorded VMWare session.

(In reply to comment #241) > Do we need more data here? I think I've got this in a recorded VMWare session. The point we need to look at is known now (testOpenCloseRestoreFromPopup in browser_354894.js), and it's relatively easy to get additional data, since it's a chrome test and failing rather regularly, so I think we should be able to figure this out soon. However if this doesn't work out as planned, we might want to resort to the recorded session indeed.

WINNT 5.2 mozilla-central opt test everythingelse on 2009/12/16 06:51:08 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1260975068.1260979450.22354.gz

This doesn't happen anymore, but I don't think it has actually been fixed... For the record, when this failed, newWin was still restoring (i.e. newWin.__SS_restoreID was nonempty) at the end of testOpenCloseRestoreFromPopup.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264198769.1264201991.5676.gz WINNT 5.2 mozilla-central debug test mochitest-other on 2010/01/22 14:19:29 s: win32-slave20

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264199633.1264202394.10478.gz WINNT 5.2 mozilla-central debug test mochitest-other on 2010/01/22 14:33:53 s: win32-slave22 Odd that after that long layoff, we're suddenly seeing this (well, something very like this, anyway) again.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1264688941.1264690788.7408.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/01/28 06:29:01 s: win32-slave16

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1266529143.1266534986.2625.gz WINNT 5.2 mozilla-central debug test mochitest-other on 2010/02/18 13:39:03 s: win32-slave42

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267003061.1267004634.15588.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267072622.1267074461.19032.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/24 20:37:02 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267104072.1267105699.7455.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/25 05:21:12

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267137811.1267139960.3982.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/25 14:43:31

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267231772.1267234478.14670.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/26 16:49:32 s: win32-slave16 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267278006.1267280004.14581.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/27 05:40:06 s: mw32-ix-slave10 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267278989.1267280858.17392.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/27 05:56:29 s: mw32-ix-slave07 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267284112.1267285767.32442.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/02/27 07:21:52 s: win32-slave39

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267449435.1267451377.6402.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/03/01 05:17:15 s: win32-slave39

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267472123.1267476628.30337.gz Linux mozilla-central debug test mochitest-other on 2010/03/01 11:35:23 So, the thing that is happening here is that it seems that two tests are running interleaved. I'm not really sure why, but Marco thinks that it should be relevant to this bug. ++DOMWINDOW == 135 (0xb518ad8) [serial = 1436] [outer = 0xb3085f0] WARNING: NS_ENSURE_SUCCESS(rv, 0) failed with result 0x8000FFFF: file /builds/moz2_slave/mozilla-central-linux-debug/build/content/base/src/nsContentUtils.cpp, line 2809 NEXT ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | Timed out TEST-INFO | checking window state Running chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js... Chrome file doesn't exist: /builds/slave/mozilla-central-linux-debug-unittest-mochitest-other/build/mochitest/browser/browser/components/sessionstore/test/browser/head.js TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Only one browser window should be open initially TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js was correctly removed: true TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | sessionstore.js is being written TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | There were 0 popup windows to repoen NEXT ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | There were 3 normal windows to repoen - Got 0, expected 3 ++DOMWINDOW == 136 (0xa9cdcc0) [serial = 1437] [outer = 0xa7117f8] TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Private Browsing is disabled TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Correctly set window count TEST-INFO | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759_privatebrowsing.js | Opening new window pldhash: for the table at address 0xaf1a348, the given entrySize of 48 probably favors chaining over double hashing. ++DOCSHELL 0xaf1a2e0 == 23 ++DOMWINDOW == 137 (0xb2205f0) [serial = 1438] [outer = (nil)] ++DOMWINDOW == 138 (0xaea5b60) [serial = 1439] [outer = 0xb2205c0] TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | number of browser windows after test_behavior TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | 1 tab was removed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The correct tab was removed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The correct tab was remembered TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | Selected tab has changed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The window title was correctly updated TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | 2 tabs were removed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The correct tabs were removed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The correct tabs were remembered TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | Selected tab has changed TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The window title was correctly updated TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | The correct number of tabs were removed, and the correct ones TEST-PASS | chrome://mochikit/content/browser/browser/components/sessionstore/test/browser/browser_394759.js | All tabs to be forgotten were indeed removed

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1267483473.1267486086.1321.gz WINNT 5.2 mozilla-1.9.2 opt test mochitest-other on 2010/03/01 14:44:33 s: win32-slave40

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267564669.1267566070.14563.gz Linux mozilla-central opt test mochitest-other on 2010/03/02 13:17:49

i'm going to double the timeout for this test, it takes some time to run. and let's see how it will behave.