Android BugReport 中包含文本 (.txt) 格式的 dumpsys、dumpstate、logcat 数据,便于轻松搜索特定内容。以下各部分详细说明了BugReport 的组成部分及常见问题,并提供了关于查找与这些错误相关的日志的实用提示和 grep 命令。
一、如何阅读 BugReport
1、Logcat
Logcat 日志是所有 Logcat 信息采用字符串形式的转储。其中,包括:System Log、Event Log。
(1)System Log 部分专门用于记录框架方面的信息,与包含所有其他内容的 main 部分相比,该部分包含更长时间内的记录。
每行都以 timestamp PID TID log-level
开头。
(2)Event Log 中包含将二进制格式转换成了字符串形式的日志消息。它比 Logcat 日志要清晰明了,但也有些难以阅读。在查看 Event Log时,可以在这一部分中搜索特定进程 ID (PID),以查看相应进程一直在做什么。基本格式是:timestamp PID TID log-level log-tag tag-values
。
注意:日志级别包括以下几种:
<1> V:详细
<2> D:调试
<3> I:信息
<4> W:警告
<5> E:错误
2、ANR(应用无响应)
BugReport 有助于找出导致 ANR 错误和死锁事件的原因。当某个应用在一定时间内没有响应(通常是由于主线程被阻塞或繁忙)时,系统会终止该进程,并将堆栈转储到 /data/anr。
(1)为了找出 ANR 背后的罪魁祸首,可以对二进制事件日志中的 am_anr 执行 grep 命令。
$ grep "am_anr" bugreport.txt
10-01 18:12:49.599 4600 4614 I am_anr : [0,29761,com.google.android.youtube,953695941,executing service com.google.android.youtube/com.google.android.apps.youtube.app.offline.transfer.OfflineTransferService]
10-01 18:14:10.211 4600 4614 I am_anr : [0,30363,com.google.android.apps.plus,953728580,executing service com.google.android.apps.plus/com.google.android.apps.photos.service.PhotosService]
(2)也可以对 Logcat 日志(包含关于发生 ANR 时,是什么在占用 CPU 的更多信息)中的 ANR in 执行 grep 命令。
$ grep "ANR in" bugreport.txt
10-01 18:13:11.984 4600 4614 E ActivityManager: ANR in com.google.android.youtube
10-01 18:14:31.720 4600 4614 E ActivityManager: ANR in com.google.android.apps.plus
10-01 18:14:31.720 4600 4614 E ActivityManager: PID: 30363
10-01 18:14:31.720 4600 4614 E ActivityManager: Reason: executing service com.google.android.apps.plus/com.google.android.apps.photos.service.PhotosService
10-01 18:14:31.720 4600 4614 E ActivityManager: Load: 35.27 / 23.9 / 16.18
10-01 18:14:31.720 4600 4614 E ActivityManager: CPU usage from 16ms to 21868ms later:
10-01 18:14:31.720 4600 4614 E ActivityManager: 74% 3361/mm-qcamera-daemon: 62% user + 12% kernel / faults: 15276 minor 10 major
10-01 18:14:31.720 4600 4614 E ActivityManager: 41% 4600/system_server: 18% user + 23% kernel / faults: 18597 minor 309 major
10-01 18:14:31.720 4600 4614 E ActivityManager: 32% 27420/com.google.android.GoogleCamera: 24% user + 7.8% kernel / faults: 48374 minor 338 major
10-01 18:14:31.720 4600 4614 E ActivityManager: 16% 130/kswapd0: 0% user + 16% kernel
10-01 18:14:31.720 4600 4614 E ActivityManager: 15% 283/mmcqd/0: 0% user + 15% kernel
...
10-01 18:14:31.720 4600 4614 E ActivityManager: 0.1% 27248/irq/503-synapti: 0%
10-01 18:14:31.721 4600 4614 I ActivityManager: Killing 30363:com.google.android.apps.plus/u0a206 (adj 0): bg anr
(3)查找堆栈轨迹
通常可以找到与 ANR 对应的堆栈轨迹。首先确保虚拟机轨迹上的 timeStamp 和 PID 与您正在调查的 ANR 相符,然后再检查进程的主线程。注意:
<1> 主线程只能了解发生 ANR 时,它在做什么,这可能是导致 ANR 的真正原因,也可能不是。(BugReport 中的堆栈可能是无辜的,可能有其它线程在恢复正常之前,粘滞了很长时间,但不足以导致 ANR。)
<2> 可能存在多组堆栈轨迹(VM TRACES JUST NOW
和 VM TRACES AT LAST ANR
),要确保查看的是正确的部分。
(4)查找死锁
由于线程出现粘滞,死锁往往首先表现为 ANR。如果系统服务器发生死锁,监控定时器最终会将其终止,从而导致日志中出现类似以下的条目:WATCHDOG KILLING SYSTEM PROCESS
。对于用户来说,他们看到的是设备重新启动,但从技术上来讲,这是运行时重启,而不是真正的设备重新启动。说明:
<1> 在运行时重启时,系统服务器已死机并会重启,并且用户会看到设备返回到显示启动动画。
<2> 在设备重新启动时,内核已崩溃,并且用户会看到设备返回到显示 Google 启动徽标。
要查找死锁,请检查 VM 跟踪部分中是否存在以下模式:线程 A 在等待线程 B 占用的某些资源,而线程 B 也在等待线程 A 占用的某些资源。
3、Activity
Activity 是一种应用组件,为用户提供一个可互动的屏幕,用来执行某些操作(如:拨号、拍照、发送电子邮件等)。从 BugReport 的角度来看,Activity 是用户可以执行的一项明确具体的操作,这使得查找在崩溃期间处于聚焦状态的 Activity 变得非常重要。Activity 通过 ActivityManager 运行进程,因此找出指定 Activity 的所有进程启动和停止事件也有助于进行问题排查。
(1)查看处于聚焦状态的 Activity 的历史记录:
$ grep "am_focused_activity" bugreport.txt
10-01 18:10:41.409 4600 14112 I am_focused_activity: [0,com.google.android.GoogleCamera/com.android.camera.CameraActivity]
10-01 18:11:17.313 4600 5687 I am_focused_activity: [0,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL]
(2)查看进程启动事件的历史记录
$ grep "Start proc" bugreport.txt
10-01 18:09:15.309 4600 4612 I ActivityManager: Start proc 24533:com.metago.astro/u0a240 for broadcast com.metago.astro/com.inmobi.commons.analytics.androidsdk.IMAdTrackerReceiver
10-01 18:09:15.687 4600 14112 I ActivityManager: Start proc 24548:com.google.android.apps.fitness/u0a173 for service com.google.android.apps.fitness/.api.services.ActivityUpsamplingService
10-01 18:09:15.777 4600 6604 I ActivityManager: Start proc 24563:cloudtv.hdwidgets/u0a145 for broadcast cloudtv.hdwidgets/cloudtv.switches.SwitchSystemUpdateReceiver
10-01 18:09:20.574 4600 6604 I ActivityManager: Start proc 24617:com.wageworks.ezreceipts/u0a111 for broadcast com.wageworks.ezreceipts/.ui.managers.IntentReceiver
...
(3)确定设备是否发生抖动,需检查在 am_proc_died
和 am_proc_start
前后的短时间内,是否出现 Activity 异常增多的情况。
$ grep -e "am_proc_died" -e "am_proc_start" bugreport.txt
10-01 18:07:06.494 4600 9696 I am_proc_died: [0,20074,com.android.musicfx]
10-01 18:07:06.555 4600 6606 I am_proc_died: [0,31166,com.concur.breeze]
10-01 18:07:06.566 4600 14112 I am_proc_died: [0,18812,com.google.android.apps.fitness]
10-01 18:07:07.018 4600 7513 I am_proc_start: [0,20361,10113,com.sony.playmemories.mobile,broadcast,com.sony.playmemories.mobile/.service.StartupReceiver]
10-01 18:07:07.357 4600 4614 I am_proc_start: [0,20381,10056,com.google.android.talk,service,com.google.android.talk/com.google.android.libraries.hangouts.video.CallService]
10-01 18:07:07.784 4600 4612 I am_proc_start: [0,20402,10190,com.andcreate.app.trafficmonitor:loopback_measure_serivce,service,com.andcreate.app.trafficmonitor/.loopback.LoopbackMeasureService]
10-01 18:07:10.753 4600 5997 I am_proc_start: [0,20450,10097,com.amazon.mShop.android.shopping,broadcast,com.amazon.mShop.android.shopping/com.amazon.identity.auth.device.storage.LambortishClock$ChangeTimestampsBroadcastReceiver]
10-01 18:07:15.267 4600 6605 I am_proc_start: [0,20539,10173,com.google.android.apps.fitness,service,com.google.android.apps.fitness/.api.services.ActivityUpsamplingService]
10-01 18:07:15.985 4600 4612 I am_proc_start: [0,20568,10022,com.android.musicfx,broadcast,com.android.musicfx/.ControlPanelReceiver]
10-01 18:07:16.315 4600 7512 I am_proc_died: [0,20096,com.google.android.GoogleCamera]
4、内存
由于 Android 设备的物理内存通常都存在限制,因此管理 RAM (随机存取存储器) 至关重要。BugReport 中包含一些用于指示内存不足的指标以及一个提供内存快照的 dumpstate。
(1)发现内存不足的情况
内存不足可能会导致系统发生抖动,这是因为虽然内存不足时,系统会终止某些进程来释放内存,但又会继续启动其它进程。如需查看内存不足的确凿证据,请检查二进制事件日志中的 am_proc_died
和 am_proc_start
条目的密集程度。
内存不足还可能会减慢任务切换速度,并且可能会阻止进行返回的尝试(因为用户尝试返回的任务已被终止)。如果启动器被终止,它会在用户触摸主屏幕按钮时重启,并且日志中会显示启动器重新加载其内容。
<1> 查看历史指标
二进制事件日志中的 am_low_memory
条目,表示最后一个缓存的进程已终止。在此之后,系统开始终止各项服务。
$ grep "am_low_memory" bugreport.txt
10-01 18:11:02.219 4600 7513 I am_low_memory: 41
10-01 18:12:18.526 4600 14112 I am_low_memory: 39
10-01 18:12:18.874 4600 7514 I am_low_memory: 38
10-01 18:12:22.570 4600 14112 I am_low_memory: 40
10-01 18:12:34.811 4600 20319 I am_low_memory: 43
10-01 18:12:37.945 4600 6521 I am_low_memory: 43
10-01 18:12:47.804 4600 14110 I am_low_memory: 43
<2> 查看抖动指标
关于系统抖动(分页、直接回收等)的其它指标,包括:kswapd、kworker、mmcqd 消耗周期。( 注意:收集 BugReport 可能会影响抖动指标 )
ANR 日志可以提供类似的内存快照。
(2)获取内存快照
内存快照是一种 dumpstate,其中会列出正在运行的 Java 进程和本机进程。( 注意:快照仅提供特定时刻的状态,在此快照之前,系统的状况可能更好,也可能更糟。)
5、广播
应用会生成广播,以便在当前应用内或向其它应用发送事件。广播接收器可以(通过过滤器)订阅特定消息,以便收听和响应广播。BugReport 中包含已发送广播和未发送广播的相关信息,以及关于收听特定广播的所有接收器的 dumpsys。
(1)查看历史广播
历史广播(即:已发送的广播),按时间逆序排列。
<1> summary(摘要)部分,用于提供最近 300 个前台广播和最近 300 个后台广播的概况。
Historical broadcasts summary [foreground]:#0: act=android.intent.action.SCREEN_ON flg=0x50000010+1ms dispatch +90ms finishenq=2015-10-29 17:10:51 disp=2015-10-29 17:10:51 fin=2015-10-29 17:10:51#1: act=android.intent.action.SCREEN_OFF flg=0x500000100 dispatch +60ms finishenq=2015-10-29 17:10:05 disp=2015-10-29 17:10:05 fin=2015-10-29 17:10:05...Historical broadcasts summary [background]:...
<2> detail(详情)部分,包含最近 50 条前台广播和最近 50 条后台广播的完整信息,以及每个广播的接收方。其中:
具有 BroadcastFilter 条目的接收器是在运行时注册的,并且只会被发送到已在运行的进程。
具有 ResolveInfo 条目的接收器是通过清单条目注册的。ActivityManager 会为每个 ResolveInfo 启动相应进程(如果相应进程尚未在运行)。
(2)查看待发送的广播
待发送的广播(即:尚未发送的广播),如果队列中存在大量广播,则意味着系统无法足够快地发送广播来跟上进度。
Active ordered broadcasts [background]:
Active Ordered Broadcast background #133: // size of queue
...
(3)查看广播监听器
如需查看监听广播的接收器列表,请查看 dumpsys activity broadcasts 中的 Receiver Resolver Table。以下示例显示了监听 USER_PRESENT 的所有接收器。
ACTIVITY MANAGER BROADCAST STATE (dumpsys activity broadcasts)
..Receiver Resolver Table:Full MIME Types:..Wild MIME Types:..Schemes:..Non-Data Actions:..android.intent.action.USER_PRESENT:BroadcastFilter{8181cc1 u-1 ReceiverList{5d929a8 902 system/1000/u-1 local:eca4dcb}}BroadcastFilter{6371c97 u-1 ReceiverList{2938b16 902 system/1000/u-1 local:840b831}}BroadcastFilter{320c00 u0 ReceiverList{d3a6283 902 system/1000/u0 local:799c532}}BroadcastFilter{e486048 u0 ReceiverList{36fbaeb 902 system/1000/u0 local:5f51e3a}}BroadcastFilter{22b02 u-1 ReceiverList{b3f744d 902 system/1000/u-1 local:de837e4}}BroadcastFilter{3e989ab u0 ReceiverList{f8deffa 2981 com.google.process.gapps/10012/u0 remote:26bd225}}BroadcastFilter{fb56150 u0 ReceiverList{22b7b13 2925 com.android.systemui/10027/u0 remote:c54a602}}BroadcastFilter{63bbb6 u-1 ReceiverList{ba6c751 3484 com.android.nfc/1027/u-1 remote:5c4a478}}BroadcastFilter{95ad20d u0 ReceiverList{d8374a4 3586 com.google.android.googlequicksearchbox/10029/u0 remote:feb3737}}BroadcastFilter{fdef551 u0 ReceiverList{28ca78 3745 com.google.android.gms.persistent/10012/u0 remote:f23afdb}}BroadcastFilter{9830707 u0 ReceiverList{aabd946 3745 com.google.android.gms.persistent/10012/u0 remote:a4da121}}BroadcastFilter{83c43d2 u0 ReceiverList{d422e5d 3745 com.google.android.gms.persistent/10012/u0 remote:f585034}}BroadcastFilter{8890378 u0 ReceiverList{26d2cdb 3745 com.google.android.gms.persistent/10012/u0 remote:dfa61ea}}BroadcastFilter{7bbb7 u0 ReceiverList{214b2b6 3745 com.google.android.gms.persistent/10012/u0 remote:8353a51}}BroadcastFilter{38d3566 u0 ReceiverList{de859c1 3745 com.google.android.gms.persistent/10012/u0 remote:e003aa8}}BroadcastFilter{3435d9f u0 ReceiverList{6e38b3e 3745 com.google.android.gms.persistent/10012/u0 remote:8dd7ff9}}BroadcastFilter{d0a34bb u0 ReceiverList{5091d4a 3745 com.google.android.gms.persistent/10012/u0 remote:d6d22b5}}BroadcastFilter{d43c416 u0 ReceiverList{51a3531 3745 com.google.android.gms.persistent/10012/u0 remote:d0b9dd8}}BroadcastFilter{aabf36d u0 ReceiverList{a88bf84 3745 com.google.android.gms.persistent/10012/u0 remote:a9d6197}}BroadcastFilter{93f16b u0 ReceiverList{5c61eba 17016 com.google.android.gm/10079/u0 remote:24083e5}}BroadcastFilter{68f794e u0 ReceiverList{4cb1c49 947 com.google.android.googlequicksearchbox:search/10029/u0 remote:251d250}}..MIME Typed Actions:
6、监视器争用
监视器争用日志记录,有时可以表明实际的监视器争用情况,但通常情况下表明系统负载过重,从而导致所有进程都变慢了。可能会在System Log 或 Event Log 中看到 ART(Android Runtime)记录的长时间占用监视器的事件。
(1)在 System Log 中:
10-01 18:12:44.343 29761 29914 W art : Long monitor contention event with owner method=void android.database.sqlite.SQLiteClosable.acquireReference() from SQLiteClosable.java:52 waiters=0 for 3.914s
(2)在 Event Log 中:
10-01 18:12:44.364 29761 29914 I dvm_lock_sample : [com.google.android.youtube,0,pool-3-thread-9,3914,ScheduledTaskMaster.java,138,SQLiteClosable.java,52,100]