Closed Bug 1438572 Opened 7 years ago Closed 6 years ago

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

Categories

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

Version 3
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=162444052&repo=autoland https://queue.taskcluster.net/v1/task/X_VZQlfVQfKV76Mwpn7geg/runs/0/artifacts/public/logs/live_backing.log 16:23:44 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile 16:23:44 INFO - 1518711824488 Marionette TRACE 3 -> [0,2,"deleteSession",{}] 16:23:44 INFO - 1518711824490 Marionette TRACE 3 <- [1,2,null,{}] 16:23:44 INFO - 1518711824490 Marionette DEBUG Closed connection 3 16:23:44 INFO - 1518711824492 Marionette DEBUG Accepted connection 4 from 127.0.0.1:51681 16:23:44 INFO - 1518711824494 Marionette TRACE 4 -> [0,1,"newSession",{}] 16:23:44 INFO - 1518711824496 Marionette DEBUG Register listener.js for window 2147483649 16:23:44 INFO - 1518711824498 Marionette TRACE 4 <- [1,1,null,{"sessionId":"ab8f2412-a215-46f5-8cfa-62e3298260d0","capabilities":{"browserName":"firefox","browserVersion":"60.0a ... cWorker\\AppData\\Local\\Temp\\tmp211ly4.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 16:23:44 INFO - 1518711824500 Marionette TRACE 4 -> [0,2,"setTimeouts",{"script":30000}] 16:23:44 INFO - 1518711824502 Marionette TRACE 4 <- [1,2,null,{}] 16:23:44 INFO - 1518711824502 Marionette TRACE 4 -> [0,3,"setTimeouts",{"pageLoad":300000}] 16:23:44 INFO - 1518711824502 Marionette TRACE 4 <- [1,3,null,{}] 16:23:44 INFO - 1518711824506 Marionette TRACE 4 -> [0,4,"setTimeouts",{"implicit":0}] 16:23:44 INFO - 1518711824508 Marionette TRACE 4 <- [1,4,null,{}] 16:23:44 INFO - 1518711824512 Marionette TRACE 4 -> [0,5,"deleteSession",{}] 16:23:44 INFO - 1518711824514 Marionette TRACE 4 <- [1,5,null,{}] 16:23:44 INFO - Application command: Z:\task_1518711490\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\genericworker\appdata\local\temp\tmpjtm76texternal 16:25:44 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors 16:25:44 INFO - Traceback (most recent call last): 16:25:44 INFO - File "Z:\task_1518711490\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run 16:25:44 INFO - testMethod() 16:25:44 INFO - File "Z:\task_1518711490\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 211, in test_replace_with_external_profile 16:25:44 INFO - self.marionette.start_session() 16:25:44 INFO - File "Z:\task_1518711490\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 16:25:44 INFO - return func(*args, **kwargs) 16:25:44 INFO - File "Z:\task_1518711490\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1211, in start_session 16:25:44 INFO - self.start_binary(timeout) 16:25:44 INFO - File "Z:\task_1518711490\build\venv\lib\site-packages\marionette_driver\marionette.py", line 645, in start_binary 16:25:44 INFO - reraise(IOError, msg.format(timeout), tb) 16:25:44 INFO - File "Z:\task_1518711490\build\venv\lib\site-packages\marionette_driver\marionette.py", line 636, in start_binary 16:25:44 INFO - self.raise_for_port(timeout=timeout) 16:25:44 INFO - File "Z:\task_1518711490\build\venv\lib\site-packages\marionette_driver\marionette.py", line 716, in raise_for_port 16:25:44 INFO - self.host, self.port)) 16:25:44 INFO - TEST-INFO took 120351ms 16:25:44 INFO - Application command: Z:\task_1518711490\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\genericworker\appdata\local\temp\tmpb4dlwh.mozrunner 16:25:45 INFO - 1518711945260 Marionette DEBUG Received observer notification profile-after-change 16:25:45 INFO - 1518711945342 Marionette DEBUG Received observer notification command-line-startup 16:25:45 INFO - 1518711945342 Marionette DEBUG Received observer notification nsPref:changed 16:25:45 INFO - [DEBUG SHUTDOWN] Register: decoder=00000272BACA5400, count=1 16:25:45 INFO - [DEBUG SHUTDOWN] ShutdownDecoder: decoder: 'wmf software video decoder - yuv420' (00000272B32DC680) flush:1 16:25:45 INFO - [DEBUG SHUTDOWN] operator (): pool=00000272B8354520 shutdown=false count=0
This is a hang during startup.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=173552260&repo=autoland&lineNumber=31111 16:55:30 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile 16:55:30 INFO - 1523638530615 Marionette TRACE 3 -> [0,2,"WebDriver:DeleteSession",{}] 16:55:30 INFO - 1523638530617 Marionette TRACE 3 <- [1,2,null,{}] 16:55:30 INFO - 1523638530618 Marionette DEBUG Closed connection 3 16:55:30 INFO - 1523638530620 Marionette DEBUG Accepted connection 4 from 127.0.0.1:51649 16:55:30 INFO - 1523638530624 Marionette TRACE 4 -> [0,1,"WebDriver:NewSession",{}] 16:55:30 INFO - 1523638530626 Marionette DEBUG Register listener.js for window 2147483649 16:55:30 INFO - 1523638530628 Marionette TRACE 4 <- [1,1,null,{"sessionId":"ff32615f-d15e-43f7-94bf-5989bf142b9f","capabilities":{"browserName":"firefox","browserVersion":"61.0a ... 3637078\\AppData\\Local\\Temp\\tmpglfhdk.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 16:55:30 INFO - 1523638530630 Marionette TRACE 4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}] 16:55:30 INFO - 1523638530630 Marionette TRACE 4 <- [1,2,null,{}] 16:55:30 INFO - 1523638530633 Marionette TRACE 4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}] 16:55:30 INFO - 1523638530634 Marionette TRACE 4 <- [1,3,null,{}] 16:55:30 INFO - 1523638530642 Marionette TRACE 4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}] 16:55:30 INFO - 1523638530643 Marionette TRACE 4 <- [1,4,null,{}] 16:55:30 INFO - 1523638530648 Marionette TRACE 4 -> [0,5,"WebDriver:DeleteSession",{}] 16:55:30 INFO - 1523638530649 Marionette TRACE 4 <- [1,5,null,{}] 16:55:30 INFO - 1523638530651 Marionette DEBUG Closed connection 4 16:55:30 INFO - Application command: Z:\task_1523637078\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1523637078\appdata\local\temp\tmpwm_daaexternal 16:55:33 INFO - Application command: Z:\task_1523637078\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1523637078\appdata\local\temp\tmp4nrn4d.mozrunner 16:55:34 INFO - 1523638534313 Marionette DEBUG Received observer notification profile-after-change 16:57:34 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors 16:57:34 INFO - Traceback (most recent call last): 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 190, in run 16:57:34 INFO - self.tearDown() 16:57:34 INFO - File "Z:\task_1523637078\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 76, in tearDown 16:57:34 INFO - super(ExternalProfileMixin, self).tearDown() 16:57:34 INFO - File "Z:\task_1523637078\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 31, in tearDown 16:57:34 INFO - super(BaseProfileManagement, self).tearDown() 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 338, in tearDown 16:57:34 INFO - self.marionette.start_session() 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 16:57:34 INFO - return func(*args, **kwargs) 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1211, in start_session 16:57:34 INFO - self.start_binary(timeout) 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_driver\marionette.py", line 640, in start_binary 16:57:34 INFO - reraise(IOError, msg.format(timeout), tb) 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_driver\marionette.py", line 631, in start_binary 16:57:34 INFO - self.raise_for_port(timeout=timeout) 16:57:34 INFO - File "Z:\task_1523637078\build\venv\lib\site-packages\marionette_driver\marionette.py", line 711, in raise_for_port 16:57:34 INFO - self.host, self.port)) 16:57:34 INFO - TEST-INFO took 123544ms
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=182253904&repo=mozilla-central&lineNumber=31540 11:16:09 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile 11:16:09 INFO - 1528370169722 Marionette TRACE 3 -> [0,2,"WebDriver:DeleteSession",{}] 11:16:09 INFO - 1528370169726 Marionette TRACE 3 <- [1,2,null,{"value":null}] 11:16:09 INFO - 1528370169729 Marionette DEBUG Closed connection 3 11:16:09 INFO - 1528370169734 Marionette DEBUG Accepted connection 4 from 127.0.0.1:51992 11:16:09 INFO - 1528370169737 Marionette TRACE 4 -> [0,1,"WebDriver:NewSession",{}] 11:16:09 INFO - 1528370169742 Marionette DEBUG Register listener.js for window 2147483649 11:16:09 INFO - 1528370169755 Marionette TRACE 4 <- [1,1,null,{"sessionId":"b5f76eb9-0311-4b77-b522-53a163261899","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... 8368837\\AppData\\Local\\Temp\\tmphyxwsa.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] 11:16:09 INFO - 1528370169804 Marionette TRACE 4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}] 11:16:09 INFO - 1528370169805 Marionette TRACE 4 <- [1,2,null,{"value":null}] 11:16:09 INFO - 1528370169811 Marionette TRACE 4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}] 11:16:09 INFO - 1528370169812 Marionette TRACE 4 <- [1,3,null,{"value":null}] 11:16:09 INFO - 1528370169815 Marionette TRACE 4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}] 11:16:09 INFO - 1528370169818 Marionette TRACE 4 <- [1,4,null,{"value":null}] 11:16:09 INFO - 1528370169825 Marionette TRACE 4 -> [0,5,"WebDriver:DeleteSession",{}] 11:16:09 INFO - 1528370169827 Marionette TRACE 4 <- [1,5,null,{"value":null}] 11:16:09 INFO - Application command: Z:\task_1528368837\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1528368837\appdata\local\temp\tmpl_rhzfexternal 11:16:10 INFO - *** You are running in headless mode. 11:16:21 INFO - 1528370181422 Marionette INFO Listening on port 2828 11:16:21 INFO - JavaScript error: resource://normandy/lib/NormandyApi.jsm, line 59: TypeError: is not a valid URL. 11:16:22 INFO - Application command: Z:\task_1528368837\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\task_1528368837\appdata\local\temp\tmplulozz.mozrunner 11:16:22 INFO - *** You are running in headless mode. 11:16:24 INFO - 1528370184983 Marionette DEBUG Received observer notification profile-after-change 11:16:25 INFO - 1528370185191 Marionette DEBUG Received observer notification command-line-startup 11:16:25 INFO - 1528370185191 Marionette DEBUG Received observer notification nsPref:changed 11:16:25 INFO - 1528370185192 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) 11:18:22 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors 11:18:22 INFO - Traceback (most recent call last): 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 190, in run 11:18:22 INFO - self.tearDown() 11:18:22 INFO - File "Z:\task_1528368837\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 76, in tearDown 11:18:22 INFO - super(ExternalProfileMixin, self).tearDown() 11:18:22 INFO - File "Z:\task_1528368837\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 31, in tearDown 11:18:22 INFO - super(BaseProfileManagement, self).tearDown() 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 338, in tearDown 11:18:22 INFO - self.marionette.start_session() 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _ 11:18:22 INFO - return func(*args, **kwargs) 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1210, in start_session 11:18:22 INFO - self.start_binary(timeout) 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_driver\marionette.py", line 639, in start_binary 11:18:22 INFO - reraise(IOError, msg.format(timeout), tb) 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_driver\marionette.py", line 630, in start_binary 11:18:22 INFO - self.raise_for_port(timeout=timeout) 11:18:22 INFO - File "Z:\task_1528368837\build\venv\lib\site-packages\marionette_driver\marionette.py", line 710, in raise_for_port 11:18:22 INFO - self.host, self.port))
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Missing `sessionstore-windows-restored` notification. So it's blocked on bug 1382162.
Depends on: 1382162
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 7 years ago6 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
(In reply to Intermittent Failures Robot from comment #19) > 1 failures in 2808 pushes (0.0 failures/push) were associated with this bug > in the last 7 days. This was wrongly classified because there was an assertion before, and as such should have been bug 1444701.
Flags: needinfo?(apavel)
(In reply to Henrik Skupin (:whimboo) from comment #20) > (In reply to Intermittent Failures Robot from comment #19) > > 1 failures in 2808 pushes (0.0 failures/push) were associated with this bug > > in the last 7 days. > > This was wrongly classified because there was an assertion before, and as > such should have been bug 1444701. Shouldn't both bugs be used in this case?
Flags: needinfo?(apavel) → needinfo?(hskupin)
(In reply to Andreea Pavel [:apavel] from comment #21) > > This was wrongly classified because there was an assertion before, and as > > such should have been bug 1444701. > > Shouldn't both bugs be used in this case? No, you cannot predict what will happen after an assertion. There can be nothing, but also a hang, or a crash. In the above case it crashed, so the test will clearly fail.
Flags: needinfo?(hskupin)
Oh, thank you for clarifying that Henrik. Sorry for all the questions :)
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=236180697&repo=mozilla-central&lineNumber=32135

19:09:26 INFO - Application command: Z:\task_1553626085\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile c:\users\task_1553626085\appdata\local\temp\tmpqicrbiexternal
19:09:26 INFO - *** You are running in headless mode.
19:11:26 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithoutWorkspace.test_replace_with_external_profile | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors
19:11:26 INFO - Traceback (most recent call last):
19:11:26 INFO - File "Z:\task_1553626085\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run
19:11:26 INFO - testMethod()
19:11:26 INFO - File "Z:\task_1553626085\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py", line 211, in test_replace_with_external_profile
19:11:26 INFO - self.marionette.start_session()
19:11:26 INFO - File "Z:\task_1553626085\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
19:11:26 INFO - return func(*args, **kwargs)
19:11:26 INFO - File "Z:\task_1553626085\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1103, in start_session
19:11:26 INFO - self.start_binary(timeout)
19:11:26 INFO - File "Z:\task_1553626085\build\venv\lib\site-packages\marionette_driver\marionette.py", line 491, in start_binary
19:11:26 INFO - reraise(IOError, msg.format(timeout), tb)
19:11:26 INFO - File "Z:\task_1553626085\build\venv\lib\site-packages\marionette_driver\marionette.py", line 482, in start_binary
19:11:26 INFO - self.raise_for_port(timeout=timeout)
19:11:26 INFO - File "Z:\task_1553626085\build\venv\lib\site-packages\marionette_driver\marionette.py", line 569, in raise_for_port
19:11:26 INFO - self.host, self.port))
19:11:26 INFO - TEST-INFO took 120349ms
19:11:26 INFO - Application command: Z:\task_1553626085\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile c:\users\task_1553626085\appdata\local\temp\tmpuqw2dj.mozrunner
19:11:26 INFO - *** You are running in headless mode.

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 6 years ago6 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.