Closed
Bug 1174756
Opened 9 years ago
Closed 9 years ago
Android emulator checks for boot completed can take hours in pathological worst case
Categories
(Testing :: General, defect)
Testing
General
Tracking
(firefox41 affected)
RESOLVED
FIXED
Tracking | Status | |
---|---|---|
firefox41 | --- | affected |
People
(Reporter: gbrown, Assigned: gbrown)
Details
Attachments
(1 file)
5.58 KB,
patch
|
kmoir
:
review+
|
Details | Diff | Splinter Review |
To assist in diagnosing test failures, Android emulator jobs verify emulator connectivity during the stop-emulator step. One such check is to verify that "getprop sys.boot_completed" returns 1, indicating that Android has booted; if there is no response, or if the response is not "1", stop-emulator retries up to 30 times, pausing for 10 seconds between each attempt. The expectation is that this procedure will complete in under 30x10 = 300 seconds, or 5 minutes. That seems reasonable. BUT, if adb hangs, each adb call will not return for the specified timeout of 5 minutes, so there can be a delay of up to 30*(300+10) = 9300 seconds, or 155 minutes -- way too long! Of course, this actually happens: http://ftp.mozilla.org/pub/mozilla.org/mobile/tinderbox-builds/mozilla-inbound-android-api-11/1434152741/mozilla-inbound_ubuntu64_vm_armv7_mobile_test-mochitest-14-bm52-tests1-linux64-build213.txt.gz 19:22:17 INFO - ##### 19:22:17 INFO - ##### Running stop-emulator step. 19:22:17 INFO - ##### 19:22:17 INFO - Running pre-action listener: _resource_record_pre_action 19:22:17 INFO - Running main action method: stop_emulator 19:22:17 INFO - Verifying adb connectivity 19:22:17 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb wait-for-device 19:22:18 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb devices 19:22:18 INFO - List of devices attached 19:22:18 INFO - emulator-5554 device 19:22:18 INFO - >> Verify Android boot completed: Attempt #1 of 30 19:22:18 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:27:18 INFO - Sleeping 10 seconds 19:27:28 INFO - >> Verify Android boot completed: Attempt #2 of 30 19:27:28 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:32:28 INFO - Sleeping 10 seconds 19:32:38 INFO - >> Verify Android boot completed: Attempt #3 of 30 19:32:38 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:37:38 INFO - Sleeping 10 seconds 19:37:48 INFO - >> Verify Android boot completed: Attempt #4 of 30 19:37:48 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:42:48 INFO - Sleeping 10 seconds 19:42:58 INFO - >> Verify Android boot completed: Attempt #5 of 30 19:42:58 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:47:58 INFO - Sleeping 10 seconds 19:48:08 INFO - >> Verify Android boot completed: Attempt #6 of 30 19:48:08 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:53:08 INFO - Sleeping 10 seconds 19:53:18 INFO - >> Verify Android boot completed: Attempt #7 of 30 19:53:18 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 19:58:18 INFO - Sleeping 10 seconds 19:58:28 INFO - >> Verify Android boot completed: Attempt #8 of 30 19:58:28 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:03:28 INFO - Sleeping 10 seconds 20:03:38 INFO - >> Verify Android boot completed: Attempt #9 of 30 20:03:38 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:08:38 INFO - Sleeping 10 seconds 20:08:48 INFO - >> Verify Android boot completed: Attempt #10 of 30 20:08:48 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:13:48 INFO - Sleeping 10 seconds 20:13:58 INFO - >> Verify Android boot completed: Attempt #11 of 30 20:13:58 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:18:58 INFO - Sleeping 10 seconds 20:19:08 INFO - >> Verify Android boot completed: Attempt #12 of 30 20:19:08 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:24:08 INFO - Sleeping 10 seconds 20:24:18 INFO - >> Verify Android boot completed: Attempt #13 of 30 20:24:18 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:29:18 INFO - Sleeping 10 seconds 20:29:28 INFO - >> Verify Android boot completed: Attempt #14 of 30 20:29:28 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:34:28 INFO - Sleeping 10 seconds 20:34:38 INFO - >> Verify Android boot completed: Attempt #15 of 30 20:34:38 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:39:38 INFO - Sleeping 10 seconds 20:39:48 INFO - >> Verify Android boot completed: Attempt #16 of 30 20:39:48 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:44:48 INFO - Sleeping 10 seconds 20:44:58 INFO - >> Verify Android boot completed: Attempt #17 of 30 20:44:58 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:49:58 INFO - Sleeping 10 seconds 20:50:08 INFO - >> Verify Android boot completed: Attempt #18 of 30 20:50:08 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 20:55:08 INFO - Sleeping 10 seconds 20:55:18 INFO - >> Verify Android boot completed: Attempt #19 of 30 20:55:18 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 21:00:18 INFO - Sleeping 10 seconds 21:00:28 INFO - >> Verify Android boot completed: Attempt #20 of 30 21:00:28 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 21:05:28 INFO - Sleeping 10 seconds 21:05:38 INFO - >> Verify Android boot completed: Attempt #21 of 30 21:05:38 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 21:10:38 INFO - Sleeping 10 seconds 21:10:48 INFO - >> Verify Android boot completed: Attempt #22 of 30 21:10:48 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 21:15:48 INFO - Sleeping 10 seconds 21:15:58 INFO - >> Verify Android boot completed: Attempt #23 of 30 21:15:58 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 21:20:58 INFO - Sleeping 10 seconds 21:21:08 INFO - >> Verify Android boot completed: Attempt #24 of 30 21:21:08 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 21:26:08 INFO - Sleeping 10 seconds 21:26:18 INFO - >> Verify Android boot completed: Attempt #25 of 30 21:26:18 INFO - Running timeout 300 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed command timed out: 14400 seconds elapsed running ['/tools/buildbot/bin/python', 'scripts/scripts/android_emulator_unittest.py', '--cfg', 'android/androidarm_4_3.py', '--test-suite', 'mochitest-14', '--blob-upload-branch', 'mozilla-inbound', '--download-symbols', 'ondemand'], attempting to kill
Assignee | ||
Comment 1•9 years ago
|
||
(In reply to Geoff Brown [:gbrown] from comment #0) > BUT, if adb hangs, each adb call will not return for the specified timeout > of 5 minutes, so there can be a delay of up to 30*(300+10) = 9300 seconds, > or 155 minutes -- way too long! The 300 second timeout on adb is excessive, at least for a simple command like getprop. Reducing to 30 seconds gives a maximum time of 30*(30+10) = 1200 seconds, or 20 minutes. That's still too long, but a great improvement. We can reduce the timeout for other adb commands like "ps", but we should keep 300 seconds for, for instance, "adb wait-for-device", which we expect to sometimes take a couple of minutes.
Assignee | ||
Comment 2•9 years ago
|
||
This makes 2 changes: - Reduce the time-out for some simple adb commands from 300 seconds to 30 seconds. - Introduces an optional max-time parameter in _retry(): If specified and max-time seconds have elapsed, abandon further retry attempts. This is only used for the boot completion check, for now, with a 330 second max time. If adb is working but Android has not booted, we run 30 checks 10 seconds apart and complete in about 300 seconds; if adb is consistently hanging, each check takes 30 seconds for adb to time-out + 10 seconds for the retry interval and after about 9 attempts, further attempts are abandoned because it has taken more than 330 seconds.
Attachment #8622550 -
Flags: review?(kmoir)
Updated•9 years ago
|
Attachment #8622550 -
Flags: review?(kmoir) → review+
Assignee | ||
Comment 3•9 years ago
|
||
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cc970136ff89
Assignee | ||
Comment 4•9 years ago
|
||
https://hg.mozilla.org/build/mozharness/rev/038e0e12dcbd
Comment 5•9 years ago
|
||
mozharness production tag moved to: https://hg.mozilla.org/build/mozharness/rev/321d9dcec7b2
Assignee | ||
Comment 6•9 years ago
|
||
Verified: http://ftp.mozilla.org/pub/mozilla.org/mobile/tinderbox-builds/mozilla-inbound-android-api-11/1434524689/mozilla-inbound_ubuntu64_vm_armv7_large_test-crashtest-1-bm113-tests1-linux64-build107.txt.gz 02:38:00 INFO - >> Verify Android boot completed: Attempt #8 of 30 02:38:00 INFO - Running timeout 30 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 02:38:30 INFO - Sleeping 10 seconds 02:38:40 INFO - >> Verify Android boot completed: Attempt #9 of 30 02:38:40 INFO - Running timeout 30 /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 shell getprop sys.boot_completed 02:39:10 INFO - Maximum retry run-time of 330 seconds exceeded; remaining attempts abandoned 02:39:10 WARNING - Unable to verify Android boot completion 02:39:10 INFO - Let's kill every process called emulator64-arm
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
You need to log in
before you can comment on or make changes to this bug.
Description
•