ANR分析 & SNR

https://duanqz.github.io/2015-10-12-ANR-Analysis#anr-2

ANR

ANR属于应用程序的范畴，明确将问题定位在应用程序。Android在系统层实现了一套精密的机制来发现ANR，核心原理是消息调度和超时处理。

一旦应用程序处理消息不当，超时限制就起作用了，它收集一些系统状态，譬如CPU/IO使用情况、进程函数调用栈，并且报告用户有进程无响应了(ANR对话框)。

ANR问题本质是一个性能问题。ANR机制实际上对应用程序主线程的限制，要求主线程在限定的时间内处理完一些最常见的操作(启动服务、处理广播、处理输入)， 如果处理超时，则认为主线程已经失去了响应其他操作的能力。主线程中的耗时操作，譬如密集CPU运算、大量IO、复杂界面布局等，都会降低应用程序的响应能力。

引起ANR的一些场景

  • Service Timeout:服务在20s内未执行完成；
  • BroadcastQueue Timeout：比如前台广播在10s内执行完成
  • ContentProvider Timeout：内容提供者执行超时
  • inputDispatching Timeout: 输入事件分发超时5s，包括按键分发事件的超时。
  • 或者任何在主线程操作过长时间的操作

ANR机制

ANR机制可以分为两部分：

  • ANR的监测。Android对于不同的ANR类型(Broadcast, Service, InputEvent)都有一套监测机制。
  • ANR的报告。在监测到ANR以后，需要显示ANR对话框、输出日志(发生ANR时的进程函数调用栈、CPU使用情况等)。

整个ANR机制的代码也是横跨了Android的几个层：

  • App层：应用主线程的处理逻辑
  • Framework层： ANR机制的核心
    • frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java
    • frameworks/base/services/core/java/com/android/server/am/BroadcastQueue.java
    • frameworks/base/services/core/java/com/android/server/am/ActiveServices.java
    • frameworks/base/services/core/java/com/android/server/input/InputManagerService.java
    • frameworks/base/services/core/java/com/android/server/wm/InputMonitor.java
    • frameworks/base/core/java/android/view/InputChannel
    • frameworks/base/services/core/java/com/android/internal/os/ProcessCpuTracker
  • Native层：... ...

ANR检测

Service Timeout

Service Timeout触发时机，简单说就是AMS中的mHandler收到SERVICE_TIMEOUT_MSG消息时触发。

如何检测Service超时呢？Android是通过设置定时消息实现的。定时消息是由AMS的消息队列处理的(system_server的ActivityManager线程)。

当发生Service ANR时，一般可以先排查一下在Service的生命周期函数中(onCreate(), onStartCommand()等)有没有做耗时的操作，譬如复杂的运算、IO操作等。 如果应用程序的代码逻辑查不出问题，就需要深入检查当前系统的状态：CPU的使用情况、系统服务的状态等，判断当时发生ANR进程是否受到系统运行异常的影响。

>>> 具体流程 <<<

当Service的生命周期开始时，ActiveServices#bumpServiceExecutingLocked()会被调用，紧接着会调用ActiveServices#scheduleServiceTimeoutLocked()：

void scheduleServiceTimeoutLocked(ProcessRecord proc) {
    ...
    Message msg = mAm.mHandler.obtainMessage(
            ActivityManagerService.SERVICE_TIMEOUT_MSG);
    msg.obj = proc;
    // 通过AMS.MainHandler抛出一个定时消息
    mAm.mHandler.sendMessageAtTime(msg,
         proc.execServicesFg ? (now+SERVICE_TIMEOUT) : (now+ SERVICE_BACKGROUND_TIMEOUT));
}

上述方法通过AMS.MainHandler抛出一个定时消息SERVICE_TIMEOUT_MSG：

  • 前台进程中执行Service，超时时间是SERVICE_TIMEOUT(20秒)
  • 后台进程中执行Service，超时时间是SERVICE_BACKGROUND_TIMEOUT(200秒)

当Service的生命周期结束时，会调用ActiveServices#serviceDoneExecutingLocked()方法，之前抛出的SERVICE_TIMEOUT_MSG消息在这个方法中会被清除。 如果在超时时间内，SERVICE_TIMEOUT_MSG没有被清除，那么，AMS.MainHandler就会响应这个消息:

case SERVICE_TIMEOUT_MSG: {
    // 判断是否在做dexopt操作， 该操作的比较耗时，允许再延长20秒
    if (mDidDexOpt) {
        mDidDexOpt = false;
        Message nmsg = mHandler.obtainMessage(SERVICE_TIMEOUT_MSG);
        nmsg.obj = msg.obj;
        mHandler.sendMessageDelayed(nmsg, ActiveServices.SERVICE_TIMEOUT);
        return;
    }
    mServices.serviceTimeout((ProcessRecord)msg.obj);
}

