Intermittent B2G "marionette.errors.TimeoutException: socket.timeout" (apparent emulator hang on startup)

RESOLVED WORKSFORME

Status

Firefox OS
General
RESOLVED WORKSFORME
5 years ago
3 years ago

People

(Reporter: emorley, Unassigned)

Tracking

({intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

(Reporter)

Description

5 years ago
Probably just a dupe of some of the other bugs, but I find these failure modes fairly unhelpful to grok (ideally we'd have all socket.timeouts caught and a constant message given, if they re all due to the same emulator issue)

b2g_ics_armv7a_gecko_emulator mozilla-inbound opt test reftest-6 on 2013-01-11 00:43:14 PST for push 11879a83e5e7

slave: talos-r3-fed-079

https://tbpl.mozilla.org/php/getParsedLog.php?id=18702752&tree=Mozilla-Inbound

{
00:48:40     INFO -  REFTEST INFO | runreftest.py | Running tests: start.
00:48:45     INFO -  MOZPROCESS WARNING: ProcessHandler.waitForFinish() is deprecated, use ProcessHandler.wait() instead
00:52:04     INFO -  Traceback (most recent call last):
00:52:04     INFO -    File "runreftestb2g.py", line 564, in main
00:52:04     INFO -      retVal = reftest.runTests(manifest, options, cmdlineArgs)
00:52:04     INFO -    File "/home/cltbld/talos-slave/test/build/tests/reftest/runreftest.py", line 140, in runTests
00:52:04     INFO -      timeout=options.timeout + 30.0)
00:52:04     INFO -    File "/home/cltbld/talos-slave/test/build/tests/reftest/automation.py", line 1072, in runApp
00:52:04     INFO -      stderr = subprocess.STDOUT)
00:52:04     INFO -    File "/home/cltbld/talos-slave/test/build/tests/reftest/b2gautomation.py", line 253, in Process
00:52:04     INFO -      session = self.marionette.start_session()
00:52:04     INFO -    File "/home/cltbld/talos-slave/test/build/venv/lib/python2.6/site-packages/marionette/marionette.py", line 306, in start_session
00:52:04     INFO -      self.session = self._send_message('newSession', 'value')
00:52:04     INFO -    File "/home/cltbld/talos-slave/test/build/venv/lib/python2.6/site-packages/marionette/marionette.py", line 212, in _send_message
00:52:04    ERROR -      raise TimeoutException(message='socket.timeout', status=ErrorCodes.TIMEOUT, stacktrace=None)
00:52:04    ERROR -  TimeoutException: socket.timeout
00:52:04     INFO -  Automation Error: Exception caught while running tests
}
https://tbpl.mozilla.org/php/getParsedLog.php?id=20150580&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=20170963&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=20196290&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=20203241&tree=Firefox
https://tbpl.mozilla.org/php/getParsedLog.php?id=20343168&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=20349987&tree=Mozilla-Inbound
(Reporter)

Comment 6

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=20409869&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=20579213&tree=Mozilla-Inbound
(Reporter)

Comment 8

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=20637577&tree=Mozilla-Inbound
(Reporter)

Comment 9

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=20646184&tree=Firefox
https://tbpl.mozilla.org/php/getParsedLog.php?id=20733353&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21120759&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21222453&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21344915&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21380947&tree=Firefox
https://tbpl.mozilla.org/php/getParsedLog.php?id=21431782&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21448724&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21455473&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21464291&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21493815&tree=Fx-Team
https://tbpl.mozilla.org/php/getParsedLog.php?id=21463429&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21539624&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=21541138&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21577403&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=21581398&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21593833&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21618511&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21622535&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21667390&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21704008&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21733342&tree=Mozilla-B2g18
https://tbpl.mozilla.org/php/getParsedLog.php?id=21786487&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21803955&tree=Mozilla-B2g18
https://tbpl.mozilla.org/php/getParsedLog.php?id=21918700&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=21922088&tree=Mozilla-B2g18
https://tbpl.mozilla.org/php/getParsedLog.php?id=22292695&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=22337342&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22369809&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22374121&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22591641&tree=Mozilla-B2g18_v1_0_1
https://tbpl.mozilla.org/php/getParsedLog.php?id=22628102&tree=Mozilla-B2g18
https://tbpl.mozilla.org/php/getParsedLog.php?id=22693670&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=22698472&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=22729182&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22789096&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22804018&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22882080&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=22976746&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=23060844&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=23095454&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=23195554&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=23213636&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23295758&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23360324&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=23400326&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23402267&tree=Fx-Team
https://tbpl.mozilla.org/php/getParsedLog.php?id=23438667&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23480818&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23485037&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23549530&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23561763&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23588124&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=23596982&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23636012&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23665880&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23683428&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23729471&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23760154&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23766676&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=23835181&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23914838&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23914993&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=23944330&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=23959208&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=23983244&tree=Mozilla-Inbound
(Reporter)

Comment 74

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=24002762&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=24016801&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24019716&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24065511&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24076157&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=24087630&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24093137&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24093295&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=24094420&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24105027&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24105345&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24111404&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24132779&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=24149603&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24154481&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24163871&tree=Mozilla-Inbound

I'd be remiss if I didn't point out that basically every single one of these happens at the same point. Jonathan, any ideas?

13:17:58     INFO -  copying /data/local/b2g/dictionaries/en-US.aff to /system/b2g/dictionaries/en-US.aff
13:17:58     INFO -  copying /data/local/b2g/dictionaries/en-US.dic to /system/b2g/dictionaries/en-US.dic
13:17:58     INFO -  restarting B2G
13:17:58     INFO -  Traceback (most recent call last):
13:17:58     INFO -    File "runreftestb2g.py", line 573, in <module>
13:17:58     INFO -      sys.exit(main())
13:17:58     INFO -    File "runreftestb2g.py", line 493, in main
13:17:58     INFO -      marionette = Marionette.getMarionetteOrExit(**kwargs)
13:17:58     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/marionette.py", line 291, in getMarionetteOrExit
13:17:58     INFO -      m = cls(*args, **kwargs)
13:17:58     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/marionette.py", line 266, in __init__
13:17:58     INFO -      busybox=busybox)
13:17:58     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/emulator.py", line 353, in setup
13:17:58     INFO -      self.wait_for_system_message(marionette)
13:17:58     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/emulator.py", line 256, in wait_for_system_message
13:17:58     INFO -      marionette.start_session()
13:17:58     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/marionette.py", line 444, in start_session
13:17:58     INFO -      self.session = self._send_message('newSession', 'value')
13:17:58     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/marionette.py", line 340, in _send_message
13:17:58    ERROR -      raise TimeoutException(message='socket.timeout', status=ErrorCodes.TIMEOUT, stacktrace=None)
13:17:58    ERROR -  marionette.errors.TimeoutException: socket.timeout
Flags: needinfo?(jgriffin)
This has something to do with the way we're updating gecko in these static emulator snapshots.  The good news is, as soon as we get tests running against the full-stack emulator builds (which will be soon), this error will go away since we'll no longer be updating gecko.
Flags: needinfo?(jgriffin)
https://tbpl.mozilla.org/php/getParsedLog.php?id=24233848&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24240618&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24290098&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24298788&tree=Birch
(Reporter)

