Closed Bug 1826079 Opened 1 year ago Closed 5 months ago

Intermittent dom/xhr/tests/test_worker_xhr_timeout.html | single tracking bug

Categories

(Core :: DOM: Networking, defect, P3)

defect

Tracking

()

RESOLVED FIXED
122 Branch
Tracking Status
firefox122 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: smayya)

References

(Blocks 2 open bugs, Regressed 1 open bug)

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [necko-triaged])

Attachments

(1 file)

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=411189222&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SIW4RxIvTIqG77xBSiZ3AA/runs/0/artifacts/public/logs/live_backing.log


[task 2023-04-03T11:54:41.530Z] 11:54:41     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 2023-04-03T11:54:41.530Z] 11:54:41     INFO - Buffered messages finished
[task 2023-04-03T11:54:41.531Z] 11:54:41     INFO - TEST-UNEXPECTED-FAIL | 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 - got "timeout", expected "load"
[task 2023-04-03T11:54:41.531Z] 11:54:41     INFO - SimpleTest.is@https://mochi.test:8888/tests/SimpleTest/SimpleTest.js:504:14
[task 2023-04-03T11:54:41.531Z] 11:54:41     INFO - @https://mochi.test:8888/tests/dom/xhr/tests/test_worker_xhr_timeout.html:37:16
[task 2023-04-03T11:54:41.531Z] 11:54:41     INFO - EventListener.handleEvent*@https://mochi.test:8888/tests/dom/xhr/tests/test_worker_xhr_timeout.html:28:10
[task 2023-04-03T11:54:48.365Z] 11:54:48     INFO - TEST-PASS | 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 

For the most recent m-c failure log of https://treeherder.mozilla.org/logviewer?job_id=425967827&repo=mozilla-central&lineNumber=3601 we're seeing:

TEST-UNEXPECTED-FAIL | 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 - got "timeout", expected "load"

This corresponds to this RequestTracker creation where the check logic here is assuming that we'll see the load event prior to the timeout event because the expected sequence is:

  • @3000ms : file_XHR_timeout.sjs responds to the request.
  • expected: sometime after that but before the 4000ms setTimeout, we get the "load" event.
  • @4000ms: the setTimeout resets the XHR timeout to 1000ms which will end up effectively as a 0ms delay timer because per the spec the timeout is relative to the start of the fetch, not when we set the timeout.
  • @5000ms: the original XHR timeout would fire if it hasn't been reset.

Since this only happens on debug builds, it seems quite plausible that the timing is too tight to account for machine jank. The SJS timeout of 3000ms could likely be reduced to 2500ms without problem since its timer will strictly be started after the XHR timeout timer and the XHR test timeouts of 2000ms will then strictly happen before the timeout could happen. It's not clear this would be sufficient to compensate for all jank problems, but could likely make the problem more rare. We'd want to scale with the timeout multiplier if we wanted more resiliency but wanted to be using realistic-looking timers.

(In reply to Andrew Sutherland [:asuth] (he/him) from comment #16)

Since this only happens on debug builds, it seems quite plausible that the timing is too tight to account for machine jank. The SJS timeout of 3000ms could likely be reduced to 2500ms without problem ...

Sounds like a plan. Thank you for the investigation.

Priority: P5 → P3
Whiteboard: [necko-triaged]
Assignee: nobody → smayya
Pushed by smayya@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/3ff69f28c340
decrease timeout from 3000 to 2500 for test_worker_xhr_timeout.html. r=necko-reviewers,valentin
Status: NEW → RESOLVED
Closed: 5 months ago
Resolution: --- → FIXED
Target Milestone: --- → 122 Branch
Regressions: 1868894
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: