Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/execute_script/cyclic.py | expected OK
Categories
(Remote Protocol :: Marionette, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure)
Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=338578561&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Aw5Ou_6pTCuarb94YD-iJA/runs/0/artifacts/public/logs/live_backing.log
[task 2021-05-03T20:33:59.546Z] 20:33:59 INFO - TEST-OK | /webdriver/tests/execute_script/collections.py | took 9818ms
[task 2021-05-03T20:33:59.548Z] 20:33:59 INFO - TEST-START | /webdriver/tests/execute_script/cyclic.py
[task 2021-05-03T20:33:59.641Z] 20:33:59 INFO - STDOUT: ============================= test session starts =============================
[task 2021-05-03T20:33:59.642Z] 20:33:59 INFO - STDOUT: platform win32 -- Python 3.7.3, pytest-6.1.1, py-1.5.2, pluggy-unknown -- c:\mozilla-build\python3\python.exe
[task 2021-05-03T20:33:59.644Z] 20:33:59 INFO - STDOUT: rootdir: Z:\task_1620073059\build
[task 2021-05-03T20:33:59.645Z] 20:33:59 INFO - STDOUT: plugins: asyncio-0.14.0
[task 2021-05-03T20:33:59.646Z] 20:33:59 INFO - STDOUT: collecting ...
[task 2021-05-03T20:33:59.660Z] 20:33:59 INFO - STDOUT: collected 6 items
[task 2021-05-03T20:33:59.661Z] 20:33:59 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/execute_script/cyclic.py::test_array
[task 2021-05-03T20:33:59.663Z] 20:33:59 INFO - PID 2584 | 1620074039661 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:01.127Z] 20:34:01 INFO - PID 2584 | 1620074041122 Marionette DEBUG 0 -> [0,156,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:01.128Z] 20:34:01 INFO - PID 2584 | 1620074041122 Marionette DEBUG 0 <- [1,156,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:01.129Z] 20:34:01 INFO - PID 2584 | 1620074041125 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:01.130Z] 20:34:01 INFO - PID 2584 | 1620074041127 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"x": 100, "y": 100}
[task 2021-05-03T20:34:06.534Z] 20:34:06 INFO - PID 2584 | 1620074046527 Marionette DEBUG 0 -> [0,157,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2021-05-03T20:34:06.535Z] 20:34:06 INFO - PID 2584 | 1620074046527 Marionette DEBUG 0 <- [1,157,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:06.537Z] 20:34:06 INFO - PID 2584 | 1620074046533 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:06.538Z] 20:34:06 INFO - PID 2584 | 1620074046535 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/execute/sync {"script": "\n let arr = [];\n arr.push(arr);\n return arr;\n ", "args": []}
[task 2021-05-03T20:34:06.539Z] 20:34:06 INFO - PID 2584 | 1620074046532 Marionette DEBUG 0 -> [0,158,"WebDriver:ExecuteScript",{"args":[],"script":"\n let arr = [];\n arr.push(arr);\n return arr;\n "}]
[task 2021-05-03T20:34:06.542Z] 20:34:06 INFO - STDOUT: PASSED
[task 2021-05-03T20:34:06.543Z] 20:34:06 INFO - PID 2584 | 1620074046535 Marionette DEBUG 0 <- [1,158,{"error":"javascript error","message":"Cyclic object value","stacktrace":"WebDriverError@chrome://marionette/content/e ... te/content/evaluate.js:301:12\nreceiveMessage@chrome://marionette/content/actors/MarionetteCommandsChild.jsm:155:31\n"},null]
[task 2021-05-03T20:34:06.545Z] 20:34:06 INFO - PID 2584 | 1620074046540 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"javascript error","message":"Cyclic object value","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nJavaScriptError@chrome://marionette/content/error.js:360:5\nassert.acyclic@chrome://marionette/content/assert.js:47:11\nevaluate.toJSON@chrome://marionette/content/evaluate.js:301:12\nreceiveMessage@chrome://marionette/content/actors/MarionetteCommandsChild.jsm:155:31\n"}}
[task 2021-05-03T20:34:06.547Z] 20:34:06 INFO - PID 2584 | 1620074046541 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"implicit": 0}
[task 2021-05-03T20:34:06.548Z] 20:34:06 INFO - PID 2584 | 1620074046537 Marionette DEBUG 0 -> [0,159,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-05-03T20:34:06.549Z] 20:34:06 INFO - PID 2584 | 1620074046537 Marionette DEBUG 0 <- [1,159,null,{"value":null}]
[task 2021-05-03T20:34:06.550Z] 20:34:06 INFO - PID 2584 | 1620074046542 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:06.551Z] 20:34:06 INFO - PID 2584 | 1620074046544 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"pageLoad": 300000}
[task 2021-05-03T20:34:06.552Z] 20:34:06 INFO - PID 2584 | 1620074046539 Marionette DEBUG 0 -> [0,160,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-05-03T20:34:06.554Z] 20:34:06 INFO - PID 2584 | 1620074046540 Marionette DEBUG 0 <- [1,160,null,{"value":null}]
[task 2021-05-03T20:34:06.555Z] 20:34:06 INFO - PID 2584 | 1620074046544 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:06.556Z] 20:34:06 INFO - PID 2584 | 1620074046546 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"script": 30000}
[task 2021-05-03T20:34:06.558Z] 20:34:06 INFO - PID 2584 | 1620074046542 Marionette DEBUG 0 -> [0,161,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-05-03T20:34:06.559Z] 20:34:06 INFO - PID 2584 | 1620074046542 Marionette DEBUG 0 <- [1,161,null,{"value":null}]
[task 2021-05-03T20:34:06.560Z] 20:34:06 INFO - PID 2584 | 1620074046547 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:06.561Z] 20:34:06 INFO - PID 2584 | 1620074046548 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:06.562Z] 20:34:06 INFO - PID 2584 | 1620074046544 Marionette DEBUG 0 -> [0,162,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:06.563Z] 20:34:06 INFO - PID 2584 | 1620074046544 Marionette DEBUG 0 <- [1,162,null,{"value":"19"}]
[task 2021-05-03T20:34:06.565Z] 20:34:06 INFO - PID 2584 | 1620074046549 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:06.566Z] 20:34:06 INFO - PID 2584 | 1620074046550 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:06.567Z] 20:34:06 INFO - PID 2584 | 1620074046545 Marionette DEBUG 0 -> [0,163,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:06.569Z] 20:34:06 INFO - PID 2584 | 1620074046546 Marionette DEBUG 0 <- [1,163,null,{"value":"19"}]
[task 2021-05-03T20:34:06.570Z] 20:34:06 INFO - PID 2584 | 1620074046550 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:06.571Z] 20:34:06 INFO - PID 2584 | 1620074046552 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/handles
[task 2021-05-03T20:34:06.572Z] 20:34:06 INFO - PID 2584 | 1620074046547 Marionette DEBUG 0 -> [0,164,"WebDriver:GetWindowHandles",{}]
[task 2021-05-03T20:34:06.573Z] 20:34:06 INFO - PID 2584 | 1620074046548 Marionette DEBUG 0 <- [1,164,null,["19"]]
[task 2021-05-03T20:34:06.574Z] 20:34:06 INFO - PID 2584 | 1620074046552 webdriver::server DEBUG <- 200 OK {"value":["19"]}
[task 2021-05-03T20:34:06.576Z] 20:34:06 INFO - PID 2584 | 1620074046554 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:06.577Z] 20:34:06 INFO - PID 2584 | 1620074046550 Marionette DEBUG 0 -> [0,165,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:06.578Z] 20:34:06 INFO - PID 2584 | 1620074046550 Marionette DEBUG 0 <- [1,165,null,{"value":null}]
[task 2021-05-03T20:34:06.579Z] 20:34:06 INFO - PID 2584 | 1620074046555 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:06.581Z] 20:34:06 INFO - PID 2584 | 1620074046556 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/alert/dismiss {}
[task 2021-05-03T20:34:06.582Z] 20:34:06 INFO - PID 2584 | 1620074046552 Marionette DEBUG 0 -> [0,166,"WebDriver:DismissAlert",{}]
[task 2021-05-03T20:34:06.584Z] 20:34:06 INFO - PID 2584 | 1620074046552 Marionette DEBUG 0 <- [1,166,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchA ... t@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"},null]
[task 2021-05-03T20:34:06.586Z] 20:34:06 INFO - PID 2584 | 1620074046557 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchAlertError@chrome://marionette/content/error.js:382:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:2722:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:2625:8\ndespatch@chrome://marionette/content/server.js:291:40\nexecute@chrome://marionette/content/server.js:264:16\nonPacket/<@chrome://marionette/content/server.js:237:20\nonPacket@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"}}
[task 2021-05-03T20:34:06.587Z] 20:34:06 INFO - PID 2584 | 1620074046558 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:06.589Z] 20:34:06 INFO - PID 2584 | 1620074046554 Marionette DEBUG 0 -> [0,167,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:06.590Z] 20:34:06 INFO - PID 2584 | 1620074046554 Marionette DEBUG 0 <- [1,167,null,{"value":null}]
[task 2021-05-03T20:34:06.591Z] 20:34:06 INFO - PID 2584 | 1620074046559 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:06.592Z] 20:34:06 INFO - PID 2584 | 1620074046560 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:06.594Z] 20:34:06 INFO - PID 2584 | 1620074046556 Marionette DEBUG 0 -> [0,168,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:06.595Z] 20:34:06 INFO - PID 2584 | 1620074046556 Marionette DEBUG 0 <- [1,168,null,{"value":"19"}]
[task 2021-05-03T20:34:06.596Z] 20:34:06 INFO - PID 2584 | 1620074046561 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:06.597Z] 20:34:06 INFO - PID 2584 | 1620074046562 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/handles
[task 2021-05-03T20:34:06.598Z] 20:34:06 INFO - PID 2584 | 1620074046558 Marionette DEBUG 0 -> [0,169,"WebDriver:GetWindowHandles",{}]
[task 2021-05-03T20:34:06.600Z] 20:34:06 INFO - PID 2584 | 1620074046558 Marionette DEBUG 0 <- [1,169,null,["19"]]
[task 2021-05-03T20:34:06.601Z] 20:34:06 INFO - PID 2584 | 1620074046563 webdriver::server DEBUG <- 200 OK {"value":["19"]}
[task 2021-05-03T20:34:06.602Z] 20:34:06 INFO - PID 2584 | 1620074046564 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:12.352Z] 20:34:12 INFO - PID 2584 | 1620074052343 Marionette DEBUG 0 -> [0,170,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:12.353Z] 20:34:12 INFO - PID 2584 | 1620074052343 Marionette DEBUG 0 <- [1,170,null,{"value":null}]
[task 2021-05-03T20:34:12.354Z] 20:34:12 INFO - PID 2584 | 1620074052351 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:12.355Z] 20:34:12 INFO - PID 2584 | 1620074052352 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:12.364Z] 20:34:12 INFO - PID 2584 | 1620074052354 Marionette DEBUG 0 -> [0,171,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:12.365Z] 20:34:12 INFO - PID 2584 | 1620074052354 Marionette DEBUG 0 <- [1,171,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:12.365Z] 20:34:12 INFO - PID 2584 | 1620074052361 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:12.366Z] 20:34:12 INFO - PID 2584 | 1620074052362 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/frame {"id": null}
[task 2021-05-03T20:34:12.369Z] 20:34:12 INFO - PID 2584 | 1620074052361 Marionette DEBUG 0 -> [0,172,"WebDriver:SwitchToFrame",{"id":null}]
[task 2021-05-03T20:34:15.975Z] 20:34:15 INFO - PID 2584 | 1620074055966 Marionette DEBUG 0 <- [1,172,null,{"value":null}]
[task 2021-05-03T20:34:15.981Z] 20:34:15 INFO - PID 2584 | 1620074055979 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:15.983Z] 20:34:15 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/execute_script/cyclic.py::test_object
[task 2021-05-03T20:34:15.984Z] 20:34:15 INFO - PID 2584 | 1620074055982 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:21.480Z] 20:34:21 INFO - PID 2584 | 1620074061470 Marionette DEBUG 0 -> [0,173,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:21.482Z] 20:34:21 INFO - PID 2584 | 1620074061470 Marionette DEBUG 0 <- [1,173,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:21.483Z] 20:34:21 INFO - PID 2584 | 1620074061479 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:21.484Z] 20:34:21 INFO - PID 2584 | 1620074061481 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"x": 100, "y": 100}
[task 2021-05-03T20:34:21.485Z] 20:34:21 INFO - PID 2584 | 1620074061473 Marionette DEBUG 0 -> [0,174,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2021-05-03T20:34:21.487Z] 20:34:21 INFO - PID 2584 | 1620074061473 Marionette DEBUG 0 <- [1,174,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:21.488Z] 20:34:21 INFO - PID 2584 | 1620074061482 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:21.489Z] 20:34:21 INFO - PID 2584 | 1620074061484 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/execute/sync {"script": "\n let obj = {};\n obj.reference = obj;\n return obj;\n ", "args": []}
[task 2021-05-03T20:34:21.491Z] 20:34:21 INFO - PID 2584 | 1620074061477 Marionette DEBUG 0 -> [0,175,"WebDriver:ExecuteScript",{"args":[],"script":"\n let obj = {};\n obj.reference = obj;\n return obj;\n "}]
[task 2021-05-03T20:34:21.492Z] 20:34:21 INFO - PID 2584 | 1620074061480 Marionette DEBUG 0 <- [1,175,{"error":"javascript error","message":"Cyclic object value","stacktrace":"WebDriverError@chrome://marionette/content/e ... te/content/evaluate.js:337:12\nreceiveMessage@chrome://marionette/content/actors/MarionetteCommandsChild.jsm:155:31\n"},null]
[task 2021-05-03T20:34:21.493Z] 20:34:21 INFO - STDOUT: PASSED
[task 2021-05-03T20:34:21.495Z] 20:34:21 INFO - PID 2584 | 1620074061489 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"javascript error","message":"Cyclic object value","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nJavaScriptError@chrome://marionette/content/error.js:360:5\nassert.acyclic@chrome://marionette/content/assert.js:47:11\nevaluate.toJSON@chrome://marionette/content/evaluate.js:337:12\nreceiveMessage@chrome://marionette/content/actors/MarionetteCommandsChild.jsm:155:31\n"}}
[task 2021-05-03T20:34:21.496Z] 20:34:21 INFO - PID 2584 | 1620074061492 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"implicit": 0}
[task 2021-05-03T20:34:21.497Z] 20:34:21 INFO - PID 2584 | 1620074061487 Marionette DEBUG 0 -> [0,176,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-05-03T20:34:21.498Z] 20:34:21 INFO - PID 2584 | 1620074061487 Marionette DEBUG 0 <- [1,176,null,{"value":null}]
[task 2021-05-03T20:34:21.499Z] 20:34:21 INFO - PID 2584 | 1620074061496 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:21.501Z] 20:34:21 INFO - PID 2584 | 1620074061498 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"pageLoad": 300000}
[task 2021-05-03T20:34:21.502Z] 20:34:21 INFO - PID 2584 | 1620074061490 Marionette DEBUG 0 -> [0,177,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-05-03T20:34:21.503Z] 20:34:21 INFO - PID 2584 | 1620074061490 Marionette DEBUG 0 <- [1,177,null,{"value":null}]
[task 2021-05-03T20:34:21.505Z] 20:34:21 INFO - PID 2584 | 1620074061499 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:21.506Z] 20:34:21 INFO - PID 2584 | 1620074061500 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"script": 30000}
[task 2021-05-03T20:34:21.507Z] 20:34:21 INFO - PID 2584 | 1620074061492 Marionette DEBUG 0 -> [0,178,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-05-03T20:34:21.508Z] 20:34:21 INFO - PID 2584 | 1620074061492 Marionette DEBUG 0 <- [1,178,null,{"value":null}]
[task 2021-05-03T20:34:21.509Z] 20:34:21 INFO - PID 2584 | 1620074061501 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:21.510Z] 20:34:21 INFO - PID 2584 | 1620074061502 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:21.511Z] 20:34:21 INFO - PID 2584 | DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-05-03T20:34:21.513Z] 20:34:21 INFO - PID 2584 | 1620074061495 Marionette DEBUG 0 -> [0,179,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:21.514Z] 20:34:21 INFO - PID 2584 | 1620074061495 Marionette DEBUG 0 <- [1,179,null,{"value":"19"}]
[task 2021-05-03T20:34:21.515Z] 20:34:21 INFO - PID 2584 | 1620074061505 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:21.516Z] 20:34:21 INFO - PID 2584 | 1620074061506 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:23.946Z] 20:34:23 INFO - PID 2584 | DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-05-03T20:34:23.951Z] 20:34:23 INFO - PID 2584 | 1620074063938 Marionette DEBUG 0 -> [0,180,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:23.953Z] 20:34:23 INFO - PID 2584 | 1620074063939 Marionette DEBUG 0 <- [1,180,null,{"value":"19"}]
[task 2021-05-03T20:34:23.953Z] 20:34:23 INFO - PID 2584 | 1620074063950 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:23.954Z] 20:34:23 INFO - PID 2584 | 1620074063952 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/handles
[task 2021-05-03T20:34:24.767Z] 20:34:24 INFO - PID 2584 | 1620074064755 Marionette DEBUG 0 -> [0,181,"WebDriver:GetWindowHandles",{}]
[task 2021-05-03T20:34:24.768Z] 20:34:24 INFO - PID 2584 | 1620074064755 Marionette DEBUG 0 <- [1,181,null,["19"]]
[task 2021-05-03T20:34:24.769Z] 20:34:24 INFO - PID 2584 | 1620074064766 webdriver::server DEBUG <- 200 OK {"value":["19"]}
[task 2021-05-03T20:34:24.771Z] 20:34:24 INFO - PID 2584 | 1620074064768 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:24.841Z] 20:34:24 INFO - PID 2584 | 1620074064829 Marionette DEBUG 0 -> [0,182,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:24.841Z] 20:34:24 INFO - PID 2584 | 1620074064829 Marionette DEBUG 0 <- [1,182,null,{"value":null}]
[task 2021-05-03T20:34:24.843Z] 20:34:24 INFO - PID 2584 | 1620074064839 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:24.844Z] 20:34:24 INFO - PID 2584 | 1620074064841 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/alert/dismiss {}
[task 2021-05-03T20:34:24.847Z] 20:34:24 INFO - PID 2584 | 1620074064836 Marionette DEBUG 0 -> [0,183,"WebDriver:DismissAlert",{}]
[task 2021-05-03T20:34:24.849Z] 20:34:24 INFO - PID 2584 | 1620074064837 Marionette DEBUG 0 <- [1,183,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchA ... t@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"},null]
[task 2021-05-03T20:34:24.851Z] 20:34:24 INFO - PID 2584 | 1620074064847 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchAlertError@chrome://marionette/content/error.js:382:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:2722:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:2625:8\ndespatch@chrome://marionette/content/server.js:291:40\nexecute@chrome://marionette/content/server.js:264:16\nonPacket/<@chrome://marionette/content/server.js:237:20\nonPacket@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"}}
[task 2021-05-03T20:34:24.852Z] 20:34:24 INFO - PID 2584 | 1620074064848 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:24.854Z] 20:34:24 INFO - PID 2584 | 1620074064839 Marionette DEBUG 0 -> [0,184,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:24.855Z] 20:34:24 INFO - PID 2584 | 1620074064839 Marionette DEBUG 0 <- [1,184,null,{"value":null}]
[task 2021-05-03T20:34:24.856Z] 20:34:24 INFO - PID 2584 | 1620074064849 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:24.857Z] 20:34:24 INFO - PID 2584 | 1620074064851 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:24.863Z] 20:34:24 INFO - PID 2584 | 1620074064852 Marionette DEBUG 0 -> [0,185,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:24.865Z] 20:34:24 INFO - PID 2584 | 1620074064852 Marionette DEBUG 0 <- [1,185,null,{"value":"19"}]
[task 2021-05-03T20:34:24.866Z] 20:34:24 INFO - PID 2584 | 1620074064862 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:24.867Z] 20:34:24 INFO - PID 2584 | 1620074064864 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/handles
[task 2021-05-03T20:34:24.874Z] 20:34:24 INFO - PID 2584 | 1620074064862 Marionette DEBUG 0 -> [0,186,"WebDriver:GetWindowHandles",{}]
[task 2021-05-03T20:34:24.875Z] 20:34:24 INFO - PID 2584 | 1620074064863 Marionette DEBUG 0 <- [1,186,null,["19"]]
[task 2021-05-03T20:34:24.876Z] 20:34:24 INFO - PID 2584 | 1620074064873 webdriver::server DEBUG <- 200 OK {"value":["19"]}
[task 2021-05-03T20:34:24.877Z] 20:34:24 INFO - PID 2584 | 1620074064873 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:24.883Z] 20:34:24 INFO - PID 2584 | 1620074064871 Marionette DEBUG 0 -> [0,187,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:24.883Z] 20:34:24 INFO - PID 2584 | 1620074064872 Marionette DEBUG 0 <- [1,187,null,{"value":null}]
[task 2021-05-03T20:34:24.885Z] 20:34:24 INFO - PID 2584 | 1620074064881 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:24.886Z] 20:34:24 INFO - PID 2584 | 1620074064883 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:24.888Z] 20:34:24 INFO - PID 2584 | 1620074064877 Marionette DEBUG 0 -> [0,188,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:24.889Z] 20:34:24 INFO - PID 2584 | 1620074064877 Marionette DEBUG 0 <- [1,188,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:24.891Z] 20:34:24 INFO - PID 2584 | 1620074064887 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:24.892Z] 20:34:24 INFO - PID 2584 | 1620074064888 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/frame {"id": null}
[task 2021-05-03T20:34:26.704Z] 20:34:26 INFO - PID 2584 | 1620074066691 Marionette DEBUG 0 -> [0,189,"WebDriver:SwitchToFrame",{"id":null}]
[task 2021-05-03T20:34:27.570Z] 20:34:27 INFO - PID 2584 | 1620074067558 Marionette DEBUG 0 <- [1,189,null,{"value":null}]
[task 2021-05-03T20:34:27.574Z] 20:34:27 INFO - PID 2584 | 1620074067571 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:27.575Z] 20:34:27 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/execute_script/cyclic.py::test_array_in_object
[task 2021-05-03T20:34:27.576Z] 20:34:27 INFO - PID 2584 | 1620074067574 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:27.582Z] 20:34:27 INFO - PID 2584 | 1620074067570 Marionette DEBUG 0 -> [0,190,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:27.583Z] 20:34:27 INFO - PID 2584 | 1620074067570 Marionette DEBUG 0 <- [1,190,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:27.584Z] 20:34:27 INFO - PID 2584 | 1620074067581 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:27.586Z] 20:34:27 INFO - PID 2584 | 1620074067582 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"x": 100, "y": 100}
[task 2021-05-03T20:34:29.395Z] 20:34:29 INFO - PID 2584 | 1620074069382 Marionette DEBUG 0 -> [0,191,"WebDriver:SetWindowRect",{"x":100,"y":100}]
[task 2021-05-03T20:34:29.396Z] 20:34:29 INFO - PID 2584 | 1620074069382 Marionette DEBUG 0 <- [1,191,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:29.398Z] 20:34:29 INFO - PID 2584 | 1620074069394 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:29.399Z] 20:34:29 INFO - PID 2584 | 1620074069396 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/execute/sync {"script": "\n let arr = [];\n arr.push(arr);\n return {'arrayValue': arr};\n ", "args": []}
[task 2021-05-03T20:34:29.403Z] 20:34:29 INFO - PID 2584 | 1620074069389 Marionette DEBUG 0 -> [0,192,"WebDriver:ExecuteScript",{"args":[],"script":"\n let arr = [];\n arr.push(arr);\n return {'arrayValue': arr};\n "}]
[task 2021-05-03T20:34:29.407Z] 20:34:29 INFO - STDOUT: PASSED
[task 2021-05-03T20:34:29.409Z] 20:34:29 INFO - PID 2584 | 1620074069392 Marionette DEBUG 0 <- [1,192,{"error":"javascript error","message":"Cyclic object value","stacktrace":"WebDriverError@chrome://marionette/content/e ... te/content/evaluate.js:337:12\nreceiveMessage@chrome://marionette/content/actors/MarionetteCommandsChild.jsm:155:31\n"},null]
[task 2021-05-03T20:34:29.410Z] 20:34:29 INFO - PID 2584 | 1620074069404 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"javascript error","message":"Cyclic object value","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nJavaScriptError@chrome://marionette/content/error.js:360:5\nassert.acyclic@chrome://marionette/content/assert.js:47:11\nevaluate.toJSON@chrome://marionette/content/evaluate.js:337:12\nreceiveMessage@chrome://marionette/content/actors/MarionetteCommandsChild.jsm:155:31\n"}}
[task 2021-05-03T20:34:29.411Z] 20:34:29 INFO - PID 2584 | 1620074069405 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"implicit": 0}
[task 2021-05-03T20:34:29.412Z] 20:34:29 INFO - PID 2584 | 1620074069394 Marionette DEBUG 0 -> [0,193,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-05-03T20:34:29.413Z] 20:34:29 INFO - PID 2584 | 1620074069394 Marionette DEBUG 0 <- [1,193,null,{"value":null}]
[task 2021-05-03T20:34:29.415Z] 20:34:29 INFO - PID 2584 | 1620074069406 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.416Z] 20:34:29 INFO - PID 2584 | 1620074069407 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"pageLoad": 300000}
[task 2021-05-03T20:34:29.417Z] 20:34:29 INFO - PID 2584 | 1620074069396 Marionette DEBUG 0 -> [0,194,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-05-03T20:34:29.419Z] 20:34:29 INFO - PID 2584 | 1620074069397 Marionette DEBUG 0 <- [1,194,null,{"value":null}]
[task 2021-05-03T20:34:29.420Z] 20:34:29 INFO - PID 2584 | 1620074069409 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.421Z] 20:34:29 INFO - PID 2584 | 1620074069410 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/timeouts {"script": 30000}
[task 2021-05-03T20:34:29.423Z] 20:34:29 INFO - PID 2584 | 1620074069399 Marionette DEBUG 0 -> [0,195,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-05-03T20:34:29.424Z] 20:34:29 INFO - PID 2584 | 1620074069399 Marionette DEBUG 0 <- [1,195,null,{"value":null}]
[task 2021-05-03T20:34:29.425Z] 20:34:29 INFO - PID 2584 | 1620074069411 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.426Z] 20:34:29 INFO - PID 2584 | 1620074069412 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:29.428Z] 20:34:29 INFO - PID 2584 | 1620074069401 Marionette DEBUG 0 -> [0,196,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:29.429Z] 20:34:29 INFO - PID 2584 | 1620074069401 Marionette DEBUG 0 <- [1,196,null,{"value":"19"}]
[task 2021-05-03T20:34:29.430Z] 20:34:29 INFO - PID 2584 | 1620074069413 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:29.432Z] 20:34:29 INFO - PID 2584 | 1620074069414 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:29.433Z] 20:34:29 INFO - PID 2584 | 1620074069403 Marionette DEBUG 0 -> [0,197,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:29.435Z] 20:34:29 INFO - PID 2584 | 1620074069403 Marionette DEBUG 0 <- [1,197,null,{"value":"19"}]
[task 2021-05-03T20:34:29.436Z] 20:34:29 INFO - PID 2584 | 1620074069415 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:29.437Z] 20:34:29 INFO - PID 2584 | 1620074069416 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/handles
[task 2021-05-03T20:34:29.438Z] 20:34:29 INFO - PID 2584 | 1620074069405 Marionette DEBUG 0 -> [0,198,"WebDriver:GetWindowHandles",{}]
[task 2021-05-03T20:34:29.440Z] 20:34:29 INFO - PID 2584 | 1620074069405 Marionette DEBUG 0 <- [1,198,null,["19"]]
[task 2021-05-03T20:34:29.441Z] 20:34:29 INFO - PID 2584 | 1620074069417 webdriver::server DEBUG <- 200 OK {"value":["19"]}
[task 2021-05-03T20:34:29.442Z] 20:34:29 INFO - PID 2584 | 1620074069418 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:29.444Z] 20:34:29 INFO - PID 2584 | 1620074069407 Marionette DEBUG 0 -> [0,199,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:29.445Z] 20:34:29 INFO - PID 2584 | 1620074069407 Marionette DEBUG 0 <- [1,199,null,{"value":null}]
[task 2021-05-03T20:34:29.446Z] 20:34:29 INFO - PID 2584 | 1620074069419 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.448Z] 20:34:29 INFO - PID 2584 | 1620074069420 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/alert/dismiss {}
[task 2021-05-03T20:34:29.449Z] 20:34:29 INFO - PID 2584 | 1620074069409 Marionette DEBUG 0 -> [0,200,"WebDriver:DismissAlert",{}]
[task 2021-05-03T20:34:29.451Z] 20:34:29 INFO - PID 2584 | 1620074069410 Marionette DEBUG 0 <- [1,200,{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchA ... t@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"},null]
[task 2021-05-03T20:34:29.453Z] 20:34:29 INFO - PID 2584 | 1620074069422 webdriver::server DEBUG <- 404 Not Found {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchAlertError@chrome://marionette/content/error.js:382:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://marionette/content/driver.js:2722:11\nGeckoDriver.prototype.dismissDialog@chrome://marionette/content/driver.js:2625:8\ndespatch@chrome://marionette/content/server.js:291:40\nexecute@chrome://marionette/content/server.js:264:16\nonPacket/<@chrome://marionette/content/server.js:237:20\nonPacket@chrome://marionette/content/server.js:238:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"}}
[task 2021-05-03T20:34:29.454Z] 20:34:29 INFO - PID 2584 | 1620074069423 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:29.456Z] 20:34:29 INFO - PID 2584 | 1620074069412 Marionette DEBUG 0 -> [0,201,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:29.457Z] 20:34:29 INFO - PID 2584 | 1620074069412 Marionette DEBUG 0 <- [1,201,null,{"value":null}]
[task 2021-05-03T20:34:29.458Z] 20:34:29 INFO - PID 2584 | 1620074069424 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.459Z] 20:34:29 INFO - PID 2584 | 1620074069425 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window
[task 2021-05-03T20:34:29.461Z] 20:34:29 INFO - PID 2584 | 1620074069414 Marionette DEBUG 0 -> [0,202,"WebDriver:GetWindowHandle",{}]
[task 2021-05-03T20:34:29.462Z] 20:34:29 INFO - PID 2584 | 1620074069414 Marionette DEBUG 0 <- [1,202,null,{"value":"19"}]
[task 2021-05-03T20:34:29.463Z] 20:34:29 INFO - PID 2584 | 1620074069426 webdriver::server DEBUG <- 200 OK {"value":"19"}
[task 2021-05-03T20:34:29.465Z] 20:34:29 INFO - PID 2584 | 1620074069427 webdriver::server DEBUG -> GET /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/handles
[task 2021-05-03T20:34:29.466Z] 20:34:29 INFO - PID 2584 | 1620074069416 Marionette DEBUG 0 -> [0,203,"WebDriver:GetWindowHandles",{}]
[task 2021-05-03T20:34:29.467Z] 20:34:29 INFO - PID 2584 | 1620074069416 Marionette DEBUG 0 <- [1,203,null,["19"]]
[task 2021-05-03T20:34:29.468Z] 20:34:29 INFO - PID 2584 | 1620074069428 webdriver::server DEBUG <- 200 OK {"value":["19"]}
[task 2021-05-03T20:34:29.470Z] 20:34:29 INFO - PID 2584 | 1620074069430 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window {"handle": "19"}
[task 2021-05-03T20:34:29.471Z] 20:34:29 INFO - PID 2584 | 1620074069419 Marionette DEBUG 0 -> [0,204,"WebDriver:SwitchToWindow",{"handle":"19","name":"19"}]
[task 2021-05-03T20:34:29.472Z] 20:34:29 INFO - PID 2584 | 1620074069419 Marionette DEBUG 0 <- [1,204,null,{"value":null}]
[task 2021-05-03T20:34:29.473Z] 20:34:29 INFO - PID 2584 | 1620074069431 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.475Z] 20:34:29 INFO - PID 2584 | 1620074069432 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:29.476Z] 20:34:29 INFO - PID 2584 | 1620074069421 Marionette DEBUG 0 -> [0,205,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:29.477Z] 20:34:29 INFO - PID 2584 | 1620074069422 Marionette DEBUG 0 <- [1,205,null,{"x":100,"y":100,"width":800,"height":600}]
[task 2021-05-03T20:34:29.479Z] 20:34:29 INFO - PID 2584 | 1620074069434 webdriver::server DEBUG <- 200 OK {"value":{"x":100,"y":100,"width":800,"height":600}}
[task 2021-05-03T20:34:29.480Z] 20:34:29 INFO - PID 2584 | 1620074069435 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/frame {"id": null}
[task 2021-05-03T20:34:29.481Z] 20:34:29 INFO - STDOUT: tests/web-platform/tests/webdriver/tests/execute_script/cyclic.py::test_object_in_array
[task 2021-05-03T20:34:29.482Z] 20:34:29 INFO - PID 2584 | 1620074069424 Marionette DEBUG 0 -> [0,206,"WebDriver:SwitchToFrame",{"id":null}]
[task 2021-05-03T20:34:29.484Z] 20:34:29 INFO - PID 2584 | 1620074069425 Marionette DEBUG 0 <- [1,206,null,{"value":null}]
[task 2021-05-03T20:34:29.485Z] 20:34:29 INFO - PID 2584 | 1620074069437 webdriver::server DEBUG <- 200 OK {"value":null}
[task 2021-05-03T20:34:29.486Z] 20:34:29 INFO - PID 2584 | 1620074069440 webdriver::server DEBUG -> POST /session/a78268f3-39d5-43ea-9a9c-1287828dc26a/window/rect {"width": 800, "height": 600}
[task 2021-05-03T20:34:29.561Z] 20:34:29 INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/execute_script/cyclic.py | expected OK
[task 2021-05-03T20:34:29.561Z] 20:34:29 INFO - TEST-INFO took 30019ms
[task 2021-05-03T20:34:29.875Z] 20:34:29 INFO - PID 2584 | 1620074069547 Marionette DEBUG 0 -> [0,207,"WebDriver:SetWindowRect",{"height":600,"width":800}]
[task 2021-05-03T20:34:29.875Z] 20:34:29 INFO - PID 2584 | Exiting due to channel error.
[task 2021-05-03T20:34:29.876Z] 20:34:29 INFO - Closing logging queue
[task 2021-05-03T20:34:29.877Z] 20:34:29 INFO - queue closed
[task 2021-05-03T20:34:29.879Z] 20:34:29 INFO - Starting runner
[task 2021-05-03T20:34:30.555Z] 20:34:30 INFO - PID 1100 | 1620074070553 geckodriver INFO Listening on 127.0.0.1:54317
[task 2021-05-03T20:34:31.046Z] 20:34:31 INFO - WebDriver HTTP server listening at http://127.0.0.1:54317/
[task 2021-05-03T20:34:31.048Z] 20:34:31 INFO - TEST-START | /webdriver/tests/execute_script/execute.py```
Comment 1•5 years ago
|
||
In some cases there are 6s delays between geckodriver receiving a command and when Marionette gets it. I filed 1709264 to get this investigated.
| Comment hidden (Intermittent Failures Robot) |
Comment 3•5 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
| Reporter | ||
Comment 4•4 years ago
|
||
| treeherder | ||
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=378881493&repo=mozilla-central
| Comment hidden (Intermittent Failures Robot) |
Comment 6•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Comment 7•3 years ago
|
||
Description
•