Comment 95

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=24556945&tree=Birch
(Reporter)

Comment 96

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=24567759&tree=Mozilla-Inbound
(Reporter)

Comment 97

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=24653002&tree=Birch
(Reporter)

Comment 98

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=24657869&tree=Mozilla-Inbound
(Reporter)

Comment 99

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=24658102&tree=Birch
https://tbpl.mozilla.org/php/getParsedLog.php?id=24799022&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=24799581&tree=Birch
And another probably 30 per day - I can't be bothered to paste links into a "we're going to redo everything to get new and different bugs instead!" bug.
https://tbpl.mozilla.org/php/getParsedLog.php?id=25100003&tree=Mozilla-Inbound

Weren't the full-stack emulator tests going to save us?
https://tbpl.mozilla.org/php/getParsedLog.php?id=25136785&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=25139973&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=25150232&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=25172317&tree=Mozilla-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=25175144&tree=Mozilla-Inbound

What philor said.
Flags: needinfo?(jgriffin)
It was our hope that this error had something to do with updating gecko in the emulator at the beginning of a run, but apparently that was not the case.  :(

From the log, it looks like the emulator is hanging on startup.

I expect to see this in the logcat, indicating that Gaia has loaded:

I/Gecko   (   43): ###################################### forms.js loaded
I/Gecko   (   43): ############################### browserElementPanning.js loaded
I/Gecko   (   43): ######################## BrowserElementChildPreload.js loaded

But in these failing logs, this output never appears, which would seem to indicate that Gaia is never loaded.

I'll try to escalate this.
Flags: needinfo?(jgriffin)
Summary: Intermittent B2G "TimeoutException: socket.timeout" → Intermittent B2G "TimeoutException: socket.timeout" (apparent emulator hang on startup)
https://tbpl.mozilla.org/php/getParsedLog.php?id=25195677&tree=Mozilla-Inbound
(Reporter)

Updated

4 years ago
Depends on: 892958
(Reporter)

Comment 111

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=25412461&tree=Mozilla-Inbound
Summary: Intermittent B2G "TimeoutException: socket.timeout" (apparent emulator hang on startup) → Intermittent B2G "marionette.errors.TimeoutException: socket.timeout" (apparent emulator hang on startup)
(Reporter)

Comment 112

4 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=25418756&tree=Mozilla-Central
https://tbpl.mozilla.org/php/getParsedLog.php?id=26040134&tree=Try
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Reporter)

Comment 138

3 years ago
Closing bugs where TBPLbot has previously commented, but have now not been modified for >3 months & do not contain the whiteboard strings for disabled/annotated tests or use the keyword leave-open. Filter on: mass-intermittent-bug-closure-2014-07
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.