Android开发Android开发经验谈Android技术知识

Android卡顿优化分析及解决方案，全面掌握！

2022-07-29  本文已影响0人  Android技术圈

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

1.1. 卡顿问题介绍

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

卡顿问题难点：

1.2. 优化工具选择

①、CPU Profiler

使用方式：

②、Systrace

使用方式：

Systrace优点

③、StrictMode

现在到之前的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. 自动化卡顿检测方案原理

我在这里从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处理的开始和结束的时机。

具体的实现原理：

2.3. AndroidPerformanceMonitor

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

首先在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的堆栈信息等等，我们就可以根据这些堆栈找到对应哪个类的哪一行代码出现了问题，然后进行修改即可。

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

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

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

自动检测方案优化

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

三、ANR实战分析

3.1. 什么是 ANR？

ANR（Application Not Responding）是指应用程序未响应，Android 系统对于一些事件需要在一定时间范围内完成，如果超过预定时间未能得到有效响应或者响应时间过长，都会造成 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，就必须对于原理了解清楚，且知道有多少情况会导致出现事件被拉长的问题。

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. 日志分析思路

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

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

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

简单说就是我们至少需要两份文件：/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 时进程中各个线程的堆栈，一般有几种情况：

/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 信息中大概可以分析：

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 问题主要就是两类问题：

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

3.5. 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();

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

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 定位分析总结如下：

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

四、应用界面秒开

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

4.1. 界面秒开率统计

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

下面我们来具体使用一下这个库，我们使用这个库来统计页面的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();
    }
 
}

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

界面秒开监控纬度

五、优雅监控耗时盲区

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

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

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

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

最后输出的结果如下：

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

耗时盲区监控难点

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

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

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

可行性方案：

上一篇 下一篇

猜你喜欢

热点阅读