961207 - Full logcat for Android x86 emulator unittests

Status: RESOLVED FIXED

(Testing :: General, defect)

Description

[Geoff Brown [:gbrown]]

Our mochitest and reftest test harnesses collect and report logcats, but that approach has several limitations:
 - logcat is collected at the end of the job; since logcat is collected in a limited size circular buffer, we often only report that last minute or so of tests
 - if connectivity to the device is lost while running tests, no logcat is reported
 - if a test or browser hangs, no logcat is reported

I think we can solve all of that simply in mozharness. I would like to start with the Android x86 tests, and then consider using the same approach for the Pandas.

I think we can simply launch a new process for each emulator "adb -s emulator-nnnn logcat > $MOZ_UPLOAD_DIR".

Comment 1

[Geoff Brown [:gbrown]]

Attachment: wip - needs testing

Comment 2

[Geoff Brown [:gbrown]]

I got this working on Ash. Here's a sample: https://tbpl.mozilla.org/php/getParsedLog.php?id=33312976&tree=Ash&full=1

The logcats are full of interesting info, complete, and consistent.

Logcat file sizes for what appear to be typical runs:

M-1   9M
JSR  19
     S1 total: 28M
M-2  39
M-GL  3
     S2 total: 42M
C     3
R-1   3
R-2   2	
R-3   3
     S3 total: 11M
RC-1  7
RC-2  1
RC-3  1
X    44
     S4 total: 53M
         Overall total: 134M

Is there a capacity issue here? Is it okay to upload ~150 MB to blobber for each check-in?

Comment 3

[Armen [:armenzg]]

catlee mentioned that we can upload 400MB and gets deleted after 60 days.

*we* think :)

Comment 4

[Geoff Brown [:gbrown]]

Attachment: collect full logcat for android emulator unit tests

See comment 2 for an example log showing this patch in use. I am hopeful that making full logcats available will help us understand and debug a wide range of problems.

The strategy is dead simple:

 - start emulators and wait for start up
 - launch a background process for each emulator: "adb -s emulator-nnnn logcat > {blobber-upload-dir} &" 
 - run tests, stop emulators; logcat processes end normally when the associated emulator is killed
 - let the blobber upload mechanism save our logcats

My main concern is blobber capacity (Comment 2): will this possibly exhaust some aws capacity limit, or is it costly to use this much storage?

Comment 5

[(not currently active) Ted Mielczarek]

Can we gzip them beforehand? Seems like that'd take the size way down.

Comment 6

[Geoff Brown [:gbrown]]

I like that idea! It looks like that 134MB can be compressed to under 10MB, which seems much more reasonable.

I wonder if it would be better to do the zipping in android_emulator_unittest.py (where we know these are huge logcats) or in the blobber mixin (so we save space for txt and log files across the board).

Comment 7

[(not currently active) Ted Mielczarek]

The latter is probably the best long-term solution, but I'd do whatever is quickest at the moment, as long as you file the nicer solution for later.

Comment 8

[Geoff Brown [:gbrown]]

Ted kindly added compression support to blobber. It is not in production yet, but I don't think it can do much harm to go ahead with this logcat patch and push uncompressed files in the interim.

https://hg.mozilla.org/build/mozharness/rev/1ca6ffbe37e3

Comment 9

[John Hopkins (:jhopkins)]

in production.

Comment 10

[Geoff Brown [:gbrown]]

Working as expected: https://tbpl.mozilla.org/php/getParsedLog.php?id=33465967&tree=Mozilla-Inbound&full=1

