Closed Bug 1292735 Opened 8 years ago Closed 8 years ago

Intermittent dom/xhr/tests/test_worker_xhr_timeout.html | load fires normally with same timeout set twice, original timeout at 5000, reset at 2000 to 5000 - got "timeout", expected "load"

Categories

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

defect

Tracking

()

RESOLVED FIXED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed])

Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
This test started failing frequently, on Android Debug only, on March 7. Comment 6 suggests this is a regression from bug 1333799, but I don't see an immediate connection between that change and this test. On the other hand, bug 1335751 is just 2 changesets earlier, and that caused a significant reduction in performance in several other tests on Android Debug. I'll dig deeper on try.
Flags: needinfo?(gbrown)
I notice that almost all the current failures are slightly different from the bug title. https://public-artifacts.taskcluster.net/feXG20e8TW6VWHBzi1oEBQ/0/public/logs/live_backing.log seems typical: [task 2017-03-09T05:32:58.582416Z] 05:32:58 INFO - 145 INFO TEST-START | dom/xhr/tests/test_worker_xhr_timeout.html [task 2017-03-09T05:34:22.859130Z] 05:34:22 INFO - Buffered messages logged at 05:33:10 [task 2017-03-09T05:34:22.859251Z] 05:34:22 INFO - 146 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | no time out scheduled, load fires normally, timeout scheduled at 0 [task 2017-03-09T05:34:22.859306Z] 05:34:22 INFO - Buffered messages logged at 05:33:19 [task 2017-03-09T05:34:22.859369Z] 05:34:22 INFO - 147 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | load fires normally, timeout scheduled at 5000 [task 2017-03-09T05:34:22.859413Z] 05:34:22 INFO - Buffered messages logged at 05:33:28 [task 2017-03-09T05:34:22.859487Z] 05:34:22 INFO - 148 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout hit before load, timeout scheduled at 2000 [task 2017-03-09T05:34:22.859541Z] 05:34:22 INFO - Buffered messages logged at 05:33:36 [task 2017-03-09T05:34:22.860653Z] 05:34:22 INFO - 149 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | load fires normally with no timeout set, twice, original timeout at 0, reset at 2000 to 0 [task 2017-03-09T05:34:22.861298Z] 05:34:22 INFO - Buffered messages logged at 05:33:48 [task 2017-03-09T05:34:22.862602Z] 05:34:22 INFO - 150 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | load fires normally with same timeout set twice, original timeout at 5000, reset at 2000 to 5000 [task 2017-03-09T05:34:22.862652Z] 05:34:22 INFO - Buffered messages logged at 05:33:55 [task 2017-03-09T05:34:22.862705Z] 05:34:22 INFO - 151 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout fires normally with same timeout set twice, original timeout at 2000, reset at 1000 to 2000 [task 2017-03-09T05:34:22.862729Z] 05:34:22 INFO - Buffered messages logged at 05:34:03 [task 2017-03-09T05:34:22.863055Z] 05:34:22 INFO - 152 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout disabled after initially set, original timeout at 5000, reset at 2000 to 0 [task 2017-03-09T05:34:22.863247Z] 05:34:22 INFO - Buffered messages finished [task 2017-03-09T05:34:22.863725Z] 05:34:22 INFO - 153 INFO TEST-UNEXPECTED-FAIL | dom/xhr/tests/test_worker_xhr_timeout.html | timeout overrides load after a delay, original timeout at 5000, reset at 1000 to 2000 - got "load", expected "timeout" [task 2017-03-09T05:34:22.864140Z] 05:34:22 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:310:5 [task 2017-03-09T05:34:22.864602Z] 05:34:22 INFO - @dom/xhr/tests/test_worker_xhr_timeout.html:38:7 [task 2017-03-09T05:34:33.298888Z] 05:34:33 INFO - 154 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout enabled after initially disabled, original timeout at 0, reset at 2000 to 5000 [task 2017-03-09T05:34:33.299321Z] 05:34:33 INFO - 155 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout set to expiring value after load fires, original timeout at 5000, reset at 4000 to 1000 [task 2017-03-09T05:34:43.744093Z] 05:34:43 INFO - 156 INFO TEST-UNEXPECTED-FAIL | dom/xhr/tests/test_worker_xhr_timeout.html | timeout set to expired value before load fires, original timeout at 5000, reset at 2000 to 1000 - got "load", expected "timeout" [task 2017-03-09T05:34:43.744261Z] 05:34:43 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:310:5 [task 2017-03-09T05:34:43.744555Z] 05:34:43 INFO - @dom/xhr/tests/test_worker_xhr_timeout.html:38:7 [task 2017-03-09T05:34:54.182224Z] 05:34:54 INFO - 157 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout set to non-expiring value after timeout fires, original timeout at 1000, reset at 2000 to 5000 [task 2017-03-09T05:35:04.629524Z] 05:35:04 INFO - 158 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | No events should fire for an unsent, unaborted request [task 2017-03-09T05:35:04.629828Z] 05:35:04 INFO - 159 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | time to abort is -1, timeout set at 2000 [task 2017-03-09T05:35:15.067413Z] 05:35:15 INFO - 160 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | time to abort is 5000, timeout set at 2000 [task 2017-03-09T05:35:25.514409Z] 05:35:25 INFO - 161 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | no time out scheduled, load fires normally, timeout scheduled at 0 [task 2017-03-09T05:35:25.514699Z] 05:35:25 INFO - 162 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | load fires normally, timeout scheduled at 5000 [task 2017-03-09T05:35:35.961767Z] 05:35:35 INFO - 163 INFO TEST-PASS | dom/xhr/tests/test_worker_xhr_timeout.html | timeout hit before load, timeout scheduled at 2000 [task 2017-03-09T05:35:46.507350Z] 05:35:46 INFO - 164 INFO TEST-OK | dom/xhr/tests/test_worker_xhr_timeout.html | took 159587ms Current failures have '...original timeout at 5000, reset at 2000 to 1000 - got "load", expected "timeout"' rather than '...original timeout at 5000, reset at 2000 to 5000 - got "timeout", expected "load"', as in bug title.
(In reply to Geoff Brown [:gbrown] from comment #7) > This test started failing frequently, on Android Debug only, on March 7. > > Comment 6 suggests this is a regression from bug 1333799, but I don't see an > immediate connection between that change and this test. On the other hand, > bug 1335751 is just 2 changesets earlier, and that caused a significant > reduction in performance in several other tests on Android Debug. I'll dig > deeper on try. https://treeherder.mozilla.org/#/jobs?repo=try&author=gbrown@mozilla.com&tochange=e12db62debf5e2af25420f380ccc49ec19768123&fromchange=2b2c5003626c5e65db7db8815a0c04ae87d696ed Failures persist if I backout bug 1333799, but I get a green run if I backout bug 1335751.
Blocks: 1335751
:sfink is working on a few other bugs related to this, this will most likely get fixed when a fix is in place.
Whiteboard: [stockwell needswork]
(In reply to Joel Maher ( :jmaher) from comment #11) > :sfink is working on a few other bugs related to this, this will most likely > get fixed when a fix is in place. Actually, after bug 1284763 comment 13 I wasn't. But this bug seems like it may require more than just making more chunks and/or increasing timeouts. Bug 1346874 should resolve this (or at least, return it back to its previous frequency.)
Depends on: 1346874
this is still a problem, we started up on March 7th and the frequency is cut down about 1/3, but that is still too often.
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Whiteboard: [stockwell needswork] → [stockwell fixed]
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.