(I had noticed this previously...) <http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1218631417.1218635037.28019.gz&fulltext=1> {{ Win2k3 comm-central dep unit test on 2008/08/13 05:43:37 *** 29167 INFO Running /tests/extensions/cookie/test/test_loadflags.html... *** 29168 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | cookie wasn't inited search "file" not found - skipping. *** 29169 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | cookie wasn't sent *** 29170 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | cookie wasn't sent Document http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html loaded successfully *** 29171 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | wrong event type *** 29172 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | incorrect number of cookies *** 29173 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | incorrect number of request headers }} <http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1218636691.1218640318.11441.gz> {{ Win2k3 comm-central dep unit test on 2008/08/13 07:11:31 *** 29167 INFO Running /tests/extensions/cookie/test/test_loadflags.html... *** 29168 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | cookie wasn't inited search "file" not found - skipping. *** 29169 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | cookie wasn't sent Document http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html loaded successfully *** 29170 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | wrong event type *** 29171 ERROR TEST-UNEXPECTED-FAIL | /tests/extensions/cookie/test/test_loadflags.html | incorrect number of cookies - got 4, expected 5 *** 29172 ERROR TEST-UNEXPECTED-FAIL | /tests/extensions/cookie/test/test_loadflags.html | incorrect number of request headers - got 1, expected 2 }} Same with <http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1218640095.1218643700.21145.gz> "Win2k3 comm-central dep unit test on 2008/08/13 08:08:15"

Again: <http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1219255689.1219259438.29082.gz> "Win2k3 comm-central dep unit test on 2008/08/20 11:08:09"

i commented briefly on this in https://bugzilla.mozilla.org/show_bug.cgi?id=421494#c37 - feel free to disable the test if it continues to fail.

(In reply to comment #2) > i commented briefly on this in Bug 421494 comment 36: {{ Robert Strong [:rs] (do not email) 2008-08-17 13:36:47 PDT test_loadflags.html had a test failure on "WINNT 5.2 mozilla-central qm-win2k3-unittest-hw dep unit test" http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1218999946.1219003990.21553.gz&fulltext=1#err4 Can this test be made more robust? }} Could you add a (= one) comment here if it happens again on Firefox ? > https://bugzilla.mozilla.org/show_bug.cgi?id=421494#c37 - feel free to disable CC: Robert, if he has a preference. > the test if it continues to fail. It really does: <http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1219332694.1219336456.21647.gz> "Win2k3 comm-central dep unit test on 2008/08/21 08:31:34"

I'd prefer if the reason the test is failing was debugged and fixed...

(In reply to comment #3) > Could you add a (= one) comment here if it happens again on Firefox ? <http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1219356345.1219360758.26214.gz> "WINNT 5.2 mozilla-central qm-win2k3-unittest-hw dep unit test on 2008/08/21 15:05:45" Not SeaMonkey specific, then. (NB: That was still before the (current) TraceMonkey landing.)

(In reply to comment #4) > I'd prefer if the reason the test is failing was debugged and fixed... of course; i don't have time to do so at the moment unfortunately, so barring someone else from stepping up (give it a week or so?), we should just disable it. i can look into it after i'm done graduating.

(SeaMonkey) Linux can have it too: http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1219583153.1219587427.4898.gz Linux comm-central dep unit test on 2008/08/24 06:05:53 [ *** 31838 ERROR TEST-UNEXPECTED-FAIL | /tests/extensions/cookie/test/test_loadflags.html | incorrect number of cookies - got 4, expected 5 *** 31839 ERROR TEST-UNEXPECTED-FAIL | /tests/extensions/cookie/test/test_loadflags.html | incorrect number of request headers - got 1, expected 2 ]

Given the number of regressions from bug 421494, we desperately need these tests enabled. Serge: have you looked at this test? Is there anything obviously broken about it?

"My" part from bug 454857 comment 4. Iiuc, this won't help this test, but it should "help" the ones which follow it.

[Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.9.1b2pre) Gecko/20081031 Minefield/3.1b2pre] (home, optim default) (W2Ksp4) *removeEventListener() should "help" following tests; and the first test/listener "could" have been disturbing the second one... *(unrelated) Some code/text rewrites. *Reenable the second test. (So we can learn what the new/current behavior is.)

thanks serge!

Was this checked in? Is this fixed? It's true that we should never leave event listeners on windows as they will (try to) fire on all following tests as well, which is obviously a bad idea.

(In reply to comment #13) Not checked in: waiting for review(er).!. Not actually fixed: only can't happen, as the test is currently disabled :->

(In reply to comment #11) > *removeEventListener() should "help" following tests; > and the first test/listener "could" have been disturbing the second one... Per bug 454717, this should not be needed ... but this patch is 7.5 months old and it can't hurt, at least. The one (and only) thing which may actually make a difference is the (2) added |return;|!

dwitte, ping for review ?

Comment on attachment 345655 [details] [diff] [review] (Av2) Call |window.removeEventListener()| ++ [Checkin: See comment 18 & 19] Thanks for the patch - I'm not sure if it'll help, but it's worth a try, and if you're willing to watch out for intermittent orange after landing then go for it. I'd note that if the problem is indeed event listeners from previous tests (including these) that weren't removed, perhaps we shouldn't fail on receiving the wrong event type. We could use a unique message string for each test, and just continue listening if we get something different.

Comment on attachment 345655 [details] [diff] [review] (Av2) Call |window.removeEventListener()| ++ [Checkin: See comment 18 & 19] http://hg.mozilla.org/mozilla-central/rev/a460bfd4f1df (Av2a) Call |window.removeEventListener()| ++ Av2, with sorting the file names in Makefile.in (Sorry, forgot to update the checkin summary.)

Comment on attachment 345655 [details] [diff] [review] (Av2) Call |window.removeEventListener()| ++ [Checkin: See comment 18 & 19] http://hg.mozilla.org/releases/mozilla-1.9.1/rev/7e630f5d110a

Not reported to fail after comment 18 check-in, so assuming it's fixed, thought we don't know whether the issue was in Core or in the test.

What is the best/simplest way for QA to verify this bug?

(In reply to comment #21) > What is the best/simplest way for QA to verify this bug? The only thing which can be "easily" checked (somewhat) is that the test does not randomly fail anymore: to achieve this, one has to check logs/reports from all (orange/red) tests run since the comment 19.

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1249120707.1249127328.25821.gz&fulltext=1 WINNT 5.2 comm-1.9.1 unit test on 2009/08/01 02:58:27 { ... | number of cookies - got 4, expected 5 ... | number of request headers - got 1, expected 2 } Bug still there, unchanged, on 1.9.1.

From the log, it looks like the header (and its cookie) to load image1.png is missed somehow. Source code is { file_loadflags_inner.html <img src="http://example.org/tests/extensions/cookie/test/image1.png" onload="runTest()" /> } Note that onload= is actually run yet. *** Fwiw, I found on the web: { http://www.htmlcodetutorial.com/images/_IMG_onLoad.html Unfortunately, onLoad is not a very reliable event handler. Netscape particularly has trouble firing onLoad when the image is malformed in some way or if the image is loaded from cache instead of freshly downloaded from the net. } but I would guess this is not relevant (here).

New expected success log is { ok - number of cookies for domain example.org ok - cookie 'oh=hai' is in header for http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html ok - cookie 'oh=hai' is in header for http://example.org/tests/extensions/cookie/test/image1.png ok - message data received from popup ok - number of observed request headers ok - total number of cookies } ***** (In reply to comment #17) > perhaps we shouldn't fail on receiving the wrong event type. The type is "message / MessageEvent": it would be very odd to receive another type than the one asked for. I removed the (useless) check for this. > We could use a unique message string for each test, I changed the data string, fwiw. > and just continue listening if we get something different. I disagree: something would be very wrong and we should abort this test asap. ***** As with patch Av2, I'm not sure this will fix the issue (which I never reproduced), but it should at least help reading the code and the logs.

Bv1, without an unwanted line.

Comment on attachment 392095 [details] [diff] [review] (Bv1a) Make it more serial, explicit and documented [Checkin: Comment 27 & 28] http://hg.mozilla.org/mozilla-central/rev/9281246909f0

Comment on attachment 392095 [details] [diff] [review] (Bv1a) Make it more serial, explicit and documented [Checkin: Comment 27 & 28] http://hg.mozilla.org/releases/mozilla-1.9.1/rev/1cb9bec9a965

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1250142781.1250149793.20557.gz WINNT 5.2 comm-1.9.1 unit test on 2009/08/12 22:53:01 { ... | number of observed request headers - got 1, expected 2 ... | total number of cookies - got 4, expected 5 } Confirming (comment 24 and comment 25): { ... | cookie 'oh=hai' is in header for http://example.org/tests/extensions/cookie/test/image1.png } is missing :-/

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1250137300.1250145549.7075.gz OS X 10.5 comm-1.9.1 unit test on 2009/08/12 21:21:40

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1250249575.1250256813.12889.gz WINNT 5.2 comm-1.9.1 unit test on 2009/08/14 04:32:55

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5-Unittest/1250504961.1250507733.7809.gz OS X 10.5.2 mozilla-1.9.1 test mochitests on 2009/08/17 03:29:21

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5-Unittest/1250530280.1250533017.15931.gz OS X 10.5.2 mozilla-1.9.1 test mochitests on 2009/08/17 10:31:20

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1250503968.1250510422.6678.gz OS X 10.4 comm-central unit test on 2009/08/17 03:12:48

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1251210305.1251217061.29044.gz OS X 10.4 comm-central unit test on 2009/08/25 07:25:05

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey2.0/1252497604.1252506744.2636.gz OS X 10.5 comm-1.9.1 unit test on 2009/09/09 05:00:04

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5/1253186727.1253195358.5813.gz OS X 10.5.2 mozilla-1.9.1 unit test on 2009/09/17 04:25:27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1253688214.1253698514.4258.gz WINNT 5.2 mozilla-central unit test on 2009/09/22 23:43:34

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257977127.1257981052.23192.gz Linux mozilla-central debug test mochitests-3/5 on 2009/11/11 14:05:27

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5/1264182020.1264184763.618.gz OS X 10.5.2 mozilla-1.9.1 test mochitests on 2010/01/22 09:40:20

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1264231965.1264233555.30805.gz Linux mozilla-central debug test mochitests-3/5 on 2010/01/22 23:32:45 s: moz2-linux-slave06

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1265163740.1265165687.28422.gz WINNT 5.2 mozilla-central debug test mochitests-3/5 on 2010/02/02 18:22:20 s: win32-slave36

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1265643897.1265646031.7169.gz Linux mozilla-central debug test mochitests-3/5 on 2010/02/08 07:44:57

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267370918.1267373370.23892.gz WINNT 5.2 mozilla-central debug test mochitests-3/5 on 2010/02/28 07:28:38 s: win32-slave22

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267345249.1267347412.1264.gz WINNT 5.2 mozilla-central debug test mochitests-3/5 on 2010/02/28 00:20:49 s: win32-slave22

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1267407732.1267409177.30181.gz Linux mozilla-central debug test mochitests-3/5 on 2010/02/28 17:42:12 s: moz2-linux-slave16

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.5/1270071391.1270074133.8935.gz OS X 10.5.2 mozilla-1.9.1 test mochitests on 2010/03/31 14:36:31

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274775241.1274776557.4782.gz WINNT 5.2 mozilla-central debug test mochitests-4/5 on 2010/05/25 01:14:01 s: win32-slave35 17 ERROR TEST-UNEXPECTED-FAIL | /tests/extensions/cookie/test/test_loadflags.html | number of observed request headers - got 1, expected 2 18 ERROR TEST-UNEXPECTED-FAIL | /tests/extensions/cookie/test/test_loadflags.html | total number of cookies - got 4, expected 5

Landed some debugging output to try to figure out what is going on here http://hg.mozilla.org/mozilla-central/rev/ccf3b452d0f4

To try to find out when the load event for the page file_loadflags_inner.html happens (in relation to the load of the image) I made the test wait for the load event of the page as well and log it. So there is a chance the above changeset might fix (or reduce) the random orange here.

The onload for the image is fired, but we don't get the http-on-modify-request observer notification. I wonder if this could be because we don't open an http channel for the image because it is cached already from the other tests that use the same image? Is that the expected behaviour if the image is cached?

I landed some more debug stuff to see if the cookie for the image was already set and we delete it when we remove all cookies at the start of the test and to see if maybe we get a really late http request for the image by delaying the test end by 5 seconds. http://hg.mozilla.org/mozilla-central/rev/fbea64d46081

Hmm. For both image1.png and image2.png we specify a 'Cache-Control: no-cache' header. So caching shouldn't be happening. biesi, is that correct? Perhaps the load is occurring before we register the observer? To test the caching theory, you could use different images for each test. Just copy the image (and the corresponding ^headers^ file) and rename it.

You should really use Cache-Control: no-store if you never want to reuse the image. That said... for this case this shouldn't make a difference. Get a log with nsHttp:5 and imgRequest:5?

11520 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | setupTest uri: http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html domain: example.org cookies: 5 loads: 2 headers: 2 11521 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | we are going to remove these cookies 11522 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | 0 cookies 11523 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | number of cookies for domain example.org - 1 should equal 1 11524 INFO TEST-PASS | /tests/extensions/cookie/test/test_loadflags.html | adding observer Looks like there aren't any cookies removed at the beginning of the test. Timothy, you agree? I'll switch the Cache-Control to no-store...

Yeah, I agree. Thanks for taking this up.

Switched to no-store: http://hg.mozilla.org/mozilla-central/rev/d261faaa483a Added new images to guarantee cache circumvention: http://hg.mozilla.org/mozilla-central/rev/70175407282a Hopefully those (or rather, the latter) should fix this.

I *think* this is fixed on trunk. Assigning to :tn, since he did most of the legwork here. tn, feel free to backport this to 3.6 if you want. ;)