1027597 - B2G reftest timeouts are outputting only "TimeoutException: TimeoutException: Connection timed out"

Status: RESOLVED WONTFIX

(Testing :: Reftest, defect, P2)

Description

[Ed Morley [:emorley]]

In:
https://tbpl.mozilla.org/php/getParsedLog.php?id=42039025&tree=Mozilla-Inbound#error0
03:03:27     INFO -  INFO | remotereftests.py | Server pid: 1779
03:03:40     INFO -  REFTEST INFO | runreftest.py | Running tests: start.
03:10:45     INFO -  Traceback (most recent call last):
03:10:45     INFO -    File "runreftestb2g.py", line 585, in run_remote_reftests
03:10:45     INFO -      retVal = reftest.runTests(manifest, options, cmdlineArgs)
03:10:45     INFO -    File "/builds/slave/test/build/tests/reftest/runreftest.py", line 244, in runTests
03:10:45     INFO -      return self.runSerialTests(testPath, options, cmdlineArgs)
03:10:45     INFO -    File "/builds/slave/test/build/tests/reftest/runreftest.py", line 340, in runSerialTests
03:10:45     INFO -      timeout=options.timeout + 30.0)
03:10:45     INFO -    File "/builds/slave/test/build/tests/reftest/automation.py", line 857, in runApp
03:10:45     INFO -      stderr = subprocess.STDOUT)
03:10:45     INFO -    File "/builds/slave/test/build/tests/reftest/b2gautomation.py", line 270, in Process
03:10:45     INFO -      session = self.marionette.start_session()
03:10:45     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/marionette.py", line 759, in start_session
03:10:45     INFO -      self.session = self._send_message('newSession', 'value')
03:10:45     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/decorators.py", line 35, in _
03:10:45     INFO -      return func(*args, **kwargs)
03:10:45     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/marionette.py", line 627, in _send_message
03:10:45     INFO -      "Connection timed out", status=ErrorCodes.TIMEOUT)
03:10:45    ERROR -  TimeoutException: TimeoutException: Connection timed out
03:10:45     INFO -  Automation Error: Exception caught while running tests
03:10:45    ERROR - Return code: 1
03:10:45     INFO - dumping logcat

There are a few issues:
1) Where did we time out? At startup? In which case the timeout message should be something like:
TEST-UNEXPECTED-FAIL | B2G Startup | TimeoutException: TimeoutException: Connection timed out
(see the proposal in bug 1023935).

2) Log level ERROR was used for:
03:10:45    ERROR -  TimeoutException: TimeoutException: Connection timed out
...which means that TBPL matches against it and tries to search for bugs, but bails after finding too many results.

Jonathan, don't suppose you could find someone to look at this? :-)

Comment 1

[Jonathan Griffin (:jgriffin)]

This is undeniably ugly.  This actually looks like our generic emulator networking problem, but it's logged very unhelpfully.

To fix it, I think we'll need to do a little refactoring of b2gautomation.py (which is only used by B2G reftests IIRC) and the related mozharness scripts, similar to what we did in bug 1017559.

I put it on the list of things to track for Q3, but if it becomes so bothersome you think we need to address it immediately, let me know.