1467740 - 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...

Reporter

Description

•

6 years ago

treeherder

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.

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 1

•

6 years ago

No "sessionstore-windows-restored" notification. So it depends on bug 1382162.

Depends on: 1382162

Comment hidden (Intermittent Failures Robot)

1 failures in 669 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1467740&startday=2018-06-04&endday=2018-06-10&tree=trunk

Firefox Bug Husbandry Bot

Comment 3

•

6 years ago

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

Status: NEW → RESOLVED

Closed: 6 years ago

Resolution: --- → INCOMPLETE

Eliza Balazs [:ebalazs_]

Comment 4

•

6 years ago

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 → ---

Andreas Tolfsen ❲:ato❳

Comment 5

•

6 years ago

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)

Comment hidden (Intermittent Failures Robot)

1 failures in 623 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1467740&startday=2018-07-09&endday=2018-07-15&tree=trunk

Firefox Bug Husbandry Bot

Comment 7

•

6 years ago

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

Status: REOPENED → RESOLVED

Closed: 6 years ago → 6 years ago

Resolution: --- → INCOMPLETE

BMO Automation

Updated

•

1 year ago

Product: Testing → Remote Protocol

BMO Automation

Comment 8

•

1 year ago

Moving bug to Testing::Marionette Client and Harness component per bug 1815831.

Component: Marionette → Marionette Client and Harness

Product: Remote Protocol → Testing

Bugzilla

Quick Search

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)

Tracking

(Not tracked)

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7

Updated

Comment 8