1137320 - mozharness apk install sometimes fails on Android 4.3

Status: RESOLVED FIXED

(Testing :: General, defect)

Description

[Geoff Brown [:gbrown]]

apk installation infrequently fails on the Android 4.3 emulator.

http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/[e-mail]-9a7bba18541b/try-android-api-9/try_ubuntu64_vm_mobile_test-robocop-2-bm121-tests1-linux64-build3.txt.gz

16:43:22     INFO - Copy/paste: /tools/android-sdk18/platform-tools/adb -s emulator-5554 shell date
16:43:23     INFO - Reading from file tmpfile_stdout
16:43:23     INFO - Output received:
16:43:23     INFO -  Wed Feb 25 16:43:20 PST 2015
16:43:23     INFO - Wed Feb 25 16:43:20 PST 2015
16:43:23     INFO - Getting output from command: ['/tools/android-sdk18/platform-tools/adb', '-s', 'emulator-5554', 'shell', 'ls -d /data/data/org.mozilla.fennec']
16:43:23     INFO - Copy/paste: /tools/android-sdk18/platform-tools/adb -s emulator-5554 shell "ls -d /data/data/org.mozilla.fennec"
16:43:23     INFO - Reading from file tmpfile_stdout
16:43:23     INFO - Output received:
16:43:23     INFO -  /data/data/org.mozilla.fennec: No such file or directory
16:43:23     INFO - Running command: ['/tools/android-sdk18/platform-tools/adb', '-s', 'emulator-5554', 'install', '-r', '/builds/slave/test/build/fennec-39.0a1.en-US.android-arm.apk']
16:43:23     INFO - Copy/paste: /tools/android-sdk18/platform-tools/adb -s emulator-5554 install -r /builds/slave/test/build/fennec-39.0a1.en-US.android-arm.apk
16:43:23     INFO - Calling ['/tools/android-sdk18/platform-tools/adb', '-s', 'emulator-5554', 'install', '-r', '/builds/slave/test/build/fennec-39.0a1.en-US.android-arm.apk'] with output_timeout 300
16:46:32     INFO -  202 KB/s (39050246 bytes in 188.189s)
16:46:44     INFO -  Error: Could not access the Package Manager.  Is the system running?
16:46:45     INFO - Return code: 0

Notice that Android is running, adb is okay, the shell is responding. It looks like there is just a (temporary?) problem with the package manager.

Can we defend against this condition with a retry?

If not, can we detect this condition and fail the job?

Comment 1

[Geoff Brown [:gbrown]]

No help here, but it is a known issue: http://code.google.com/p/android/issues/detail?id=77686

Comment 2

[Geoff Brown [:gbrown]]

Another example:

http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/[e-mail]-f13be49be7c0/try-android-api-9/try_ubuntu64_vm_mobile_test-mochitest-9-bm116-tests1-linux64-build27.txt.gz

Notice that the system is still booting, even though uptime exceeds 5 minutes:

16:44:06     INFO -    uptime: 0 days 0 hours 5 minutes 0 seconds
16:44:06     INFO -    memtotal: 840868 kB
16:44:06     INFO -    process:
16:44:06     INFO -       USER     PID   PPID  VSIZE  RSS     WCHAN    PC         NAME
16:44:06     INFO -       root      1     0     364    268   c0098770 00017d58 S /init
16:44:06     INFO -       root      2     0     0      0     c005048c 00000000 S kthreadd
16:44:06     INFO -       root      3     2     0      0     c0042268 00000000 S ksoftirqd/0
16:44:06     INFO -       root      4     2     0      0     c004ce30 00000000 S events/0
16:44:06     INFO -       root      5     2     0      0     c004ce30 00000000 S khelper
16:44:06     INFO -       root      6     2     0      0     c004ce30 00000000 S suspend
16:44:06     INFO -       root      7     2     0      0     c004ce30 00000000 S kblockd/0
16:44:06     INFO -       root      8     2     0      0     c004ce30 00000000 S cqueue
16:44:06     INFO -       root      9     2     0      0     c016f7c4 00000000 S kseriod
16:44:06     INFO -       root      10    2     0      0     c004ce30 00000000 S kmmcd
16:44:06     INFO -       root      11    2     0      0     c006f36c 00000000 S pdflush
16:44:06     INFO -       root      12    2     0      0     c006f36c 00000000 S pdflush
16:44:06     INFO -       root      13    2     0      0     c007340c 00000000 S kswapd0
16:44:06     INFO -       root      14    2     0      0     c004ce30 00000000 S aio/0
16:44:06     INFO -       root      25    2     0      0     c016d0f8 00000000 S mtdblockd
16:44:06     INFO -       root      26    2     0      0     c004ce30 00000000 S kstriped
16:44:06     INFO -       root      27    2     0      0     c004ce30 00000000 S hid_compat
16:44:06     INFO -       root      28    2     0      0     c004ce30 00000000 S rpciod/0
16:44:06     INFO -       root      29    2     0      0     c0189ddc 00000000 S mmcqd
16:44:06     INFO -       root      30    1     356    204   c0098770 00017d58 S /sbin/ueventd
16:44:06     INFO -       system    31    1     852    356   c0195c08 400342d8 S /system/bin/servicemanager
16:44:06     INFO -       root      32    1     3976   868   ffffffff 40049b90 S /system/bin/vold
16:44:06     INFO -       root      35    1     888    440   c01a10a0 40042f20 S /system/bin/debuggerd
16:44:06     INFO -       radio     36    1     5464   880   ffffffff 40034b90 S /system/bin/rild
16:44:06     INFO -       system    37    1     30820  2312  ffffffff 400772d8 S /system/bin/surfaceflinger
16:44:06     INFO -       drm       39    1     6796   2480  ffffffff 400d52d8 S /system/bin/drmserver
16:44:06     INFO -       install   41    1     848    452   c01a10a0 40042f20 S /system/bin/installd
16:44:06     INFO -       keystore  42    1     3216   1224  c0195c08 400422d8 S /system/bin/keystore
16:44:06     INFO -       root      43    1     784    376   c00b4eb0 400433dc S /system/bin/qemud
16:44:06     INFO -       shell     46    1     776    460   c0148178 4002f014 S /system/bin/sh
16:44:06     INFO -       root      47    1     5536   296   ffffffff 00016c7c S /sbin/adbd
16:44:06     INFO -       root      280   47    740    416   c0098770 40034424 S logcat
16:44:06     INFO -       media     524   1     17012  5564  ffffffff 4009a2d8 S /system/bin/mediaserver
16:44:06     INFO -       root      525   1     2076   1020  c0098770 40065464 S /system/bin/netd
16:44:06     INFO -       nobody    526   1     277196 24696 ffffffff 40893022 R zygote
16:44:06     INFO -       graphics  527   1     13516  3640  ffffffff 400422d8 S /system/bin/bootanimation
16:44:06     INFO -       root      746   47    760    432   c002a7a0 4002fdb0 S /system/bin/sh
16:44:06     INFO -       root      748   746   1100   468   00000000 40042014 R ps