最后走到超时的方法里面去：

void serviceTimeout(ProcessRecord proc) {
    ...
    final long maxTime =  now -
              (proc.execServicesFg ? SERVICE_TIMEOUT : SERVICE_BACKGROUND_TIMEOUT);
    ...
    // 寻找运行超时的Service
    for (int i=proc.executingServices.size()-1; i>=0; i--) {
        ServiceRecord sr = proc.executingServices.valueAt(i);
        if (sr.executingStart < maxTime) {
            timeout = sr;
            break;
        }
       ...
    }
    ...
    // 判断执行Service超时的进程是否在最近运行进程列表，如果不在，则忽略这个ANR
    if (timeout != null && mAm.mLruProcesses.contains(proc)) {
        anrMessage = "executing service " + timeout.shortName;
    }
    ...
    if (anrMessage != null) {
        mAm.appNotResponding(proc, null, null, false, anrMessage);
    }
}

上述方法会找到当前进程已经超时的Service，经过一些判定后，决定要报告ANR，最终调用AMS.appNotResponding()方法。 走到这一步，ANR机制已经完成了监测报告任务，剩下的任务就是ANR结果的输出，我们称之为ANR的报告机制。 ANR的报告机制是通过AMS.appNotResponding()完成的，这个后面再分析。

broadcast超时

应用程序可以注册广播接收器，实现BroadcastReceiver.onReceive()方法来完成对广播的处理。 通常，这个方法是在主线程执行的，Android限定它执行时间不能超过10秒，否则，就会引发ANR。

onReceive()也可以调度在其他线程执行，通过Context.registerReceiver(BroadcastReceiver, IntentFilter, String, Handler)这个方法注册广播接收器， 可以指定一个处理的Handler，将onReceive()调度在非主线程执行。（但是这个是不建议的，因为广播接收者被销毁后进程就成为了空进程，很容易被系统杀掉）

AMS维护了两个广播队列BroadcastQueue:

  • foreground queue，前台队列的超时时间是10秒
  • background queue，后台队列的超时时间是60秒

之所以有两个，就是因为要区分的不同超时时间。所有发送的广播都会进入到队列中等待调度，在发送广播时，可以通过Intent.FLAG_RECEIVER_FOREGROUND参数将广播投递到前台队列。 AMS线程会不断地从队列中取出广播消息派发到各个接收器(BroadcastReceiver)。当要派发广播时，AMS会调用BroadcastQueue.scheduleBroadcastsLocked()方法：

public void scheduleBroadcastsLocked() {
    ...
    if (mBroadcastsScheduled) {
        return;
    }
    mHandler.sendMessage(mHandler.obtainMessage(BROADCAST_INTENT_MSG, this));
    mBroadcastsScheduled = true;
}
Input处理超时

输入事件最开始由硬件设备(譬如按键或触摸屏幕)发起，Android有一套输入子系统来发现各种输入事件， 这些事件最终都会被InputDispatcher分发到各个需要接收事件的窗口。 那么，窗口如何告之InputDispatcher自己需要处理输入事件呢？Android通过InputChannel 连接InputDispatcher和窗口，InputChannel其实是封装后的Linux管道(Pipe)。 每一个窗口都会有一个独立的InputChannel，窗口需要将这个InputChannel注册到InputDispatcher中。

对于InputDispatcher而言，每注册一个InputChannel都被视为一个Connection，通过文件描述符来区别。InputDispatcher是一个消息处理循环，当有新的Connection时，就需要唤醒消息循环队列进行处理。

输入事件的类型有很多，按键、轨迹球、触屏等，Android对这些事件进行了分类，处理这些事件的窗口也被赋予了一个类型(targetType)：Foucused或Touched， 如果当前输入事件是按键类型，则寻找Focused类型的窗口;如果当前输入事件类型是触摸类型，则寻找Touched类型的窗口。

一个正常的输入事件会经过从outboundQueue挪到waitQueue的过程，表示消息已经派发出去;再经过从waitQueue中移除的过程，表示消息已经被窗口接收。 InputDispatcher作为中枢，不停地在递送着输入事件，当一个事件无法得到处理的时候，InputDispatcher不能就此死掉啊，否则系统也太容易崩溃了。 InputDispatcher的策略是放弃掉处理不过来的事件，并发出通知(这个通知机制就是ANR)，继续进行下一轮消息的处理。

输入事件作为一个消息，需要排队等待派发，每一个Connection都维护两个队列：

  • outboundQueue: 等待发送给窗口的事件。每一个新消息到来，都会先进入到此队列
  • waitQueue: 已经发送给窗口的事件

