Closed Bug 1550417 Opened 4 months ago Closed 4 months ago

Capture logcat if apk installation fails

Categories

(Firefox for Android :: Testing, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
Firefox 68
Tracking Status
firefox68 --- fixed

People

(Reporter: bc, Assigned: bc)

Details

(Whiteboard: [cia:logs:2019])

Attachments

(2 files)

We've had intermittent failures when installing apks previously.

Yesterday while investigating an issue with new devices at bitbar we had a flurry of them for a specific set of devices but have had trouble diagnosing the issue due to the fact that we do not start logging logcat until after we have installed the build and started a test and therefore miss any logcat messages from the installation.

I attempted to record the logcat in install_apk via the attached patch but it failed under try

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=245504034&repo=try&lineNumber=793

07:45:05    FATAL - Uncaught exception: Traceback (most recent call last):
07:45:05    FATAL -   File "/builds/task_1557387855/workspace/mozharness/mozharness/base/script.py", line 2097, in run
07:45:05    FATAL -     self.run_action(action)
07:45:05    FATAL -   File "/builds/task_1557387855/workspace/mozharness/mozharness/base/script.py", line 2036, in run_action
07:45:05    FATAL -     self._possibly_run_method(method_name, error_if_missing=True)
07:45:05    FATAL -   File "/builds/task_1557387855/workspace/mozharness/mozharness/base/script.py", line 1991, in _possibly_run_method
07:45:05    FATAL -     return getattr(self, method_name)()
07:45:05    FATAL -   File "/builds/task_1557387855/workspace/mozharness/mozharness/mozilla/testing/raptor.py", line 474, in install
07:45:05    FATAL -     self.install_apk(self.installer_path)
07:45:05    FATAL -   File "/builds/task_1557387855/workspace/mozharness/mozharness/mozilla/testing/android.py", line 345, in install_apk
07:45:05    FATAL -     self.logcat_start()
07:45:05    FATAL -   File "/builds/task_1557387855/workspace/mozharness/mozharness/mozilla/testing/android.py", line 316, in logcat_start
07:45:05    FATAL -     self.logcat_file = open(logcat_path, 'w')
07:45:05    FATAL - IOError: [Errno 2] No such file or directory: u'/builds/task_1557387855/workspace/build/blobber_upload_dir/logcat-HT86C1A02550.log'

even though earlier we had executed

mkdir -p "$WORKSPACE/build/blobber_upload_dir"
+ mkdir -p /builds/task_1557387855/workspace/build/blobber_upload_dir

I suppose it might be a permissions problem, but I don't know why it would work in general but not in this case.

gbrown: Do you have any idea what I did wrong or have a suggestion on how to capture logcat during the apk installation?

Attachment #9063733 - Flags: feedback?(gbrown)

(In reply to Bob Clary [:bc:] from comment #0)

Yesterday while investigating an issue with new devices at bitbar we had a flurry of them for a specific set of devices but have had trouble diagnosing the issue due to the fact that we do not start logging logcat until after we have installed the build and started a test and therefore miss any logcat messages from the installation.

I believe that is not correct.

logcat_start() is called from verify_device().
install_apk() is called from install().

verify_device() runs before install(): Currently, without changes, logcat is started before apk installation.

https://searchfox.org/mozilla-central/rev/197210b8c139b64f642edaa3336d26b9c1761568/testing/mozharness/configs/android/android_common.py#41-42

Example:

https://treeherder.mozilla.org/logviewer.html#?job_id=245485637&repo=mozilla-central

https://taskcluster-artifacts.net/CFl0fsQyRIqR7CHhBTpsOQ/0/public/test_info/logcat-FA84C1A00154.log

05-08 21:23:45.023 1186 1243 I PackageManager.DexOptimizer: Running dexopt (dexoptNeeded=1) on: /data/app/vmdl1844681567.tmp/base.apk pkg=org.mozilla.fennec_aurora isa=arm dexoptFlags=boot_complete,debuggable,public target-filter=quicken oatDir=/data/app/vmdl1844681567.tmp/oat sharedLibraries=null

It may be that, in the case of install failure, the logcat is not being retrieved, or the artifact not uploaded...maybe?

Comment on attachment 9063733 [details] [diff] [review]
mozharness-install-apk-logcat.patch

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

...but I can't explain why your patch would fail that way.
Attachment #9063733 - Flags: feedback?(gbrown)

Oh, raptor! I wasn't thinking of that. It turns out raptor does things differently:

https://searchfox.org/mozilla-central/rev/b9da45f63cb567244933c77b2c7e827a057d3f9b/testing/mozharness/mozharness/mozilla/testing/raptor.py#175-176

So, install(), then run_tests() -- that makes sense. And raptor doesn't use verify_device(). Instead, it starts logcat on its own, in run_tests():

https://searchfox.org/mozilla-central/rev/b9da45f63cb567244933c77b2c7e827a057d3f9b/testing/mozharness/mozharness/mozilla/testing/raptor.py#597

So raptor tests don't start the logcat until after install.

Great. At first I was thinking raptor but then thought it was more mozharness. I'll look into that.

The issue I had earlier was due to the mozharness clobber that killed the upload directory after I had started collecting the log. I added an override in raptor to recreate it after the clobber which worked around that issue. I also overrode install_apk to start and stop the logcat collection around the installation. I also made a tweak to AndroidMixin's install_apk to emit more information about the error in the log info and to remove the path from the error message since task_123456789 does not help and actually prevents error matching with suggestions.

I did a couple of try runs:

https://treeherder.mozilla.org/#/jobs?repo=try&author=bclary%40mozilla.com&fromchange=c439cbf6cb7a855f5c57356d4fc998c5629acb05&tochange=baaeb6cd3a7405acd9a479cda7d68c957b742a3c

one with a fake installation target to cause a failure and one without. It looks good to me.

Whiteboard: [cia:logs:2019]
Pushed by bclary@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/852d2cec86d6
Capture logcat if apk installation fails in raptor, r=gbrown,rwood.
Status: NEW → RESOLVED
Closed: 4 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 68
You need to log in before you can comment on or make changes to this bug.