Comment 3

[Geoff Brown [:gbrown]]

Waiting for "getprop sys.boot_completed" before installing may be helpful.

Comment 4

[Geoff Brown [:gbrown]]

Attachment: wait for boot completed

Wait - in 10 second increments, up to 5 minutes - for "adb shell getprop sys.boot_completed" to return "1" before attempting to install fennec.

This seems to avoid the intermittent install failures I was seeing.

Comment 5

[Geoff Brown [:gbrown]]

https://hg.mozilla.org/build/mozharness/rev/cba147db08a5

Comment 6

[Geoff Brown [:gbrown]]

The landed patch definitely helps, but I still found one exception:

http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/[e-mail]-dc6ff134d2d2/try-android-api-9/try_ubuntu64_vm_mobile_test-mochitest-7-bm113-tests1-linux64-build35.txt.gz

http://mozilla-releng-blobs.s3.amazonaws.com/blobs/try/sha512/7725d50863f52ed6762eacc232f221513baaffb3cca05b6656fec9dca93e27b807916c3f0352b580febfbbe86ac2d97610d57c43e918600420e8d938ccd95fd0

It looks to me like Android booted, then re-started some system services right around the time the mozharness script was trying to install firefox.

Improvements to system boot stability would help here.

Retry on failed install might help too.

Comment 7

[Chris Cooper [:coop] (he/him)]

mozharness production tag moved to: https://hg.mozilla.org/build/mozharness/rev/cba147db08a5

Comment 8

[Geoff Brown [:gbrown]]

Attachment: check for successful apk installation; wait and retry if necessary

The normal / fast-success case here:

http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/[e-mail]-06eab2de61b9/try-android-api-9/try_ubuntu64_vm_large_test-crashtest-2-bm116-tests1-linux64-build35.txt.gz

10:14:27     INFO - Getting output from command: ['/builds/slave/test/build/android-sdk18/platform-tools/adb', '-s', 'emulator-5554', 'install', '-r', '/builds/slave/test/build/fennec-39.0a1.en-US.android-arm.apk']
10:14:27     INFO - Copy/paste: /builds/slave/test/build/android-sdk18/platform-tools/adb -s emulator-5554 install -r /builds/slave/test/build/fennec-39.0a1.en-US.android-arm.apk
10:15:04     INFO - Reading from file tmpfile_stdout
10:15:04     INFO - Output received:
10:15:04     INFO -  	pkg: /data/local/tmp/fennec-39.0a1.en-US.android-arm.apk
10:15:04     INFO -  Success
10:15:04     INFO - Reading from file tmpfile_stderr
10:15:04     INFO - Finished installing apps for test-1

Comment 9

[Geoff Brown [:gbrown]]

https://hg.mozilla.org/build/mozharness/rev/0096bf04b6a4

Comment 10

[Ryan VanderMeulen [:RyanVM]]

(In reply to Geoff Brown [:gbrown] from comment #9)
> https://hg.mozilla.org/build/mozharness/rev/0096bf04b6a4

Merged to production and bumped on m-c.