在派发事件时，dispatchKeyLocked()和dispatchMotionLocked()， 需要找到当前的焦点窗口,焦点窗口才是最终接收事件的地方，找窗口的过程就会判断是否已经发生了ANR。

发生ANR时，Java层最开始的入口是InputManagerService.notifyANR()，它是直接被Native层调用的。

在InputDispatcher派发输入事件时，会寻找接收事件的窗口，如果无法正常派发，则可能会导致当前需要派发的事件超时(默认是5秒)。 Native层发现超时了，会通知Java层，Java层经过一些处理后，会反馈给Native层，是继续等待还是丢弃当前派发的事件。

ANR报告

是在ActivityManagerService#appNotResponding里将ANR的信息上报到手机上。

final void appNotResponding(ProcessRecord app, ActivityRecord activity,
        ActivityRecord parent, boolean aboveSystem, final String annotation) {
    // app: 当前发生ANR的进程
    // activity: 发生ANR的界面
    // parent: 发生ANR的界面的上一级界面
    // aboveSystem:
    // annotation: 发生ANR的原因
    ...
    // 1. 更新CPU使用信息。ANR的第一次CPU信息采样
    updateCpuStatsNow();
    ...
    // 2. 填充firstPids和lastPids数组。从最近运行进程(Last Recently Used)中挑选：
    //    firstPids用于保存ANR进程及其父进程，system_server进程和persistent的进程(譬如Phone进程)
    //    lastPids用于保存除firstPids外的其他进程
    firstPids.add(app.pid);
    int parentPid = app.pid;
    if (parent != null && parent.app != null && parent.app.pid > 0)
        parentPid = parent.app.pid;
    if (parentPid != app.pid) firstPids.add(parentPid);
    if (MY_PID != app.pid && MY_PID != parentPid) firstPids.add(MY_PID);

    for (int i = mLruProcesses.size() - 1; i >= 0; i--) {
        ProcessRecord r = mLruProcesses.get(i);
        if (r != null && r.thread != null) {
            int pid = r.pid;
            if (pid > 0 && pid != app.pid && pid != parentPid && pid != MY_PID) {
                if (r.persistent) {
                    firstPids.add(pid);
                } else {
                    lastPids.put(pid, Boolean.TRUE);
                }
            }
        }
    }
    ...
    // 3. 打印调用栈
    File tracesFile = dumpStackTraces(true, firstPids, processCpuTracker, lastPids,
                NATIVE_STACKS_OF_INTEREST);
    ...
    // 4. 更新CPU使用信息。ANR的第二次CPU使用信息采样
    updateCpuStatsNow();
    ...
    // 5. 显示ANR对话框
    Message msg = Message.obtain();
    HashMap<String, Object> map = new HashMap<String, Object>();
    msg.what = SHOW_NOT_RESPONDING_MSG;
    ...
    mHandler.sendMessage(msg);
}

该方法的主体逻辑可以分成五个部分来看：

  1. 更新CPU的统计信息。这是发生ANR时，第一次CPU使用信息的采样，采样数据会保存在mProcessStats这个变量中
  2. 填充firstPids和lastPids数组。当前发生ANR的应用会首先被添加到firstPids中，这样打印函数栈的时候，当前进程总是在trace文件的最前面
  3. 打印函数调用栈(StackTrace)。具体实现由dumpStackTraces()函数完成
  4. 更新CPU的统计信息。这是发生ANR时，第二次CPU使用信息的采样，两次采样的数据分别对应ANR发生前后的CPU使用情况
  5. 显示ANR对话框。抛出SHOW_NOT_RESPONDING_MSG消息，AMS.MainHandler会处理这条消息，显示AppNotRespondingDialog

如何分析traces.txt

如果ANR发生，对应的应用会收到SIGQUIT异常终止信号，dalvik虚拟机就会自动在/data/anr/traces.txt文件，这个文件记录了在发生ANR时刻系统各个线程的执行状态，获取这个文件是不需要root权限的，因此首先需要做的就是通过adb pull命令将这个文件导出并等待分析。

----- pid 901 at 2015-11-28 14:38:34 -----
Cmd line: system_server

JNI: CheckJNI is off; workarounds are off; pins=6; globals=2154 (plus 409 weak)

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x415a4e88 self=0x414c48d8
  | sysTid=901 nice=-2 sched=0/0 cgrp=apps handle=1073926484
  | state=S schedstat=( 303590361913 618664734427 651535 ) utm=19466 stm=10893 core=0
  #00  pc 00021914  /system/lib/libc.so (epoll_wait+12)
  #01  pc 0001065f  /system/lib/libutils.so (android::Looper::pollInner(int)+98)
  #02  pc 00010889  /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92)
  #03  pc 0006b771  /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
  #04  pc 0002034c  /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #05  pc 00050fcf  /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+398)
  #06  pc 00000214  /dev/ashmem/dalvik-jit-code-cache (deleted)
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:138)
  at android.os.Looper.loop(Looper.java:196)
  at com.android.server.ServerThread.initAndLoop(SystemServer.java:1174)
  at com.android.server.SystemServer.main(SystemServer.java:1271)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:515)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:878)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:694)
  at dalvik.system.NativeStart.main(Native Method)

