快速排查

应用发生崩溃,如果是生产环境,通常容易找到,如果不是,那就麻烦很多。bug的发生总是那么突如其来,有时候让我们措手不及,现在我就来理一理如何淡定的解决bug;

应用异常退出有两种可能,一种是出现了异常挂掉了,另一种是被系统杀死了。第一种是程序原因,第二种不一定是程序原因,但多数情况下还是应用的原因。

Bug排查的一般步骤:

  1. 确定应用什么时候挂掉的。
  2. 找出来应用挂掉的原因;
  3. 针对原因寻找解决方案并验证;

定位bug发生的时间

对于容易复现的bug,我们只需要在我们的程序中假如关键打印就能很容易确定什么时候应用崩溃,如果是现的bug,那就需要通过一些辅助日志来定位了;

不过这也不难,我们在bugreport的txt里面可以通过以下几种方法定位:
1. am_proc_died
有进程被杀时间点及原因包名,则直接搜索

am_proc_died: [0,[0-9]*,xxxx,,xxxx//代表包名

拿到这行log的时间点以及进程pid
eg: 08-19 10:06:55.302 1000 1699 12137 I am_proc_died: [0,9307,com.quark.browser,905,11]
如上栗子:时间点为08-19 10:06:55.302 (搜索时可自行减几毫秒,否则可能搜索不到同时间点的其他log),进程pid为9307

2. ApplicationExitInfo
在bugReport中搜索这个关键字,能找到你的应用及整个应用在最近一段时间内什么时候退出以及退出的原因,比如在我这里:

package: cn.skyruler.appHistorical Process Exit for userId=10284ApplicationExitInfo #0:timestamp=2021-11-23 18:05:14.376pid=15455realUid=10284packageUid=10284definingUid=10284user=0process=cn.xxxx.appreason=5 (APP CRASH(NATIVE))status=11importance=100pss=431MBrss=535MBdescription=crashstate=emptytrace=null

查找应用挂掉的原因

如果是java层的崩溃我们可在logcat日志中找到RuntimeException或者crash字样;如果不是,比如上面这种情况,就需要看native的日志;

  1. 通过java层logcat看是否崩溃(crashHandler或者调试版logcat)
  2. 如果java层没有任何相关日志打印就从c层看(在bugreport.zip->FS->data->tombstones->对应时间的日志)

LowMemoryKiller(低内存)

logcat中直接搜索lowmemorykiller: Kill ‘com.xxx.aaa’ (pid)

08-19 10:06:55.207 lmkd 954 954 E lowmemorykiller: Kill ‘com.xxx.aaa’ (9307), uid 10248, oom_adj 905 to free 69048kB
08-19 10:06:55.207 lmkd 954 954 I lowmemorykiller: Reclaimed 69048kB, cache(718372kB) and free(314436kB)-reserved(43892kB) below min(765000kB) for oom_adj 900

解读:手机cache 内存为718372kb,低于oom_adj 900这个级别的最低值765000kB,所以lmkd会查杀pid为9307的com.xxx.aaa进程,该进程当前的adj为905(高于900),释放了69048kb;

未有lowmemorykiller打印,但是am_low_memory递减同时,am_proc_died同时打印,且system log中有has died 打印

07-30 22:18:26.746 1000 1718 5108 I ActivityManager: Process com.xiaomi.channel (pid 21963) has died: hvy HVY
07-30 22:18:26.746 1000 1718 5127 I am_low_memory: 68
07-30 22:18:26.746 1000 1718 5108 I am_proc_died: [0,21963,com.xiaomi.channel,400,14]
07-30 22:18:26.803 1000 1718 5127 I am_low_memory: 66

解读:am_low_memory 后面的数字代表当前系统中lru 中进程的数量,数字递减代表有进程被杀,has died 代表非AMS查杀(lmk查杀或信号查杀),hvy HVY代表进程的优先级(进程自查一览表)

被其他进程杀死(比如系统进程)

在Android 11后引入了新的安全策略,其中谷歌引入了新的api:

流程退出原因api:getHistoricalProcessExitReasons

这个api使我们对私有数据访问和流程退出(主要是crash)的原因更加清晰明了。我们可以通过在bugreport日志文件里面搜索Historical Process Exit for关键字,就能看到自己的进程被谁杀死。

空进程被杀
这种是说进程已经不活动了被系统杀了,通常这种情况很少,大概是这样的:

08-10 13:32:13.057 1000 1700 1812 I am_kill : [0,2409,com.miui.screenrecorder,955,empty for 1800s]

empty进程数量达到阈值了,会查杀30min内没活跃的进程

08-10 16:00:54.244 1000 1700 1795 I ActivityManager: Killing 20081:com.android.providers.calendar/u0a72 (adj 985): empty #26

系统内empty进程数量达到阈值26(不同手机略有不同)会按时间顺序查杀进程;

进程自己退出
有时候应用退出不一定是因为奔溃,可能是程序员代码没写对或者漏掉了一些环境细节让应用主动退出了。除了看ApplicationExitInfo外我们还能通过logcat看到。

08-13 10:17:04.053 root 689 689 I Zygote : Process 29263 exited cleanly (0)
08-13 10:17:04.056 1000 1692 1805 I libprocessgroup: Successfully killed process cgroup uid 10252 pid 29263 in 122ms
08-13 10:17:03.933 1000 1692 5189 I ActivityManager: Process com.tencent.tmgp.pubgmhd (pid 29263) has died: hvy HVY

被系统进程杀掉
系统app调用forceStopPackage 接口,杀掉我们的应用,我们搜索stop com.xxx.aaa due to from process

03-25 19:34:10.498 26589 29585 I ActivityManager: Killing 14459:com.xiaomi.misubscreenui/1000 (adj 0): stop com.xiaomi.misubscreenui due to from process:com.miui.voiceassist

线程异常被杀

过渡使用CPU

09-06 18:07:44.445 1000 1651 1798 I am_kill : [0,22157,com.ximalaya.ting.android,900,excessive cpu 16720 during 300044 dur=2221553 limit=2]
09-06 18:07:44.445 1000 1651 1798 I ActivityManager: Killing 22157:com.ximalaya.ting.android/u0a239 (adj 900): excessive cpu 16720 during 300044 dur=2221553 limit=2
09-06 18:07:44.566 root 681 681 I Zygote : Process 22157 exited due to signal 9 (Killed)

上次adj降为Service以下到现在经历2221553 ms,cpu POWER_CHECK_MAX_CPU_4 = 2, 两次检测时间间隔为300044 ms,使用cpu时间为16720ms,超过2%,就会被杀。

进程的线程异常
进程的某个线程发生异常,自己发Signal 9信号给Zygote 杀掉自己

09-07 16:53:03.027 1000 2566 2582 I Process : Sending signal. PID: 2566 SIG: 9
09-07 16:53:03.154 root 681 681 I Zygote : Process 2566 exited due to signal 9 (Killed)
09-07 16:53:03.167 1000 1734 4006 I ActivityManager: Process com.android.systemui (pid 2566) has died: pers PER

应用重装,卸载被杀

installPackageLI/ deletePackageX等
只要是forceStopPackage接口查杀就有可能查杀到关联的进程,如下拨号就是因为与gms关联被杀

08-10 15:59:30.827 1000 1700 1812 I ActivityManager: Force stopping com.google.android.gms appid=10190 user=-1: installPackageLI
08-10 15:59:30.984 1000 1700 1812 I ActivityManager: Killing 3876:com.google.android.dialer/u0a180 (adj -700): stop com.google.android.gms: installPackageLI

其他退出

  • ANR退出:这个我以前写过一篇文章《ANR排查手册》;
  • OOM内存溢出:参阅阅读错误报告的查看内存情况;
  • exception导致crash:参阅阅读错误报告的设备是否发生系统崩溃?;
  • 死锁导致主线程卡住ANR:参阅阅读错误报告的查找死锁;

排查工具Battery Historian

Battery Historian是Google提供的用于可视化分析bugreport的一款工具。虽然bugreport的生成非常简单,目录结构也很好理解,但问题是,这个生成的文件非常庞大,包含的信息量也很大,如果逐个排查确实也痛苦,因此Google针对Android5.0(API21)以上的系统开发了一个分析工具Battery Historian来解析bugreport文件,并用web图形的形式展

关于电量的关键信息在DUMP OF SERVICE batterystats下,我们可以通过这个关键字在文件中找到。Battery Historian这款工具很多人推荐使用别人做好的镜像,也就是使用docker来使用,主要是简单(如果没有docker则需要先安装docker并配置mirror):

docker run -d -p 9999:9999 bhaavan/battery-historian

然后就可以通过9999端口访问了,大概长这样:

但是实际在使用的时候可能并不是很好用,比如我的会经常出现Note: Could not parse aggregated battery stats.,图标就出不来,这样就不太舒服了。

bathist网址在线bugreport解析
使用bathist最大的好处是省去了我们自己去搭建更新docker环境,相当实用。

Battery Historian使用

即使你成功生成了对应的结果试图,你不会看,那也是白瞎,下面我们来缕一缕怎么看Battery Historian;
Battery Historian 工具提供各种应用和系统行为的系统级可视化结果,以及它们随时间推移与耗电量的相关性。如图 1 所示,此视图可帮助你诊断和识别应用存在的耗电问题。

如图. Battery Historian 显示了影响功耗的系统级事件

该图中特别值得注意的是表示电池电量的黑色水平下降趋势线(在 y 轴上进行测量)。例如,在电池电量线的最开始处,大约早上 6:50 时,该图表显示电量出现较为急剧的下降。

下图 为该部分显示画面的特写图。

Battery Historian 时间轴(大约从早上 6:50 到 7:20)的特写图。

在电池电量线的最开始处,随着电池电量的急剧下降,显示画面上显示有三件事正在发生:CPU 正在运行,应用已获取唤醒锁定,且屏幕已打开。通过这种方式,Battery Historian 可帮助你了解耗电量高时正在发生什么事件。然后,你可以针对应用中的这些行为,研究是否可以进行相关优化。

系统级可视化还可以提供其他线索。例如,如果它显示移动无线装置频繁关闭和开启,则可能有机会通过智能调度 API(如 JobScheduler 或 Firebase Job Dispatcher 等)优化此行为。

系统的数据太多了,看起来头大,如果我们想要看某个特定应用的视图怎么看呢?

查看具体应用的数据

除了系统级数据视图提供的宏观数据外,Battery Historian 还提供特定于设备上运行的每个应用的数据表格和部分可视化内容。表格数据包括:

  • 应用在设备上的估计耗电量。
  • 网络信息。
  • 唤醒锁定次数。
  • 服务。
  • 进程信息。

表格提供了关于应用的两个数据维度。首先,你可以查找应用的耗电量与其他应用相比的排名位置。为此,请点击“Tables”下的“Device Power Estimates”表格。本示例研究了一款名为“Pug Power”的虚构应用。下图中研究哪些应用的耗电量最大。


图 中的表格显示,Pug Power 在此设备上的耗电量排名第九,在不属于操作系统的应用中排名第三。这些数据表明此应用需要更深入的研究。

要查找特定应用的数据,在可视化图表左侧下方,在“App Selection”下方的第二个下拉菜单中输入应用的软件包名称。

当你选择特定应用时,以下数据可视化类别将更改为显示具体应用数据,而不是系统级数据:

  • SyncManager。
  • 前台进程。
  • 用户空间唤醒锁定。
  • 热门应用。
  • JobScheduler。
  • Activity Manager Proc。

如果你的应用以不必要的频率执行同步和执行作业,SyncManager 和 JobScheduler 可视化图表会立即突出显示这种情况。这样,它们能快速展露出优化应用行为以提升电池性能的机会。

你还可以再获取具体应用的一条可视化数据,即用户空间唤醒锁定。要将此信息包含在错误报告中,请在终端窗口中输入以下命令:

$ adb shell dumpsys batterystats --enable full-wake-history

注意:从 Android 6.0(API 级别 23)开始,平台包含对应用实施特定优化的低电耗模式功能。例如,无论 JobScheduler 的调度方式如何,低电耗模式都会将作业处理成在简短的维护期间批量进行。

下面两张图 显示了 PugPower 的数据:图 5 显示了具体应用数据的可视化图表,图 6 显示了相应的表格数据。


查看可视化图表并没有发现任何显而易见的问题。JobScheduler 行显示应用没有调度作业。SyncManager 行显示应用尚未执行任何同步操作。

不过,查看表格数据的“唤醒锁定”部分发现,Pug Power 获取了 1 个小时内的唤醒锁定总次数。这种代价高昂的异常行为可能是应用耗电量较高的原因。这条信息有助于开发者专攻优化后可能会大大获益的方面。在这种情况下,为什么应用会获得如此多的唤醒锁定时间,开发者又如何改善这种行为呢?

Battery Historian 的其他功能

在很多其他情况下,Battery Historian 也可帮助你找出改善电池行为的机会。例如,Battery Historian 可以显示应用是否具有以下行为:

  • 过于频繁地触发唤醒提醒(至少每 10 秒钟一次)。
  • 持续保留 GPS 锁定。
  • 至少每 30 秒调度一次作业。
  • 至少每 30 秒调度一次同步。
  • 使用手机无线装置的频率高于预期。

获取错误报告

获取错误报告有三种方式:通过手机的开发者选项生成错误报告/从 Android 模拟器上获取错误报告/使用 adb 获取错误报告;

错误报告包含设备日志、堆栈轨迹和其他诊断信息,可以帮助你查找和修复应用中的错误。你可以通过以下几种方式从设备上获取错误报告:使用设备上的生成错误报告开发者选项、Android 模拟器菜单或开发机器上的 adb bugreport 命令。

如需生成错误报告,你必须在设备上启用开发者选项,以便访问生成错误报告选项。

从设备上获取错误报告

如需直接从你的设备上获取错误报告,请执行以下操作:

  1. 确保你已启用开发者选项。
  2. 在开发者选项中,点按生成错误报告。
  3. 选择所需的错误报告类型,然后点按报告。稍后,你便会收到错误报告已准备就绪的通知。
  4. 如需分享错误报告,请点按该通知。

从 Android 模拟器上获取错误报告

在 Android 模拟器中,你可以使用“Extended controls”窗口中的 File a bug 功能:

  1. 点击模拟器面板中的 More 图标 。
  2. 在 Extended controls 窗口中,选择左侧的 Bug report。
    此时系统会打开一个屏幕,你可以在其中查看错误报告详细信息,例如屏幕截图、AVD 配置信息和错误报告日志。你还可以输入一条包含重现步骤的消息,以便与报告一起保存。
  3. 等待错误报告完成收集,然后点击 Save Report。

使用 adb 获取错误报告

如果你只连接了一台设备,则可以使用 adb 获取错误报告,如下所示:

$ adb bugreport E:\Reports\MyBugReports

如果你没有指定错误报告的路径,系统会将其保存到本地目录。

如果你连接了多台设备,则必须使用 -s 选项指定设备。运行以下 adb 命令可获取设备序列号并生成 bug 报告。

$ adb devices
List of devices attached
emulator-5554      device
8XV7N15C31003476 device$ adb -s 8XV7N15C31003476 bugreport

保存旧版 bug 报告
默认情况下,bug 报告保存在 /bugreports 中,并可使用如下方式查看:

$ adb shell ls /bugreports/
bugreport-foo-bar.xxx.YYYY-MM-DD-HH-MM-SS-dumpstate_log-yyy.txt
bugreport-foo-bar.xxx.YYYY-MM-DD-HH-MM-SS.zip
dumpstate-stats.txt

然后,你可以通过 adb pull 提取 ZIP 文件,如下所示:

$ adb pull /bugreports/bugreport-foo-bar.xxx.YYYY-MM-DD-HH-MM-SS.zip

检查 bug 报告 ZIP 文件

默认情况下,ZIP 文件称为 bugreport-BUILD_ID-DATE.zip,它可能会包含多个文件,但最重要的文件是 bugreport-BUILD_ID-DATE.txt。此文件就是错误报告,它包含系统服务 (dumpsys)、错误日志 (dumpstate) 和系统消息日志 (logcat) 的诊断输出。系统消息包括设备抛出错误时的堆栈轨迹,以及从所有应用中使用 Log 类写入的消息。

ZIP 文件中有一个 version.txt 元数据文件,其中包含 Android 版本号,而且启用 systrace 后,ZIP 文件中还会包含 systrace.txt 文件。Systrace 工具可以获取并显示应用进程和其他 Android 系统进程的执行时间,从而帮助分析应用的性能。

dumpstate 工具会将文件从设备的文件系统复制到 ZIP 文件的 FS 文件夹下,以便你引用它们。例如,设备中的 /dirA/dirB/fileC 文件会在 ZIP 文件中生成 FS/dirA/dirB/fileC 条目。

阅读错误报告

无论是任何类型的开发工作,出错都在所难免,而错误报告对于找出和解决问题至关重要。Android 的所有版本都支持通过 Android 调试桥 (adb) 获取错误报告;Android 4.2 及更高版本支持一个旨在获取错误报告以及通过电子邮件、云端硬盘等分享报告的开发者选项。

Android 错误报告中包含文本 (.txt) 格式的 dumpsys、dumpstate 和 logcat 数据,以便你轻松搜索特定内容。以下各部分详细说明了错误报告的组成部分、介绍了常见问题,并提供了关于查找与这些错误相关的日志的实用提示和 grep 命令。大多数部分中还包括 grep 命令及输出和/或 dumpsys 输出方面的示例。

Logcat

logcat 日志是所有 logcat 信息的转储,并采用字符串形式。system(系统)部分专门用于记录框架方面的信息,与包含所有其他内容的 main(主要内容)部分相比,该部分包含更长时间内的记录。每行都以 timestamp PID TID log-level 开头。

------ SYSTEM LOG (logcat -v threadtime -d *:v) ------
--------- beginning of system
Blah
Blah
Blah--------- beginning of main
Blah
Blah
Blah

查看事件日志

该日志中包含将二进制格式转换成了字符串形式的日志消息。它比 logcat 日志要清晰明了,但也有些难以阅读。在查看事件日志时,你可以在这一部分中搜索特定进程 ID (PID),以查看相应进程一直在做什么。基本格式为:timestamp PID TID log-level log-tag tag-values。

日志级别包括以下几种:

  • V:详细
  • D:调试
  • I:信息
  • W:警告
  • E:错误
------ EVENT LOG (logcat -b events -v threadtime -d *:v) ------
09-28 13:47:34.179   785  5113 I am_proc_bound: [0,23054,com.google.android.gms.unstable]
09-28 13:47:34.777   785  1975 I am_proc_start: [0,23134,10032,com.android.chrome,broadcast,com.android.chrome/org.chromium.chrome.browser.precache.PrecacheServiceLauncher]
09-28 13:47:34.806   785  2764 I am_proc_bound: [0,23134,com.android.chrome]
...

有关其他实用的事件日志标记,请参阅 /services/core/java/com/android/server/EventLogTags.logtags。

ANR 和死锁

错误报告有助于你找出导致应用无响应 (ANR) 错误和死锁事件的原因。

找出无响应的应用

当某个应用在一定时间内没有响应(通常是由于主线程被阻塞或繁忙)时,系统会终止该进程并将堆栈转储到 /data/anr。要找出 ANR 背后的罪魁祸首,请为二进制事件日志中的 am_anr 执行 grep 命令。

grep "am_anr" bugreport-2015-10-01-18-13-48.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]

你也可以为 logcat 日志(其中包含关于发生 ANR 时是什么在占用 CPU 的更多信息)中的 ANR in 执行 grep 命令。

grep "ANR in" bugreport-2015-10-01-18-13-48.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

查找堆栈跟踪

通常你可以找到与 ANR 对应的堆栈跟踪。请确保 VM 跟踪上的时间戳和 PID 与你正在调查的 ANR 相符,然后再检查进程的主线程。请注意:

主线程只能让你了解发生 ANR 时它在做什么,这可能是导致 ANR 的真正原因,也可能不是。(错误报告中的堆栈可能是无辜的;可能有其他线程在恢复正常之前粘滞了很长时间,但不足以导致 ANR。)
可能存在多组堆栈跟踪(VM TRACES JUST NOW 和 VM TRACES AT LAST ANR)。请确保你查看的是正确的部分。

------ VM TRACES AT LAST ANR (/data/anr/traces.txt: 2015-10-01 18:14:41) ----------- pid 30363 at 2015-10-01 18:14:11 -----
Cmd line: com.google.android.apps.plus
Build fingerprint: 'google/angler/angler:6.0/MDA89D/2294819:userdebug/dev-keys'
ABI: 'arm'
Build type: optimized
Zygote loaded classes=3978 post zygote classes=27
Intern table: 45068 strong; 21 weak
JNI: CheckJNI is off; globals=283 (plus 360 weak)
Libraries: /system/lib/libandroid.so /system/lib/libcompiler_rt.so /system/lib/libjavacrypto.so /system/lib/libjnigraphics.so /system/lib/libmedia_jni.so /system/lib/libwebviewchromium_loader.so libjavacore.so (7)
Heap: 29% free, 21MB/30MB; 32251 objects
Dumping cumulative Gc timings
Total number of allocations 32251
Total bytes allocated 21MB
Total bytes freed 0B
Free memory 9MB
Free memory until GC 9MB
Free memory until OOME 490MB
Total memory 30MB
Max memory 512MB
Zygote space size 1260KB
Total mutator paused time: 0
Total time waiting for GC to complete: 0
Total GC count: 0
Total GC time: 0
Total blocking GC count: 0
Total blocking GC time: 0suspend all histogram:  Sum: 119.728ms 99% C.I. 0.010ms-107.765ms Avg: 5.442ms Max: 119.562ms
DALVIK THREADS (12):
"Signal Catcher" daemon prio=5 tid=2 Runnable| group="system" sCount=0 dsCount=0 obj=0x12c400a0 self=0xef460000| sysTid=30368 nice=0 cgrp=default sched=0/0 handle=0xf4a69930| state=R schedstat=( 9021773 5500523 26 ) utm=0 stm=0 core=1 HZ=100| stack=0xf496d000-0xf496f000 stackSize=1014KB| held mutexes= "mutator lock"(shared held)native: #00 pc 0035a217  /system/lib/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, int, char const*, art::ArtMethod*, void*)+126)native: #01 pc 0033b03b  /system/lib/libart.so (art::Thread::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char> >&) const+138)native: #02 pc 00344701  /system/lib/libart.so (art::DumpCheckpoint::Run(art::Thread*)+424)native: #03 pc 00345265  /system/lib/libart.so (art::ThreadList::RunCheckpoint(art::Closure*)+200)native: #04 pc 00345769  /system/lib/libart.so (art::ThreadList::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char> >&)+124)native: #05 pc 00345e51  /system/lib/libart.so (art::ThreadList::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits<char> >&)+312)native: #06 pc 0031f829  /system/lib/libart.so (art::Runtime::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits<char> >&)+68)native: #07 pc 00326831  /system/lib/libart.so (art::SignalCatcher::HandleSigQuit()+896)native: #08 pc 003270a1  /system/lib/libart.so (art::SignalCatcher::Run(void*)+324)native: #09 pc 0003f813  /system/lib/libc.so (__pthread_start(void*)+30)native: #10 pc 00019f75  /system/lib/libc.so (__start_thread+6)(no managed stack frames)"main" prio=5 tid=1 Suspended| group="main" sCount=1 dsCount=0 obj=0x747552a0 self=0xf5376500| sysTid=30363 nice=0 cgrp=default sched=0/0 handle=0xf74feb34| state=S schedstat=( 331107086 164153349 851 ) utm=6 stm=27 core=3 HZ=100| stack=0xff00f000-0xff011000 stackSize=8MB| held mutexes=kernel: __switch_to+0x7c/0x88kernel: futex_wait_queue_me+0xd4/0x130kernel: futex_wait+0xf0/0x1f4kernel: do_futex+0xcc/0x8f4kernel: compat_SyS_futex+0xd0/0x14ckernel: cpu_switch_to+0x48/0x4cnative: #00 pc 000175e8  /system/lib/libc.so (syscall+28)native: #01 pc 000f5ced  /system/lib/libart.so (art::ConditionVariable::Wait(art::Thread*)+80)native: #02 pc 00335353  /system/lib/libart.so (art::Thread::FullSuspendCheck()+838)native: #03 pc 0011d3a7  /system/lib/libart.so (art::ClassLinker::LoadClassMembers(art::Thread*, art::DexFile const&, unsigned char const*, art::Handle<art::mirror::Class>, art::OatFile::OatClass const*)+746)native: #04 pc 0011d81d  /system/lib/libart.so (art::ClassLinker::LoadClass(art::Thread*, art::DexFile const&, art::DexFile::ClassDef const&, art::Handle<art::mirror::Class>)+88)native: #05 pc 00132059  /system/lib/libart.so (art::ClassLinker::DefineClass(art::Thread*, char const*, unsigned int, art::Handle<art::mirror::ClassLoader>, art::DexFile const&, art::DexFile::ClassDef const&)+320)native: #06 pc 001326c1  /system/lib/libart.so (art::ClassLinker::FindClassInPathClassLoader(art::ScopedObjectAccessAlreadyRunnable&, art::Thread*, char const*, unsigned int, art::Handle<art::mirror::ClassLoader>, art::mirror::Class**)+688)native: #07 pc 002cb1a1  /system/lib/libart.so (art::VMClassLoader_findLoadedClass(_JNIEnv*, _jclass*, _jobject*, _jstring*)+264)native: #08 pc 002847fd  /data/dalvik-cache/arm/system@framework@boot.oat (Java_java_lang_VMClassLoader_findLoadedClass__Ljava_lang_ClassLoader_2Ljava_lang_String_2+112)at java.lang.VMClassLoader.findLoadedClass!(Native method)at java.lang.ClassLoader.findLoadedClass(ClassLoader.java:362)at java.lang.ClassLoader.loadClass(ClassLoader.java:499)at java.lang.ClassLoader.loadClass(ClassLoader.java:469)at android.app.ActivityThread.installProvider(ActivityThread.java:5141)at android.app.ActivityThread.installContentProviders(ActivityThread.java:4748)at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4688)at android.app.ActivityThread.-wrap1(ActivityThread.java:-1)at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1405)at android.os.Handler.dispatchMessage(Handler.java:102)at android.os.Looper.loop(Looper.java:148)at android.app.ActivityThread.main(ActivityThread.java:5417)at java.lang.reflect.Method.invoke!(Native method)at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726)at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)...Stacks for other threads in this process follow...

查找死锁

由于线程出现粘滞,死锁往往首先表现为 ANR。如果系统服务器发生死锁,监控程序最终会将其终止,从而导致日志中出现类似以下的条目:WATCHDOG KILLING SYSTEM PROCESS。对于用户来说,他们看到的是设备重新启动,但从技术上来讲这是运行时重启,而不是真正的设备重新启动。

在运行时重启时,系统服务器已死机并会重启,并且用户会看到设备返回到显示启动动画。
在设备重新启动时,内核已崩溃,并且用户会看到设备返回到显示 Google 启动徽标。
要查找死锁,请检查 VM 跟踪部分中是否存在以下模式:线程 A 在等待线程 B 占用的某些资源,而线程 B 也在等待线程 A 占用的某些资源。

"Binder_B" prio=5 tid=73 Blocked| group="main" sCount=1 dsCount=0 obj=0x13faa0a0 self=0x95e24800| sysTid=2016 nice=0 cgrp=default sched=0/0 handle=0x8b68d930| state=S schedstat=( 9351576559 4141431119 16920 ) utm=819 stm=116 core=1 HZ=100| stack=0x8b591000-0x8b593000 stackSize=1014KB| held mutexes=at com.android.server.pm.UserManagerService.exists(UserManagerService.java:387)- waiting to lock <0x025f9b02> (a android.util.ArrayMap) held by thread 20at com.android.server.pm.PackageManagerService.getApplicationInfo(PackageManagerService.java:2848)at com.android.server.AppOpsService.getOpsRawLocked(AppOpsService.java:881)at com.android.server.AppOpsService.getOpsLocked(AppOpsService.java:856)at com.android.server.AppOpsService.noteOperationUnchecked(AppOpsService.java:719)- locked <0x0231885a> (a com.android.server.AppOpsService)at com.android.server.AppOpsService.noteOperation(AppOpsService.java:713)at com.android.server.AppOpsService$2.getMountMode(AppOpsService.java:260)at com.android.server.MountService$MountServiceInternalImpl.getExternalStorageMountMode(MountService.java:3416)at com.android.server.am.ActivityManagerService.startProcessLocked(ActivityManagerService.java:3228)at com.android.server.am.ActivityManagerService.startProcessLocked(ActivityManagerService.java:3170)at com.android.server.am.ActivityManagerService.startProcessLocked(ActivityManagerService.java:3059)at com.android.server.am.BroadcastQueue.processNextBroadcast(BroadcastQueue.java:1070)- locked <0x044d166f> (a com.android.server.am.ActivityManagerService)at com.android.server.am.ActivityManagerService.finishReceiver(ActivityManagerService.java:16950)at android.app.ActivityManagerNative.onTransact(ActivityManagerNative.java:494)at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2432)at android.os.Binder.execTransact(Binder.java:453)
..."PackageManager" prio=5 tid=20 Blocked| group="main" sCount=1 dsCount=0 obj=0x1304f4a0 self=0xa7f43900| sysTid=1300 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9fcf9930| state=S schedstat=( 26190141996 13612154802 44357 ) utm=2410 stm=209 core=2 HZ=100| stack=0x9fbf7000-0x9fbf9000 stackSize=1038KB| held mutexes=at com.android.server.AppOpsService.noteOperationUnchecked(AppOpsService.java:718)- waiting to lock <0x0231885a> (a com.android.server.AppOpsService) held by thread 73at com.android.server.AppOpsService.noteOperation(AppOpsService.java:713)at com.android.server.AppOpsService$2.getMountMode(AppOpsService.java:260)at com.android.server.AppOpsService$2.hasExternalStorage(AppOpsService.java:273)at com.android.server.MountService$MountServiceInternalImpl.hasExternalStorage(MountService.java:3431)at com.android.server.MountService.getVolumeList(MountService.java:2609)at android.os.storage.StorageManager.getVolumeList(StorageManager.java:880)at android.os.Environment$UserEnvironment.getExternalDirs(Environment.java:83)at android.os.Environment.isExternalStorageEmulated(Environment.java:708)at com.android.server.pm.PackageManagerService.isExternalMediaAvailable(PackageManagerService.java:9327)at com.android.server.pm.PackageManagerService.startCleaningPackages(PackageManagerService.java:9367)- locked <0x025f9b02> (a android.util.ArrayMap)at com.android.server.pm.PackageManagerService$PackageHandler.doHandleMessage(PackageManagerService.java:1320)at com.android.server.pm.PackageManagerService$PackageHandler.handleMessage(PackageManagerService.java:1122)at android.os.Handler.dispatchMessage(Handler.java:102)at android.os.Looper.loop(Looper.java:148)at android.os.HandlerThread.run(HandlerThread.java:61)at com.android.server.ServiceThread.run(ServiceThread.java:46)

Activity

Activity 是一种应用组件,可提供一个屏幕,用户能够通过与该屏幕互动来执行某些操作,例如拨打电话号码、拍照、发送电子邮件,等等。从错误报告的角度来看,一个 Activity 是用户可以执行一项明确具体的操作,这使得查找在崩溃期间处于聚焦状态的 Activity 变得非常重要。Activity 通过 ActivityManager 运行进程,因此找出指定 Activity 的所有进程停止和启动事件也有助于进行问题排查。

查看处于聚焦状态的 Activity

要查看记录的处于聚焦状态的 Activity,请搜索 am_focused_activity。

grep "am_focused_activity" bugreport-2015-10-01-18-13-48.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]
10-01 18:11:52.747  4600 14113 I am_focused_activity: [0,com.google.android.GoogleCamera/com.android.camera.CameraActivity]
10-01 18:14:07.762  4600  5687 I am_focused_activity: [0,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL]

查看进程启动事件

要查看记录的进程启动事件,请搜索 Start proc。

grep "Start proc" bugreport-2015-10-01-18-13-48.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
...

设备是否发生系统崩溃?

要确定设备是否发生系统颠簸,请检查 am_proc_died 和 am_proc_start 前后在短时间内是否出现活动异常增加。

grep -e "am_proc_died" -e "am_proc_start" bugreport-2015-10-01-18-13-48.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]

内存

由于 Android 设备的物理内存通常都存在限制,因此管理随机存取存储器 (RAM) 至关重要。错误报告中包含一些用于指示内存不足的指标以及一个提供内存快照的 dumpstate。

发现内存不足的情况

内存不足可能会导致系统发生崩溃,这是因为虽然内存不足时系统会终止某些进程来释放内存,但又会继续启动其他进程。要查看内存不足的确凿证据,请检查二进制事件日志中 am_proc_died 和 am_proc_start 条目的密集程度。

内存不足还可能会减慢任务切换速度,并且可能会阻止进行返回尝试(因为用户尝试返回到的任务已被终止)。如果启动器被终止,它会在用户触摸主屏幕按钮时重启,并且日志中会显示启动器重新加载其内容。

查看历史指标
二进制事件日志中的 am_low_memory 条目表示最后一个缓存的进程已终止。在此之后,系统开始终止各项服务。

grep "am_low_memory" bugreport-2015-10-01-18-13-48.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

查看系统颠簸指标
关于系统颠簸(分页、直接回收等)的其他指标包括 kswapd、kworker 和 mmcqd 消耗的 CPU 周期。(请注意,收集错误报告可能会影响系统颠簸指标。)

------ CPU INFO (top -n 1 -d 1 -m 30 -t) ------User 15%, System 54%, IOW 28%, IRQ 0%
User 82 + Nice 2 + Sys 287 + Idle 1 + IOW 152 + IRQ 0 + SIRQ 5 = 529PID   TID PR CPU% S     VSS     RSS PCY UID      Thread          Proc
15229 15229  0  19% R      0K      0K  fg root     kworker/0:2
29512 29517  1   7% D 1173524K 101188K  bg u0_a27   Signal Catcher  com.google.android.talk
24565 24570  3   6% D 2090920K 145168K  fg u0_a22   Signal Catcher  com.google.android.googlequicksearchbox:search
19525 19525  2   6% R   3476K   1644K  fg shell    top             top
24957 24962  2   5% R 1706928K 125716K  bg u0_a47   Signal Catcher  com.google.android.GoogleCamera
19519 19519  3   4% S      0K      0K  fg root     kworker/3:1120   120  0   3% S      0K      0K  fg root     mmcqd/1
18233 18233  1   3% S      0K      0K  fg root     kworker/1:1
25589 25594  1   2% D 1270476K  75776K  fg u0_a8    Signal Catcher  com.google.android.gms
19399 19399  2   1% S      0K      0K  fg root     kworker/2:21963  1978  1   0% S 1819100K 125136K  fg system   android.fg      system_server1963  1981  3   0% S 1819100K 125136K  fg system   android.display system_server

ANR 日志可以提供类似的内存快照。

10-03 17:19:59.959  1963  1976 E ActivityManager: ANR in com.google.android.apps.magazines
10-03 17:19:59.959  1963  1976 E ActivityManager: PID: 18819
10-03 17:19:59.959  1963  1976 E ActivityManager: Reason: Broadcast of Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.apps.magazines/com.google.apps.dots.android.newsstand.appwidget.NewsWidgetProvider (has extras) }
10-03 17:19:59.959  1963  1976 E ActivityManager: Load: 19.19 / 14.76 / 12.03
10-03 17:19:59.959  1963  1976 E ActivityManager: CPU usage from 0ms to 11463ms later:
10-03 17:19:59.959  1963  1976 E ActivityManager:   54% 15229/kworker/0:2: 0% user + 54% kernel
10-03 17:19:59.959  1963  1976 E ActivityManager:   38% 1963/system_server: 14% user + 23% kernel / faults: 17152 minor 1073 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   11% 120/mmcqd/1: 0% user + 11% kernel
10-03 17:19:59.959  1963  1976 E ActivityManager:   10% 2737/com.android.systemui: 4.7% user + 5.6% kernel / faults: 7211 minor 149 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   0.2% 1451/debuggerd: 0% user + 0.2% kernel / faults: 15211 minor 147 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   8.7% 6162/com.twofortyfouram.locale: 4% user + 4.7% kernel / faults: 4924 minor 260 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   6.1% 24565/com.google.android.googlequicksearchbox:search: 2.4% user + 3.7% kernel / faults: 2902 minor 129 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   6% 55/kswapd0: 0% user + 6% kernel
10-03 17:19:59.959  1963  1976 E ActivityManager:   4.9% 18819/com.google.android.apps.magazines: 1.5% user + 3.3% kernel / faults: 10129 minor 986 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   2.8% 18233/kworker/1:1: 0% user + 2.8% kernel
10-03 17:19:59.959  1963  1976 E ActivityManager:   4.2% 3145/com.android.phone: 2% user + 2.2% kernel / faults: 3005 minor 43 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   4.2% 8084/com.android.chrome: 2% user + 2.1% kernel / faults: 4798 minor 380 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   3.4% 182/surfaceflinger: 1.1% user + 2.3% kernel / faults: 842 minor 13 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   3% 18236/kworker/1:2: 0% user + 3% kernel
10-03 17:19:59.959  1963  1976 E ActivityManager:   2.9% 19231/com.android.systemui:screenshot: 0.8% user + 2.1% kernel / faults: 6119 minor 348 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   2.3% 15350/kworker/0:4: 0% user + 2.3% kernel
10-03 17:19:59.959  1963  1976 E ActivityManager:   2.2% 1454/mediaserver: 0% user + 2.2% kernel / faults: 479 minor 6 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   2% 16496/com.android.chrome:sandboxed_process10: 0.1% user + 1.8% kernel / faults: 3610 minor 234 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   1% 3119/com.android.nfc: 0.4% user + 0.5% kernel / faults: 1789 minor 17 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   1.7% 19337/com.jarettmillard.localeconnectiontype:background: 0.1% user + 1.5% kernel / faults: 7854 minor 439 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   0.7% 3066/com.google.android.inputmethod.latin: 0.3% user + 0.3% kernel / faults: 1336 minor 7 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   1% 25589/com.google.android.gms: 0.3% user + 0.6% kernel / faults: 2867 minor 237 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   0.9% 1460/sensors.qcom: 0.5% user + 0.4% kernel / faults: 262 minor 5 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   0.8% 3650/mpdecision: 0% user + 0.8% kernel / faults: 160 minor 1 major
10-03 17:19:59.959  1963  1976 E ActivityManager:   0.1% 3132/com.redbend.vdmc: 0% user + 0% kernel / faults: 1746 minor 5 major

获取内存快照

内存快照是一种 dumpstate,其中会列出正在运行的 Java 进程和本机进程(有关详情,请参阅查看整体内存分配)。请注意,快照仅提供特定时刻的状态;在此快照之前,系统的状况可能更好,也可能更糟。

要了解某个进程的运行时长,请参阅进程运行时。
要了解为什么某个进程当前正在运行,请参阅某个进程为什么正在运行?

Total PSS by OOM adjustment:86752 kB: Native22645 kB: surfaceflinger (pid 197)18597 kB: mediaserver (pid 204)...136959 kB: System136959 kB: system (pid 785)220218 kB: Persistent138859 kB: com.android.systemui (pid 947 / activities)39178 kB: com.android.nfc (pid 1636)28313 kB: com.android.phone (pid 1659)13868 kB: com.redbend.vdmc (pid 1646)9534 kB: Persistent Service9534 kB: com.android.bluetooth (pid 23807)178604 kB: Foreground168620 kB: com.google.android.googlequicksearchbox (pid 1675 / activities)9984 kB: com.google.android.apps.maps (pid 13952)188286 kB: Visible85326 kB: com.google.android.wearable.app (pid 1535)38978 kB: com.google.process.gapps (pid 1510)31936 kB: com.google.android.gms.persistent (pid 2072)27950 kB: com.google.android.gms.wearable (pid 1601)4096 kB: com.google.android.googlequicksearchbox:interactor (pid 1550)52948 kB: Perceptible52948 kB: com.google.android.inputmethod.latin (pid 1566)150851 kB: A Services81121 kB: com.google.android.gms (pid 1814)37586 kB: com.google.android.talk (pid 9584)10949 kB: com.google.android.music:main (pid 4019)10727 kB: com.motorola.targetnotif (pid 31071)10468 kB: com.google.android.GoogleCamera (pid 9984)33298 kB: Previous33298 kB: com.android.settings (pid 9673 / activities)165188 kB: B Services49490 kB: com.facebook.katana (pid 15035)22483 kB: com.whatsapp (pid 28694)21308 kB: com.iPass.OpenMobile (pid 5325)19788 kB: com.google.android.apps.googlevoice (pid 23934)17399 kB: com.google.android.googlequicksearchbox:search (pid 30359)9073 kB: com.google.android.apps.youtube.unplugged (pid 21194)7660 kB: com.iPass.OpenMobile:remote (pid 23754)7291 kB: com.pujie.wristwear.pujieblack (pid 24240)7157 kB: com.instagram.android:mqtt (pid 9530)3539 kB: com.qualcomm.qcrilmsgtunnel (pid 16186)204324 kB: Cached43424 kB: com.amazon.mShop.android (pid 13558)22563 kB: com.google.android.apps.magazines (pid 13844)...4298 kB: com.google.android.apps.enterprise.dmagent (pid 13826)

广播

应用会生成广播,以便在当前应用内发送事件或向其他应用发送事件。广播接收方可以通过过滤器订阅特定消息,以便收听和响应广播。错误报告中包含已发送广播和未发送广播的相关信息,以及关于收听特定广播的所有接收方的 dumpsys。

查看历史广播

历史广播是指已发送的广播,按时间逆序排列。

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]:...

detail(详情)部分包含最近 50 个前台广播和最近 50 个后台广播的完整信息,以及每个广播的接收方。

具有 BroadcastRecord 条目的接收方是在运行时注册的,并且只会被发送到已在运行的进程。
具有 ResolveInfo 条目的接收方是通过清单条目注册的。ActivityManager 会为每个 ResolveInfo 启动相应进程(如果相应进程尚未在运行)。

Historical broadcasts [foreground]:...Historical broadcasts [background]:Historical Broadcast background #0:...Historical Broadcast background #5:BroadcastRecord{18dbb16 u0 android.intent.action.USER_PRESENT} to user 0Intent { act=android.intent.action.USER_PRESENT flg=0x24000010 }caller=com.android.systemui 2925:com.android.systemui/u0a27 pid=2925 uid=10027enqueueClockTime=2015-10-29 17:10:55 dispatchClockTime=2015-10-29 17:10:55dispatchTime=-2s321ms (0 since enq) finishTime=-2s320ms (+1ms since disp)Receiver #0: BroadcastFilter{8181cc1 u-1 ReceiverList{5d929a8 902 system/1000/u-1 local:eca4dcb}}Receiver #1: BroadcastFilter{6371c97 u-1 ReceiverList{2938b16 902 system/1000/u-1 local:840b831}}...Receiver #19: BroadcastFilter{93f16b u0 ReceiverList{5c61eba 17016 com.google.android.gm/10079/u0 remote:24083e5}}...Historical Broadcast background #37:BroadcastRecord{7f6dd6 u0 android.hardware.action.NEW_PICTURE} to user 0Intent { act=android.hardware.action.NEW_PICTURE dat=content://media/external/images/media/6345 flg=0x10 }caller=com.google.android.GoogleCamera 32734:com.google.android.GoogleCamera/u0a53 pid=32734 uid=10053enqueueClockTime=2015-10-29 17:09:48 dispatchClockTime=2015-10-29 17:09:49dispatchTime=-45s720ms (+399ms since enq) finishTime=-45s701ms (+19ms since disp)resultTo=null resultCode=0 resultData=nullnextReceiver=4 receiver=nullReceiver #0: ResolveInfo{33d2857 com.google.android.gms/com.google.android.libraries.social.mediamonitor.MediaMonitor m=0x608000}priority=0 preferredOrder=0 match=0x608000 specificIndex=-1 isDefault=falseActivityInfo:name=com.google.android.libraries.social.mediamonitor.MediaMonitorpackageName=com.google.android.gmsenabled=true exported=true processName=com.google.android.gms...Receiver #1: ResolveInfo{d9edf44 com.google.android.apps.maps/com.google.android.apps.gmm.ugc.clientnotification.StartPhotoTakenNotifierServiceReceiver m=0x608000}priority=0 preferredOrder=0 match=0x608000 specificIndex=-1 isDefault=falseActivityInfo:name=com.google.android.apps.gmm.ugc.clientnotification.StartPhotoTakenNotifierServiceReceiverpackageName=com.google.android.apps.mapsenabled=true exported=true processName=com.google.android.apps.maps...Receiver #2: ResolveInfo{743f82d com.google.android.apps.photos/com.google.android.libraries.social.mediamonitor.MediaMonitor m=0x608000}priority=0 preferredOrder=0 match=0x608000 specificIndex=-1 isDefault=falseActivityInfo:name=com.google.android.libraries.social.mediamonitor.MediaMonitorpackageName=com.google.android.apps.photosenabled=true exported=true processName=com.google.android.apps.photos...Receiver #3: ResolveInfo{d5c9162 com.google.android.apps.plus/com.google.android.libraries.social.mediamonitor.MediaMonitor m=0x608000}priority=0 preferredOrder=0 match=0x608000 specificIndex=-1 isDefault=falseActivityInfo:name=com.google.android.libraries.social.mediamonitor.MediaMonitorpackageName=com.google.android.apps.plusenabled=true exported=true processName=com.google.android.apps.plus...

查看待发送的广播

待发送的广播是指尚未发送的广播。如果队列中存在大量广播,则意味着系统无法足够快地发送广播来跟上进度。

 Active ordered broadcasts [background]:Active Ordered Broadcast background #133: // size of queue...

查看广播收听方

要查看收听某个广播的接收方列表,请查看 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:

显示器争用

显示器争用日志记录有时可以表明实际的显示器争用情况,但通常情况下会表明系统负载过重,从而导致所有进程都变慢了。你可能会在系统日志或事件日志中看到 ART 记录的长时间占用显示器的事件。

在系统日志中:

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

在事件日志中:

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]

后台编译

编译可能会占用大量资源,而且会加重设备负载。

09-14 06:27:05.670  2508  2587 E ActivityManager: CPU usage from 0ms to 5857ms later:
09-14 06:27:05.670  2508  2587 E ActivityManager:   84% 5708/dex2oat: 81% user + 2.3% kernel / faults: 3731 minor 1 major
09-14 06:27:05.670  2508  2587 E ActivityManager:   73% 2508/system_server: 21% user + 51% kernel / faults: 10019 minor 28 major
09-14 06:27:05.670  2508  2587 E ActivityManager:   1% 3935/com.android.phone: 0.3% user + 0.6% kernel / faults: 2684 minor 2 major

下载 Google Play 商店更新时,编译可能会在后台进行。在这种情况下,来自 Google Play 商店应用 (finsky) 和 installd 的消息会显示在 dex2oat 消息之前。

10-07 08:42:33.725 11051 11051 D Finsky  : [1] InstallerTask.advanceState: Prepare to patch com.garmin.android.apps.virb (com.garmin.android.apps.virb) from content://downloads/my_downloads/3602 format 2
10-07 08:42:33.752   495   495 I installd: free_cache(48637657) avail 15111192576
…
10-07 08:42:39.998  2497  2567 I PackageManager.DexOptimizer: Running dexopt (dex2oat) on: /data/app/vmdl436577137.tmp/base.apk pkg=com.garmin.android.apps.virb isa=arm vmSafeMode=false debuggable=false oatDir = /data/app/vmdl436577137.tmp/oat bootComplete=true

当某个应用正在加载尚未编译的 dex 文件时,编译也可能会在后台进行。在这种情况下,你将看不到 finsky 或 installd 日志记录。

09-14 07:29:20.433 15736 15736 I dex2oat : /system/bin/dex2oat -j4 --dex-file=/data/user/0/com.facebook.katana/app_secondary_program_dex/program-72cef82b591768306676e10161c886b58b34315a308602be.dex.jar --oat-file=/data/user/0/com.facebook.katana/app_secondary_program_dex_opt/program-72cef82b591768306676e10161c886b58b34315a308602be.dex.dex
...
09-14 07:29:25.102 15736 15736 I dex2oat : dex2oat took 4.669s (threads: 4) arena alloc=7MB java alloc=3MB native alloc=29MB free=4MB

叙述

创建问题叙述(如何开始、发生了什么、系统是如何应对的)需要一个固定的事件时间轴。你可以利用错误报告中的信息来同步多个日志中的时间轴并确定错误报告的确切时间戳。

同步时间轴

错误报告会反映多个并行时间轴(系统日志、事件日志、内核日志)以及针对广播、电池统计信息等的多个专用时间轴。遗憾的是,系统通常会使用不同的时间基准来报告时间轴。

系统日志时间戳和事件日志时间戳采用用户所用的时区(与大多数其他时间戳一样)。例如,当用户点按主屏幕按钮时,系统日志会报告以下内容:

10-03 17:19:52.939  1963  2071 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 on display 0

对于上述操作,事件日志会报告以下内容:

10-03 17:19:54.279  1963  2071 I am_focused_activity: [0,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL]

内核 (dmesg) 日志采用不同的时间基准,按距离引导加载程序完成的时间来标记日志内容(以秒为单位)。要按照其他时间表的时间基准记录此时间表,请搜索“suspend exit”(暂停退出)和“suspend entry”(暂停进入)消息。

<6>[201640.779997] PM: suspend exit 2015-10-03 19:11:06.646094058 UTC
…
<6>[201644.854315] PM: suspend entry 2015-10-03 19:11:10.720416452 UTC

由于内核日志在暂停状态下可能不会包含时间,因此你应该分段记录暂停进入和暂停退出消息之间的日志。此外,内核日志使用 UTC 时区,你必须将其调整为用户时区。

确定错误报告的生成时间

要确定错误报告的生成时间,请先查看系统日志 (Logcat) 中的 dumpstate: begin:

10-03 17:19:54.322 19398 19398 I dumpstate: begin

接下来,查看内核日志 (dmesg) 时间戳中的 Starting service ‘bugreport’ 消息:

<5>[207064.285315] init: Starting service 'bugreport'...

进行逆向推算以关联这两个事件,同时牢记同步时间轴中提到的注意事项。尽管在初始化错误报告之后发生了很多活动,但大多数活动并不是非常有用,因为生成错误报告这一活动会大大加重系统负载。

电源

事件日志中包含屏幕电源状态,其中 0 表示屏幕关闭,1 表示屏幕打开,2 表示已锁屏。

显示示例

grep screen_toggled bugreport-2015-10-18-16-52-22.txt
10-18 15:05:04.383   992   992 I screen_toggled: 1
10-18 15:05:07.010   992   992 I screen_toggled: 0
10-18 15:23:15.063   992   992 I screen_toggled: 1
10-18 15:23:25.684   992   992 I screen_toggled: 0
10-18 15:36:31.623   992   992 I screen_toggled: 1
10-18 15:36:37.660  3283  3283 I screen_toggled: 2

错误报告中还包含关于唤醒锁的统计信息,唤醒锁是应用开发者采用的一种机制,用于表明其应用需要设备保持开启状态。(要详细了解唤醒锁,请参阅 PowerManager.WakeLock 和使 CPU 保持运行状态。)

唤醒锁总时长统计信息仅跟踪唤醒锁实际负责使设备保持唤醒状态的时间,不包括屏幕处于开启状态的时间。此外,如果同时持有多个唤醒锁,系统会在它们之间分配唤醒锁时长。

如需直观呈现电源状态方面的更多帮助,请使用 Battery Historian(一种 Google 开放源代码工具,能够利用 Android 错误报告文件分析电池消耗进程)。

程序包

“DUMP OF SERVICE”程序包中包含应用版本(以及其他实用信息)。

显示示例

...
Packages:
...Package [com.google.android.gms] (3cf534b):userId=10013sharedUser=SharedUserSetting{98f3d28 com.google.uid.shared/10013}pkg=Package{b8f6a41 com.google.android.gms}codePath=/system/priv-app/PrebuiltGmsCoreresourcePath=/system/priv-app/PrebuiltGmsCorelegacyNativeLibraryDir=/system/priv-app/PrebuiltGmsCore/libprimaryCpuAbi=arm64-v8asecondaryCpuAbi=armeabi-v7aversionCode=8186448 targetSdk=23versionName=8.1.86 (2287566-448)splits=[base]applicationInfo=ApplicationInfo{5158507 com.google.android.gms}flags=[ SYSTEM HAS_CODE ALLOW_CLEAR_USER_DATA ]privateFlags=[ PRIVILEGED ]dataDir=/data/user/0/com.google.android.gmssupportsScreens=[small, medium, large, xlarge, resizeable, anyDensity]libraries:com.google.android.gmsusesOptionalLibraries:com.android.location.providercom.google.android.blecom.android.media.remotedisplayusesLibraryFiles:/system/framework/com.android.media.remotedisplay.jar/system/framework/com.android.location.provider.jartimeStamp=2015-10-14 15:17:56firstInstallTime=2015-09-22 14:08:35lastUpdateTime=2015-10-14 15:17:56signatures=PackageSignatures{db63be6 [1af63d8]}installPermissionsFixed=true installStatus=1pkgFlags=[ SYSTEM HAS_CODE ALLOW_CLEAR_USER_DATA ]declared permissions:com.google.android.gms.permission.INTERNAL_BROADCAST: prot=signature, INSTALLED...com.google.android.gms.permission.CAR_VENDOR_EXTENSION: prot=dangerous, INSTALLEDUser 0:  installed=true hidden=false stopped=false notLaunched=false enabled=0disabledComponents:com.google.android.gms.icing.service.PowerConnectedReceiver...com.google.android.gms.icing.proxy.AppsMonitorenabledComponents:com.google.android.gms.mdm.receivers.GmsRegisteredReceiver...com.google.android.gms.subscribedfeeds.SyncService

