Closed
Bug 1692542
Opened 5 years ago
Closed 5 years ago
Intermittent [tier2] MnFr testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt | IOError: Process killed because the connection to Marionette server is lost.
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Testing
Marionette Client and Harness
Tracking
(Not tracked)
RESOLVED
INVALID
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=329801594&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/eITRF7B0R6eEZi755AjXpg/runs/1/artifacts/public/logs/live_backing.log
[task 2021-02-12T17:25:51.412Z] 17:25:51 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_confirm | took 240ms
[task 2021-02-12T17:25:51.413Z] 17:25:51 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt
[task 2021-02-12T17:25:51.413Z] 17:25:51 INFO - 1613150751402 Marionette TRACE Received observer notification message-manager-disconnect
[task 2021-02-12T17:25:51.413Z] 17:25:51 INFO - 1613150751402 Marionette TRACE Received observer notification message-manager-disconnect
[task 2021-02-12T17:25:51.414Z] 17:25:51 INFO - 1613150751402 Marionette DEBUG 20 <- [1,24,null,["26"]]
[task 2021-02-12T17:25:51.414Z] 17:25:51 INFO - 1613150751403 Marionette DEBUG 20 -> [0,25,"WebDriver:SwitchToWindow",{"handle":"26","focus":true}]
[task 2021-02-12T17:25:51.415Z] 17:25:51 INFO - 1613150751403 Marionette DEBUG 20 <- [1,25,null,{"value":null}]
[task 2021-02-12T17:25:51.416Z] 17:25:51 INFO - 1613150751404 Marionette DEBUG 20 -> [0,26,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-02-12T17:25:51.418Z] 17:25:51 INFO - 1613150751404 Marionette DEBUG 20 <- [1,26,null,["1"]]
[task 2021-02-12T17:25:51.418Z] 17:25:51 INFO - 1613150751404 Marionette DEBUG 20 -> [0,27,"WebDriver:GetWindowHandles",{}]
[task 2021-02-12T17:25:51.419Z] 17:25:51 INFO - 1613150751404 Marionette DEBUG 20 <- [1,27,null,["26"]]
[task 2021-02-12T17:25:51.419Z] 17:25:51 INFO - 1613150751405 Marionette DEBUG 20 -> [0,28,"WebDriver:DeleteSession",{}]
[task 2021-02-12T17:25:51.420Z] 17:25:51 INFO - 1613150751406 Marionette DEBUG 20 <- [1,28,null,{"value":null}]
[task 2021-02-12T17:25:51.421Z] 17:25:51 INFO - 1613150751408 Marionette DEBUG Closed connection 20
[task 2021-02-12T17:25:51.421Z] 17:25:51 INFO - 1613150751409 Marionette DEBUG Accepted connection 21 from 127.0.0.1:37438
[task 2021-02-12T17:25:51.421Z] 17:25:51 INFO - 1613150751410 Marionette DEBUG 21 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-02-12T17:25:51.422Z] 17:25:51 INFO - 1613150751411 Marionette TRACE [26] Frame script loaded
[task 2021-02-12T17:25:51.423Z] 17:25:51 INFO - 1613150751416 Marionette DEBUG 21 <- [1,1,null,{"sessionId":"a33ceb61-de91-4981-93cc-11f1e7e4672a","capabilities":{"browserName":"firefox","browserVersion":"87.0a ... mp/tmpF4zRpc.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2021-02-12T17:25:51.424Z] 17:25:51 INFO - 1613150751417 Marionette DEBUG 21 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2021-02-12T17:25:51.425Z] 17:25:51 INFO - 1613150751418 Marionette DEBUG 21 <- [1,2,null,{"value":null}]
[task 2021-02-12T17:25:51.425Z] 17:25:51 INFO - 1613150751419 Marionette DEBUG 21 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2021-02-12T17:25:51.425Z] 17:25:51 INFO - 1613150751419 Marionette DEBUG 21 <- [1,3,null,{"value":null}]
[task 2021-02-12T17:25:51.425Z] 17:25:51 INFO - 1613150751421 Marionette DEBUG 21 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2021-02-12T17:25:51.425Z] 17:25:51 INFO - 1613150751422 Marionette DEBUG 21 <- [1,4,null,{"value":null}]
[task 2021-02-12T17:25:51.428Z] 17:25:51 INFO - 1613150751426 Marionette DEBUG 21 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2021-02-12T17:25:51.429Z] 17:25:51 INFO - 1613150751426 Marionette DEBUG 21 <- [1,5,null,{"value":"1"}]
[task 2021-02-12T17:25:51.429Z] 17:25:51 INFO - 1613150751426 Marionette DEBUG 21 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2021-02-12T17:25:51.429Z] 17:25:51 INFO - 1613150751427 Marionette DEBUG 21 <- [1,6,null,["1"]]
[task 2021-02-12T17:25:51.429Z] 17:25:51 INFO - 1613150751427 Marionette DEBUG 21 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2021-02-12T17:25:51.430Z] 17:25:51 INFO - 1613150751427 Marionette DEBUG 21 <- [1,7,null,{"value":"26"}]
[task 2021-02-12T17:25:51.430Z] 17:25:51 INFO - 1613150751428 Marionette DEBUG 21 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2021-02-12T17:25:51.430Z] 17:25:51 INFO - 1613150751428 Marionette DEBUG 21 <- [1,8,null,["26"]]
[task 2021-02-12T17:25:51.434Z] 17:25:51 INFO - 1613150751431 Marionette DEBUG 21 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2021-02-12T17:25:51.434Z] 17:25:51 INFO - 1613150751431 Marionette DEBUG 21 <- [1,9,null,["26"]]
[task 2021-02-12T17:25:51.434Z] 17:25:51 INFO - 1613150751432 Marionette DEBUG 21 -> [0,10,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2021-02-12T17:25:51.440Z] 17:25:51 INFO - 1613150751436 Marionette TRACE Received DOM event TabOpen for [object XULElement]
[task 2021-02-12T17:25:51.443Z] 17:25:51 INFO - 1613150751441 Marionette TRACE [63] Frame script loaded
[task 2021-02-12T17:25:51.460Z] 17:25:51 INFO - 1613150751450 Marionette DEBUG 21 <- [1,10,null,{"handle":"63","type":"tab"}]
[task 2021-02-12T17:25:51.467Z] 17:25:51 INFO - 1613150751461 Marionette DEBUG 21 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2021-02-12T17:25:51.468Z] 17:25:51 INFO - 1613150751462 Marionette DEBUG 21 <- [1,11,null,["26","63"]]
[task 2021-02-12T17:25:51.468Z] 17:25:51 INFO - 1613150751462 Marionette DEBUG 21 -> [0,12,"WebDriver:GetWindowHandles",{}]
[task 2021-02-12T17:25:51.468Z] 17:25:51 INFO - 1613150751463 Marionette DEBUG 21 <- [1,12,null,["26","63"]]
[task 2021-02-12T17:25:51.469Z] 17:25:51 INFO - 1613150751465 Marionette DEBUG 21 -> [0,13,"WebDriver:SwitchToWindow",{"handle":"63","focus":true}]
[task 2021-02-12T17:25:51.477Z] 17:25:51 INFO - 1613150751472 Marionette TRACE Received DOM event TabSelect for [object XULElement]
[task 2021-02-12T17:25:51.478Z] 17:25:51 INFO - 1613150751476 Marionette DEBUG 21 <- [1,13,null,{"value":null}]
[task 2021-02-12T17:25:51.479Z] 17:25:51 INFO - 1613150751477 Marionette DEBUG 21 -> [0,14,"WebDriver:Navigate",{"url":"http://127.0.0.1:42309/test_tab_modal_dialogs.html"}]
[task 2021-02-12T17:25:51.499Z] 17:25:51 INFO - 1613150751489 Marionette TRACE Received event pagehide for about:blank
[task 2021-02-12T17:25:51.501Z] 17:25:51 INFO - 1613150751491 Marionette TRACE Received event DOMContentLoaded for about:blank
[task 2021-02-12T17:25:51.501Z] 17:25:51 INFO - 1613150751491 Marionette TRACE Received event pageshow for about:blank
[task 2021-02-12T17:25:51.502Z] 17:25:51 INFO - 1613150751493 Marionette DEBUG 21 <- [1,14,null,{"value":null}]
[task 2021-02-12T17:25:51.517Z] 17:25:51 INFO - 1613150751505 Marionette DEBUG 21 -> [0,15,"WebDriver:FindElement",{"using":"id","value":"tab-modal-prompt"}]
[task 2021-02-12T17:25:51.517Z] 17:25:51 INFO - 1613150751510 Marionette TRACE [63] Frame script loaded
[task 2021-02-12T17:25:51.534Z] 17:25:51 INFO - 1613150751524 Marionette TRACE [63] Frame script unloaded
[task 2021-02-12T17:25:51.535Z] 17:25:51 INFO - 1613150751525 Marionette TRACE Detected remoteness change. New browsing context: 63
[task 2021-02-12T17:26:05.393Z] 17:26:05 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-02-12T17:26:05.393Z] 17:26:05 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2021-02-12T17:26:07.358Z] 17:26:07 INFO - DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2021-02-12T17:29:47.356Z] 17:29:47 INFO - DEBUG: Adding blocker places.sqlite#1: PlacesUtils: promiseKeywordsCache (1) for phase places.sqlite#1: waiting for clients
[task 2021-02-12T17:29:47.356Z] 17:29:47 INFO - DEBUG: Completed blocker places.sqlite#1: PlacesUtils: promiseKeywordsCache (1) for phase places.sqlite#1: waiting for clients
[task 2021-02-12T17:31:51.600Z] 17:31:51 INFO - 1613151111598 Marionette DEBUG Closed connection 21
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - Traceback (most recent call last):
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 214, in run
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - testMethod()
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 64, in wrapper
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - return func(self, *args, **kwargs)
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py", line 83, in test_dismiss
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - self.marionette.find_element(By.ID, "tab-modal-{}".format(value)).click()
[task 2021-02-12T17:33:02.666Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1763, in find_element
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - return self._send_message("WebDriver:FindElement", body, key="value")
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - m._handle_socket_failure()
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 716, in _handle_socket_failure
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - return func(*args, **kwargs)
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 621, in _send_message
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - msg = self.client.request(name, params)
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 292, in request
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - return self.receive()
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 196, in receive
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - "Connection timed out after {}s".format(self.socket_timeout)
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - TEST-INFO took 431253ms
[task 2021-02-12T17:33:02.667Z] 17:33:02 ERROR - test_end for testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt logged while not in progress. Logged with data: {"status": "ERROR", "extra": {"class_name": "test_modal_dialogs.TestTabModalAlerts", "method_name": "test_dismiss_prompt"}, "expected": "PASS", "test": "testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt", "message": "InvalidSessionIdException: Please start a session", "stack": "Traceback (most recent call last):\n File \"/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py\", line 247, in run\n self.tearDown()\n File \"/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py\", line 46, in tearDown\n alert.dismiss()\n File \"/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py\", line 388, in dismiss\n self.marionette._send_message(\"WebDriver:DismissAlert\")\n File \"/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py\", line 27, in _\n return func(*args, **kwargs)\n File \"/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py\", line 618, in _send_message\n raise errors.InvalidSessionIdException(\"Please start a session\")\n"}
[task 2021-02-12T17:33:02.667Z] 17:33:02 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_handle_two_dialogs```
|
||
Comment 1•5 years ago
|
||
The problem here is:
[task 2021-02-12T17:25:51.517Z] 17:25:51 INFO - 1613150751505 Marionette DEBUG 21 -> [0,15,"WebDriver:FindElement",{"using":"id","value":"tab-modal-prompt"}]
[task 2021-02-12T17:25:51.517Z] 17:25:51 INFO - 1613150751510 Marionette TRACE [63] Frame script loaded
[task 2021-02-12T17:25:51.534Z] 17:25:51 INFO - 1613150751524 Marionette TRACE [63] Frame script unloaded
[task 2021-02-12T17:25:51.535Z] 17:25:51 INFO - 1613150751525 Marionette TRACE Detected remoteness change. New browsing context: 63
This is framescript related, which is known to be broken. Bug 1669172 will remove all the related code and MnFr jobs soon.
Depends on: 1669172
Summary: Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connectio → Intermittent [tier2] MnFr testing/marionette/harness/marionette_harness/tests/unit/test_modal_dialogs.py TestTabModalAlerts.test_dismiss_prompt | IOError: Process killed because the connection to Marionette server is lost.
|
|
||
Comment 2•5 years ago
|
||
Marking as invalid because the framescript implementation doesn't exist anymore.
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INVALID
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•3 years ago
|
Product: Testing → Remote Protocol
|
|
||
Comment 4•3 years ago
|
||
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in
before you can comment on or make changes to this bug.
Description
•