分析：

----- pid 901 at 2015-11-28 14:38:34 ----- Cmd line: system_server

说明了发生ANR的进程id、时间和进程名称。

JNI: CheckJNI is off; workarounds are off; pins=6; globals=2154 (plus 409 weak) DALVIK THREADS: (mutexes: tll=0 tsl=0 tscl=0 ghl=0)

线程的基本信息，其中tll、tsl、tscl、ghl、hwl、hwll分别对应：thread list lock, thread suspend lock, thread suspend count lock, gc heap lock, heap worker lock和heap worker list lock。

main prio=5 tid=1 NATIVE

说明了线程名称、线程的优先级、线程锁id和线程状态。线程名称是启动线程的时候手动指明的，这里的main标识是主线程，是Android自动设定的一个线程名称，如果是自己手动创建的线程，一般会被命名成“Thread-xx”的格式，其中xx是线程id，它只增不减不会被复用；注意这其中的tid不是线程的id,它是一个在Java虚拟机中用来实现线程锁的变量，随着线程的增减，这个变量的值是可能被复用的。

线程的状态：

group="main" sCount=1 dsCount=0 obj=0x415a4e88 self=0x414c48d8

group是线程组名称。sCount是此线程被挂起的次数，dsCount是线程被调试器挂起的次数，当一个进程被调试后，sCount会重置为0，调试完毕后sCount会根据是否被正常挂起增长，但是dsCount不会被重置为0，所以dsCount也可以用来判断这个线程是否被调试过。obj表示这个线程的Java对象的地址，self表示这个线程本身的地址。

sysTid=901 nice=-2 sched=0/0 cgrp=apps handle=1073926484

是线程的调度信息。sysTid是Linux下的内核线程id，nice是线程的调度优先级，sched分别标志了线程的调度策略和优先级，cgrp是调度属组，handle是线程的处理函数地址。

state=S schedstat=( 303590361913 618664734427 651535 ) utm=19466 stm=10893 core=0

是线程当前上下文信息。state是调度状态；schedstat从 /proc/[pid]/task/[tid]/schedstat读出，三个值分别表示线程在cpu上执行的时间、线程的等待时间和线程执行的时间片长度，有的android内核版本不支持这项信息，得到的三个值都是0；utm是线程用户态下使用的时间值(单位是jiffies）;stm是内核态下的调度时间值；core是最后执行这个线程的cpu核的序号。

再后面就是线的调用栈信息了。

如何分析？

trace文件顶部的线程一般是ANR的元凶

这是一个简单的方法，但是大部分情况下都适用，可以通过这个方法来快速判断是否是自己的应用造成了本次ANR。说明以下，并不是trace文件包含的应用就一定是造成ANR的帮凶，应用出现在trace文件中，只能说明出现ANR的时候这个应用进程还活着，trace文件的顶部则是触发ANR的应用信息。因此，如果你的应用出现在了trace文件的顶部，那么很有可能是因为你的应用造成了ANR，否则是你的应用造成ANR的可能性不大，但是具体是不是还需要进一步分析。

注意死锁和等待

ps:

ANR出现不一定是应用本身的问题，如果机器由于某个原因就已经很慢了，然后打开某个应用，之后该应用报个ANR，这个实属正常。

CPU数据分析

CPU负载/平均负载

CPU负载是指某一时刻系统中运行队列长度之和加上当前正在CPU上运行的进程数，而CPU平均负载可以理解为一段时间内正在使用和等待使用CPU的活动进程的平均数量。在Linux中“活动进程”是指当前状态为运行或不可中断阻塞的进程。通常所说的负载其实就是指平均负载。

Load: 13.12 / 13.27 / 12.82

系统一般记录了三个值，分别是前一分钟、五分钟、十五分钟的CPU平均负载。在android上，我们只需要关心前一分钟的负载。

CPU使用率

系统会在发生前后打印2次的CPU使用率，一个是ANR前的，一个是ANR后的。一些参数：

  • user： CPU在用户态的运行时间，不包括nice值为负数的进程运行的时间
  • nice： CPU在用户态并且nice值为负数的进程运行的时间
  • system：CPU在内核态运行的时间
  • idle： CPU空闲时间，不包括iowait时间
  • iowait： CPU等待I/O操作的时间
  • irq： CPU硬中断的时间
  • softirq：CPU软中断的时间

results matching ""

    No results matching ""