IssueTracker

1/ What are the detail of the two columns? One is correct while the other seems to have a problem when we use protobuffer outputs.

2/ What are the repro steps?

3/ Note that this is not a timing issue. I think this may happen when we retrieve the process name too early when the process was just created and before it became specialized. Difficult to tell until we know more about how to repro.

The column that looks correct is the application id (AKA package name), which I believe we get later from the debuggable process.

To repro:

• Connect to a device running API 35
• Ensure the flag logcat.protobuf.enable is true. It should be on already by default.
• Create a new project
• Start logcat on the device and set the filter to process:zygote64
• Run the app

Logcat will show something like this (I truncated the longer messages):

2024-07-08 09:12:24.183   865-865   Zygote                  zygote64                            zygote64                             D  Forked child process 31233...
2024-07-08 09:12:24.191 31233-31233 obolectric.test         zygote64                            zygote64                             I  Late-enabling -Xcheck:jni...
2024-07-08 09:12:24.214 31233-31233 obolectric.test         zygote64                            zygote64                             I  Using CollectorTypeCMC GC....
2024-07-08 09:12:24.225 31233-31233 nativeloader            zygote64                            zygote64                             D  Load libframework-connecti...
2024-07-08 09:12:24.247 31233-31233 re-initialized>         zygote64                            zygote64                             W  type=1400 audit(0.0:209745...
2024-07-08 09:12:24.249 31233-31233 nativeloader            zygote64                            zygote64                             D  Load /data/user/0/com.test...
2024-07-08 09:12:24.249 31233-31233 studio.deploy           zygote64                            zygote64                             V  Startup agent attached to ...
2024-07-08 09:12:24.249 31233-31233 studio.deploy           zygote64                            zygote64                             V  No existing instrumentatio...
2024-07-08 09:12:24.255 31233-31233 obolectric.test         zygote64                            zygote64                             W  DexFile /data/data/com.tes...
2024-07-08 09:12:24.257 31233-31233 studio.deploy           zygote64                            zygote64                             V  Applying transforms with c...
2024-07-08 09:12:24.432 31233-31233 obolectric.test         zygote64                            zygote64                             W  Redefining intrinsic metho...
2024-07-08 09:12:24.432 31233-31233 obolectric.test         zygote64                            zygote64                             W  Redefining intrinsic metho...
2024-07-08 09:12:24.436 31233-31233 studio.deploy           zygote64                            zygote64                             I  Registering DispatchJNI...
2024-07-08 09:12:24.436 31233-31233 studio.deploy           zygote64                            zygote64                             I  Found com/android/tools/de...
2024-07-08 09:12:24.447 31233-31233 CompatChangeReporter    zygote64                            zygote64                             D  Compat change id reported:...
---------------------------- PROCESS STARTED (31233) for package com.test.robolectric.test ----------------------------...
2024-07-08 09:12:24.463 31233-31233 ziparchive              com.test.robolectric.test           zygote64                             W  Unable to open '/data/data...
2024-07-08 09:12:24.463 31233-31233 ziparchive              com.test.robolectric.test           zygote64                             W  Unable to open '/data/app/...
2024-07-08 09:12:24.463 31233-31233 ziparchive              com.test.robolectric.test           zygote64                             W  Unable to open '/data/app/...
2024-07-08 09:12:24.577 31233-31233 nativeloader            com.test.robolectric.test           zygote64                             D  Configuring clns-7 for oth...
2024-07-08 09:12:24.588 31233-31233 GraphicsEnvironment     com.test.robolectric.test           zygote64                             V  Currently set values for:...
2024-07-08 09:12:24.588 31233-31233 GraphicsEnvironment     com.test.robolectric.test           zygote64                             V    angle_gl_driver_selectio...
2024-07-08 09:12:24.588 31233-31233 GraphicsEnvironment     com.test.robolectric.test           zygote64                             V    angle_gl_driver_selectio...
2024-07-08 09:12:24.588 31233-31233 GraphicsEnvironment     com.test.robolectric.test           zygote64                             V  com.test.robolectric.test ...
2024-07-08 09:12:24.588 31233-31233 GraphicsEnvironment     com.test.robolectric.test           zygote64                             V  Neither updatable producti...
2024-07-08 09:12:25.292 31233-31239 obolectric.test         com.test.robolectric.test           zygote64                             I  Compiler allocated 5250KB ...
2024-07-08 09:12:30.353 31233-31358 ProfileInstaller        com.test.robolectric.test           zygote64                             D  Installing profile for com...
2024-07-08 09:12:55.292 31233-31240 obolectric.test         com.test.robolectric.test           zygote64                             I  Background concurrent mark...

Note that 12:24.447 both application id and process name are zygote. This is early on the process lifetime, before we acquire the proper application id.

Yes, I agree with point 3 above.

What I meant by not a timing issue is that it doesn't just affect logs that are created early. The `zygote name persists throughout the lifetime of the logcat process.

Note that if I restart logcat after the the process was launched, I do get the correct process name.

I think the problem is that when an app starts, we retrieve the process name early, before zygote specializes and then we cache the results of the lookup. We can fix this by not caching the lookup if the result if either of:

• zygote
• zygote64
• <pre-initialized>

Thank you for addressing this. In case it helps I can add that, for me, logcat intermittently picks for the process name either the correct process name, "zygote64", or "<pre-initialized>" (and sticks with that name for the lifetime of the app run). So the suggestion from #5 makes sense to me.

I see the correct process names in the Processes tab in Device Explorer.

What happens if you restart logcat when the process name is wrong?

See screenshot.

It does appear that restarting logcat regenerates the log with the correct process names reliably for me

I also see, though, that the app/process has to still be running. If I restart logcat after app killed, I lose all process name information. That's not good.

Re comment #8, yes, that's consistent with the root cause

Re comment #9, yes. I can see why that's happening.

Unfortunately, the process name information is not encoded in the Logcat buffer on the device.

The way we get the process name on API 35 is by having the logcat process that reads from the system logcat buffer check the pid field and see what process currently belongs to that pid. This doesn't work when the process has already died.

I think I have a fix, but because of the other bug, I'm going to turn off proto parsing for now anyway.

So your best bet is to run with -Dlogcat.protobuf.enable=false

FYI: I've created a feature request for a process ID (PID) logcat filter to have something that is more robust: b/351843810

I am unable to repro locally, is the issue inconsistent?

See screenshot

I was able to repro and fix the bug.

After further investigation, it turned out the cache was populated via a ART hook which triggerd after zygote forked.

Great, thank you for the fix!

Repro step for future references.

1. Make sure you are using a device API >= 35
2. Enable proto logcat in Studio Flags
3. Open "modify view" (see screenshot)
4. Check "process name" checkbox.

Thank you for your patience while our engineering team worked to resolve this issue. A fix for this issue is now available in:

• Android Studio Ladybug | 2024.1.3 Canary 1
• Android Gradle Plugin 8.7.0-alpha01

We encourage you to try the latest update.

If you notice further issues or have questions, please file a new bug report.

Thank you for taking the time to submit feedback — we really appreciate it!

Further fixes for this issue are now available in:

• Android Studio Ladybug | 2024.1.3 Canary 2
• Android Gradle Plugin 8.7.0-alpha02

We encourage you to try the latest update.

If you notice further issues or have questions, please file a new bug report.

Seems to work now in Ladybug. Thank you!