一、卡顿介绍及优化工具选择

1.1. 卡顿问题介绍

对于用户来说我们的应用当中的很多性能问题比如内存占用高、流量消耗快等不容易被发现，但是卡顿却很容易被直观的感受到，对于开发者来说，卡顿问题又难以定位，那么它究竟难在哪里呢？

卡顿问题难点：

• 产生原因错综复杂：代码、内存、绘制、IO等都有可能导致卡顿
• 不易复现：线上卡顿问题在线下难以复现，这和用户当时的系统环境有很大关系（比如当时用户磁盘空间不足导致的IO写入性能下降从而引发了卡顿，所以我们最好能记录在发生卡顿时用户当时的场景）

1.2. 优化工具选择

①、CPU Profiler

• 图形化的形式展示执行时间、调用栈等
• 信息全面，包含所有线程
• 运行时开销严重，整体都会变慢

使用方式：

• Debug.startMethodTracing("");
• Debug.stopMethodTracing("");
• 生成文件在sd卡：Android/data/packagename/files

②、Systrace

• 监控和跟踪Api调用，线程运行情况，生成Html报告
• 要求是在API18以上使用，所以这里推荐使用TraceCompat

使用方式：

• python systrace.py -t 10 [other-options] [categories]
• 详见官方文档

Systrace优点

• 轻量级，开销小
• 直观反映CPU利用率
• 右侧Alert一栏会给出相关建议

③、StrictMode

• Android2.3引入的工具类——严苛模式，Android提供的一种运行时检测机制，帮助开发者检测代码中的一些不规范的问题
• 包含：线程策略和虚拟机策略检测
• 线程策略：1、自定义的耗时调用，detectCustomSlowCalls() 2、磁盘读取操作，detectDiskReads 3、网络操作，detectNetwork
• 虚拟机策略：1、Activity泄露，detectActivityLeaks() 2、Sqlite对象泄露，detectLeakedSqliteObjects 3、检测实例数量，setClassInstanceLimit()

现在到之前的Demo中来实际使用一下，找到我们的Application类，新增一个方法initStrictMode()：

private void initStrictMode(){
        if (DEV_MODE) {
            StrictMode.setThreadPolicy(new StrictMode.ThreadPolicy.Builder()
                    .detectCustomSlowCalls() //API等级11，使用StrictMode.noteSlowCode
                    .detectDiskReads()
                    .detectDiskWrites()
                    .detectNetwork()// or .detectAll() for all detectable problems
                    .penaltyLog() //在Logcat 中打印违规异常信息
                    .build());
            StrictMode.setVmPolicy(new StrictMode.VmPolicy.Builder()
                    .detectLeakedSqlLiteObjects()
                    .setClassInstanceLimit(FeedBean.class, 1)
                    .detectLeakedClosableObjects() //API等级11
                    .penaltyLog()
                    .build());
        }
    }

首先在这里加了一个标记位DEV_MODE，也就是只在线下开发的时候才会走到这个方法。对于线程策略使用方式就是StrictMode.setThreadPolicy，然后就是一些配置比如磁盘的读取、写入、网络监控等，如果出现了违规情况我们使用的是penaltyLog()方法在日志中打印出违规信息，这里你也可以选择别的方式。对于虚拟机策略这里是配置需要检测出Sqlite对象的泄露，并且这里还设置某个类的实例数量是x，如果大于x它应该会被检测出不合规。

二、自动化卡顿检测方案及优化

2.1. 为什么需要自动化卡顿检测

• 上面介绍的几种系统工具只适合线下实际问题作针对性分析
• 线上及测试环节需要自动化检测方案帮助开发者定位卡顿，记录卡顿发生时的场景

2.2. 自动化卡顿检测方案原理

• 消息处理机制，一个线程不管有多少Handler都只会有一个Looper对象存在，主线程中执行的任何代码都会通过Looper.loop()方法执行，loop()函数中有一个mLogging对象
• mLogging对象在每个message处理前后都会被调用
• 主线程如果发生卡顿，则一定是在dispatchMessage方法中执行了耗时操作，然后我们可以通过mLogging对象对dispatchMessage执行的时间进行监控

我在这里从Looper.java的loop()方法的源码中截取了一段代码，大家看下：

// This must be in a local variable, in case a UI event sets the logger
if (logging != null) {
    logging.println(">>>>> Dispatching to " + msg.target + " " +
        msg.callback + ": " + msg.what);
}
 
......
此处省略一大段代码
 
if (logging != null) {
    logging.println("<<<<< Finished to " + msg.target + " " + msg.callback);
}            

它在Message执行的前后都打印了一段日志并且是不同的，所以我们可以通过这个来判断Message处理的开始和结束的时机。

具体的实现原理：

• 使用 Looper.getMainLooper.setMessageLogging()来设置自己的logging
• 匹配>>>>> Dispatching，阈值之后在子线程中执行任务（获取堆栈及场景信息，比如内存大小、电量、网络状态等）
• 匹配<<<<< Finished，说明在指定的阈值之内message被执行完成没有发生卡顿，任务启动之前取消掉

2.3. AndroidPerformanceMonitor

• 非侵入式的性能监控组件，通知形式弹出卡顿信息
• implementation 'com.github.markzhai:blockcanary-android:1.5.0'

下面我们在项目中实际使用一下：

首先在application中进行初始化：

//BlockCanary初始化
BlockCanary.install(this,new AppBlockCanaryContext()).start();

这里入参有一个AppBlockCanaryContext，这个是我们自定义BlockCanary配置的一些信息：

public class AppBlockCanaryContext extends BlockCanaryContext {
  
    public String provideQualifier() {
        return "unknown";
    }
 
    public String provideUid() {
        return "uid";
    }
 
    public String provideNetworkType() {
        return "unknown";
    }
 
    public int provideMonitorDuration() {
        return -1;
    }
 
    //设置卡顿阈值为500ms
    public int provideBlockThreshold() {
        return 500;
    }
 
    public int provideDumpInterval() {
        return provideBlockThreshold();
    }
 
    public String providePath() {
        return "/blockcanary/";
    }
 
    public boolean displayNotification() {
        return true;
    }
 
    public boolean zip(File[] src, File dest) {
        return false;
    }
 
    public void upload(File zippedFile) {
        throw new UnsupportedOperationException();
    }
 
    public List<String> concernPackages() {
        return null;
    }
 
    public boolean filterNonConcernStack() {
        return false;
    }
 
    public List<String> provideWhiteList() {
        LinkedList<String> whiteList = new LinkedList<>();
        whiteList.add("org.chromium");
        return whiteList;
    }
 
    public boolean deleteFilesInWhiteList() {
        return true;
    }
 
    public void onBlock(Context context, BlockInfo blockInfo) {
        Log.i("jarchie","blockInfo "+blockInfo.toString());
    }
}

然后在MainActivity中模拟一次卡顿，让当前线程休息2s，然后来看一下这个组件会不会通知我们：

        try {
            Thread.currentThread().sleep(2000);
        }catch (InterruptedException e){
            e.printStackTrace();
        }        

当我们把程序运行之后，会发现手机桌面上出现了一个Blocks的图标，这个玩意和之前我们使用LeakCanary的时候有点像哈，然后点进去果然发现了刚刚的Block信息，如下所示：

这里详细的打出了当前的CPU核心数、进程名、内存情况、block的堆栈信息等等，我们就可以根据这些堆栈找到对应哪个类的哪一行代码出现了问题，然后进行修改即可。

对于这种方案的总结如下：

• 非侵入式方案：可以监控在主线程中执行的任何方法并且不需要我们手动埋点
• 方便精准，定位到代码某一行

这种方案网上有很多的使用资料，但是实际上它也是存在一定的问题的，自动检测方案的问题：

• 确实卡顿了，但卡顿堆栈可能不准确
• 和OOM一样，最后的堆栈只是表象，不是真正的问题

举个栗子：主线程在T1 T2时间段内发生了卡顿，卡顿检测方案获取卡顿堆栈的信息是T2时刻，但是实际情况可能是整个这一段时间之内某个函数的耗时过长导致的卡顿，捕获堆栈的时机此时该函数已经执行完成，所以在T2时刻捕获的堆栈信息并不能准确的反应现场情况。

自动检测方案优化

• 获取监控周期内的多个堆栈，而不仅是最后一个，这样如果发生卡顿，由于我们有多个堆栈信息，所以可以推测出整个周期内究竟发生了什么，能够更加清晰的还原卡顿现场

海量卡顿堆栈处理：高频卡顿上报量太大，会导致服务端有压力

• 分析：一个卡顿下多个堆栈大概率有重复
• 解决：对一个卡顿下堆栈进行hash排重，找出重复的堆栈
• 效果：极大的减少展示量同时更高效找到卡顿堆栈

三、ANR实战分析

3.1. 什么是 ANR？

ANR（Application Not Responding）是指应用程序未响应，Android 系统对于一些事件需要在一定时间范围内完成，如果超过预定时间未能得到有效响应或者响应时间过长，都会造成 ANR。

ANR 的产生需要满足三个条件：

• 主线程：只有 应用程序的主线程 响应超时才会产生 ANR
• 超时时间：产生 ANR 的上下文不同，超时时间也会不同，但只要在这个时间上限内没有响应就会 ANR
• 输入事件/特定操作：输入事件是指按键、触屏等设备输入事件，特定操作是指 BroadcastReceiver 和 Service 的生命周期中的各个函数，产生 ANR 的上下文不同，导致 ANR 的原因也会不同

为了降低因网络访问导致的 ANR，在 Android 4.0 之后强制规定访问网络必须在子线程处理，如果在主线程访问网络将会抛出 NetworkOnMainThreadException。

只要是耗时操作都可能会阻塞主线程，耗时操作要求放在子线程。

3.2. ANR 发生场景

不同的场景产生 ANR 的方式也不同，在这里详细讲讲各种情况产生的场景。

ANR 事件	超时时间	相应日志描述
点击事件（按键和触摸事件）	5s 内没被处理	Input event dispatching timed out
Service	前台 Service 20s，后台 Service 200s 未完成启动	Timeout executing service
BroadcastReceiver	前台广播 10s，后台广播 60s，onReceive() 在规定时间内没处理完	Timeout of broadcast Broadcast Record
ContentProvider	publish 在 10s 内没处理完	Timeout publishing content providers

需要注意的是，前台广播的 ANR 时间虽然是 10s 内 onReceive() 没有执行完就提示，这是在没有点击触摸事件导致 ANR 的前提下才是 10s，否则会先触发点击事件的 ANR，onReceive() 有可能执行不到 10s 就发生 ANR，所以不要在 onReceive() 处理耗时操作。

在实际项目中，大多数的 ANR 都是点击触摸事件超时导致，会超时的原因也主要由以下三个原因导致：

• 数据导致的 ANR：频繁 GC 导致线程暂停，处理事件时间被拉长
• 线程阻塞或死锁导致的 ANR
• Binder 导致的 ANR：Binder 通信数据量过大

所以，我们想要得到为什么会出现 ANR，就必须对于原理了解清楚，且知道有多少情况会导致出现事件被拉长的问题。

3.3. 系统对 ANR 的捕捉原理

在网上有很多分析 ANR 的文章都都将 ANR 触发过程理解为装炸弹和拆炸弹的过程，但说到本质上，系统内部对于 ANR 的触发流程其实也很简单，ANR 也是建立在主线程 Looper 机制上的，简单理解就是 先发送一个延时消息，然后在特定位置移除这个消息，如果消息没有被移除则证明整个流程出现问题，执行 ANR 处理。

触发 ANR 生成日志时，在不同的系统版本会有所不同，上图中是通过 ANRHelper 类处理 ANR 日志收集，在其他较低系统版本上是 AppErrors 类处理 ANR 日志收集。

3.4. 如何分析 ANR

3.4.1. traces.txt 信息概览

当发生 ANR 时系统会在 /data/anr/ 目录额外生成一份 traces.txt 日志，方便我们可以了解到发生 ANR 时的基本信息和堆栈信息。

traces.txt 日志信息如下（以主线程为例）：

