Closed Bug 1467740 Opened 7 years ago Closed 7 years ago

Intermittent testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_new_random_profile_name | IOError: Process killed after 120s because no connection to Marionette server could...

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

Details

(Keywords: intermittent-failure)

Filed by: aiakab [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=182474034&repo=autoland https://queue.taskcluster.net/v1/task/DfFfIX4KSMKaW6PqjumHcA/runs/0/artifacts/public/logs/live_backing.log 08:51:29 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_new_random_profile_name 08:51:29 INFO - 1528447889168 Marionette DEBUG Closed connection 3 08:51:29 INFO - 1528447889172 Marionette DEBUG Accepted connection 4 from 127.0.0.1:51901 08:51:29 INFO - 1528447889174 Marionette TRACE 4 -> [0,1,"WebDriver:NewSession",{}] 08:51:29 INFO - 1528447889180 Marionette DEBUG Register listener.js for window 4294967297 08:51:29 INFO - 1528447889185 Marionette TRACE 4 <- [1,1,null,{"sessionId":"6a66f7be-6bb9-461e-882f-cf6726f9c27c","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... _1528445624\\AppData\\Local\\Temp\\tmpkgvrmw.$¢€ἶA","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 08:51:29 INFO - 1528447889188 Marionette TRACE 4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}] 08:51:29 INFO - 1528447889190 Marionette TRACE 4 <- [1,2,null,{"value":null}] 08:51:29 INFO - 1528447889192 Marionette TRACE 4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}] 08:51:29 INFO - 1528447889193 Marionette TRACE 4 <- [1,3,null,{"value":null}] 08:51:29 INFO - 1528447889196 Marionette TRACE 4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}] 08:51:29 INFO - 1528447889199 Marionette TRACE 4 <- [1,4,null,{"value":null}] 08:51:29 INFO - 1528447889206 Marionette TRACE 4 -> [0,5,"WebDriver:DeleteSession",{}] 08:51:29 INFO - 1528447889208 Marionette TRACE 4 <- [1,5,null,{"value":null}] 08:51:29 INFO - Application command: Z:\task_1528445624\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1528445624\appdata\local\temp\tmp3uxgbs.mozrunner 08:51:29 INFO - *** You are running in headless mode. 08:51:31 INFO - 1528447891506 Marionette DEBUG Received observer notification profile-after-change 08:51:31 INFO - 1528447891701 Marionette DEBUG Received observer notification command-line-startup 08:51:31 INFO - 1528447891701 Marionette DEBUG Received observer notification nsPref:changed 08:51:31 INFO - 1528447891701 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) 08:53:29 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_new_random_profile_name | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors 08:53:29 INFO - Traceback (most recent call last): 08:53:29 INFO - File "Z:\task_1528445624\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run 08:53:29 INFO - testMethod() 08:53:29 INFO - File "Z:\task_1528445624\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 164, in test_new_random_profile_name 08:53:29 INFO - self.marionette.start_session() 08:53:29 INFO - File "Z:\task_1528445624\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 08:53:29 INFO - return func(*args, **kwargs) 08:53:29 INFO - File "Z:\task_1528445624\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1210, in start_session 08:53:29 INFO - self.start_binary(timeout) 08:53:29 INFO - File "Z:\task_1528445624\build\venv\lib\site-packages\marionette_driver\marionette.py", line 639, in start_binary 08:53:29 INFO - reraise(IOError, msg.format(timeout), tb) 08:53:29 INFO - File "Z:\task_1528445624\build\venv\lib\site-packages\marionette_driver\marionette.py", line 630, in start_binary 08:53:29 INFO - self.raise_for_port(timeout=timeout) 08:53:29 INFO - File "Z:\task_1528445624\build\venv\lib\site-packages\marionette_driver\marionette.py", line 710, in raise_for_port 08:53:29 INFO - self.host, self.port)) 08:53:29 INFO - TEST-INFO took 120639ms 08:53:29 INFO - Application command: Z:\task_1528445624\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1528445624\appdata\local\temp\tmpwqdjrn.mozrunner 08:53:30 INFO - *** You are running in headless mode. 08:53:31 INFO - 1528448011803 Marionette DEBUG Received observer notification profile-after-change 08:53:32 INFO - 1528448011996 Marionette DEBUG Received observer notification command-line-startup 08:53:32 INFO - 1528448011996 Marionette DEBUG Received observer notification nsPref:changed 08:53:32 INFO - 1528448011997 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) 08:53:34 INFO - 1528448014969 Marionette DEBUG Received observer notification sessionstore-windows-restored 08:53:34 INFO - 1528448014970 Marionette DEBUG Waiting for delayed startup... 08:53:36 INFO - 1528448016195 Marionette DEBUG Waiting for startup tests... 08:53:36 INFO - 1528448016394 Marionette INFO Listening on port 2828 08:53:36 INFO - 1528448016395 Marionette DEBUG Remote service is active 08:53:36 INFO - 1528448016431 Marionette DEBUG Accepted connection 0 from 127.0.0.1:52176 08:53:36 INFO - 1528448016442 Marionette DEBUG Closed connection 0 08:53:36 INFO - 1528448016444 Marionette DEBUG Accepted connection 1 from 127.0.0.1:52177 08:53:36 INFO - 1528448016458 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}] 08:53:36 INFO - 1528448016581 Marionette DEBUG Register listener.js for window 4294967297 08:53:36 INFO - 1528448016611 Marionette TRACE 1 <- [1,1,null,{"sessionId":"5fa555c6-3d1e-4465-bad6-c5d0a91b82bf","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... 8445624\\AppData\\Local\\Temp\\tmpwqdjrn.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 08:53:36 INFO - 1528448016630 Marionette TRACE 1 -> [0,2,"WebDriver:DeleteSession",{}] 08:53:36 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_current_profile 08:53:36 INFO - 1528448016634 Marionette TRACE 1 <- [1,2,null,{"value":null}] 08:53:36 INFO - 1528448016639 Marionette DEBUG Closed connection 1 08:53:36 INFO - 1528448016640 Marionette DEBUG Accepted connection 2 from 127.0.0.1:52178 08:53:36 INFO - 1528448016647 Marionette TRACE 2 -> [0,1,"WebDriver:NewSession",{}] 08:53:36 INFO - 1528448016653 Marionette DEBUG Register listener.js for window 4294967297 08:53:36 INFO - 1528448016660 Marionette TRACE 2 <- [1,1,null,{"sessionId":"ba6a5578-bde6-41d4-9911-fffadc728ed3","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... 8445624\\AppData\\Local\\Temp\\tmpwqdjrn.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 08:53:36 INFO - 1528448016670 Marionette TRACE 2 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}] 08:53:36 INFO - 1528448016671 Marionette TRACE 2 <- [1,2,null,{"value":null}] 08:53:36 INFO - 1528448016677 Marionette TRACE 2 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}] 08:53:36 INFO - 1528448016678 Marionette TRACE 2 <- [1,3,null,{"value":null}] 08:53:36 INFO - 1528448016685 Marionette TRACE 2 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}] 08:53:36 INFO - 1528448016687 Marionette TRACE 2 <- [1,4,null,{"value":null}] 08:53:36 INFO - 1528448016694 Marionette TRACE 2 -> [0,5,"WebDriver:DeleteSession",{}] 08:53:36 INFO - 1528448016697 Marionette TRACE 2 <- [1,5,null,{"value":null}] 08:53:36 INFO - Application command: Z:\task_1528445624\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1528445624\appdata\local\temp\tmpwqdjrn.mozrunner 08:53:37 INFO - *** You are running in headless mode.
No "sessionstore-windows-restored" notification. So it depends on bug 1382162.
Depends on: 1382162
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=187142379&repo=autoland&lineNumber=33093 INFO - Application command: Z:\task_1531138823\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1531138823\appdata\local\temp\tmpvx9gnx.mozrunner 12:29:17 INFO - 1531139357630 Marionette DEBUG Received observer notification profile-after-change 12:31:17 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_new_random_profile_name | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors 12:31:17 INFO - Traceback (most recent call last): 12:31:17 INFO - File "Z:\task_1531138823\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run 12:31:17 INFO - testMethod() 12:31:17 INFO - File "Z:\task_1531138823\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 164, in test_new_random_profile_name 12:31:17 INFO - self.marionette.start_session() 12:31:17 INFO - File "Z:\task_1531138823\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 12:31:17 INFO - return func(*args, **kwargs) 12:31:17 INFO - File "Z:\task_1531138823\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1227, in start_session 12:31:17 INFO - self.start_binary(timeout) 12:31:17 INFO - File "Z:\task_1531138823\build\venv\lib\site-packages\marionette_driver\marionette.py", line 660, in start_binary 12:31:17 INFO - reraise(IOError, msg.format(timeout), tb) 12:31:17 INFO - File "Z:\task_1531138823\build\venv\lib\site-packages\marionette_driver\marionette.py", line 651, in start_binary 12:31:17 INFO - self.raise_for_port(timeout=timeout) 12:31:17 INFO - File "Z:\task_1531138823\build\venv\lib\site-packages\marionette_driver\marionette.py", line 731, in raise_for_port 12:31:17 INFO - self.host, self.port))
Status: RESOLVED → REOPENED
Flags: needinfo?(dburns)
Resolution: INCOMPLETE → ---
I triggered a few of these jobs in the same push and it appears to happen very infrequently. Previous OF statistics on this bug indicate it happens at a 0.001 rate, which is extremely infrequent. As whimboo noted above, it depends on https://bugzilla.mozilla.org/show_bug.cgi?id=1382162.
Flags: needinfo?(dburns)
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 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.