进程

错误报告中包含大量的进程数据,例如启动和停止时间、运行时时长、相关服务、oom_adj 得分等。要详细了解 Android 如何管理进程,请参阅进程和线程。

确定进程运行时

procstats 部分包含有关进程及相关服务已运行时长的完整统计信息。要快速获得便于用户阅读的摘要,请搜索 AGGREGATED OVER 以查看最近 3 个小时或 24 个小时的数据,然后搜索 Summary: 以查看进程列表、这些进程已以各种优先级运行的时长,以及它们使用 RAM 的情况(格式为“最小-平均-最大 PSS”/“最小-平均-最大 USS”)。


-------------------------------------------------------------------------------
DUMP OF SERVICE processinfo:
-------------------------------------------------------------------------------
DUMP OF SERVICE procstats:
COMMITTED STATS FROM 2015-10-19-23-54-56 (checked in):
...
COMMITTED STATS FROM 2015-10-20-03-00-00 (checked in):
...
CURRENT STATS:
...
AGGREGATED OVER LAST 24 HOURS:
System memory usage:
...
Per-Package Stats:
...
Summary:
...* com.google.android.gms.persistent / u0a13 / v8186448:TOTAL: 100% (21MB-27MB-40MB/20MB-24MB-38MB over 597)Top: 51% (22MB-26MB-38MB/21MB-24MB-36MB over 383)Imp Fg: 49% (21MB-27MB-40MB/20MB-25MB-38MB over 214)
…Start time: 2015-10-19 09:14:37Total elapsed time: +1d0h22m7s390ms (partial) libart.soAGGREGATED OVER LAST 3 HOURS:
System memory usage:
...
Per-Package Stats:
...
Summary:* com.google.android.gms.persistent / u0a13 / v8186448:TOTAL: 100% (23MB-27MB-32MB/21MB-25MB-29MB over 111)Top: 61% (23MB-26MB-31MB/21MB-24MB-28MB over 67)Imp Fg: 39% (23MB-28MB-32MB/21MB-26MB-29MB over 44)
...Start time: 2015-10-20 06:49:24Total elapsed time: +2h46m59s736ms (partial) libart.so

某个进程为什么正在运行?

dumpsys activity processes 部分会列出当前正在运行的所有进程,并按 oom_adj 得分排序(Android 通过为进程分配 oom_adj 值来表明进程的重要性,该值可由 ActivityManager 动态更新)。这种输出类似于内存快照的输出,但包含有关是什么导致进程运行的更多信息。在以下示例中,以粗体显示的条目表明 gms.persistent 进程正在以 vis(可见)优先级运行,因为该系统进程已经与其 NetworkLocationService 绑定。

显示示例

扫描

你可以按照以下步骤来确定过度执行蓝牙低功耗 (BLE) 扫描的应用:

  • 查找 BluetoothLeScanner 的日志消息:
$ grep 'BluetoothLeScanner' ~/downloads/bugreport.txt
07-28 15:55:19.090 24840 24851 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
  • 在日志消息中找到 PID。在此示例中,“24840”和“24851”分别为 PID(进程 ID)和 TID(线程 ID)。
  • 找到与该 PID 关联的应用:
PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}

在此示例中,程序包名称为 com.badapp。

  • 在 Google Play 上查找该程序包名称,以找出相应的应用;

Android BugReport异常快速排查手册相关推荐

  1. Java虚拟机知识点快速复习手册(上)

    前言 本文快速回顾了常考的的知识点,用作面试复习,事半功倍. 上篇主要内容为:虚拟机数据区域,垃圾回收 下篇主要内容为:类加载机制 面试知识点复习手册 全复习手册文章导航 Csdn全复习手册文章导航: ...

  2. 无线常见问题排查手册

    目录 常见问题排查手册 1 AC常见故障 3 结构类问题 3 设备晃动有异响 3 以太网端口网线插不紧 3 整机电源类问题 3 无法启动类问题 4 AC可以上电,但无法正常启动,且串口没有打印信息 4 ...

  3. android 如何混淆以及排查混淆后不明Bug

    前言 混淆是保护apk的必要手段,通过混淆,如果apk被反编译,会对一些关键词使用a,b,c之类的字符替换,加大解读难度 如何混淆 在build.gradle文件中配置如下代码: android {b ...

  4. 快速排查feign.FeignException: status 500 …

    feign.FeignException: status 500 - 总结一下feign报500的时候快速排查问题的方法, 这个bug容易出现的地方分别为: 1. 远程调用的时候feign的注册信息有 ...

  5. 高通5G平台(SDX55\SDX62\SDX65):ping包异常问题排查指南

    高通5G平台:ping包异常问题排查指南 1. 背景 2. Ping包数据流走向及网络架构 2.1 终端与网络架构图 2.2 终端与基站之间协议栈数据流走向图 3. Ping包问题常见分析思路 3.1 ...

  6. Medusa(美杜莎)和Hydra(九头蛇)快速入门手册:02

    本文是Medusa和Hydra快速入门手册的第二部分,第一部分的传送门这两篇也是后续爆破篇的一部分,至于字典,放在最后,后续会把祖传的几十G字典准备好 Hydra入门使用手册 vanHauser Th ...

  7. 计算机网络基础知识点快速复习手册

    前言 本文快速回顾了计算机网络书本中常考的的知识点,用作面试复习,事半功倍. 主要内容有:计算机网络体系结构,TCP与UDP,UDP/TCP实现DEMO代码 面试知识点复习手册 全复习手册文章导航 全 ...

  8. 阿里技术:如何快速排查线上故障?

    阿里技术:如何快速排查线上故障? 以下文章来源于阿里技术 ,作者小峯 阿里技术 阿里巴巴官方技术号,关于阿里的技术创新均呈现于此. 有哪些常见的线上故障?如何快速定位问题?本文详细总结工作中的经验,从 ...

  9. windows服务器被黑快速排查

    生活中windows系统我们用得最多了,如果windows 服务器被黑,如何快速排查. 下面是小梁的一些总结,可以快速检查出大部分windows服务器是否被黑,可供大家参考. 感谢大家(关注.转发.收 ...

最新文章

  1. Windows 7 部署(一):安装和部署简述
  2. 彻底理解Canal,看这篇就够了
  3. Python入门100题 | 第037题
  4. CPU_X86架构和ARM架构入门篇
  5. 【Scratch】青少年蓝桥杯_每日一题_2.17_城堡
  6. 【数据库】MySQL创建视图(CREATE VIEW)
  7. Promise第三篇:async和await关键字
  8. linux自学笔记--vim和文本三剑客基础
  9. 万物皆可Graph | 当推荐系统遇上图神经网络(四)
  10. rust建深海_rust怎么移动自己的领地柜 | 手游网游页游攻略大全
  11. 在C++中各类型拼接成一个string
  12. iOS 各种坐标系对比
  13. mysql可以授予的权限包括多选题_mysql中的权限有( )。 (5.0分)_学小易找答案
  14. 学习了1!+...10!
  15. 第五章 二叉树(a)树
  16. 开源微信共享记账小程序
  17. 230. Kth Smallest Element in a BSTs
  18. 国内及国际公共DNS收录
  19. 传统密码学(三)——转轮密码机
  20. 2020年9月中国编程语言排行榜

热门文章

  1. 深度学习书籍推荐!最新,最实用,最前沿!
  2. PPPoE拨号的工作原理
  3. 系统资源是什么,以及线程什么时候不会释放 共享资源
  4. PHP判断IP属于国内国外
  5. mysql中什么叫外键_数据库中外键是什么?
  6. 串口及串口通信硬件详解UART,I2C,SPI,USB
  7. vue实现机器人聊天
  8. Flex 4 stage.scaleMode详解 (第二部分 Flex 4 Web项目)
  9. 维地水流动运移模型ESI.Groundwater.Vistas.Premium.v7.08.build6
  10. Sqlalchemy 使用通配符查询