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}]
Description
•