1503590 - Intermittent Android File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb_android.py", line 100, in __init__

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: csabou [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/NIPx0q5ST-KxBOoQ1g3pQQ/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/NIPx0q5ST-KxBOoQ1g3pQQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2018-10-31T14:36:22.950Z] 14:36:22     INFO - Running post-action listener: _resource_record_post_action
[task 2018-10-31T14:36:22.950Z] 14:36:22     INFO - Running post-action listener: _start_resource_monitoring
[task 2018-10-31T14:36:22.967Z] 14:36:22     INFO - Starting resource monitoring.
[task 2018-10-31T14:36:22.972Z] 14:36:22     INFO - [mozharness: 2018-10-31 14:36:22.971622Z] Finished create-virtualenv step (success)
[task 2018-10-31T14:36:22.972Z] 14:36:22     INFO - [mozharness: 2018-10-31 14:36:22.972088Z] Running verify-device step.
[task 2018-10-31T14:36:22.972Z] 14:36:22     INFO - Running pre-action listener: _resource_record_pre_action
[task 2018-10-31T14:36:22.972Z] 14:36:22     INFO - Running main action method: verify_device
[task 2018-10-31T14:36:22.972Z] 14:36:22     INFO - >> Check emulator: Attempt #1 of 5
[task 2018-10-31T14:36:22.972Z] 14:36:22     INFO - >> Verify Android boot completed: Attempt #1 of 30
[task 2018-10-31T14:36:22.987Z] 14:36:22     INFO - Using adb 1.0.40
[task 2018-10-31T14:36:26.205Z] 14:36:26     INFO - adbd running as root
[task 2018-10-31T14:36:26.205Z] 14:36:26     INFO - adbd restarted as root
[task 2018-10-31T14:36:26.412Z] 14:36:26     INFO - su 0 supported
[task 2018-10-31T14:36:26.621Z] 14:36:26     INFO - /system/bin/ls -1A supported
[task 2018-10-31T14:36:26.725Z] 14:36:26     INFO - Native cp support: True
[task 2018-10-31T14:36:26.828Z] 14:36:26     INFO - Native chmod -R support: True
[task 2018-10-31T14:36:26.932Z] 14:36:26     INFO - Native chown -R support: True
[task 2018-10-31T14:36:27.036Z] 14:36:27     INFO - Setting SELinux Permissive
[task 2018-10-31T14:36:27.244Z] 14:36:27     INFO - Running post-action listener: _resource_record_post_action
[task 2018-10-31T14:36:27.244Z] 14:36:27     INFO - [mozharness: 2018-10-31 14:36:27.244483Z] Finished verify-device step (failed)
[task 2018-10-31T14:36:27.245Z] 14:36:27    FATAL - Uncaught exception: Traceback (most recent call last):
[task 2018-10-31T14:36:27.245Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/base/script.py", line 2089, in run
[task 2018-10-31T14:36:27.245Z] 14:36:27    FATAL -     self.run_action(action)
[task 2018-10-31T14:36:27.245Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/base/script.py", line 2028, in run_action
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -     self._possibly_run_method(method_name, error_if_missing=True)
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/base/script.py", line 1983, in _possibly_run_method
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -     return getattr(self, method_name)()
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 489, in verify_device
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -     "Check emulator")
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 232, in _retry
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -     status = func()
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 196, in _verify_emulator_and_restart_on_fail
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -     emulator_ok = self._verify_emulator()
[task 2018-10-31T14:36:27.246Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 189, in _verify_emulator
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -     max_time=330)
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 232, in _retry
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -     status = func()
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 331, in is_boot_completed
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -     out = self.device.get_prop('sys.boot_completed', timeout=30)
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -   File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/android.py", line 64, in device
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -     verbose=True)
[task 2018-10-31T14:36:27.247Z] 14:36:27    FATAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb_android.py", line 100, in __init__
[task 2018-10-31T14:36:27.248Z] 14:36:27    FATAL -     timeout=timeout))
[task 2018-10-31T14:36:27.248Z] 14:36:27    FATAL - ValueError: invalid literal for int() with base 10: ''
[task 2018-10-31T14:36:27.248Z] 14:36:27    FATAL - Running post_fatal callback...
[task 2018-10-31T14:36:27.248Z] 14:36:27    FATAL - Exiting -1
[task 2018-10-31T14:36:27.248Z] 14:36:27     INFO - Running post-run listener: _resource_record_post_run
[task 2018-10-31T14:36:27.292Z] 14:36:27     INFO - Total resource usage - Wall time: 4s; CPU: 37.0%; Read bytes: 0; Write bytes: 2401280; Read time: 0; Write time: 0
[task 2018-10-31T14:36:27.292Z] 14:36:27     INFO - TinderboxPrint: CPU usage<br/>37.3%
[task 2018-10-31T14:36:27.292Z] 14:36:27     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2018-10-31T14:36:27.292Z] 14:36:27     INFO - TinderboxPrint: I/O write bytes / time<br/>2,401,280 / 0
[task 2018-10-31T14:36:27.293Z] 14:36:27     INFO - TinderboxPrint: CPU guest<br/>2.3 (6.6%)
[task 2018-10-31T14:36:27.293Z] 14:36:27     INFO - TinderboxPrint: CPU idle<br/>20.1 (58.5%)
[task 2018-10-31T14:36:27.293Z] 14:36:27     INFO - TinderboxPrint: CPU system<br/>1.2 (3.6%)
[task 2018-10-31T14:36:27.293Z] 14:36:27     INFO - TinderboxPrint: CPU user<br/>10.7 (31.1%)
[task 2018-10-31T14:36:27.293Z] 14:36:27     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2018-10-31T14:36:27.293Z] 14:36:27     INFO - verify-device - Wall time: 4s; CPU: 37.0%; Read bytes: 0; Write bytes: 2401280; Read time: 0; Write time: 0

