Closed Bug 1838145 Opened 2 years ago Closed 2 months ago

Intermittent Wd | <random> - webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted [fetch request failed]

Categories

(Remote Protocol :: WebDriver BiDi, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

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


[task 2023-06-13T06:15:42.339Z] 06:15:42     INFO - TEST-PASS | /webdriver/tests/bidi/network/response_completed/response_completed.py | test_load_page_twice 
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/bidi/network/response_completed/response_completed.py | test_response_status[101-Switching Protocols] - webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted.
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x0000021637D58340>
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x0000021637D63D30>
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - url = <function url.<locals>.url at 0x0000021637E011F0>
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - fetch = <function fetch.<locals>.fetch at 0x0000021637D63F70>
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - setup_network_test = <function setup_network_test.<locals>._setup_network_test at 0x0000021637E01790>
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - status = 101, status_text = 'Switching Protocols'
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -     @pytest.mark.parametrize(
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -         "status, status_text",
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -         HTTP_STATUS_AND_STATUS_TEXT,
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -     )
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -     @pytest.mark.asyncio
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -     async def test_response_status(
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -         bidi_session, wait_for_event, url, fetch, setup_network_test, status, status_text
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -     ):
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -         status_url = url(
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -             f"/webdriver/tests/support/http_handlers/status.py?status={status}&nocache={RESPONSE_COMPLETED_EVENT}"
[task 2023-06-13T06:15:42.346Z] 06:15:42     INFO -         )
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO -     
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO -         network_events = await setup_network_test(events=[RESPONSE_COMPLETED_EVENT])
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO -         events = network_events[RESPONSE_COMPLETED_EVENT]
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO -     
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO -         on_response_completed = wait_for_event(RESPONSE_COMPLETED_EVENT)
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO - >       await fetch(status_url)
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO - bidi_session = <webdriver.bidi.client.BidiSession object at 0x0000021637D58340>
[task 2023-06-13T06:15:42.347Z] 06:15:42     INFO - events     = []
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - fetch      = <function fetch.<locals>.fetch at 0x0000021637D63F70>
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - network_events = {'network.responseCompleted': []}
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - on_response_completed = <Future pending>
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - setup_network_test = <function setup_network_test.<locals>._setup_network_test at 0x0000021637E01790>
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - status     = 101
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - status_text = 'Switching Protocols'
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - status_url = 'http://web-platform.test:8000/webdriver/tests/support/http_handlers/status.py?status=101&nocache=network.responseCompleted'
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - url        = <function url.<locals>.url at 0x0000021637E011F0>
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - wait_for_event = <function wait_for_event.<locals>.wait_for_event at 0x0000021637D63D30>
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - tests\web-platform\tests\webdriver\tests\bidi\network\response_completed\response_completed.py:144: 
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO - tests\web-platform\tests\webdriver\tests\bidi\network\conftest.py:30: in fetch
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -     await bidi_session.script.evaluate(
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -         bidi_session = <webdriver.bidi.client.BidiSession object at 0x0000021637D58340>
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -         configuration = {'browser': {'args': ['--profile',
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -                       'C:\\Users\\task_168663216796581\\AppData\\Local\\Temp\\tmpn9bhwnxd.mozrunner'],
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -              'binary': 'Z:\\task_168663216796581\\build\\application\\firefox\\firefox.exe'},
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -  'capabilities': {'moz:firefoxOptions': {'args': ['--profile',
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -                                                   'C:\\Users\\task_168663216796581\\AppData\\Local\\Temp\\tmpn9bhwnxd.mozrunner']}},
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -  'host': '127.0.0.1',
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -  'port': 49745,
[task 2023-06-13T06:15:42.348Z] 06:15:42     INFO -  'timeout_multiplier': 1,
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -  'webdriver': {'args': ['-vv',
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -                         '--binary',
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -                         'Z:\\task_168663216796581\\build\\application\\firefox\\firefox.exe'],
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -                'binary': 'Z:\\task_168663216796581\\fetches\\geckodriver.exe'}}
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         context    = {'children': [],
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -  'context': '0073754f-11d1-4265-a22b-c93fd60d87d4',
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -  'parent': None,
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -  'url': 'http://web-platform.test:8000/webdriver/tests/bidi/network/support/empty.html'}
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         headers    = None
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         headers_arg = ''
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         method     = 'GET'
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         method_arg = "method: 'GET',"
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         timeout_in_seconds = 3
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         url        = 'http://web-platform.test:8000/webdriver/tests/support/http_handlers/status.py?status=101&nocache=network.responseCompleted'
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO - tests\web-platform\tests\tools\webdriver\webdriver\bidi\modules\_module.py:76: in inner
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -     result = result_fn(self, result)
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         cmd_name   = 'script.evaluate'
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         future     = <Future finished result={'exceptionDetails': {'columnNumber': 22, 'exception': {'type': 'error'}, 'lineNumber': 8, 'stackTrace': {'callFrames': [{'columnNumber': 22, 'functionName': '', 'lineNumber': 8, 'url': 'http://web-p...rt/empty.html'}]}, ...}, 'realm': '7e7b8061-e0d...-e8054baba8ed', 'type': 'exception'}>
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -         kwargs     = {'await_promise': True,
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -  'expression': '\n'
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -                '                 {\n'
[task 2023-06-13T06:15:42.349Z] 06:15:42     INFO -                '                   const controller = new AbortController();\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                   setTimeout(() => controller.abort(), '
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '3000);\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                   '
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                'fetch("http://web-platform.test:8000/webdriver/tests/support/http_handlers/status.py?status=101&nocache=network.responseCompleted", '
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '{\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                "                     method: 'GET',\n"
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                     \n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                     signal: controller.signal\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                   }).then(response => response.text());\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                 }',
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -  'target': {'context': '0073754f-11d1-4265-a22b-c93fd60d87d4'}}
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -         mod_name   = 'script'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -         name       = 'evaluate'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -         owner      = <class 'webdriver.bidi.modules.script.Script'>
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -         params     = {'awaitPromise': True,
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -  'expression': '\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                 {\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                   const controller = new AbortController();\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                   setTimeout(() => controller.abort(), '
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '3000);\n'
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                '                   '
[task 2023-06-13T06:15:42.350Z] 06:15:42     INFO -                'fetch("http://web-platform.test:8000/webdriver/tests/support/http_handlers/status.py?status=101&nocache=network.responseCompleted", '
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                '{\n'
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                "                     method: 'GET',\n"
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                '                     \n'
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                '                     signal: controller.signal\n'
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                '                   }).then(response => response.text());\n'
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                '                 }',
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -  'target': {'context': '0073754f-11d1-4265-a22b-c93fd60d87d4'}}
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -         params_fn  = <function Script.evaluate at 0x0000021637C361F0>
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -         raw_result = False
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -         result     = {'exceptionDetails': {'columnNumber': 22,
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                       'exception': {'type': 'error'},
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                       'lineNumber': 8,
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                       'stackTrace': {'callFrames': [{'columnNumber': 22,
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                                                      'functionName': '',
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                                                      'lineNumber': 8,
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                                                      'url': 'http://web-platform.test:8000/webdriver/tests/bidi/network/support/empty.html'}]},
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -                       'text': 'AbortError: The operation was aborted. '},
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -  'realm': '7e7b8061-e0d2-4dd8-9cd4-e8054baba8ed',
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -  'type': 'exception'}
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -         result_fn  = <function Script._evaluate at 0x0000021637C36280>
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO -         self       = <webdriver.bidi.modules.script.Script object at 0x0000021637D589A0>
[task 2023-06-13T06:15:42.351Z] 06:15:42     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO - self = <webdriver.bidi.modules.script.Script object at 0x0000021637D589A0>
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO - result = {'exceptionDetails': {'columnNumber': 22, 'exception': {'type': 'error'}, 'lineNumber': 8, 'stackTrace': {'callFrames'.../tests/bidi/network/support/empty.html'}]}, ...}, 'realm': '7e7b8061-e0d2-4dd8-9cd4-e8054baba8ed', 'type': 'exception'}
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -     @evaluate.result
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -     def _evaluate(self, result: Mapping[str, Any]) -> Any:
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -         assert "type" in result
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -     
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -         if result["type"] == "success":
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -             return result["result"]
[task 2023-06-13T06:15:42.352Z] 06:15:42     INFO -         elif result["type"] == "exception":
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - >           raise ScriptEvaluateResultException(result)
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - E           webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted. 
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - E           
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - E           Stacktrace:
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - E           
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - E           eval code@http://web-platform.test:8000/webdriver/tests/bidi/network/support/empty.html:8:22
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - result     = {'exceptionDetails': {'columnNumber': 22,
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                       'exception': {'type': 'error'},
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                       'lineNumber': 8,
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                       'stackTrace': {'callFrames': [{'columnNumber': 22,
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                                                      'functionName': '',
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                                                      'lineNumber': 8,
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                                                      'url': 'http://web-platform.test:8000/webdriver/tests/bidi/network/support/empty.html'}]},
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -                       'text': 'AbortError: The operation was aborted. '},
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -  'realm': '7e7b8061-e0d2-4dd8-9cd4-e8054baba8ed',
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO -  'type': 'exception'}
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - self       = <webdriver.bidi.modules.script.Script object at 0x0000021637D589A0>
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - 
[task 2023-06-13T06:15:42.353Z] 06:15:42     INFO - tests\web-platform\tests\tools\webdriver\webdriver\bidi\modules\script.py:189: ScriptEvaluateResultException
[task 2023-06-13T06:15:42.354Z] 06:15:42     INFO - PID 9788 | 1686636940715	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de <- {"id":227,"result":{}}
[task 2023-06-13T06:15:42.355Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.355Z] 06:15:42     INFO - PID 9788 | 1686636940715	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de -> {"id":228,"method":"session.subscribe","params":{"events":["network.responseCompleted"]}}
[task 2023-06-13T06:15:42.356Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.356Z] 06:15:42     INFO - PID 9788 | 1686636940715	RemoteAgent	TRACE	Module root/session.jsm found for ROOT
[task 2023-06-13T06:15:42.357Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.357Z] 06:15:42     INFO - PID 9788 | 1686636940715	RemoteAgent	TRACE	Received command session.subscribe for destination ROOT
[task 2023-06-13T06:15:42.358Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.358Z] 06:15:42     INFO - PID 9788 | 1686636940715	RemoteAgent	TRACE	Module root/session.jsm found for ROOT
[task 2023-06-13T06:15:42.359Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.360Z] 06:15:42     INFO - PID 9788 | 1686636940716	RemoteAgent	TRACE	Module root/network.jsm found for ROOT
[task 2023-06-13T06:15:42.360Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.360Z] 06:15:42     INFO - PID 9788 | 1686636940717	RemoteAgent	TRACE	Module windowglobal-in-root/network.jsm not found for WINDOW_GLOBAL
[task 2023-06-13T06:15:42.362Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.362Z] 06:15:42     INFO - PID 9788 | 1686636940717	RemoteAgent	TRACE	Module windowglobal/network.jsm not found for WINDOW_GLOBAL
[task 2023-06-13T06:15:42.363Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.364Z] 06:15:42     INFO - PID 9788 | 1686636940717	RemoteAgent	TRACE	Module root/network.jsm found for ROOT
[task 2023-06-13T06:15:42.364Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.365Z] 06:15:42     INFO - PID 9788 | 1686636940717	RemoteAgent	TRACE	Received command network._applySessionData for destination ROOT
[task 2023-06-13T06:15:42.365Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.366Z] 06:15:42     INFO - PID 9788 | 1686636940717	RemoteAgent	TRACE	Module root/network.jsm found for ROOT
[task 2023-06-13T06:15:42.366Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.366Z] 06:15:42     INFO - PID 9788 | 1686636940717	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de <- {"id":228,"result":{}}
[task 2023-06-13T06:15:42.368Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.368Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de -> {"id":229,"method":"script.evaluate","params":{"expression":"\n                 {\n                   const controller = new AbortController();\n                   setTimeout(() => controll ...   \n                     signal: controller.signal\n                   }).then(response => response.text());\n                 }","target":{"context":"0073754f-11d1-4265-a22b-c93fd60d87d4"},"awaitPromise":true}}
[task 2023-06-13T06:15:42.370Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.370Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	TRACE	Module root/script.jsm found for ROOT
[task 2023-06-13T06:15:42.371Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.371Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	TRACE	Received command script.evaluate for destination ROOT
[task 2023-06-13T06:15:42.372Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.372Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	TRACE	Module root/script.jsm found for ROOT
[task 2023-06-13T06:15:42.373Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.374Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	TRACE	Received command script.evaluateExpression for destination WINDOW_GLOBAL
[task 2023-06-13T06:15:42.374Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.375Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	TRACE	Module windowglobal/script.jsm found for WINDOW_GLOBAL
[task 2023-06-13T06:15:42.376Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.376Z] 06:15:42     INFO - PID 9788 | 1686636940719	RemoteAgent	TRACE	Module windowglobal/script.jsm found for WINDOW_GLOBAL
[task 2023-06-13T06:15:42.377Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.377Z] 06:15:42     INFO - PID 9788 | 1686636940726	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de <- {"id":229,"result":{"realm":"17ee6844-1f03-4d38-8612-2f4b17361c5c","type":"success","result":{"type":"string","value":"HTTP Response Status"}}}
[task 2023-06-13T06:15:42.380Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.380Z] 06:15:42     INFO - PID 9788 | 1686636940727	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de <- {"method":"network.responseCompleted","params":{"context":"0073754f-11d1-4265-a22b-c93fd60d87d4","navigation":null,"redirectCount":0,"request":{"bodySize":null,"cookies":[],"headers":[{"name":"Host","value":"web-platform.test:8000"},{"name":"User-Agent","value":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/116.0"},{"name":"Accept","value":"*/*"},{"name":"Accept-Language","value":"en-US,en;q=0.5"},{"name":"Accept-Encoding","value":"gzip, deflate"},{"name":"Referer","value":"http://web-platform.test:8000/webdriver/tests/bidi/network/support/empty.html"},{"name":"Connection","value":"keep-alive"}],"headersSize":424,"method":"GET","request":"77","timings":{"timeOrigin":0,"requestTime":1686636940720000,"redirectStart":0,"redirectEnd":0,"fetchStart":1686636940720553,"dnsStart":1686636940720553,"dnsEnd":1686636940721099,"connectStart":1686636940721651,"connectEnd":1686636940721878,"tlsStart":0,"tlsEnd":1686636940721878,"requestStart":1686636940721962,"responseStart":1686636940723421,"responseEnd":1686636940723688},"url":"http://web-platform.test:8000/webdriver/tests/support/http_handlers/status.py?status=501&nocache=network.responseCompleted"},"timestamp":1686636940727,"response":{"bodySize":20,"content":{"size":20},"headersSize":151,"url":"http://web-platform.test:8000/webdriver/tests/support/http_handlers/status.py?status=501&nocache=network.responseCompleted","bytesReceived":171,"fromCache":false,"headers":[{"name":"Content-Type","value":"text/plain"},{"name":"Server","value":"BaseHTTP/0.6 Python/3.9.10"},{"name":"Date","value":"Tue, 13 Jun 2023 06:15:40 GMT"},{"name":"Content-Length","value":"20"}],"mimeType":"text/plain","protocol":"http/1.1","status":501,"statusText":"Not Implemented"}}}
[task 2023-06-13T06:15:42.381Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.382Z] 06:15:42     INFO - PID 9788 | 1686636940729	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de -> {"id":230,"method":"session.unsubscribe","params":{"events":["network.responseCompleted"]}}
[task 2023-06-13T06:15:42.383Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.383Z] 06:15:42     INFO - PID 9788 | 1686636940729	RemoteAgent	TRACE	Module root/session.jsm found for ROOT
[task 2023-06-13T06:15:42.384Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.384Z] 06:15:42     INFO - PID 9788 | 1686636940729	RemoteAgent	TRACE	Received command session.unsubscribe for destination ROOT
[task 2023-06-13T06:15:42.385Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.385Z] 06:15:42     INFO - PID 9788 | 1686636940729	RemoteAgent	TRACE	Module root/session.jsm found for ROOT
[task 2023-06-13T06:15:42.386Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.386Z] 06:15:42     INFO - PID 9788 | 1686636940729	RemoteAgent	TRACE	Module root/network.jsm found for ROOT
[task 2023-06-13T06:15:42.387Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.387Z] 06:15:42     INFO - PID 9788 | 1686636940731	RemoteAgent	TRACE	Module windowglobal-in-root/network.jsm not found for WINDOW_GLOBAL
[task 2023-06-13T06:15:42.388Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.388Z] 06:15:42     INFO - PID 9788 | 1686636940731	RemoteAgent	TRACE	Module windowglobal/network.jsm not found for WINDOW_GLOBAL
[task 2023-06-13T06:15:42.390Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.390Z] 06:15:42     INFO - PID 9788 | 1686636940731	RemoteAgent	TRACE	Module root/network.jsm found for ROOT
[task 2023-06-13T06:15:42.391Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.391Z] 06:15:42     INFO - PID 9788 | 1686636940731	RemoteAgent	TRACE	Received command network._applySessionData for destination ROOT
[task 2023-06-13T06:15:42.392Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.392Z] 06:15:42     INFO - PID 9788 | 1686636940731	RemoteAgent	TRACE	Module root/network.jsm found for ROOT
[task 2023-06-13T06:15:42.393Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.393Z] 06:15:42     INFO - PID 9788 | 1686636940731	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de <- {"id":230,"result":{}}
[task 2023-06-13T06:15:42.394Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.395Z] 06:15:42     INFO - PID 9788 | 1686636940733	RemoteAgent	DEBUG	WebDriverBiDiConnection bba797f6-a971-4f66-b277-a2ce173531de closed
[task 2023-06-13T06:15:42.395Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.395Z] 06:15:42     INFO - PID 9788 | 1686636940734	webdriver::server	DEBUG	-> POST /session/b23d4c8d-ad61-458c-82dd-05e14161d9d4/timeouts {"implicit": 0}
[task 2023-06-13T06:15:42.397Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.397Z] 06:15:42     INFO - PID 9788 | 1686636940734	Marionette	DEBUG	0 -> [0,516,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-06-13T06:15:42.398Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.398Z] 06:15:42     INFO - PID 9788 | 1686636940734	Marionette	DEBUG	0 <- [1,516,null,{"value":null}]
[task 2023-06-13T06:15:42.399Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.400Z] 06:15:42     INFO - PID 9788 | 1686636940734	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-06-13T06:15:42.401Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.401Z] 06:15:42     INFO - PID 9788 | 1686636940735	webdriver::server	DEBUG	-> POST /session/b23d4c8d-ad61-458c-82dd-05e14161d9d4/timeouts {"pageLoad": 300000}
[task 2023-06-13T06:15:42.402Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.402Z] 06:15:42     INFO - PID 9788 | 1686636940736	Marionette	DEBUG	0 -> [0,517,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-06-13T06:15:42.403Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.403Z] 06:15:42     INFO - PID 9788 | 1686636940736	Marionette	DEBUG	0 <- [1,517,null,{"value":null}]
[task 2023-06-13T06:15:42.404Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.404Z] 06:15:42     INFO - PID 9788 | 1686636940736	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2023-06-13T06:15:42.406Z] 06:15:42     INFO - .
[task 2023-06-13T06:15:42.406Z] 06:15:42     INFO - PID 9788 | 1686636940737	webdriver::server	DEBUG	-> POST /session/b23d4c8d-ad61-458c-82dd-05e14161d9d4/timeouts {"script": 30000}
[task 2023-06-13T06:15:42.407Z] 06:15:42     INFO - PID 9788 | 1686636940738	Marionette	DEBUG	0 -> [0,518,"WebDriver:SetTimeouts",{"script":30000}]

Here the fetch request failed after 3s to load a page as served by wptserve. Maybe related to bug 1832294.

See Also: → 1832294

A fix for bug 1837949 might help here.

Depends on: 1837949
See Also: → 1832294
Summary: Intermittent /webdriver/tests/bidi/network/response_completed/response_completed.py | test_response_status[101-Switching Protocols] - webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted. → Intermittent /webdriver/tests/bidi/network/response_completed/response_completed.py | test_response_status[101-Switching Protocols] - webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted [fetch request failed]
See Also: → 1849207

This affects multiple tests. As such lets make it a general bug.

Summary: Intermittent /webdriver/tests/bidi/network/response_completed/response_completed.py | test_response_status[101-Switching Protocols] - webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted [fetch request failed] → Intermittent Wd | <random> - webdriver.bidi.modules.script.ScriptEvaluateResultException: AbortError: The operation was aborted [fetch request failed]
Duplicate of this bug: 1849207

I wonder if that is related to the other navigation issues that we have and timing out (bug 1825501). Maybe some kind of overlapping navigation or network issue.

See Also: → 1825501
Duplicate of this bug: 1866185
Status: NEW → RESOLVED
Closed: 4 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 months ago2 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.