Intermittent test_IE_cookies.js | xpcshell return code: 0

RESOLVED FIXED in Firefox 41

Status

()

Firefox
Migration
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: Tomcat, Assigned: mak)

Tracking

({intermittent-failure})

unspecified
Firefox 43
x86
Windows 8
intermittent-failure
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox40 wontfix, firefox41 fixed, firefox42 fixed, firefox43 fixed, firefox-esr31 unaffected, firefox-esr38 unaffected)

Details

(URL)

Attachments

(1 attachment)

(Reporter)

Description

3 years ago
Windows 8 64-bit fx-team debug test xpcshell

https://treeherder.mozilla.org/logviewer.html#?job_id=2743349&repo=fx-team

03:33:40 WARNING - TEST-UNEXPECTED-FAIL | browser/components/migration/tests/unit/test_IE_cookies.js | xpcshell return code: 0
03:33:40 INFO - TEST-INFO took 711ms
03:33:40 INFO - >>>>>>>
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: preserving unexpected JS escape sequence: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\modules\\libpref\\prefread.cpp, line 393
03:33:40 INFO - PROCESS | 5480 | [5480] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file c:\\builds\\moz2_slave\\fx-team-w64-d-0000000000000000\\build\\src\\toolkit\\crashreporter\\nsExceptionHandler.cpp, line 2333
03:33:40 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
03:33:40 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
03:33:40 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
03:33:40 INFO - running event loop
03:33:40 INFO - browser/components/migration/tests/unit/test_IE_cookies.js | Starting
03:33:40 INFO - (xpcshell/head.js) | test pending (2)
Comment hidden (Treeherder Robot)
looks like a timing issue, the cookie expiry time is different than we expect and the difference is not exactly small, like 2 days...
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(In reply to Marco Bonardo [::mak] from comment #2)
> looks like a timing issue, the cookie expiry time is different than we
> expect and the difference is not exactly small, like 2 days...

Any updates here? :)
status-firefox40: --- → affected
status-firefox41: --- → affected
status-firefox42: --- → affected
status-firefox-esr31: --- → unaffected
status-firefox-esr38: --- → unaffected
Flags: needinfo?(mak77)
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #87)
> Any updates here? :)

Nope, I have no idea.

BUT, the failure changed, until 18th of May it was a time issue, now it's 
TEST-UNEXPECTED-FAIL | browser/components/migration/tests/unit/test_IE_cookies.js |  - Migrated the expected number of cookies - 0 == 1

Somehow we are either not creating the cookie properly, or we're not migrating it.
The call to InternetSetCookieW returns true, so it seems the cookie is created.
So probably migration fails.
We might want to attach a console listener and see if there's any reportError.
Plus, head should listen to "Migration:ItemError" and report it, so we know when migration fails.

Maybe it's still the datetime issue that generates invalid dates.
Flags: needinfo?(mak77)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Tanvi, this is another frequent Windows cookies xpcshell failure we're seeing. With any luck, it'll be related to the other bug you're investigating.
status-firefox40: affected → wontfix
status-firefox43: --- → affected
Flags: needinfo?(tanvi)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Mak - can you take another look at this bug?  See also https://bugzilla.mozilla.org/show_bug.cgi?id=863738#c508.  I think these two bugs show that there is some cookie persistence issue on windows 8.
Flags: needinfo?(tanvi)
Flags: needinfo?(mak77)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Assignee: nobody → mak77
Status: NEW → ASSIGNED
Flags: needinfo?(mak77)
I'm trying to get logging from Try, but so far I was unable to get a failure, I will keep retriggering until I see one.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=5652745c25ca
Comment hidden (Treeherder Robot)
Got a failure, we set only one cookie, but we find three:

15:35:30 INFO - PROCESS | 5116 | found Windows cookie entry 3HRGLB3U.txt
15:35:30 INFO - PROCESS | 5116 | adding cookie .mycookietest.com, /, testcookie, testvalue, 0, 1437577601
15:35:30 INFO - PROCESS | 5116 | found Windows cookie entry BSJRQAW4.txt
15:35:30 INFO - PROCESS | 5116 | adding cookie .mycookietest.com, /, testcookie, testvalue, 0, 1441233329
15:35:30 INFO - PROCESS | 5116 | found Windows cookie entry OK7EMGQF.txt
15:35:30 INFO - PROCESS | 5116 | adding cookie .mycookietest.com, /, testcookie, testvalue, 0, 1431718480 

The correct one is the second.
My guess is that these machines are reused and there's nothing clearing cookies, we should clear them before exiting the process, and looks like that is possible using InternetSetOption(0, 42, NULL, 0);

We also need to change the domain, we should randomize a part of it, to reduce possibility of dupes.
Created attachment 8653410 [details] [diff] [review]
patch v1

This should do:
1. set a cookie name
2. set expiration in the past at the end of the test (removes the cookie file)
3. in any case, use a randomized host
4. set expiration just 2 days in the future, so in the worst case cookies will expire sooner on tinderboxes

 https://treeherder.mozilla.org/#/jobs?repo=try&revision=d07572b3c635
Attachment #8653410 - Flags: review?(gijskruitbosch+bugs)

Comment 152

3 years ago
Comment on attachment 8653410 [details] [diff] [review]
patch v1

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

r=me assuming try is green on Windows too (still pending, it seems, presumably because of the test backlog)
Attachment #8653410 - Flags: review?(gijskruitbosch+bugs) → review+
Comment hidden (Treeherder Robot)
https://hg.mozilla.org/mozilla-central/rev/5770dcb3b32a
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox43: affected → fixed
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → Firefox 43
You need to log in before you can comment on or make changes to this bug.