1230269 - Marionette cannot communicate with the device

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::UI Tests, defect)

Description

[Michael Bryant (uber)]

Device 15.1 in the MV QA lab is unable to communicate with marionette resulting in an inability to reboot successfully once gaiatest is initiated as part of automated test runs.

Build info:
Build ID               20151203170836
Gaia Revision          97266c579c544f5ba57a701f39893cc86d46774a
Gaia Date              2015-12-02 22:02:46
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/33d954cc69ff8e0bd22410e3641533e4fac500cf
Gecko Version          45.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.worker.20151203.162511
Firmware Date          Thu Dec  3 16:25:21 UTC 2015
Bootloader             L1TC000118D0

Comment 1

[No-Jun Park [:njpark]]

Error message:

09:44:51 + gaiatest --address=localhost:2828 --device=814fce53 --testvars=/home/webqa/webqa-credentials/b2g/common.json --log-html=results/index.html --log-mach=- --log-tbpl=tbpl.log --log-raw=raw.log --log-xunit=results.xml --locale=nl --testvars=/home/webqa/webqa-credentials/b2g/b2g-15.1.json --restart --type=b2g --reference-path=/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/reference_images --screenshots-path=/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/screenshots --fuzz-factor 20 gaiatest/tests/graphics/RTL/manifest.ini
09:44:51 + adb logcat -v threadtime
09:44:51  0:00.00 LOG: MainThread INFO Results will not be posted to Treeherder. Please set the following environment variables to enable Treeherder reports: TREEHERDER_KEY, TREEHERDER_SECRET
09:50:52 Traceback (most recent call last):
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/bin/gaiatest", line 9, in <module>
09:50:52     load_entry_point('gaiatest==0.33', 'console_scripts', 'gaiatest')()
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/tests/python/gaia-ui-tests/gaiatest/runtests.py", line 98, in main
09:50:52     cli(runner_class=GaiaTestRunner, parser_class=GaiaTestArguments)
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_client-1.0.0-py2.7.egg/marionette/runtests.py", line 59, in cli
09:50:52     runner = startTestRunner(runner_class, args)
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_client-1.0.0-py2.7.egg/marionette/runtests.py", line 38, in startTestRunner
09:50:52     runner.run_tests(tests)
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_client-1.0.0-py2.7.egg/marionette/runner/base.py", line 729, in run_tests
09:50:52     self.capabilities
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_client-1.0.0-py2.7.egg/marionette/runner/base.py", line 582, in capabilities
09:50:52     self.marionette.start_session()
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_driver-1.0.0-py2.7.egg/marionette_driver/marionette.py", line 1139, in start_session
09:50:52     resp = self._send_message("newSession", body)
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_driver-1.0.0-py2.7.egg/marionette_driver/decorators.py", line 36, in _
09:50:52     return func(*args, **kwargs)
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_driver-1.0.0-py2.7.egg/marionette_driver/marionette.py", line 686, in _send_message
09:50:52     resp = self.client.send(packet)
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_transport-0.7.1-py2.7.egg/marionette_transport/transport.py", line 109, in send
09:50:52     return self.receive()
09:50:52   File "/var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/.env/local/lib/python2.7/site-packages/marionette_transport-0.7.1-py2.7.egg/marionette_transport/transport.py", line 68, in receive
09:50:52     raise socket.timeout('connection timed out after %d s' % self.socket_timeout)
09:50:52 socket.timeout: connection timed out after 360 s
09:51:02 Process leaked file descriptors. See http://wiki.jenkins-ci.org/display/JENKINS/Spawning+processes+from+build for more information
09:51:02 Build step 'Execute shell' marked build as failure
09:51:02 Archiving artifacts
09:51:02 [htmlpublisher] Archiving HTML reports...
09:51:02 [htmlpublisher] Archiving at BUILD level /var/jenkins/1/workspace/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/tests/python/gaia-ui-tests/results to /var/lib/jenkins/jobs/flame-kk-512.mozilla-central.nightly.ui.graphics.dutch/builds/41/htmlreports/HTML_Report
09:51:02 Recording test results
09:51:02 Sending e-mails to: [e-mail]
09:51:02 Finished: FAILURE

Comment 2

[No-Jun Park [:njpark]]

This is reproducible locally with the same build.

Comment 3

[No-Jun Park [:njpark]]

Naoki, any clues why this might be happening?

Comment 4

[No-Jun Park [:njpark]]

happens with Aries as well, on following build: 

Build ID               20151203171413
Gaia Revision          97266c579c544f5ba57a701f39893cc86d46774a
Gaia Date              2015-12-02 22:02:46
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/33d954cc69ff8e0bd22410e3641533e4fac500cf
Gecko Version          45.0a1
Device Name            aries
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.worker.20151203.163240
Firmware Date          Thu Dec  3 16:32:48 UTC 2015
Bootloader             s1

when checking for regression range, only on flame device should suffice.

Comment 5

[Andreas Tolfsen ❲:ato❳]

Can you please provide a Gecko log of the failing build?

Comment 6

[No-Jun Park [:njpark]]

Attachment: noconnection.log

