Intermittent [tier 2] /webdriver/tests/bidi/browsing_context/load/load.py | test_iframe - asyncio.exceptions.CancelledError
Categories
(Remote Protocol :: WebDriver BiDi, defect, P1)
Tracking
(firefox107 fixed)
Tracking | Status | |
---|---|---|
firefox107 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: whimboo)
References
Details
(Keywords: intermittent-failure, Whiteboard: [webdriver:m5], [wptsync upstream])
Attachments
(1 file)
Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=392522430&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/LvOv4hmfSO2pLuGsHu_tVA/runs/0/artifacts/public/logs/live_backing.log
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - TEST-PASS | /webdriver/tests/bidi/browsing_context/load/load.py | test_subscribe
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/browsing_context/load/load.py | test_iframe - asyncio.exceptions.CancelledError
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - async def poll():
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - result = None
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - while True:
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - next = self.clock.time() + self.interval
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - try:
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - result = condition(self.session)
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - except self.exceptions:
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - _, _, traceback = sys.exc_info()
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - # re-adjust the interval depending on how long
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - # the callback took to evaluate the condition
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - interval_new = max(next - self.clock.time(), 0)
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.417Z] 00:14:10 INFO - if result:
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - return result
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - > await asyncio.sleep(interval_new)
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - condition = <function test_iframe.<locals>.<lambda> at 0x00000208AEB47B80>
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - interval_new = 0.10000000000002274
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - next = 563.3340000000001
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - result = False
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - self = <tests.support.sync.AsyncPoll object at 0x00000208AEB54370>
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO -
[task 2022-10-07T00:14:10.418Z] 00:14:10 INFO - tests\web-platform\tests\webdriver\tests\support\sync.py:263:
Assignee | ||
Comment 1•2 years ago
|
||
So this comes from the usage of AsyncPoll
in waiting for the browsingContext.load
event to be received. As it can be seen it took 5s until the browsing context actually got created, and that is the default timeout for the AsyncPoll.until()
call:
https://treeherder.mozilla.org/logviewer?job_id=392522430&repo=autoland&lineNumber=7787-7794
The problem is actually in these lines:
Because of the timeout the method runs into asyncio.wait_for()
raises an asyncio.TimeoutError
but at the same time also cancels the task. That is what we do not catch here or handle correctly. We might want to catch this exception as well or canceling the task ourselves by passing a shielded coroutine into asyncio.wait_for()
.
Assignee | ||
Comment 2•2 years ago
|
||
Our AsyncPoll
implementation is actually kinda busted. I'll have a patch shortly which fixes it and doesn't require us to use asyncio.wait_for()
.
Assignee | ||
Comment 3•2 years ago
|
||
The internal async poll helper should raise the timeout error
on its own. This doesn't require us to use asyncio.wait_for
which itself would force a cancellation which would fail anyway
due to the infinite while loop.
Assignee | ||
Updated•2 years ago
|
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/72d94d7acaa6 [wdspec] Fix internal polling mechanism for AsyncPoll. r=webdriver-reviewers,jgraham
Created web-platform-tests PR https://github.com/web-platform-tests/wpt/pull/36329 for changes under testing/web-platform/tests
Comment 6•2 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Upstream PR merged by jgraham
Description
•