// main 代表的主线程
// Native 是线程状态
// 下面的是堆栈信息
"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x73cff4c0 self=0xafa84400
  | sysTid=5790 nice=0 cgrp=top-app sched=1073741825/1 handle=0xb2717534
  | state=S schedstat=( 3240607247 80660807 2053 ) utm=283 stm=41 core=1 HZ=100
  | stack=0xbe7c1000-0xbe7c3000 stackSize=8MB
  | held mutexes=
  kernel: (couldn't read /proc/self/task/5790/stack)
  native: #00 pc 00048968  /system/lib/libc.so (__ioctl+8)
  native: #01 pc 0001b0cf  /system/lib/libc.so (ioctl+38)
  native: #02 pc 0003cd25  /system/lib/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+168)
  native: #03 pc 0003d737  /system/lib/libbinder.so (_ZN7android14IPCThreadState15waitForResponseEPNS_6ParcelEPi+238)
  native: #04 pc 0003662d  /system/lib/libbinder.so (_ZN7android8BpBinder8transactEjRKNS_6ParcelEPS1_j+36)
  native: #05 pc 000999cf  /system/lib/libandroid_runtime.so (???)
  native: #06 pc 00607b09  /system/framework/arm/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+140)
  at android.os.BinderProxy.transactNative(Native method)
  at android.os.BinderProxy.transact(Binder.java:930)
  at android.view.IWindowSession$Stub$Proxy.remove(IWindowSession.java:924)
  at android.view.ViewRootImpl.dispatchDetachedFromWindow(ViewRootImpl.java:3306)
  at android.view.ViewRootImpl.doDie(ViewRootImpl.java:5961)
  - locked <0x0ed5befa> (a android.view.ViewRootImpl)
  at android.view.ViewRootImpl.die(ViewRootImpl.java:5938)
  at android.view.WindowManagerGlobal.removeViewLocked(WindowManagerGlobal.java:459)
  at android.view.WindowManagerGlobal.removeView(WindowManagerGlobal.java:397)
  - locked <0x05ba7d9d> (a java.lang.Object)
  at android.view.WindowManagerImpl.removeViewImmediate(WindowManagerImpl.java:126)
  at d.h.b.q.n.a$c.removeViewImmediate(SourceFile:1)
  at android.widget.Toast$TN.handleHide(Toast.java:496)
  at android.widget.Toast$TN$2.handleMessage(Toast.java:346)
  at android.os.Handler.dispatchMessage(Handler.java:102)
  at android.os.Looper.loop(Looper.java:154)
  at android.app.ActivityThread.main(ActivityThread.java:6193)
  at java.lang.reflect.Method.invoke!(Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)

关键信息	描述
main	main 标识是主线程。在 traces.txt 中如果是线程会命名为 “thread-x” 的格式，x 表示线程 id，逐步递增
prio	线程优先级，默认是 5
tid	tid 不是线程的 id，是线程唯一标识 id
group	线程组名称
sCount	该线程被挂起的次数
dsCount	线程被调试器挂起的次数
obj	对象地址
self	该线程 native 的地址
sysTid	线程号（主线程的线程号和进程号相同）
nice	线程的调度优先级
sched	分别标志了线程的调度策略和优先级
cgrp	调度归属组
handle	线程处理函数的地址
state	调度状态
schedstat	从 /proc/[pid]/task/[tid]/schedstat 读出，三个值分别表示线程在 cpu 上执行的时间、线程的等待时间和线程执行的时间片长度，不支持这项信息的三个值都是 0
utm	线程用户态下使用的时间值（单位是 jiffies）
stm	内核态下的调度时间值
core	最后执行这个线程的 cpu 核的序号

线程状态	说明	描述
UNDEFINED = -1
ZOMBIE = 0	TERMINATED	线程已经终止
RUNNING = 1	RUNNABLE or running now	正常运行
TIMED_WAIT = 2	TIMED_WAITING Object.wait()	等待，一般是调用 Object.wait(2000)
MONITOR = 3	BLOCKED on a monitor	synchronized
WAIT = 4	WAITING in Object.wait()	调用 Object.wait() 或 LockSupport.park() 等待
INITIALIZING = 5	allocated, not yet running	已经初始化线程，但是还没有进行 start
STARTING = 6	started, not yet on thread list	已经 start 但是没有 run
NATIVE = 7	off in a JNI native method	native 线程出问题，有三种常见情况： 1、项目自己有 JNI 开发线程 2、有 IO 操作（IO 的本质是调用 Linux 内核的函数） 3、AQS 锁住了
VMWAIT = 8	waiting on a VM resource	没有时间片
SUSPENDED = 9	suspended，usually by GC or debugger	被 GC 挂起的（该情况发生的可能性不高）
Blocked		死锁（查看 CPU usage 会发现几乎都是 0%，这也是死锁的体现）

其中线程状态和堆栈信息是我们最关心的，它能够帮助我们快速定位到具体位置（堆栈信息有我们应用的函数调用的话）。

3.4.2. 日志分析思路

日志分析思路主要可以分为四个步骤：

• ANR 日志准备（traces.txt + mainlog）
• 在 traces.txt 找到 ANR 信息（发生 ANR 时间节点、主线程状态、事故点、ANR 类型）
• 在 mainlog 日志分析发生 ANR 时的 CPU 状态
• 在 traces.txt 分析发生 ANR 时的 GC 情况（分析内存）

3.4.2.1. ANR 日志准备（traces.txt + mainlog）

在发生 ANR 的时候，系统会收集 ANR 相关的信息提供给开发者：

• 发生 ANR 时会收集 trace 信息能找到各个线程的执行情况和 GC 信息，trace 文件保存在 /data/anr/traces.txt
• 在 mainlog 日志中有 ANR 相关的信息和发生 ANR 时的 CPU 使用情况

简单说就是我们至少需要两份文件：/data/anr/traces.txt 和 mainlog 日志。如果有 eventlog 能更快的定位到 ANR 的类型，当然 traces.txt 和 mainlog 也能分析得到。

traces.txt 文件通过命令 adb pull /data/anr/ 获取。

mainlog 日志需要在程序运行时就时刻记录 adb logcat -v time -b main > mainlog.log。

3.4.2.1.1. 在 traces.txt 找到 ANR 信息（发生 ANR 时间节点、主线程状态、事故点、ANR 类型）

当我们拿到 traces.txt 文件时，主要找四个信息：发生 ANR 时的时间节点、主线程状态（在文件中搜索 main）、ANR 类型、事故点（堆栈信息中找到我们应用中的函数）。

分析发生 ANR 时进程中各个线程的堆栈，一般有几种情况：

• 主线程状态是 Runnable 或 Native，堆栈信息中有我们应用中的函数，则很有可能就是执行该函数时候发生了超时
• 主线程状态是 Block，非常明显的线程被锁，这时候可以看是被哪个线程锁了，可以考虑优化代码，如果是死锁问题，就更需要及时解决了
• 由于抓 trace 的时刻很有可能耗时操作已经执行完了（ANR -> 耗时操作执行完毕 -> 系统抓 trace），这时候的 trace 就没有什么用了（在堆栈信息找不到我们应用的函数调用）

/data/anr/traces.txt

// 发生 ANR 时的时间节点
----- pid 5790 at 2022-07-19 13:23:32 -----

// 主线程状态
"main" prio=5 tid=1 Waiting

// 事故点
// 不一定能找到我们应用的调用函数，因为抓 trace 的时候耗时操作可能已经执行完了，例如下面的堆栈
at android.os.BinderProxy.transactNative(Native method)
at android.os.BinderProxy.transact(Binder.java:930)
at android.view.IWindowSession$Stub$Proxy.remove(IWindowSession.java:924)
at android.view.ViewRootImpl.dispatchDetachedFromWindow(ViewRootImpl.java:3306)
at android.view.ViewRootImpl.doDie(ViewRootImpl.java:5961)
- locked <0x0ed5befa> (a android.view.ViewRootImpl)
at android.view.ViewRootImpl.die(ViewRootImpl.java:5938)
at android.view.WindowManagerGlobal.removeViewLocked(WindowManagerGlobal.java:459)
at android.view.WindowManagerGlobal.removeView(WindowManagerGlobal.java:397)
- locked <0x05ba7d9d> (a java.lang.Object)
at android.view.WindowManagerImpl.removeViewImmediate(WindowManagerImpl.java:126)
at d.h.b.q.n.a$c.removeViewImmediate(SourceFile:1)
at android.widget.Toast$TN.handleHide(Toast.java:496)
at android.widget.Toast$TN$2.handleMessage(Toast.java:346)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:154)
at android.app.ActivityThread.main(ActivityThread.java:6193)
at java.lang.reflect.Method.invoke!(Native method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)

因为从上面的堆栈中其实不能分析到 ANR 类型，所以可以再借助 eventlog 或 mainlog 日志找到，可以在 mainlog 日志 搜索关键词 ANR in：

mainlog.log（对应的 adb logcat -v time -b main > mainlog.log）