Comment 1

[Intermittent Failures Robot]

57 failures in 575 pushes (0.099 failures/push) were associated with this bug yesterday.

Repository breakdown:
* autoland: 21
* try: 36

Platform breakdown:
* android-em-7-0-x86: 57

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-10-31&endday=2018-10-31&tree=all

Comment 2

[Intermittent Failures Robot]

37 failures in 559 pushes (0.066 failures/push) were associated with this bug yesterday.

Repository breakdown:
* try: 36
* autoland: 1

Platform breakdown:
* android-em-7-0-x86: 37

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-11-01&endday=2018-11-01&tree=all

Comment 3

[Intermittent Failures Robot]

94 failures in 2978 pushes (0.032 failures/push) were associated with this bug in the last 7 days.

This is the #10 most frequent failure this week.

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. ** 

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 22
* try: 72

Platform breakdown:
* android-em-7-0-x86: 94

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-10-29&endday=2018-11-04&tree=all

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* android-hw-p2-8-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-11-12&endday=2018-11-18&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* android-hw-p2-8-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-11-12&endday=2018-11-18&tree=all

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1
* try: 2

Platform breakdown:
* android-em-7-0-x86: 2
* android-hw-p2-8-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-11-19&endday=2018-11-25&tree=all

Comment 7

[Bob Clary [:bc] (inactive)]

ValueError: invalid literal for int() with base 10: '' typically means we haven't finished booting for some reason. Though the mozharness/mozharness/mozilla/testing/android.py attempts to retry via the _retry method it does not catch exceptions when it calls func(). If it caught ADBError and ValueError and kept trying for the maximum attempts it might help.

gbrown?

Comment 8

[Geoff Brown [:gbrown]]

Sounds good -- will give it a try.

Comment 9

[Geoff Brown [:gbrown]]

Attachment: translate ADBError and ValueError to simple failure in is_boot_completed

https://treeherder.mozilla.org/#/jobs?repo=try&revision=8e5a56393a1ed8cbdb1c3a510cb66183d6190ade

Comment 10

[Bob Clary [:bc] (inactive)]

Comment on attachment 9028026 [details] [diff] [review]
translate ADBError and ValueError to simple failure in is_boot_completed

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

r+ we can try it and see if it helps.

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c0caa96ca64a
Improve resilience when initializing mozdevice from mozharness; r=bc

Comment 12

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/c0caa96ca64a

Comment 13

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 2
* autoland: 2

Platform breakdown:
* android-em-7-0-x86: 2
* android-hw-p2-8-0-arm7-api-16: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2018-11-26&endday=2018-12-02&tree=all

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform breakdown:

• android-hw-p2-8-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1503590&startday=2019-01-21&endday=2019-01-27&tree=all