1401567 - Intermittent Return code: 1 after Marionette error on startup

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=132223303&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/GMvXsSftSdmJ8mzDOzJq6Q/runs/0/artifacts/public/logs/live_backing.log

13:03:35     INFO -  Application command: Z:\task_1505907104\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\genericworker\appdata\local\temp\tmp9mqtev.mozrunner
13:03:35     INFO -  Profile path is c:\users\genericworker\appdata\local\temp\tmp9mqtev.mozrunner
13:03:35     INFO -  Starting fixture servers
13:03:35     INFO -  *** You are running in headless mode.
13:03:35     INFO -  1505912615876	Marionette	DEBUG	Received observer notification "profile-after-change"
13:03:35     INFO -  1505912615939	Marionette	DEBUG	Received observer notification "command-line-startup"
13:03:35     INFO -  1505912615939	Marionette	INFO	Enabled via --marionette
13:03:36     INFO -  Unable to read VR Path Registry from C:\Users\GenericWorker\AppData\Local\openvr\openvrpaths.vrpath
13:03:36     INFO -  [Parent 11244, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:03:36     INFO -  Unable to read VR Path Registry from C:\Users\GenericWorker\AppData\Local\openvr\openvrpaths.vrpath
13:03:36     INFO -  [Child 5008, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:03:36     INFO -  [Child 5008, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:03:36     INFO -  1505912616932	Marionette	DEBUG	Received observer notification "sessionstore-windows-restored"
13:03:37     INFO -  1505912617290	Marionette	INFO	Listening on port 2828
13:17:36     INFO -  {"thread": "MainThread", "level": "ERROR", "pid": 3744, "source": "Marionette test runner", "time": 1505913456460, "action": "log", "message": "Failure during harness execution", "stack": "Traceback (most recent call last):\n\n  File \"Z:\\task_1505907104\\build\\tests\\marionette\\harness\\marionette_harness\\runtests.py\", line 92, in cli\n    failed = harness_instance.run()\n\n  File \"Z:\\task_1505907104\\build\\tests\\marionette\\harness\\marionette_harness\\runtests.py\", line 72, in run\n    runner.run_tests(tests)\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_harness\\runner\\base.py\", line 844, in run_tests\n    self.fixture_servers = self.start_fixture_servers()\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_harness\\runner\\base.py\", line 944, in start_fixture_servers\n    if self.appName == \"fennec\":\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_harness\\runner\\base.py\", line 678, in appName\n    self._appName = self.capabilities.get('browserName')\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_harness\\runner\\base.py\", line 668, in capabilities\n    self.marionette.start_session()\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\decorators.py\", line 23, in _\n    return func(*args, **kwargs)\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py\", line 1247, in start_session\n    resp = self._send_message(\"newSession\", body)\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\decorators.py\", line 28, in _\n    m._handle_socket_failure()\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\decorators.py\", line 23, in _\n    return func(*args, **kwargs)\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py\", line 751, in _send_message\n    msg = self.client.request(name, params)\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\transport.py\", line 284, in request\n    return self.receive()\n\n  File \"Z:\\task_1505907104\\build\\venv\\lib\\site-packages\\marionette_driver\\transport.py\", line 211, in receive\n    raise socket.timeout(\"Connection timed out after {}s\".format(self.socket_timeout))\n\nIOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)\n"}
13:17:36    ERROR - Return code: 1
13:17:36     INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
13:17:36     INFO - gecko.log not found
13:17:36     INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
13:17:36     INFO - Marionette exited with return code 1: FAILURE
13:17:36    ERROR - # TBPL FAILURE #
13:17:36  WARNING - setting return code to 2

Comment 1

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

There is the structured log entry at 13:17:36 which has not been decoded correctly. As such the strange error message.

But basically this is just bug 1401689. Keeping this bug open in cases such a failure happens again.

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401567&startday=2017-09-18&endday=2017-09-24&tree=all

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401567&startday=2017-10-02&endday=2017-10-08&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 2

Platform breakdown:
* windows10-64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401567&startday=2017-10-09&endday=2017-10-15&tree=all

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows10-64-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401567&startday=2017-10-16&endday=2017-10-22&tree=all

Comment 7

[Intermittent Failures Robot]

6 failures in 912 pushes (0.007 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 4
* autoland: 2

Platform breakdown:
* windows10-64: 6

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401567&startday=2017-10-23&endday=2017-10-29&tree=all

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1401567&startday=2017-10-30&endday=2017-11-05&tree=all

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows10-64: 1

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

Comment 10

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

Looks like this has stopped about 7 months ago.

Comment 11

[BMO Automation]

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