07-19 13:23:38.029  2003  2016 E ActivityManager: ANR in com.example.demo (com.example.demo/.ui.login.LoginActivity)
07-19 13:23:38.029  2003  2016 E ActivityManager: PID: 5790
07-19 13:23:38.029  2003  2016 E ActivityManager: PSS: 42718 kB
07-19 13:23:38.029  2003  2016 E ActivityManager: Reason: Input dispatching timed out (Waiting to send key event because the focused window has not finished processing all of the input events that were previously delivered to it.  Outbound queue length: 0.  Wait queue length: 1.)
07-19 13:23:38.029  2003  2016 E ActivityManager: Load: 16.16 / 10.88 / 4.95

在 eventlog 日志 搜索关键词 am_anr：

07-19 13:22:29.166  2003  2016 I am_anr  : [0,3392,com.example.demo,955792964,Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)]

3.4.2.1.2. 在 mainlog 日志分析发生 ANR 时的 CPU 状态

在 mainlog 日志中根据 ANR 时间节点并 搜索关键词 CPU usage 查看发生 ANR 前后 CPU 的使用情况，从 CPU usage 信息中大概可以分析：

• 如果某些进程的 CPU 占用百分比较高，几乎占用了所有 CPU 资源，而发生 ANR 的进程（一般说的是我们的 app 进程）CPU 占用为 0% 或非常低，则认为 CPU 资源被占用，app 进程没有被分配足够的资源，从而发生了 ANR。这种情况多数可以认为是系统状态的问题，并不是由应用造成的（简单讲就是其他进程 CPU 使用率非常高自己低，就是系统资源分配不足导致）
• 如果发生 ANR 的进程（一般说的是我们的 app 进程）CPU 占用较高，如到了 80% 或 90% 以上，则可以怀疑应用内一些代码不合理消耗掉了 CPU 资源，如出现了死循环或者后台有许多线程执行任务等等原因，这就要结合 traces.txt 和 ANR 前后的 mainlog 日志进一步分析（简单理解就是 IO 非常频繁，要么死循环了，要么上锁了）
• 如果 CPU 总用量不高，该进程和其他进程的占用过高，这有一定概率是由于某些主线程的操作就是耗时过长，或者是由于主进程被锁造成的

mainlog.log

07-19 13:23:38.029  2003  2016 E ActivityManager: CPU usage from 2068ms to -8489ms ago (2022-07-19 13:23:27.434 to 2022-07-19 13:23:37.991):
07-19 13:23:38.029  2003  2016 E ActivityManager:   30% 2003/system_server: 16% user + 14% kernel / faults: 7835 minor 541 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   13% 5790/com.example.demo: 9.2% user + 3.9% kernel / faults: 11775 minor 141 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   5.4% 247/mmcqd/0: 0% user + 5.4% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   5.4% 2591/com.xtc.i3launcher: 4.3% user + 1% kernel / faults: 4186 minor 276 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   3.3% 36/kworker/u8:3: 0% user + 3.3% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   2.9% 410/audioserver: 1.7% user + 1.2% kernel / faults: 79 minor 3 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   2.8% 5754/com.netease.xtc.cloudmusic: 2.8% user + 0% kernel / faults: 1954 minor 315 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   2.3% 2457/com.android.phone: 1.6% user + 0.7% kernel / faults: 2226 minor 513 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   2.2% 35/kworker/u8:2: 0% user + 2.2% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   2.2% 356/surfaceflinger: 0.9% user + 1.3% kernel / faults: 464 minor
07-19 13:23:38.029  2003  2016 E ActivityManager:   2.1% 110/kswapd0: 0% user + 2.1% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   2% 448/kworker/u8:8: 0% user + 2% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   1.9% 444/kworker/u8:7: 0% user + 1.9% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   1.9% 4683/kworker/u8:9: 0% user + 1.9% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   1.4% 4782/com.android.commands.monkey: 0.5% user + 0.8% kernel / faults: 1598 minor 3 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   1.1% 299/logd: 0.5% user + 0.5% kernel / faults: 200 minor 115 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   1.1% 3499/super_log: 0.2% user + 0.8% kernel / faults: 69 minor 1 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.9% 7/rcu_preempt: 0% user + 0.9% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.8% 2795/com.android.dialer: 0.7% user + 0% kernel / faults: 1270 minor 221 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.4% 4696/mdss_fb0: 0% user + 0.4% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.3% 12/ksoftirqd/1: 0% user + 0.3% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.3% 20/ksoftirqd/3: 0% user + 0.3% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.3% 258/core_ctl/0: 0% user + 0.3% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.3% 2178/VosRXThread: 0% user + 0.3% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.3% 2183/sdcard: 0% user + 0.3% kernel / faults: 42 minor 3 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.2% 3/ksoftirqd/0: 0% user + 0.2% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.2% 290/jbd2/mmcblk0p43: 0% user + 0.2% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.1% 15/migration/2: 0% user + 0.1% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.1% 16/ksoftirqd/2: 0% user + 0.1% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.1% 19/migration/3: 0% user + 0.1% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.1% 269/kworker/0:4: 0% user + 0.1% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0.1% 355/servicemanager: 0% user + 0% kernel / faults: 68 minor
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 1//init: 0% user + 0% kernel / faults: 6 minor 4 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 5/kworker/0:0H: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 8/rcu_sched: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 10/migration/0: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 11/migration/1: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 14/kworker/1:0H: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 135/mdp3_ppp: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 223/irq/114-5-0024: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 271/kworker/0:1H: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 276/kworker/3:3: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 309/debuggerd: 0% user + 0% kernel / faults: 237 minor 27 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 415/media.extractor: 0% user + 0% kernel / faults: 117 minor 66 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 419/netd: 0% user + 0% kernel / faults: 134 minor 2 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 2177/VosTXThread: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 2713/com.xtc.i3launcher:push: 0% user + 0% kernel / faults: 955 minor 58 major
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 2767/perffeedbackd: 0% user + 0% kernel / faults: 77 minor
07-19 13:23:38.029  2003  2016 E ActivityManager:   0% 4546/kworker/1:3: 0% user + 0% kernel
07-19 13:23:38.029  2003  2016 E ActivityManager: 84% TOTAL: 14% user + 17% kernel + 51% iowait + 0.6% softirq

发生死锁时的 CPU 状态如下：

3.4.2.1.3. 在 traces.txt 分析发生 ANR 时的 GC 情况（分析内存）

当上面分析了 CPU 状态后发现是非 CPU 问题时，就需要从内存 GC 分析，因为 GC 会触发 STW（Stop The World）导致线程执行时间被拉长。

// 这里只截取了一部分 GC 信息
// 如果还有其他信息，还需要分析如 GC 回收率等，下面的 GC 信息是正常的，这里仅用于展示
Total time waiting for GC to complete: 64.298ms
Total GC count: 30
Total GC time: 4.961s
Total blocking GC count: 1
Total blocking GC time: 149.286ms
1234567

其实 ANR 问题主要就是两类问题：

• CPU 问题
• GC 问题

所以定位 ANR 总的来说就是：

• 判定是否为 CPU 问题：常见的是在主线程事件发生
• 如果非 CPU 问题，再去定位 GC 问题
• GC 问题直接去看 traces.txt 上面的 GC 信息
  • 常规 GC 导致的问题，就是有频繁的对象创建
  • 常规少量数据不会出现有这个问题，但是数据量异常将会引发连锁反应，ANR 是结果的体现，具体体现是卡顿和内存泄漏

3.5. ANR 解决方案

• 将所有耗时操作如访问网络、socket 通信、查询大量 SQL 语句、复杂逻辑计算等都放在子线程中，然后通过 handler.sendMessage、runOnUIThread 等方式更新 UI。无论如何都要确保用户界面的流畅度，如果耗时操作需要让用户等待，可以在界面上显示进度条
• 将 IO 操作放在异步线程。在一些同步的操作主线程有可能被锁，需要等待其他线程释放响应锁才能继续执行，这样会有一定的 ANR 风险，对于这种情况有时也可以用异步线程来执行相应的逻辑，另外，要避免死锁的发生
• 使用 Thread 或 HandlerThread 时，调用 Process.setThreadPriority（Process.THREAD_PRIORITY_BACKGROUND）设置优先级，否则仍然会降低程序响应，因为默认 Thread 优先级和主线程相同
• 使用 Handler 处理工作线程结果，而不是使用 Thread.wait() 或 Thread.sleep() 来阻塞主线程
• Activity 的 onCreate() 和 onResume() 回调中避免耗时代码
• BroadcastReceiver 中 onReceive() 代码也要尽量减少耗时，建议使用 IntentService 处理
• 各个组件的生命周期函数都不应该有太耗时的操作，即使对于后台 Service 或 ContentProvider 来讲，虽然应用在后台运行时生命周期函数不会有用户输入引起无响应的 ANR，但其执行时间过长也会引起 Service 或 ContentProvider 的 ANR

以上的常规解决方案实际上只有一个核心，就是降低线程阻塞时间，将耗时操作放到子线程处理。

3.6. ANR 监控方案

3.6.1. FileObserver

FileObserver 可以做到指定文件目录的监控功能，我们可以使用它实现监控 /data/anr 目录，当该目录有变动时即说明发生了 ANR。

public class ANRFileObserver extends FileObserver {
    private static final String TAG = "ANRFileObserver";

    public ANRFileObserver(String path) {
        super(path);
    }

    @Override
    public void onEvent(int event, @Nullable String path) {
        switch (event) {
            case FileObserver.ACCESS: // 文件被访问
                Log.i(TAG, "ACCESS = " + path);
                break;
            case FileObserver.ATTRIB: // 文件属性被修改，如 chmod、chown、touch 等
                Log.i(TAG, "ATTRIB = " + path);
                break;
            case FileObserver.CLOSE_NOWRITE: // 不可写文件被 close
                Log.i(TAG, "CLOSE_NOWRITE = " + path);
                break;
            case FileObserver.CREATE: // 创建新文件
                Log.i(TAG, "CREATE = " + path);
                break;
            case FileObserver.DELETE: // 文件被删除
                Log.i(TAG, "DELETE = " + path);
                break;
            case FileObserver.DELETE_SELF: // 自删除，即一个可执行文件在执行时删除自己
                Log.i(TAG, "DELETE_SELF = " + path);
                break;
            case FileObserver.MODIFY: // 文件被修改
                Log.i(TAG, "MODIFY = " + path);
                break;
            case FileObserver.MOVE_SELF: // 自移动，即一个可执行文件在执行时移动自己
                Log.i(TAG, "MOVE_SELF = " + path);
                break;
            case FileObserver.MOVED_FROM: // 文件被移走
                Log.i(TAG, "MOVED_FROM = " + path);
                break;
            case FileObserver.MOVED_TO: // 文件被移动过来
                Log.i(TAG, "MOVED_TO = " + path);
                break;
            case FileObserver.OPEN: // 文件被打开
                Log.i(TAG, "OPEN = " + path);
                break;
            default:
                Log.i(TAG, "event = " + event + ", path = " + path);
                break;
        }
    }
}

ANRFileObserver fileObserver = new ANRFileObserver("/data/anr");
fileObserver.startWatching();

但是该监控方案也有弊端导致适配性不是很好：

• /data/anr/ 目录可能会因为厂商定制化没有权限无法访问
• 应用被杀死时可能无法及时的监控

3.6.2. ANR WatchDog

Android 基于 Looper 的方案写了一个 WatchDog 监控，同样的也是通过 Handler post 消息检测时间，相关流程如下：

我们也可以参考 WatchDog 的源码和原理自定义一个监控 ANR 的 WatchDog，事件 ANR 是 5s 无响应，那就设定每 5s 从 Looper 插一条消息，如果 5s 后还没执行完成就说明出现了 ANR。具体代码如下：

public class ANRWatchDog extends Thread {
    private static final String TAG = "ANRWatchDog";
    private static final int TIMEOUT = 5000;

    private static ANRWatchDog sWatchDog;

    private final Handler mMainHandler = new Handler(Looper.getMainLooper());

    private final ANRChecker mAnrChecker = new ANRChecker();

    private ANRListener mAnrListener;

    private ANRWatchDog() {
        super("ANR-WatchDog-Thread");
    }

    public static ANRWatchDog getInstance() {
        if (sWatchDog == null) {
            sWatchDog = new ANRWatchDog();
        }
        return sWatchDog;
    }

    @Override
    public void run() {
        // 设置为后台线程
        Process.setThreadPriority(Process.THREAD_PRIORITY_BACKGROUND);
        while (true) {
            synchronized (this) {
                // 开始计时，往主线程 Looper 插一条消息
                mAnrChecker.schedule();
                // 每 5s 循环一次
                long waitTime = TIMEOUT;
                long start = SystemClock.uptimeMillis();
                while (waitTime > 0) { // 避免提前唤醒，保证 5s 检测一次
                    try {
                        wait(waitTime);
                    } catch (InterruptedException e) {
                        Log.w(TAG, e.toString());
                    }
                    waitTime = TIMEOUT - (SystemClock.uptimeMillis() - start);
                }
                // 没有超时 5s，继续循环
                if (!mAnrChecker.isBlocked()) {
                    continue;
                }
            }

            // 响应超过 5s 认为已经发生了 ANR，将堆栈信息打印出来
            String stackTrace = getStackTraceInfo();
            if (mAnrListener != null) {
                mAnrListener.onAnrHappened(stackTrace);
            }
            mAnrListener = null;
            break;
        }
    }

    private String getStackTraceInfo() {
        StringBuilder sb = new StringBuilder();
        for (StackTraceElement element : Looper.getMainLooper().getThread().getStackTrace()) {
            sb.append(element.toString()).append("\r\n");
        }
        return sb.toString();
    }

    private class ANRChecker implements Runnable {
        private boolean completed;
        private long startTime;
        private long executeTime = SystemClock.uptimeMillis();

        @Override
        public void run() {
            synchronized (ANRWatchDog.this) {
                completed = true; // 执行完修改标志位
                executeTime = SystemClock.uptimeMillis();
            }
        }

        void schedule() {
            completed = false;
            startTime = SystemClock.uptimeMillis();
            mMainHandler.postAtFrontOfQueue(this); // 往主线程 Looper 插入一条消息
        }

        // 如果标志位是 false 或响应时间超过 5s
        boolean isBlocked() {
            return !completed || executeTime - startTime >= TIMEOUT;
        }
    }

    public ANRWatchDog setANRListener(ANRListener listener) {
        mAnrListener = listener;
        return this;
    }

    public interface ANRListener {
        void onAnrHappened(String stackTrack);
    }
}

public class MainActivity extends AppCompatActivity {

    @Override
    protected void onCreate(@Nullable Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);

        ANRWatchDog.getInstance().setANRListener(new ANRWatchDog.ANRListener() {
            @Override
            public void onAnrHappened(String stackTrack) {
                Log.i("ANRWatchDog", "stack = " + stackTrack);
            }
        }).start();

