Closed Bug 686828 Opened 14 years ago Closed 12 years ago

Intermittent Windows content/base/test/test_CrossSiteXHR_cache.html | should have failed in test for ({pass:0, method:"GET", headers:{'x-my-header':"myValue"}}) (index 13) - got false, expected true (followed by other errors)

Categories

(Core :: DOM: Core & HTML, defect)

x86
Windows 8
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla26
Tracking Status
firefox24 --- fixed
firefox25 --- fixed
firefox26 --- fixed

People

(Reporter: mbrubeck, Assigned: jdm)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

https://tbpl.mozilla.org/php/getParsedLog.php?id=6406286&tree=Mozilla-Inbound Rev3 MacOSX Leopard 10.5.8 mozilla-inbound debug test mochitests-1/5 on 2011-09-14 18:15:30 PDT for push b2c01d6dbd4a 3146 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong events in test for ({pass:1, method:"GET", headers:{'third-header':"myValue"}, allowHeaders:"third-header", cacheTime:2}) (index 31) - opening,rs1,sending,rs1,loadstart,rs2,rs3,rs4,load,loadend should equal opening,rs1,sending,rs1,loadstart,rs2,rs3,rs4,load,loadend 3147 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | shouldn't have failed in test for ({pass:1, method:"GET", headers:{'second-header':"myValue"}}) (index 33) - false should equal false 3148 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong status in test for ({pass:1, method:"GET", headers:{'second-header':"myValue"}}) (index 33) - 200 should equal 200 3149 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong responseXML in test for ({pass:1, method:"GET", headers:{'second-header':"myValue"}}) (index 33) - <res>hello pass</res> should equal <res>hello pass</res> 3150 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong responseText in test for ({pass:1, method:"GET", headers:{'second-header':"myValue"}}) (index 33) - <res>hello pass</res> should equal <res>hello pass</res> 3151 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong events in test for ({pass:1, method:"GET", headers:{'second-header':"myValue"}}) (index 33) - opening,rs1,sending,rs1,loadstart,rs2,rs3,rs4,load,loadend should equal opening,rs1,sending,rs1,loadstart,rs2,rs3,rs4,load,loadend 3152 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_CrossSiteXHR_cache.html | should have failed in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - got false, expected true 3153 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong status in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - got 200, expected 0 3154 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong responseXML in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - got <res>hello pass</res>, expected null 3155 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong responseText in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - got <res>hello pass</res> , expected 3156 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong events in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - got opening,rs1,sending,rs1,loadstart,rs2,rs3,rs4,load,loadend, expected opening,rs1,sending,rs1,loadstart,rs2,rs4,error,loadend 3157 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong events in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - 0 should equal 0 3158 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | shouldn't have failed in test for ({pass:1, method:"GET", headers:{'first-header':"myValue"}, allowHeaders:"first-header", cacheTime:2}) (index 36) - false should equal false 3159 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong status in test for ({pass:1, method:"GET", headers:{'first-header':"myValue"}, allowHeaders:"first-header", cacheTime:2}) (index 36) - 200 should equal 200 3160 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong responseXML in test for ({pass:1, method:"GET", headers:{'first-header':"myValue"}, allowHeaders:"first-header", cacheTime:2}) (index 36) - <res>hello pass</res> should equal <res>hello pass</res> 3161 INFO TEST-PASS | /tests/content/base/test/test_CrossSiteXHR_cache.html | wrong responseText in test for ({pass:1, method:"GET", headers:{'first-header':"myValue"}, allowHeaders:"first-header", cacheTime:2}) (index 36) - <res>hello pass</res> should equal <res>hello pass</res>
Whiteboard: [orange]
Resolving WFM keyword:intermittent-failure bugs last modified >3 months ago, whose whiteboard contains none of: {random,disabled,marked,fuzzy,todo,fails,failing,annotated,time-bomb,leave open} There will inevitably be some false positives; for that (and the bugspam) I apologise. Filter on orangewfm.
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → WORKSFORME
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
OS: Mac OS X → Windows 8
(This hasn't occurred on any other OS for months; this is now Win8 only)
Summary: Intermittent TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_CrossSiteXHR_cache.html | should have failed in test for ({pass:0, method:"GET", headers:{'first-header':"myValue"}}) (index 34) - got false, expected true (followed by other errors) → Intermittent Win8 content/base/test/test_CrossSiteXHR_cache.html | should have failed in test for ({pass:0, method:"GET", headers:{'x-my-header':"myValue"}}) (index 13) - got false, expected true (followed by other errors)
This happens across all Windows platforms since we switched to the iX test slaves. Sicking, I see that you originally wrote this test. Can you please take a look at this or suggest someone who can?
Flags: needinfo?(jonas)
Summary: Intermittent Win8 content/base/test/test_CrossSiteXHR_cache.html | should have failed in test for ({pass:0, method:"GET", headers:{'x-my-header':"myValue"}}) (index 13) - got false, expected true (followed by other errors) → Intermittent Windows content/base/test/test_CrossSiteXHR_cache.html | should have failed in test for ({pass:0, method:"GET", headers:{'x-my-header':"myValue"}}) (index 13) - got false, expected true (followed by other errors)
Johnny, do we have anyone on the DOM team that has the cycles to look at this? These failures sound pretty scary since it looks like cross-site requests that should be failing are not.
Flags: needinfo?(jonas) → needinfo?(jst)
khuey, can you take a look? maybe a good excuse to show the new guy the replay debugger?
Flags: needinfo?(jst)
I think we need someone other than Kyle here as he has his hands full with bug 903770 and its dependency tree.
Flags: needinfo?(doug.turner)
I'll see what I can do here.
Assignee: khuey → josh
Flags: needinfo?(doug.turner)
Here's why this occurs: 16:02:30 INFO - entry for http://mochi.test:8888/tests/content/base/test/file_CrossSiteXHR_cache_server.sjs?c=1377817350319: 00000000 16:02:30 INFO - setting expiry date of -263168504 (now 320798) ... 16:02:30 INFO - entry for http://mochi.test:8888/tests/content/base/test/file_CrossSiteXHR_cache_server.sjs?c=1377817350319: 09F68D00 16:02:30 INFO - --- purging 09F68D00 --- 16:02:30 INFO - now: 431812792 16:02:30 INFO - method 0: -263168504 16:02:30 INFO - header 0: -263168504 16:02:30 INFO - header 1: -263168504 Hence why we consider the cached CORS reply still valid and fail the test.
Sorry, that's an earlier entry. This is the correct one: 16:02:30 INFO - entry for http://mochi.test:8888/tests/content/base/test/file_CrossSiteXHR_cache_server.sjs?c=1377817350320: 00000000 16:02:30 INFO - setting expiry date of 433841792 (now 320798) ... 16:02:32 INFO - entry for http://mochi.test:8888/tests/content/base/test/file_CrossSiteXHR_cache_server.sjs?c=1377817350320: 0AB7EBE0 16:02:32 INFO - --- purging 0AB7EBE0 --- 16:02:32 INFO - now: 433825792 16:02:32 INFO - method 0: 433841792 16:02:32 INFO - header 0: 433841792
This retriggered a bunch of times and never gave me anything but green.
Attachment #797604 - Flags: review?(jonas)
Comment on attachment 797604 [details] [diff] [review] Make the CORS reply cache use a monotic clock that agrees with the clock used to control timers in tests. [Approval Request Comment] Bug caused by (feature/regressing bug #): Unclear. User impact if declined: Extreme sheriff unhappiness (#1 orange on beta) Testing completed (on m-c, etc.): m-c, numerous try runs. Risk to taking this patch (and alternatives if risky): Risk free. It's exchanging one deprecated way of timing intervals for a recommended one, and the scope of the change is limited to the internals of the module. Nobody depends on the timing behaviour of the code except tests, which is what this fixed. String or IDL/UUID changes made by this patch: None.
Attachment #797604 - Flags: approval-mozilla-beta?
Attachment #797604 - Flags: approval-mozilla-aurora?
All the instances on inbound post-comment 470 were from pushes prior to this landing. Looking good! Thanks, Josh!
Comment on attachment 797604 [details] [diff] [review] Make the CORS reply cache use a monotic clock that agrees with the clock used to control timers in tests. low risk, avoids intermittent failure's.
Attachment #797604 - Flags: approval-mozilla-beta?
Attachment #797604 - Flags: approval-mozilla-beta+
Attachment #797604 - Flags: approval-mozilla-aurora?
Attachment #797604 - Flags: approval-mozilla-aurora+
Status: REOPENED → RESOLVED
Closed: 13 years ago12 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla26
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: