Scope might increase as I get more familiar with the scripts. Copying plan from other bug:

 https://crbug.com/749239#c18 

Sounds doable, let's just call logcat directly then. Not clearing sounds better, that way we don't erase possibly useful logcat accidentally. We can have an option like -c to pass through and clear if that's really desired.

Hmm... I might go with the simplier should_show option for now and switch if GetPids() is really slow.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7e19a902f0aad51034cbc0f2124755c540158b76

commit 7e19a902f0aad51034cbc0f2124755c540158b76
Author: Peter Wen <wnwen@chromium.org>
Date: Wed Aug 30 01:42:07 2017

Android: Improve apk logcat operation

Default to filter specifically for logs from target apk.

Bug:  758670 
Change-Id: I315d5ce037fd1b47b603a66c7b0800d58cabd51c
Reviewed-on: https://chromium-review.googlesource.com/634153
Commit-Queue: Andrew Grieve <agrieve@chromium.org>
Reviewed-by: Andrew Grieve <agrieve@chromium.org>
Cr-Commit-Position: refs/heads/master@{#498336}
[modify] https://crrev.com/7e19a902f0aad51034cbc0f2124755c540158b76/build/android/apk_operations.py

Just tried it out and it's already a huge improvement! But it could be even better with some colour :).

Typically, logcat colouring has been done based on severity. I think though, that it would be much more useful to do it via:

When using --verbose:
 * Show lines that would have been hidden without --verbose as faight (grey / dim)
 * Show all primary process lines as COLOUR1
 * Show all non-primary process lines as $ONE_COLOUR_PER_PROCESS (not sure there's a generic way to make these stable)
 * Use a background colour just on the thread-id part (one colour per thread id), but don't highlight the UI thread (aka, when thread-id == process id)
 * Use a background colour on the severity character (yellow for W, red for E or F)


We'll likely want to whitelist a couple other log tags. E.g. ActivityManager logs are generally useful: 
08-30 17:18:41.803   791   791 I ActivityManager: Start proc 3163:com.google.android.googlequicksearchbox:search/u0a48 for service com.google.android.googlequicksearchbox/com.google.android.apps.gsa.tasks.BackgroundTasksJobService

Although I a little bit wonder if we'll just want to make -v the default once we have nice colour-coding.

Another thought:
ActivityManager shows lines like:
09-07 22:13:25.135 18029 18231 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=org.chromium.chrome/com.google.android.apps.chrome.Main} from pid 6977
09-08 10:18:03.945 18029 18325 I ActivityManager: Start proc com.android.chrome for service com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabsConnectionService: pid=15705 uid=10032 gids={50032, 3003, 1028, 1015}
09-08 11:28:06.865 18029 18069 I ActivityManager: Killing 15705:com.android.chrome/u0a32 (adj 15): empty for 4202s

In addition to showing them, we could parse out Chrome's PIDs from them, which would allow us to show Chrome logcat lines that belonged to processes that have been stopped before logcat is run.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/52668623db4ab636e6631b7a3598ad48f3bb292a

commit 52668623db4ab636e6631b7a3598ad48f3bb292a
Author: Andrew Grieve <agrieve@chromium.org>
Date: Wed Sep 13 16:10:17 2017

apk_operations.py: Deobfuscate java stack traces in logcat

Applicable only when building release.
Disable via --no-deobfuscate

Bug: 620323,  758670 
Change-Id: Ib1289e6eae6bb326a1879c791e673cdeba331eab
Reviewed-on: https://chromium-review.googlesource.com/656720
Reviewed-by: John Budorick <jbudorick@chromium.org>
Reviewed-by: Peter Wen <wnwen@chromium.org>
Commit-Queue: Andrew Grieve <agrieve@chromium.org>
Cr-Commit-Position: refs/heads/master@{#501645}
[modify] https://crrev.com/52668623db4ab636e6631b7a3598ad48f3bb292a/build/android/apk_operations.py
[modify] https://crrev.com/52668623db4ab636e6631b7a3598ad48f3bb292a/build/android/gyp/create_apk_operations_script.py
[modify] https://crrev.com/52668623db4ab636e6631b7a3598ad48f3bb292a/build/android/pylib/symbols/deobfuscator.py
[modify] https://crrev.com/52668623db4ab636e6631b7a3598ad48f3bb292a/build/config/android/rules.gni

Sounds good. I think with proper colors we should output all logcat lines by default. Our filters aren't perfect, so if there's anything missing the grey/dim lines will catch it.

Will work on colours and change the default to show all, get that done before moving on to advanced parsing to find older logs. :)

Another thing to whitelist: Native crash dumps backtrace at level I, so should whitelist it. E.g.: 

F/libc    (26576): Fatal signal 11 (SIGSEGV) at 0x00000000 (code=1), thread 26673 (AsyncTask #5)
I/cr_base (26576): Extracting resource /data/data/com.google.android.apps.chrome/app_chrome/paks/en-US.pak@15e81061fb3
I/Adreno-EGL(26576): <qeglDrvAPI_eglInitialize:320>: EGL 1.4 QUALCOMM Build: I0404c4692afb8623f95c43aeb6d5e13ed4b30ddbDate: 11/06/13
I/ActivityManager(18029): Start proc com.google.android.apps.chrome:sandboxed_process0 for service com.google.android.apps.chrome/org.chromium.content.app.SandboxedProcessService0: pid=26675 uid=99087 gids={}
D/dalvikvm(26675): DexOpt: couldn't find static field Landroid/os/Build;.SUPPORTED_ABIS
W/dalvikvm(26675): VFY: unable to resolve static field 8332 (SUPPORTED_ABIS) in Landroid/os/Build;
D/dalvikvm(26675): VFY: replacing opcode 0x62 at 0x0042
I/cr_ChildProcessService(26675): Creating new ChildProcessService pid=26675
D/OpenGLRenderer(26576): Enabling debug mode 0
I/DEBUG   ( 1740): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
I/DEBUG   ( 1740): Build fingerprint: 'google/hammerhead/hammerhead:4.4.4/KTU85F/4081715:userdebug/dev-keys'
I/DEBUG   ( 1740): Revision: '11'
I/DEBUG   ( 1740): pid: 26576, tid: 26673, name: AsyncTask #5  >>> com.google.android.apps.chrome <<<
I/DEBUG   ( 1740): signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 00000000
I/DEBUG   ( 1740):     r0 7648e770  r1 00000000  r2 00000000  r3 00000001
I/DEBUG   ( 1740):     r4 7674e954  r5 75d18564  r6 00005aa0  r7 7648e7e8
I/DEBUG   ( 1740):     r8 7648e770  r9 00000001  sl 75d18528  fp 00000000
I/DEBUG   ( 1740):     ip 00000000  sp 7648e740  lr 75cf51c9  pc 75cf5306  cpsr 40030030
I/DEBUG   ( 1740):     d0  732e676f6c62696c  d1  0000000000000000
I/DEBUG   ( 1740):     d2  0000000000000000  d3  0000000000000000
I/DEBUG   ( 1740):     d4  6d5aba506d46c2b0  d5  6d5abac06d5aba88
I/DEBUG   ( 1740):     d6  6d5abb306d5abaf8  d7  6d5abba06d5abb68
I/DEBUG   ( 1740):     d8  0000000000000000  d9  0000000000000000
I/DEBUG   ( 1740):     d10 0000000000000000  d11 0000000000000000
I/DEBUG   ( 1740):     d12 0000000000000000  d13 0000000000000000
I/DEBUG   ( 1740):     d14 0000000000000000  d15 0000000000000000
I/DEBUG   ( 1740):     d16 0000000000000000  d17 0000000000000000
I/DEBUG   ( 1740):     d18 0000000000000000  d19 0000000000000000
I/DEBUG   ( 1740):     d20 0000000000000000  d21 0002000200020002
I/DEBUG   ( 1740):     d22 0000000000000000  d23 0000000000000000
I/DEBUG   ( 1740):     d24 0000000000000000  d25 0002a7600002a760
I/DEBUG   ( 1740):     d26 0707070703030303  d27 0300000004000000
I/DEBUG   ( 1740):     d28 0800000009000000  d29 0001000000010000
I/DEBUG   ( 1740):     d30 010b400001088000  d31 01108000010e0000
I/DEBUG   ( 1740):     scr 60000010
I/DEBUG   ( 1740):
I/DEBUG   ( 1740): backtrace:
I/DEBUG   ( 1740):     #00  pc 00004306  /data/app-lib/com.google.android.apps.chrome-1/libchromium_android_linker.so
I/DEBUG   ( 1740):     #01  pc 000041c5  /data/app-lib/com.google.android.apps.chrome-1/libchromium_android_linker.so
I/DEBUG   ( 1740):
I/DEBUG   ( 1740): stack:
I/DEBUG   ( 1740):          7648e700  400a0dc5  /system/lib/libc.so (dlmalloc)
I/DEBUG   ( 1740):          7648e704  75d18528  [anon:libc_malloc]
I/DEBUG   ( 1740):          7648e708  402422cc  /system/lib/libz.so (zcalloc)
I/DEBUG   ( 1740):          7648e70c  00000000

That sounds good.

One question I have for you is the thread color/background colors. What happens if a process's log color is the same as one of the background colors? Like red for E/F or yellow for W? Or are you saying only have the actual log lines with colors and the info lines only have background color?

I don't think there's a way to have each process have its own color that's persistent across logcat runs unless we assign one for each of privileged process 0-2, sandbox 0-3, and browser (we only have 8 real colors in ANSI standard colorama excluding black and including default). Does that sound good and they can cycle again past that number?

agree we shouldn't be trying to achieve persistent colors across runs.

I'll let you figure out the rest :) I'm sure you'll get a better handle on what will look nice once you're working on it.

Sounds good. Thanks for the good ideas various things to whitelist. :)

Comment from https://chromium-review.googlesource.com/c/chromium/src/+/668038/3/build/android/apk_operations.py#455:

This misses printing of ActivityManager line before fast=False. Tried this out and I think it's worth special-casing this line:

I ActivityManager: Start proc 2399:org.chromium.chrome/u0a221 for activity org.chromium.chrome/com.google.android.apps.chrome.Main

2399 is the PID, so just see if the pid is in my_pids.


Also - we should print these lines not based on |fast|, but rather based on whether any lines have already been printed.

Also also - we could consider parsing the pids out of this log message to populate my_pids, but I'm afraid that would cause us to pick up previous instances. Perhaps just add them if we've already printed a line? I'm thinking this would enable us to pick up short-lived renderers / utility processes.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/1bb0b4c3eb45a2fa1c69d720555b222d4e68ac00

commit 1bb0b4c3eb45a2fa1c69d720555b222d4e68ac00
Author: Peter Wen <wnwen@chromium.org>
Date: Thu Sep 21 00:10:58 2017

Android: Colored logcat output

Logcat output from apk wrapper is now colored according to pid and
severity.

NOTRY=true  # android_n5x is flaking.
BUG= 758670 

Change-Id: I16f8c01ebad82fd232601649ba0ecfd380759882
Reviewed-on: https://chromium-review.googlesource.com/668038
Commit-Queue: Andrew Grieve <agrieve@chromium.org>
Reviewed-by: Andrew Grieve <agrieve@chromium.org>
Cr-Commit-Position: refs/heads/master@{#503288}
[modify] https://crrev.com/1bb0b4c3eb45a2fa1c69d720555b222d4e68ac00/build/android/apk_operations.py

Just using this now on a kitkat device, and there are multiple screens worth of:

09-21 12:39:37.621 18120 18123 D dalvikvm: GC_CONCURRENT freed 170K, 2% free 17891K/18092K, paused 1ms+2ms, total 12ms
09-21 12:39:37.661 18120 18120 W dalvikvm: Unable to resolve superclass of Lorg/chromium/net/NetworkChangeNotifierAutoDetect$MyNetworkCallback; (3886)
09-21 12:39:37.661 18120 18120 W dalvikvm: Link of class 'Lorg/chromium/net/NetworkChangeNotifierAutoDetect$MyNetworkCallback;' failed
09-21 12:39:37.661 18120 18120 E dalvikvm: Could not find class 'bhj', referenced from method org.chromium.net.NetworkChangeNotifierAutoDetect.<init>
09-21 12:39:37.661 18120 18120 W dalvikvm: VFY: unable to resolve new-instance 5517 (Lbhj;) in Lorg/chromium/net/NetworkChangeNotifierAutoDetect;


I think it'd be a good idea to blacklist these by default. Either just blacklist the dalvikvm logtag, or use a regexp on the messages (that might be safer, in case dalvikvm actually does show something useful ever)

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/92c3534535bfcf65639b9e99748528f03d995f0d

commit 92c3534535bfcf65639b9e99748528f03d995f0d
Author: Andrew Grieve <agrieve@chromium.org>
Date: Mon Oct 02 16:00:19 2017

apk_operations.py: More tweaks to logcat

* Color PID same as message
* Color ActivityManager as "dim"
* Color TID bright if it's the UI thread.
* Ignore most dalvikvm messages on pre-L

Bug:  758670 
Change-Id: I6a7400615b2e521113d2f3f78834145092937f5e
Reviewed-on: https://chromium-review.googlesource.com/693081
Reviewed-by: Peter Wen <wnwen@chromium.org>
Commit-Queue: Peter Wen <wnwen@chromium.org>
Cr-Commit-Position: refs/heads/master@{#505628}
[modify] https://crrev.com/92c3534535bfcf65639b9e99748528f03d995f0d/build/android/apk_operations.py

About as much as we wanted initially. Thanks agrieve@ for finishing up this work!