Closed Bug 1442088 Opened 7 years ago Closed 6 years ago

Intermittent testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile | IOError: Process killed because the connection to Marionette server is lost.

Categories

(Testing :: Marionette Client and Harness, defect, P5)

Product:
Testing
Component:
Marionette Client and Harness
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Hang during startup: 23:09:15 INFO - Application command: Z:\task_1519858410\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\genericworker\appdata\local\temp\tmp9vo_w6\tmpa0e7yt.mozrunner 23:09:15 INFO - 1519859355676 Marionette DEBUG Received observer notification profile-after-change 23:13:16 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Timed out waiting for connection on localhost:2828!) Should depend on bug 1414495.
Depends on: 1414495
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=185281660&repo=mozilla-inbound&lineNumber=32374 01:10:40 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_quit_keeps_same_profile 01:10:40 INFO - 1530148240288 Marionette DEBUG Closed connection 3 01:10:40 INFO - 1530148240290 Marionette DEBUG Accepted connection 4 from 127.0.0.1:51334 01:10:40 INFO - 1530148240292 Marionette TRACE 4 -> [0,1,"WebDriver:NewSession",{}] 01:10:40 INFO - 1530148240293 Marionette DEBUG [6442450945] Frame script loaded 01:10:40 INFO - 1530148240294 Marionette DEBUG [6442450945] Frame script registered 01:10:40 INFO - 1530148240296 Marionette TRACE 4 <- [1,1,null,{"sessionId":"6fc337f3-1cde-4522-a494-4abe829e31aa","capabilities":{"browserName":"firefox","browserVersion":"63.0a ... pData\\Local\\Temp\\tmp9kn4yz\\tmpwo0ere.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 01:10:40 INFO - 1530148240297 Marionette TRACE 4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}] 01:10:40 INFO - 1530148240298 Marionette TRACE 4 <- [1,2,null,{"value":null}] 01:10:40 INFO - 1530148240299 Marionette TRACE 4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}] 01:10:40 INFO - 1530148240299 Marionette TRACE 4 <- [1,3,null,{"value":null}] 01:10:40 INFO - 1530148240301 Marionette TRACE 4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}] 01:10:40 INFO - 1530148240302 Marionette TRACE 4 <- [1,4,null,{"value":null}] 01:10:40 INFO - 1530148240306 Marionette TRACE 4 -> [0,5,"WebDriver:DeleteSession",{}] 01:10:40 INFO - 1530148240307 Marionette TRACE 4 <- [1,5,null,{"value":null}] 01:10:40 INFO - 1530148240310 Marionette DEBUG Closed connection 4 01:10:40 INFO - Application command: Z:\task_1530146620\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1530146620\appdata\local\temp\tmp9kn4yz\tmpwo0ere.mozrunner 01:10:43 INFO - TEST-PASS | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_quit_keeps_same_profile | took 3151ms 01:10:43 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile 01:10:43 INFO - Application command: Z:\task_1530146620\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1530146620\appdata\local\temp\tmpalwum3\tmpglmqwx.mozrunner 01:10:44 INFO - 1530148244093 Marionette DEBUG Received observer notification profile-after-change 01:14:44 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Timed out waiting for connection on localhost:2828!) 01:14:44 INFO - Traceback (most recent call last): 01:14:44 INFO - File "Z:\task_1530146620\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run 01:14:44 INFO - testMethod() 01:14:44 INFO - File "Z:\task_1530146620\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 134, in test_restart_clean_creates_new_profile 01:14:44 INFO - self.marionette.restart(clean=True) 01:14:44 INFO - File "Z:\task_1530146620\build\venv\lib\site-packages\marionette_driver\decorators.py", line 31, in _ 01:14:44 INFO - m._handle_socket_failure() 01:14:44 INFO - File "Z:\task_1530146620\build\venv\lib\site-packages\marionette_driver\marionette.py", line 841, in _handle_socket_failure 01:14:44 INFO - reraise(IOError, message.format(returncode=returncode, reason=val), tb) 01:14:44 INFO - File "Z:\task_1530146620\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 01:14:44 INFO - return func(*args, **kwargs) 01:14:44 INFO - File "Z:\task_1530146620\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1179, in restart 01:14:44 INFO - self.raise_for_port(timeout=self.DEFAULT_STARTUP_TIMEOUT) 01:14:44 INFO - File "Z:\task_1530146620\build\venv\lib\site-packages\marionette_driver\marionette.py", line 731, in raise_for_port 01:14:44 INFO - self.host, self.port)) 01:14:44 INFO - TEST-INFO took 241368ms 01:14:44 INFO - Application command: Z:\task_1530146620\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1530146620\appdata\local\temp\tmpalwum3\tmpjz1lr3.mozrunner 01:14:45 INFO - 1530148485395 Marionette DEBUG Received observer notification profile-after-change 01:14:45 INFO - 1530148485483 Marionette DEBUG Received observer notification command-line-startup 01:14:45 INFO - 1530148485483 Marionette DEBUG Received observer notification nsPref:changed 01:14:45 INFO - 1530148485484 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) 01:14:46 INFO - 1530148486452 Marionette DEBUG Received observer notification sessionstore-windows-restored 01:14:46 INFO - 1530148486452 Marionette DEBUG Waiting for delayed startup... 01:14:46 INFO - 1530148486785 Marionette DEBUG Waiting for startup tests... 01:14:46 INFO - 1530148486835 Marionette INFO Listening on port 2828 01:14:46 INFO - 1530148486836 Marionette DEBUG Remote service is active 01:14:47 INFO - 1530148487031 Marionette DEBUG Accepted connection 0 from 127.0.0.1:51641 01:14:47 INFO - 1530148487130 Marionette DEBUG Closed connection 0 01:14:47 INFO - 1530148487133 Marionette DEBUG Accepted connection 1 from 127.0.0.1:51646 01:14:47 INFO - 1530148487221 Marionette DEBUG Accepted connection 2 from 127.0.0.1:51653 01:14:47 INFO - 1530148487226 Marionette DEBUG Closed connection 2 01:14:47 INFO - 1530148487226 Marionette DEBUG Closed connection 1 01:14:47 INFO - 1530148487227 Marionette DEBUG Accepted connection 3 from 127.0.0.1:51654 01:14:47 INFO - 1530148487229 Marionette TRACE 3 -> [0,1,"WebDriver:NewSession",{}] 01:14:47 INFO - 1530148487271 Marionette DEBUG [6442450945] Frame script loaded 01:14:47 INFO - 1530148487272 Marionette DEBUG [6442450945] Frame script registered 01:14:47 INFO - 1530148487279 Marionette TRACE 3 <- [1,1,null,{"sessionId":"29c42ffd-8a10-45d1-8bae-622542337444","capabilities":{"browserName":"firefox","browserVersion":"63.0a ... pData\\Local\\Temp\\tmpalwum3\\tmpjz1lr3.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 01:14:47 INFO - 1530148487283 Marionette TRACE 3 -> [0,2,"WebDriver:DeleteSession",{}] 01:14:47 INFO - 1530148487285 Marionette TRACE 3 <- [1,2,null,{"value":null}]
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=219828396&repo=mozilla-inbound&lineNumber=32337 18:41:10 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile 18:41:10 INFO - Application command: Z:\task_1546540329\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile c:\users\task_1546540329\appdata\local\temp\tmp1jtcwc\tmpuyqlwp.mozrunner 18:41:10 INFO - *** You are running in headless mode. 18:41:10 INFO - 1546540870673 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/ 18:41:10 INFO - 1546540870673 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader* 18:41:10 INFO - 1546540870791 Marionette TRACE Received observer notification profile-after-change 18:41:10 INFO - 1546540870831 Marionette TRACE Received observer notification toplevel-window-ready 18:41:10 INFO - 1546540870848 Marionette TRACE Received observer notification command-line-startup 18:41:10 INFO - 1546540870848 Marionette TRACE Received observer notification nsPref:changed 18:41:10 INFO - 1546540870848 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) 18:44:21 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Timed out waiting for connection on 127.0.0.1:2828!) 18:44:21 INFO - Traceback (most recent call last): 18:44:21 INFO - File "Z:\task_1546540329\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run 18:44:21 INFO - testMethod() 18:44:21 INFO - File "Z:\task_1546540329\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 134, in test_restart_clean_creates_new_profile 18:44:21 INFO - self.marionette.restart(clean=True) 18:44:21 INFO - File "Z:\task_1546540329\build\venv\lib\site-packages\marionette_driver\decorators.py", line 36, in _ 18:44:21 INFO - m._handle_socket_failure() 18:44:21 INFO - File "Z:\task_1546540329\build\venv\lib\site-packages\marionette_driver\marionette.py", line 844, in _handle_socket_failure 18:44:21 INFO - reraise(IOError, message.format(returncode=returncode, reason=val), tb) 18:44:21 INFO - File "Z:\task_1546540329\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 18:44:21 INFO - return func(*args, **kwargs) 18:44:21 INFO - File "Z:\task_1546540329\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1218, in restart 18:44:21 INFO - self.raise_for_port(timeout=self.DEFAULT_STARTUP_TIMEOUT) 18:44:21 INFO - File "Z:\task_1546540329\build\venv\lib\site-packages\marionette_driver\marionette.py", line 735, in raise_for_port 18:44:21 INFO - self.host, self.port)) 18:44:21 INFO - TEST-INFO took 191423ms 18:44:21 INFO - Application command: Z:\task_1546540329\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile c:\users\task_1546540329\appdata\local\temp\tmp1jtcwc\tmpyq05d4.mozrunner 18:44:21 INFO - *** You are running in headless mode. 18:44:21 INFO - 1546541061932 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/ 18:44:21 INFO - 1546541061932 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader* 18:44:22 INFO - 1546541062051 Marionette TRACE Received observer notification profile-after-change 18:44:22 INFO - 1546541062099 Marionette TRACE Received observer notification toplevel-window-ready 18:44:22 INFO - 1546541062117 Marionette TRACE Received observer notification command-line-startup 18:44:22 INFO - 1546541062117 Marionette TRACE Received observer notification nsPref:changed 18:44:22 INFO - 1546541062117 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) 18:44:22 INFO - 1546541062253 Marionette TRACE Received observer notification toplevel-window-ready 18:44:22 INFO - 1546541062873 Marionette TRACE Received observer notification sessionstore-windows-restored 18:44:22 INFO - 1546541062873 Marionette TRACE Waiting until startup recorder finished recording startup scripts... 18:44:23 INFO - 1546541063019 Marionette TRACE All scripts recorded. 18:44:23 INFO - 1546541063053 Marionette INFO Listening on port 2828 18:44:23 INFO - 1546541063053 Marionette DEBUG Remote service is active 18:44:23 INFO - 1546541063191 Marionette DEBUG Accepted connection 0 from 127.0.0.1:51937 18:44:23 INFO - 1546541063290 Marionette DEBUG Closed connection 0 18:44:23 INFO - 1546541063292 Marionette DEBUG Accepted connection 1 from 127.0.0.1:51944 18:44:23 INFO - 1546541063391 Marionette DEBUG Accepted connection 2 from 127.0.0.1:51954 18:44:23 INFO - 1546541063392 Marionette DEBUG Closed connection 2 18:44:23 INFO - 1546541063393 Marionette DEBUG Closed connection 1 18:44:23 INFO - 1546541063393 Marionette DEBUG Accepted connection 3 from 127.0.0.1:51956 18:44:23 INFO - 1546541063394 Marionette DEBUG 3 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}] 18:44:23 INFO - 1546541063423 Marionette TRACE [6442450945] Frame script loaded 18:44:23 INFO - 1546541063424 Marionette TRACE [6442450945] Frame script registered 18:44:23 INFO - 1546541063428 Marionette DEBUG 3 <- [1,1,null,{"sessionId":"dfea6198-bd8c-45ad-a965-32a497e1bd9c","capabilities":{"browserName":"firefox","browserVersion":"66.0a ... c\\tmpyq05d4.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 18:44:23 INFO - 1546541063431 Marionette DEBUG 3 -> [0,2,"WebDriver:DeleteSession",{}] 18:44:23 INFO - 1546541063432 Marionette DEBUG 3 <- [1,2,null,{"value":null}]
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED
Closed: 7 years ago → 6 years ago
Resolution: --- → INCOMPLETE

New occurrence: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=241689827&repo=mozilla-central&lineNumber=31547

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Resolution: --- → INCOMPLETE
Product: Testing → Remote Protocol
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.