        findViewById(R.id.btn).setOnClickListener(new View.OnClickListener() {
            @Override
            public void onClick(View v) {
                try {
                    // 模拟 anr
                    Thread.sleep(1000000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        });
    }
}

ANR 定位分析总结如下：

• 在 traces.txt 找到发生 ANR 时间节点、主线程的状态、ANR 类型和事故点
• 在 mainlog 日志查看 CPU 状态
• 根据以上步骤收集的信息大致判断问题原因
  • 是 CPU 问题还是 非 CPU 问题
  • 如果是非 CPU 问题，那么看 GC 处理信息
• 在 traces.txt 分析 CG 信息
• 结合项目代码和以上步骤分析到的原因，定位到问题修复 ANR

其实 ANR 发生的原因本质上只有三个：

• 线程挂起
• CPU 不给资源
• GC 触发 STW 导致线程执行时间被拉长

四、应用界面秒开

应用界面秒开的实现方案：

• SysTrace查看CPU运行程度，以及启动优化部分的优雅异步+优雅延迟初始化
• 界面异步Inflate、X2C、绘制优化
• 提前获取页面数据

4.1. 界面秒开率统计

• onCreate到onWindowFocusChanged
• 实现特定接口，在具体方法中统计耗时

这里来介绍一个开源方案：Lancet，它是一个轻量级的Android AOP框架：

• 编译速度快，支持增量编译
• API简单，没有任何多余代码插入apk（包体积优化）
• @Proxy通常用于对系统API调用的Hook
• @Insert通常用于操作APP与Library的类

下面我们来具体使用一下这个库，我们使用这个库来统计页面的onCreate()方法到onWindowsFocusChanged()方法之间的加载耗时情况：

①、添加依赖

这里大家可以参考github上的使用方式进行依赖的添加，主要是两个部分：工程的build.gradle和app module的build.gradle：

classpath 'me.ele:lancet-plugin:1.0.6' //工程的build.gradle
 
apply plugin: 'me.ele.lancet' //module的build.gradle
//lancet
compileOnly 'me.ele:lancet-base:1.0.6'

②、编写一个实体类，定义用于上述两个方法时间统计的成员变量：

public class ActivityLive {
 
    public long mOnCreateTime;
    public long mOnWindowsFocusChangedTime;
 
}

③、创建统计方法的工具类，在类中分别编写onCreate()和onWindowFocusChanged()方法，关于具体的注解的使用含义详见代码注释：

public class ActivityHooker {
 
    public static ActivityLive mLive;
 
    static {
        mLive = new ActivityLive();
    }
 
    //@Insert：使用自己程序中自己的一些类需要添加，值这里就指定onCreate()方法，
    //可配置项mayCreateSuper是当目标函数不存在的时候可以通过它来创建目标方法
    //@TargetClass：框架知道要找的类是哪个，可配置项Scope.ALL:匹配value所指定的所有类的子类
    @Insert(value = "onCreate",mayCreateSuper = true)
    @TargetClass(value = "androidx.appcompat.app.AppCompatActivity", scope = Scope.ALL)
    protected void onCreate(Bundle savedInstanceState) {
        mLive.mOnCreateTime = System.currentTimeMillis();
        Origin.callVoid(); //无返回值的调用
    }
 
 
    //注解含义同上面onCreate()
    @Insert(value = "onWindowFocusChanged",mayCreateSuper = true)
    @TargetClass(value = "androidx.appcompat.app.AppCompatActivity", scope = Scope.ALL)
    public void onWindowFocusChanged(boolean hasFocus) {
        mLive.mOnWindowsFocusChangedTime = System.currentTimeMillis();
        Log.i("onWindowFocusChanged","---"+(mLive.mOnWindowsFocusChangedTime - mLive.mOnCreateTime));
        Origin.callVoid();
    }
 
}

下面运行程序来看下结果：

界面秒开监控纬度

• 总体耗时：onCreate()--->onWindowsFocusChanged()，更精确的时间可以通过自定义接口来实现
• 生命周期耗时：onCreate()、onStart()、onResume()等等
• 生命周期间隔耗时：各个生命周期耗时时间差

五、优雅监控耗时盲区

5.1. 为什么会出现耗时盲区

对于一般的监控方案，它的监控指标只是一个大的范围，只是一个数据，比如：

• 生命周期的间隔
• onResume到Feed展示的间隔
• 举个栗子：比如在Activity的生命周期当中postMessage，很有可能在Feed展示之前执行，如果msg耗时1s，那么Feed展示时间也就相对应的延迟1s，如果是200ms，那么自动化卡顿监测方案实际上就监测不到它，但是你的列表展示就相对应的延时200ms

如下代码所示，我首先在Activity的onCreate()方法中发送了一个msg，并且打印了一条日志

然后在列表展示的第一条同样打印一条日志：

最后输出的结果如下：

从执行结果来看，这个MSG是跑在Feed展示之前的，这个msg模拟的耗时是1s，此时用户看到界面的时间也就被往后延迟了1s。其实这个场景还是很常见的，因为我们可能由于某些业务需求在某个生命周期或者某个阶段及某些第三方的SDK中会做一些handler post的操作，这个操作很有可能会在列表展示之前被执行到，所以出现这种耗时的盲区，既普遍又不好排查。

耗时盲区监控难点

• 通过细化监控的方式知道盲区时间，但是不清楚在盲区中具体在做什么
• 线上盲区无从排查

5.2. 耗时盲区监控线下方案

这种场景非常适合之前说过的一个工具，你能想到是什么吗？————答案是TraceView：

• 特别适合一段时间内的盲区监控
• 线程具体时间做了什么，一目了然

5.3. 耗时盲区监控线上方案

• 方法一：主线程的所有方法都是通过msg来执行的，那么我们是否可以通过mLogging来做盲区监测呢？mLogging确实知道主线程发送了msg执行了一段代码，但是它并不清楚msg具体的调用栈信息，它所能获取到的调用栈信息都是系统回调它的，它并不清楚msg是被谁抛出的，这个只能说可以，但是不太好。
• 方法二：是否可以通过AOP的方式来切Handler的sendMessage()等方法呢？使用这种方式我们可以知道发送msg的堆栈信息，但是这种方案并不清楚具体的执行时间，你只知道这个msg是在哪里被发送的，你并不知道它会在什么时候执行。

可行性方案：

• 使用统一的Handler：定制具体方法：sendMessageAtTime()和dispatchMessage()，对于发送消息，不管你使用哪个方法发送，最终都会走到这个sendMessageAtTime()，而处理消息同样的道理，最终都是调用dispatchMessage()
• 替换项目中所有使用的Handler，将其替换为自己定制的Handler