08:53:38     INFO - Running post-run listener: _upload_blobber_files
08:53:38     INFO - Blob upload gear active.
08:53:38     INFO - Preparing to upload files from /builds/slave/talos-slave/test/build/blobber_upload_dir.
08:53:38     INFO - Files from /builds/slave/talos-slave/test/build/blobber_upload_dir are to be uploaded with <mozilla-inbound> branch at the following location(s): https://blobupload.elasticbeanstalk.com
08:53:38     INFO - Running command: ['/builds/slave/talos-slave/test/build/venv/bin/python', '/builds/slave/talos-slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/talos-slave/test/oauth.txt', '-b', 'mozilla-inbound', '-d', '/builds/slave/talos-slave/test/build/blobber_upload_dir']
08:53:38     INFO - Copy/paste: /builds/slave/talos-slave/test/build/venv/bin/python /builds/slave/talos-slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/talos-slave/test/oauth.txt -b mozilla-inbound -d /builds/slave/talos-slave/test/build/blobber_upload_dir
08:53:38     INFO -  (blobuploader) - INFO - Open directory for files ...
08:53:38     INFO -  (blobuploader) - INFO - Uploading /builds/slave/talos-slave/test/build/blobber_upload_dir/logcat-emulator-5556.log ...
08:53:38     INFO -  (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
08:53:38     INFO -  (blobuploader) - INFO - Uploading, attempt #1.
08:53:48     INFO -  (blobuploader) - INFO - TinderboxPrint: Uploaded logcat-emulator-5556.log to http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/7a03c9cf8733c3175381fe842374f3d7bbaf29afa34e25a22d7cf909a217ee5d59581130509c2356412ad4a91d5e937ffffbec626454d17484b9f001de1ef8a6
08:53:48     INFO -  (blobuploader) - INFO - Blobserver returned 202. File uploaded!
08:53:48     INFO -  (blobuploader) - INFO - Done attempting.
08:53:49     INFO -  (blobuploader) - INFO - Uploading /builds/slave/talos-slave/test/build/blobber_upload_dir/logcat-emulator-5560.log ...
08:53:49     INFO -  (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
08:53:49     INFO -  (blobuploader) - INFO - Uploading, attempt #1.
08:54:18     INFO -  (blobuploader) - INFO - TinderboxPrint: Uploaded logcat-emulator-5560.log to http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/077f540b96175e8b1c7cd10cc6505a29c4042e6d05f7ef8e49c26fa4ae9f0e352fc0189604a9f6a91c1862492ce24b322c87a9477c9c93d7ecf29cb9b05ff5f6
08:54:18     INFO -  (blobuploader) - INFO - Blobserver returned 202. File uploaded!
08:54:18     INFO -  (blobuploader) - INFO - Done attempting.
08:54:18     INFO -  (blobuploader) - INFO - Uploading /builds/slave/talos-slave/test/build/blobber_upload_dir/logcat-emulator-5554.log ...
08:54:18     INFO -  (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
08:54:18     INFO -  (blobuploader) - INFO - Uploading, attempt #1.
08:54:29     INFO -  (blobuploader) - INFO - TinderboxPrint: Uploaded logcat-emulator-5554.log to http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/b94de4ca55d879b88f5d193f52aa78a18bda761c214e3a724886f936b452da2942af0c262e48085c267ce33a0a36f826a588b08da0444f60ddbeb784ccb016ae
08:54:29     INFO -  (blobuploader) - INFO - Blobserver returned 202. File uploaded!
08:54:29     INFO -  (blobuploader) - INFO - Done attempting.
08:54:30     INFO -  (blobuploader) - INFO - Uploading /builds/slave/talos-slave/test/build/blobber_upload_dir/logcat-emulator-5558.log ...
08:54:30     INFO -  (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
08:54:30     INFO -  (blobuploader) - INFO - Uploading, attempt #1.
08:54:41     INFO -  (blobuploader) - INFO - TinderboxPrint: Uploaded logcat-emulator-5558.log to http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/cb2d9219ffb2a0bf387250daafe5901f688c561874bd4db2f49585aafb2846a2706692e46326ce47c7ac5a0de89b8ca5d61a7f286f8820eb34a0004ffd69cf06
08:54:41     INFO -  (blobuploader) - INFO - Blobserver returned 202. File uploaded!
08:54:41     INFO -  (blobuploader) - INFO - Done attempting.
08:54:41     INFO -  (blobuploader) - INFO - Iteration through files over.
08:54:41     INFO - Return code: 0
08:54:41     INFO - Copying logs to upload dir...
08:54:41     INFO - mkdir: /builds/slave/talos-slave/test/build/upload/logs