Closed Bug 1414795 Opened 2 years ago Closed 2 years ago

Intermittent Automation Error: Exception caught while running tests in Android reftests after mozdevice ERROR | Non-zero return code (1) from ['adb', 'shell', 'rm', '-r', '/storage/sdcard/tests/reftest/profile']

Categories

(Firefox for Android :: Testing, defect, P5)

defect

Tracking

()

RESOLVED FIXED
Firefox 59
Tracking Status
firefox59 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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

https://treeherder.mozilla.org/logviewer.html#?job_id=142331092&repo=autoland

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

https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/PLu9rSVASu-k8c0E_z0oiA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2017-11-06T07:34:02.068Z] 07:34:02     INFO -  REFTEST TEST-START | http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2.htm != http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2-ref.htm
[task 2017-11-06T07:34:02.068Z] 07:34:02     INFO -  REFTEST INFO | RESTORE PREFERENCE pref(layout.css.ruby.intercharacter.enabled,false)
[task 2017-11-06T07:34:02.068Z] 07:34:02     INFO -  REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2.htm | 433 / 620 (69%)
[task 2017-11-06T07:34:02.068Z] 07:34:02     INFO -  REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2-ref.htm | 433 / 620 (69%)
[task 2017-11-06T07:34:02.068Z] 07:34:02     INFO -  REFTEST TEST-PASS | http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2.htm != http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2-ref.htm | image comparison, max difference: 255, number of differing pixels: 1975
[task 2017-11-06T07:34:02.068Z] 07:34:02     INFO -  REFTEST TEST-END | http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2.htm != http://10.0.2.2:8854/tests/layout/reftests/css-ruby/ruby-intercharacter-2-ref.htm
[task 2017-11-06T07:34:12.644Z] 07:34:12     INFO -  WARNING: Unable to retrieve log file (/storage/sdcard/tests/reftest/reftest.log) from remote device
[task 2017-11-06T07:34:12.685Z] 07:34:12     INFO -  mozdevice ERROR | Non-zero return code (1) from ['adb', 'shell', 'rm', '-r', '/storage/sdcard/tests/reftest/profile']
[task 2017-11-06T07:34:12.685Z] 07:34:12     INFO -  mozdevice ERROR | Output: ['error: no devices/emulators found']
[task 2017-11-06T07:34:12.727Z] 07:34:12     INFO -  mozdevice ERROR | Non-zero return code (1) from ['adb', 'shell', 'rm', '-r', '/storage/sdcard/tests/reftest/cache/']
[task 2017-11-06T07:34:12.727Z] 07:34:12     INFO -  mozdevice ERROR | Output: ['error: no devices/emulators found']
[task 2017-11-06T07:34:12.741Z] 07:34:12     INFO -  mozdevice ERROR | Non-zero return code (1) from ['adb', 'shell', 'rm', '-r', '/storage/sdcard/tests/reftest']
[task 2017-11-06T07:34:12.741Z] 07:34:12     INFO -  mozdevice ERROR | Output: ['error: no devices/emulators found']
[task 2017-11-06T07:34:12.748Z] 07:34:12     INFO -  Automation Error: Exception caught while running tests
[task 2017-11-06T07:34:12.749Z] 07:34:12     INFO -  Traceback (most recent call last):
[task 2017-11-06T07:34:12.749Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 456, in run_test_harness
[task 2017-11-06T07:34:12.750Z] 07:34:12     INFO -      retVal = reftest.runTests(options.tests, options)
[task 2017-11-06T07:34:12.750Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 524, in runTests
[task 2017-11-06T07:34:12.750Z] 07:34:12     INFO -      return self.runSerialTests(manifests, options, cmdargs)
[task 2017-11-06T07:34:12.751Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 812, in runSerialTests
[task 2017-11-06T07:34:12.754Z] 07:34:12     INFO -      debuggerInfo=debuggerInfo)
[task 2017-11-06T07:34:12.754Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 349, in runApp
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      timeout=timeout)
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/automation.py", line 555, in runApp
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      outputHandler=outputHandler)
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/remoteautomation.py", line 114, in waitForFinish
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      status = proc.wait(timeout = maxTime, noOutputTimeout = timeout)
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/remoteautomation.py", line 394, in wait
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      hasOutput = self.read_stdout()
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/tests/reftest/remoteautomation.py", line 329, in read_stdout
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      newLogContent = self.dm.pullFile(self.proc, self.stdoutlen)
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/devicemanagerADB.py", line 508, in pullFile
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      return tf2.read()
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -    File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozfile/mozfile.py", line 384, in __exit__
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -      os.unlink(self.__dict__['_path'])
[task 2017-11-06T07:34:12.755Z] 07:34:12     INFO -  OSError: [Errno 2] No such file or directory: '/tmp/tmpMLYdC9'
[task 2017-11-06T07:34:12.764Z] 07:34:12     INFO -  WARNING: Error getting device information
[task 2017-11-06T07:34:12.764Z] 07:34:12     INFO -  Exception OSError: (2, 'No such file or directory', '/tmp/tmpMLYdC9') in <bound method NamedTemporaryFile.__del__ of <mozfile.mozfile.NamedTemporaryFile object at 0x7faac348e850>> ignored
[task 2017-11-06T07:34:12.779Z] 07:34:12    ERROR - Return code: 1
Assignee: nobody → gbrown
This low frequency problem is likely a consequence of the adb upgrade last month. Sometimes when the emulator becomes unresponsive, devicemanager reports the error but fails to raise a DMError.

This patch updates the error handling for a range of devicemanager commands so that DMError is raised whenever a _checkCmd command returns the magic phrase "no devices/emulators found". DMError will trigger task retry.

Example:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=36819012944068af25bba186151348959a6ea6ee

https://treeherder.mozilla.org/logviewer.html#?job_id=154280019&repo=try&lineNumber=2349

[task 2018-01-05T03:08:39.744Z] 03:08:39     INFO -  REFTEST TEST-START | http://10.0.2.2:8854/tests/dom/base/crashtests/474041-1.svg
[task 2018-01-05T03:08:39.744Z] 03:08:39     INFO -  REFTEST TEST-LOAD | http://10.0.2.2:8854/tests/dom/base/crashtests/474041-1.svg | 149 / 887 (16%)
[task 2018-01-05T03:08:59.775Z] 03:08:59     INFO -  Failed to get top activity, retrying, once...
[task 2018-01-05T03:08:59.792Z] 03:08:59     INFO -  INFO | automation.py | Application ran for: 0:05:18.710633
[task 2018-01-05T03:08:59.793Z] 03:08:59     INFO -  INFO | zombiecheck | Reading PID log: /tmp/tmpYj5jylpidlog
[task 2018-01-05T03:08:59.798Z] 03:08:59     INFO -  /data/anr/traces.txt not found
[task 2018-01-05T03:08:59.826Z] 03:08:59     INFO -  WARNING: Unable to retrieve log file (/storage/sdcard/tests/reftest/reftest.log) from remote device
[task 2018-01-05T03:08:59.837Z] 03:08:59     INFO -  mozdevice ERROR | Non-zero return code (1) from ['adb', 'shell', 'rm', '-r', '/storage/sdcard/tests/reftest/profile']
[task 2018-01-05T03:08:59.838Z] 03:08:59     INFO -  mozdevice ERROR | Output: ['error: no devices/emulators found']
[task 2018-01-05T03:08:59.838Z] 03:08:59     INFO -  Automation Error: Exception caught while running tests
[task 2018-01-05T03:08:59.838Z] 03:08:59     INFO -  Traceback (most recent call last):
[task 2018-01-05T03:08:59.839Z] 03:08:59     INFO -    File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 455, in run_test_harness
[task 2018-01-05T03:08:59.839Z] 03:08:59     INFO -      retVal = reftest.runTests(options.tests, options)
[task 2018-01-05T03:08:59.840Z] 03:08:59     INFO -    File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 531, in runTests
[task 2018-01-05T03:08:59.840Z] 03:08:59     INFO -      return self.runSerialTests(manifests, options, cmdargs)
[task 2018-01-05T03:08:59.840Z] 03:08:59     INFO -    File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 852, in runSerialTests
[task 2018-01-05T03:08:59.841Z] 03:08:59     INFO -      self.cleanup(profileDir)
[task 2018-01-05T03:08:59.842Z] 03:08:59     INFO -    File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 362, in cleanup
[task 2018-01-05T03:08:59.842Z] 03:08:59     INFO -      self._devicemanager.removeDir(self.remoteProfile)
[task 2018-01-05T03:08:59.842Z] 03:08:59     INFO -    File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/devicemanagerADB.py", line 340, in removeDir
[task 2018-01-05T03:08:59.843Z] 03:08:59     INFO -      self._checkCmd(["shell", "rm", "-r", remoteDir], timeout=self.short_timeout)
[task 2018-01-05T03:08:59.844Z] 03:08:59     INFO -    File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/devicemanagerADB.py", line 752, in _checkCmd
[task 2018-01-05T03:08:59.844Z] 03:08:59 CRITICAL -      raise DMError(self._noDevicesOutput)
[task 2018-01-05T03:08:59.845Z] 03:08:59 CRITICAL -  DMError: no devices/emulators found
Attachment #8940241 - Flags: review?(jmaher)
Comment on attachment 8940241 [details] [diff] [review]
throw DMError for more cases where the emulator becomes unresponsive

Review of attachment 8940241 [details] [diff] [review]:
-----------------------------------------------------------------

thanks for keeping on top of this.
Attachment #8940241 - Flags: review?(jmaher) → review+
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/fac4ad28abfe
Throw DMError for more cases when no devices are found; r=jmaher
https://hg.mozilla.org/mozilla-central/rev/fac4ad28abfe
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 59
See Also: → 1439901
You need to log in before you can comment on or make changes to this bug.