logcat when gaiatest was triggered and there was no response from the device.  (I killed in after a minute or so)

Comment 7

[Johan Lorenzo [:jlorenzo]]

Taking the regression window.

Comment 8

[Johan Lorenzo [:jlorenzo]]

Here are the resulsts coming from the Jenkins brick jobs[1]:

                | Last working            | First broken
----------------|-------------------------|------------------
mozilla-central | Gecko: 31fc97d173b3     | 85cf2e720a84
                | BuildId: 20151203030224 | 20151203053521
----------------|-------------------------|------------------
b2g-inbound     | Gecko: 565c48fdefde     | 51fd1f4ffae1
                | BuildId: 20151203020022 | 20151203031229
----------------|-------------------------|------------------
mozilla-inbound | Gecko: 349b2d9ac5aa     | 01480efcc281
                | BuildId: 20151202051302 | 20151202055302

That's a commit comming form mozilla-inbound - 85cf2e720a84 on central is an inbound merge, and 51fd1f4ffae1 on b2g-inbound is a merge from central.

The regression window[2] points out bug 1211489.

[1] http://jenkins1.qa.scl3.mozilla.com/view/Brick/
[2] https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=349b2d9ac5aa&tochange=01480efcc281l

Comment 9

[Andreas Tolfsen ❲:ato❳]

The log suggests the packet the server receives from the client is unrecognised:

/Gecko   (  207): 1449162694891	Marionette	INFO	Accepted connection conn2 from 127.0.0.1:52205
I/Gecko   (  207): 1449162694905	Marionette	INFO	Closed connection conn2
I/GeckoDump(  207): Handler function DebuggerTransport instance's this.hooks.onPacket threw an exception: TypeError: Unrecognised message type in packet: {"name":"newSession","parameters":{"sessionId":null,"capabilities":null}}
I/GeckoDump(  207): Stack: Message.fromMsg@chrome://marionette/content/message.js:53:1
I/GeckoDump(  207): Dispatcher.prototype.onPacket@chrome://marionette/content/dispatcher.js:80:13
I/GeckoDump(  207): DebuggerTransport.prototype._onJSONObjectReady/<@chrome://marionette/content/server.js -> resource://devtools/shared/transport/transport.js:479:9
I/GeckoDump(  207): makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/DevToolsUtils.js:87:14
I/GeckoDump(  207): makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/DevToolsUtils.js:87:14
I/GeckoDump(  207): Line: 53, column: 1

I wrote an email to tools-marionette@ last week saying that existing clients would break unless they were upgraded to reasonably modern versions: https://groups.google.com/forum/#!topic/mozilla.tools.marionette/ZVWNINCjrTQ

Can you please try upgrading to at least the said versions in that email?

Comment 10

[Martijn Wargers (dead)]

Pip freeze gives me this:
You are using pip version 6.0.8, however version 7.1.2 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
b2g-util==0.0.12
blessings==1.6
boto==2.38.0
browsermob-proxy==0.7.1
easygui==0.97.2
gaiatest==0.33
httplib2==0.9.1
manifestparser==1.1
marionette-client==1.0.0
marionette-driver==1.0.0
marionette-transport==0.7.1
mozcrash==0.16
mozdevice==0.47
mozfile==1.2
mozhttpd==0.7
mozinfo==0.9
mozlog==3.0
moznetwork==0.27
mozprocess==0.22
mozprofile==0.27
mozrunner==6.11
moztest==0.7
mozversion==1.4
oauth2==1.9.0.post1
Pillow==2.9.0
plivo==0.10.1
progressbar==2.3
PyHawk-with-a-single-extra-commit==0.1.5
requests==2.7.0
slugid==1.0.6
taskcluster==0.0.27
taskcluster-util==0.0.16
treeherder-client==1.5

Comment 11

[Andreas Tolfsen ❲:ato❳]

It might be I got the version number in that email wrong.  Can you try marionette-driver 1.1.1?  The required version of marionette-transport is 1.0.0.

Comment 12

[GitHub Autolander Bot]

Attachment: [gaia] JohanLorenzo:bug-1230269 > mozilla-b2g:master

Comment 13

[Johan Lorenzo [:jlorenzo]]

I locally ran marionette-client v2.0.0 and marionette-driver v1.1.1 => The brick test passed fine. Moving this bug to UI::Tests as we can fix it from there.

Comment 14

[Johan Lorenzo [:jlorenzo]]

Comment on attachment 8695819 [details] [review]
[gaia] JohanLorenzo:bug-1230269 > mozilla-b2g:master

I propose to have only 1 reviewer for this small dependencies upgrade. This way, we can get Jenkins back up before No-Jun awakes. What do you think?

Comment 15

[Martijn Wargers (dead)]

Comment on attachment 8695819 [details] [review]
[gaia] JohanLorenzo:bug-1230269 > mozilla-b2g:master

Yes, that makes things work again for me.

Comment 16

[Johan Lorenzo [:jlorenzo]]

Landed in master at: https://github.com/mozilla-b2g/gaia/commit/ff662257263e9d71f8202d9d61a1b2035944e346