Android ANR | 原理解析及常见案例

作者：持笔写青春
转载地址：https://mp.weixin.qq.com/s/40T6ITvJNWR8F42530k4DA

前言

网上关于ANR的技术文章很多，其中不乏优秀的精品，可为何当我们遇到ANR问题时，还是经常束手无策呢？

猜测一方面是不熟悉原理机制，还有一方面对CPU/RAM/IO/GC/Thermal、GC机制、内存分配、LMK机制、同步锁原理等基础掌握的不够。

本文侧重介绍常见的ANR类型以及一般分析策略，旨在希望通过本文能够处理绝大部分的ANR案例。

本文涉及代码基于Android S

画了一张图，列举了ANR的影响因素

ANR原理

我们平时遇到的ANR问题大部分是input ANR类型，本文以input ANR为例进行梳理，这块机制并不复杂，受限于篇幅，本文只介绍埋下计时和check超时的代码部分。

正常输入事件的分发流程如下

InputDispatcher::dispatchOnce()
->InputDispatcher::dispatchOnceInnerLocked
->InputDispatcher::dispatchKeyLocked
->InputDispatcher::findFocusedWindowTargetsLocked
......
1
2
3
4
5

findFocusedWindowTargetsLocked这个函数从字面不难猜出其意图: 查找有焦点的window。

该函数较长，我们将其拆分开来进行梳理

未找到focused的window，也未找到focused的application

// If there is no currently focused window and no focused application
// then drop the event.
if (focusedWindowHandle == nullptr && focusedApplicationHandle == nullptr) {
    ALOGI("Dropping %s event because there is no focused window or focused application in "
           "display %" PRId32 ".",
    NamedEnum::string(entry.type).c_str(), displayId);
    return InputEventInjectionResult::FAILED;
}
1
2
3
4
5
6
7
8

这种情况下，则drop该事件

未找到focused的window，有focused的application

if (focusedWindowHandle == nullptr && focusedApplicationHandle != nullptr) {
        if (!mNoFocusedWindowTimeoutTime.has_value()) {
            // We just discovered that there's no focused window. Start the ANR timer
            std::chrono::nanoseconds timeout = focusedApplicationHandle->getDispatchingTimeout(
                    DEFAULT_INPUT_DISPATCHING_TIMEOUT);
            //更新超时时间，该focused事件开始进入计时
            mNoFocusedWindowTimeoutTime = currentTime + timeout.count();
            mAwaitedFocusedApplication = focusedApplicationHandle;
            mAwaitedApplicationDisplayId = displayId;
            ALOGW("Waiting because no window has focus but %s may eventually add a "
                  "window when it finishes starting up. Will wait for %" PRId64 "ms",
                  mAwaitedFocusedApplication->getName().c_str(), millis(timeout));
            *nextWakeupTime = *mNoFocusedWindowTimeoutTime;
            return InputEventInjectionResult::PENDING;
        } else if (currentTime > *mNoFocusedWindowTimeoutTime) {
            // Already raised ANR. Drop the event
            ALOGE("Dropping %s event because there is no focused window",
                  NamedEnum::string(entry.type).c_str());
            return InputEventInjectionResult::FAILED;
        } else {
            //说明之前已经埋过计时，此时还未到超时时间则继续等待
            // Still waiting for the focused window
            return InputEventInjectionResult::PENDING;
        }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25

重置超时时间

// we have a valid, non-null focused window
resetNoFocusedWindowTimeoutLocked();
1
2

如果执行到这步的话，则说明本次findFocusedWindowTargetsLocked找到了非空的window，对于这种情况会resetNoFocusedWindowTimeoutLocked。

除此之外，系统还有多个场景下也会触发该重置接口，比如

1. setFocusedApplicationLocked  当前focused应用发生变化
2. setInputDispatchMode  调用了分发模式
3. resetAndDropEverythingLocked这个接口存在多处会调用的场景，如stopFreezingDisplayLocked、performEnableScreen等场景。

其它窗口异常情况

如果当前window存在异常情况，也会做pending处理，同样可能会成为造成ANR的原因。比如窗口处于paused状态

if (focusedWindowHandle->getInfo()->paused) {
    ALOGI("Waiting because %s is paused", focusedWindowHandle->getName().c_str());
    return InputEventInjectionResult::PENDING;
}
1
2
3
4

还有其他情况也会导致pending，如窗口未连接、窗口连接已满、窗口连接死亡等，不一一列出。

这里提到了造成消息pending的情况，我们自然会想到那什么场景下消息会drop掉呢？

frameworks/native/services/inputflinger/dispatcher/InputDispatcher.cpp
1

---

void InputDispatcher::dropInboundEventLocked(const EventEntry& entry, DropReason dropReason) {
    const char* reason;
    switch (dropReason) {
        case DropReason::POLICY:
#if DEBUG_INBOUND_EVENT_DETAILS
            ALOGD("Dropped event because policy consumed it.");
#endif
            reason = "inbound event was dropped because the policy consumed it";
            break;
        case DropReason::DISABLED:
            if (mLastDropReason != DropReason::DISABLED) {
                ALOGI("Dropped event because input dispatch is disabled.");
            }
            reason = "inbound event was dropped because input dispatch is disabled";
            break;
        case DropReason::APP_SWITCH:
            ALOGI("Dropped event because of pending overdue app switch.");
            reason = "inbound event was dropped because of pending overdue app switch";
            break;
        case DropReason::BLOCKED:
            ALOGI("Dropped event because the current application is not responding and the user "
                  "has started interacting with a different application.");
            reason = "inbound event was dropped because the current application is not responding "
                     "and the user has started interacting with a different application";
            break;
        case DropReason::STALE:
            ALOGI("Dropped event because it is stale.");
            reason = "inbound event was dropped because it is stale";
            break;
        case DropReason::NOT_DROPPED: {
            LOG_ALWAYS_FATAL("Should not be dropping a NOT_DROPPED event");
            return;
        }
    }
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34

有如上几种场景会造成消息drop，dropInboundEventLocked的触发时机是在InputDispatcher::dispatchOnceInnerLocked中。

到这里我们已经清楚了埋下超时时间的流程，那么什么时候会检查超时时间有没有到呢？

InputDispatcher.cpp@dispatchOnce-> InputDispatcher.cpp@processAnrsLocked
1

---

/**
 * Check if any of the connections' wait queues have events that are too old.
 * If we waited for events to be ack'ed for more than the window timeout, raise an ANR.
 * Return the time at which we should wake up next.
 */
nsecs_t InputDispatcher::processAnrsLocked() {
    const nsecs_t currentTime = now();
    nsecs_t nextAnrCheck = LONG_LONG_MAX;
    // Check if we are waiting for a focused window to appear. Raise ANR if waited too long
    if (mNoFocusedWindowTimeoutTime.has_value() && mAwaitedFocusedApplication != nullptr) {
        if (currentTime >= *mNoFocusedWindowTimeoutTime) {
            processNoFocusedWindowAnrLocked();
            mAwaitedFocusedApplication.reset();
            mNoFocusedWindowTimeoutTime = std::nullopt;
            return LONG_LONG_MIN;
        } else {
            //mNoFocusedWindowTimeoutTime代表的是这个window超时的时间点
            // Keep waiting. We will drop the event when mNoFocusedWindowTimeoutTime comes.
            nextAnrCheck = *mNoFocusedWindowTimeoutTime;
        }
    }

    // Check if any connection ANRs are due
    nextAnrCheck = std::min(nextAnrCheck, mAnrTracker.firstTimeout());
    if (currentTime < nextAnrCheck) { // most likely scenario
        return nextAnrCheck;          // everything is normal. Let's check again at nextAnrCheck
    }

    // If we reached here, we have an unresponsive connection.
    sp connection = getConnectionLocked(mAnrTracker.firstToken());
    if (connection == nullptr) {
        ALOGE("Could not find connection for entry %" PRId64, mAnrTracker.firstTimeout());
        return nextAnrCheck;
    }
    connection->responsive = false;
    // Stop waking up for this unresponsive connection
    mAnrTracker.eraseToken(connection->inputChannel->getConnectionToken());
    onAnrLocked(connection);
    return LONG_LONG_MIN;
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40

如果当前时间已经满足超时时间，则触发onAnrLocked。

void InputDispatcher::onAnrLocked(std::shared_ptr application) {
    std::string reason =
            StringPrintf("%s does not have a focused window", application->getName().c_str());
    updateLastAnrStateLocked(*application, reason);

    std::unique_ptr commandEntry = std::make_unique(
            &InputDispatcher::doNotifyNoFocusedWindowAnrLockedInterruptible);
    commandEntry->inputApplicationHandle = std::move(application);
    postCommandLocked(std::move(commandEntry));
}
1
2
3
4
5
6
7
8
9
10

onAnrLocked这个函数所起到的主要作用是将doNotifyNoFocusedWindowAnrLockedInterruptible通过postCommandLocked塞进队列中。

在下一次触发InputDispatcher.dispatchOnce函数会执行runCommandsLockedInterruptible

void InputDispatcher::dispatchOnce() {
    nsecs_t nextWakeupTime = LONG_LONG_MAX;
    { // acquire lock
        std::scoped_lock _l(mLock);
        mDispatcherIsAlive.notify_all();

        // Run a dispatch loop if there are no pending commands.
        // The dispatch loop might enqueue commands to run afterwards.
        if (!haveCommandsLocked()) {
            dispatchOnceInnerLocked(&nextWakeupTime);
        }

        // Run all pending commands if there are any.
        // If any commands were run then force the next poll to wake up immediately.
        if (runCommandsLockedInterruptible()) {
            nextWakeupTime = LONG_LONG_MIN;
        }
        //....
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

runCommandsLockedInterruptible函数作用其实比较简单，就是取出所有的Command执行一遍

bool InputDispatcher::runCommandsLockedInterruptible() {
    if (mCommandQueue.empty()) {
        return false;
    }

    do {
        std::unique_ptr commandEntry = std::move(mCommandQueue.front());
        mCommandQueue.pop_front();
        Command command = commandEntry->command;
        command(*this, commandEntry.get()); // commands are implicitly 'LockedInterruptible'

        commandEntry->connection.clear();
    } while (!mCommandQueue.empty());
    return true;
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

这里顺便提一下，我们平时分析日志时经常会遇到类似这样的片段

上面的日志片段其实是在processAnrsLocked中打印的，这块日志打印在S上已经被谷歌移除了

一般分析步骤

确认是否是系统环境影响

首先判断下是否受系统因素影响，这里所说的系统因素通常指的是整机负载/低内存/系统异常等。

下面以高负载和低内存这两个场景为例进行说明

1. 受整机负载影响

搜索"ANR in"关键词

01-29 06:24:46.618452  1210  5962 I AnrManager: ANR in com.journeyui.calculator (com.journeyui.calculator/.Calculator), time=260439862
01-29 06:24:46.618452  1210  5962 I AnrManager: Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window)
01-29 06:24:46.618452  1210  5962 I AnrManager: Load: 31.7 / 33.43 / 30.98
01-29 06:24:46.618452  1210  5962 I AnrManager: Android time :[2022-01-29 06:24:46.60] [260451.594]
01-29 06:24:46.618452  1210  5962 I AnrManager: CPU usage from 167270ms to 0ms ago (2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860) with 99% awake:
01-29 06:24:46.618452  1210  5962 I AnrManager:   226% 1210/system_server: 173% user + 52% kernel / faults: 1026822 minor 8 major
01-29 06:24:46.618452  1210  5962 I AnrManager:   125% 459/logd: 16% user + 109% kernel / faults: 408 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   29% 21567/com.journeyui.globalsearch: 18% user + 10% kernel / faults: 45071 minor 25 major
01-29 06:24:46.618452  1210  5962 I AnrManager:   26% 639/surfaceflinger: 18% user + 8.6% kernel / faults: 4704 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   26% 20889/com.yulong.android.gamecenter: 16% user + 9.3% kernel / faults: 21143 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   24% 29706/com.sohu.inputmethod.sogou:home: 16% user + 8.6% kernel / faults: 21832 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   24% 545/com.android.messaging: 15% user + 9% kernel / faults: 26023 minor 2 major
01-29 06:24:46.618452  1210  5962 I AnrManager:   19% 803/guardserver: 3% user + 16% kernel
//....
01-29 06:24:46.618452  1210  5962 I AnrManager:   1.7% 3589/com.journeyui.calculator: 1% user + 0.6% kernel / faults: 3365 minor 5 major
//.....
01-29 06:24:46.618480  1210  5962 I AnrManager: 85% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirq
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

1. ANR in com.journeyui.calculator  ANR进程名
2. Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window)
3. Reason后面跟的是本次ANR原因，上面这个例子中通俗的解释是：
   事件落到com.tencent.mm/.ui.LauncherUI窗口上，不过该窗口直到超时时间到了仍未响应输入事件，input超时时间系统默认是5s。
4. Load: 31.7 / 33.43 / 30.98
   前 1，前 5，前 15 分钟的负载，我们通常看变化趋势。
5. 2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860  统计的时间区域
6. 85% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirq

代表了整体的负载情况，85% TOTAL说明整机负载很高。

图中(4)-(5)之间的片段则是各个进程占据的CPU情况, 发生ANR的进程com.journeyui.calculator的CPU占用只有1.7%

2. 受低内存影响

我们知道通常内存紧张的时候，kswapd线程会活跃起来进行回收内存

比如下面这个案例

kswapd的CPU占据排进top3的话，这个问题受系统低内存影响比较大。

低内存为何会成为ANR的诱发因素呢？

整机一旦陷入低内存，响应度和流畅度都会受到影响，这是因为低内存往往会伴随着IO升高，内存回收线程如kswapd、HeapTaskDaemon会变得活跃。

表现出来的现象就是操作界面如滑动列表明显卡顿、冷启动时间变长、动画顿挫掉帧严重等。

上面提到的这些现象从Systrace中能够直观的看出来，低内存时会出现大量的Uninterruptible Sleep | WakeKill，Block I/O block信息都是wait_on_page_bit_killable。而触发wait_on_page_bit_killable的上游正是do_page_fault。

这点其实比较好理解，低内存时系统往往会竭尽可能的回收内存，可能触发的fast path 回收 \ kswapd 回收 \ direct reclaim 回收 \ LMK杀进程回收等行为，都会造成do_page_fault 高频发生。

另外当出现大量的 IO 操作的时候，应用主线程的 Uninterruptible Sleep 也会变多，此时涉及到 io 操作（比如 view ，读文件，读配置文件、读 odex 文件），都会触发 Uninterruptible Sleep ， 导致整个操作的时间变长，这就解释了为何低内存下为何应用响应卡顿。

所以，分析ANR问题时如果遇到kswapd占据很高(top3)，则认为该问题受低内存影响很大。

另外这个时候，对于低内存的案例，搜索"lowmemorykiller"关键词，可以看到问题时间区域会有较多的查杀进程行为，我们通常会关注下"lowmemorykiller"这一行杀的进程adj值，adj值越低，说明当前系统内存越吃紧。

小结：
通常拿到一份完整的ANR日志，先看下是否受系统环境因素影响，比如判断是否陷入严重的低内存，是否存在系统整机负载很高等情况。
如果存在上述的这些情况，说明本次ANR的进程可能只是受害者。

分析堆栈

如果前面已经排除了系统环境影响的话，那么接下来就要分析进程的堆栈。

event日志中搜索"am_anr"关键字

可以看到时间点: 01-25 14:40:44，进程号: 17728

紧接着我们再根据时间戳，找到anr文件夹下对应的trace文件

可以通过Cmd line中的进程名，再次确认下文件没有找错

该份trace文件中搜索关键字"sysTid=17728"，这里的17728就是上面"am_anr"一行中包含的进程号，也是进程的主线程号。

依次介绍下上图中标记出来的(1)-(5)的含义

1. 线程运行状态
   nice值代表该线程优先级，nice的取值范围为-20到19。
   通常来说nice的值越大，进程的优先级就越低，获得CPU调用的机会越少，nice值越小，进程的优先级则越高，获得CPU调用的机会越多。
2. utm：该线程在用户态所执行的时间(单位是jiffies）
   stm：该线程在内核态所执行的时间
   线程的cpu耗时是两者相加(utm+stm)，utm,stm 单位换算成时间单位为 1 比 10ms。
3. core：后面的数字表示的跑在哪个核上，core=7表示打印这段日志时该线程跑在大核CPU7上。
4. 函数调用堆栈，也是我们最为关心的部分。

典型案例

下面我们将介绍导致ANR的主要场景案例

主线程耗时

这种情况是最为常见一种类型，也是最容易分析的类型

比如下面这个案例，是com.tencent.qqlive的ANR，callstack如下

通常来说，如果打印的堆栈是该进程内部的堆栈，并且经过业务证实这段代码确实可能存在耗时，那么根据callstack位置找到代码修改即可。

主线程Blocked/Waiting/Sleeping

从上面图中我们可以看到，主线程当前的状态是(1)Blocked，原因是它在等锁(2) 0x06573567，而0x06573567被(3)线程13所持有。

此时我们自然想到去看下tid=13线程的CallStack，在该份trace文件中搜索关键字"0x06573567"找到线程13的CallStack。

主线程陷入Blocked状态的缘由，通常是由于持锁线程在做繁琐的事务，或者是主线程和其它线程发生了死锁。

当然除了主线程陷入Blocked状态这种常见的情况之外，还有一些比较少见的情况。

1. 主线程处于waiting，说明其正在等待其他线程来notify它，堆栈同样是等锁，分析思路一样。
2. 主线程处于Sleeping状态，说明当前线程主动调用sleep，其堆栈通常是sleeping on <锁ID>。

Binder阻塞等待

这种案例在项目中比较常见，所谓的Binder阻塞等待指的是什么呢？

比如进程A在其主线程中向进程B发起了Binder请求，进程B因为一些原因比如正在处理耗时消息或网络异常等原因，无法及时响应进程A的Binder请求，造成进程A在主线程上一直阻塞等待Binder的返回结果，最终触发ANR。

比如下面这个案例

从图中可以看到，Keyguard在做native层的Binder通信，并处于阻塞等待对端结果返回的状态中。

这个时候我们很容易会产生这样的疑问：

对于这种等待Binder的案例，我们该如何快速的找到Binder对端？

我们以mtk平台为例，anr文件夹下的binderinfo文件，通常会打印出Binder交互信息。

可以通过搜索关键字"outgoing transaction"来进行查找，这个关键字表示的是当前线程扮演的是Client角色，向其它进程发起Binder。

上图中这一行红色标记处代表的含义是：

进程号为28444的进程中的28536线程，向进程号为22767发起了Binder。

需要注意一点的是：22767:0中的0表示该进程此时没有可用Binder线程。

如果我们在binderinfo 文件中没有找到有价值线索的话，也可以在kernel日志中搜索"binder : release" 关键词，这行日志通常会在Binder所在进程通信结束后打印出来。

Binder线程池耗尽

我们知道应用最多支持16个binder 线程，SystemServer支持最多32个binder 线程。

我们实际项目上，不时会遇到对端Binder 线程池耗尽导致不能响应的案例。

什么情况下会出现Binder 池耗尽的情况呢？

举个例子，进程A短时间内发送很多Binder 请求给进程B，这种情况下就有可能会导致在短时间内，接收端进程B的Binder 线程池中的16个Binder线程，都用来响应进程A的Binder请求。

也就是我们常说的Binder线程池耗尽的情况，此时进程B无法处理进程A发过来的新的Binder请求。

比如下面这段日志

图中可以看到17728这个进程的Binder线程池已经耗尽，这个时候就需要找到发送端是谁及其对应的callstack，如何找对端前面已经讲过，这里不再详细展开。

关于Binder耗尽的情况，通常是由于代码设计上的缺陷，导致短时间内高频发起Binder。

不过还有一种情况也可能会出现，那就是在Monkey测试环境下。

无效堆栈

在我们的实际项目上，经常会遇到这样的情况，日志提供的是完整的，可堆栈看起来却不像"作案"堆栈，即出现的堆栈并不像是真正的凶手。

常见的一种情况:  堆栈落在nativePollOnce上。

这种情况通常说明当前主线程的消息队列是空闲的，此时在等待处理下一个msg，打印日志时真正的block消息已经走完了。

我们以下面这个计算器的anr为例

01-29 06:24:46.618452  1210  5962 I AnrManager: ANR in com.journeyui.calculator (com.journeyui.calculator/.Calculator), time=260439862
01-29 06:24:46.618452  1210  5962 I AnrManager: Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window)
01-29 06:24:46.618452  1210  5962 I AnrManager: Load: 31.7 / 33.43 / 30.98
01-29 06:24:46.618452  1210  5962 I AnrManager: Android time :[2022-01-29 06:24:46.60] [260451.594]
01-29 06:24:46.618452  1210  5962 I AnrManager: CPU usage from 167270ms to 0ms ago (2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860) with 99% awake:
01-29 06:24:46.618452  1210  5962 I AnrManager:   226% 1210/system_server: 173% user + 52% kernel / faults: 1026822 minor 8 major
01-29 06:24:46.618452  1210  5962 I AnrManager:   125% 459/logd: 16% user + 109% kernel / faults: 408 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   29% 21567/com.journeyui.globalsearch: 18% user + 10% kernel / faults: 45071 minor 25 major
01-29 06:24:46.618452  1210  5962 I AnrManager:   26% 639/surfaceflinger: 18% user + 8.6% kernel / faults: 4704 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   26% 20889/com.yulong.android.gamecenter: 16% user + 9.3% kernel / faults: 21143 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   24% 29706/com.sohu.inputmethod.sogou:home: 16% user + 8.6% kernel / faults: 21832 minor
01-29 06:24:46.618452  1210  5962 I AnrManager:   24% 545/com.android.messaging: 15% user + 9% kernel / faults: 26023 minor 2 major
//...
01-29 06:24:46.618452  1210  5962 I AnrManager:   1.7% 3589/com.journeyui.calculator: 1% user + 0.6% kernel / faults: 3365 minor 5 major
//...
01-29 06:24:46.618480  1210  5962 I AnrManager: 75% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirq
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

正如我们前面所讲的策略，首先看下是否受系统环境影响。

从上面的日志片段可以看出，整机负载较高达到了75%，但是前台进程com.journeyui.calculator占用并不高只有1.7%。

top中没有kswapd身影，排除低内存的影响，所以这个问题在一定程度上受整机高负载的影响。

PS:  ANR发生时SystemServer占据稍高可能是正常的，因为Dump Trace时需要获取系统整体及各进程 CPU 使用情况，短时间内会造成SystemServer升高。

接着event日志中搜索"am_anr"关键字

01-29 06:24:34.907471 1210 5962 I am_anr : [0,3589,com.journeyui.calculator,684244549,
Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/
.Calculator t1837} does not have a focused window)]
1
2
3

根据时间戳找到对应的anr文件

此时我们注意到堆栈落在了nativePollOnce上，前面说过落在nativePollOnce上，说明应用此时已经处于idle状态了。

对于这种情况，说明耗时消息已埋没在历史消息中，历史消息的耗时可能存在下面的几种情况

1. 应用主线程历史调度中存在严重耗时的消息
2. 应用主线程历史调度中存在多个耗时的消息
3. 应用主线程历史调度中存在大量消息比如高频发送消息
4. 应用主线程本身并不耗时，而是受到系统环境因素影响(IO/低内存/高负载等)

那么历史调度中的耗时消息我们应该如何得知呢？

通常手机厂商会做日志增强，常见的思路如下:

1. 对于主线程的binder transaction 耗时情况， 超出设定阈值则输出调用信息。
2. 当线程等锁时间超出设定阈值，则输出当前的持锁状态。
3. 主线程的生命周期回调方法执行时间超出设定阈值，则输出相应信息。
4. 对于非异步Binder调用耗时超出设定阈值的时候，输出Binder信息。

对于一些头部应用厂商如字节跳动有自研的Raster消息监控平台，和手机厂商做的日志增强目的是一样的，都是为了尽可能多的收集线索。

除了落在nativePollOnce的情况，还有一种情况则更加隐蔽，容易将我们带偏分析的方向。那就是堆栈打印出来的确实是应用自身的堆栈。

但是根据堆栈找到对应代码后发现这段代码不可能会出现耗时，说明这段堆栈可能只是充当了"替罪羊"的角色，而真正的"凶手"早已藏身在了历史消息中。

用内存问题

我们实际项目中，不时会遇到应用自身内存使用不当导致的ANR。

比如下面的美团ANR案例

01-08 14:53:20.130  1074 32039 I AnrManager: ANR in com.sankuai.meituan (com.sankuai.meituan/com.meituan.android.pt.homepage.activity.MainActivity), time=48329538
01-08 14:53:20.130  1074 32039 I AnrManager: Reason: Input dispatching timed out (c961943 com.sankuai.meituan/com.meituan.android.pt.homepage.activity.MainActivity (server) is not responding. Waited 8006ms for MotionEvent)
01-08 14:53:20.130  1074 32039 I AnrManager: Load: 27.74 / 27.04 / 27.19
01-08 14:53:20.130  1074 32039 I AnrManager: Android time :[2022-01-08 14:53:20.10] [48351.410]
01-08 14:53:20.130  1074 32039 I AnrManager: CPU usage from 9706ms to 0ms ago (2022-01-08 14:52:48.524 to 2022-01-08 14:52:58.230):
01-08 14:53:20.130  1074 32039 I AnrManager:   100% 32613/com.sankuai.meituan: 99% user + 1.5% kernel / faults: 72075 minor
01-08 14:53:20.130  1074 32039 I AnrManager:   24% 16662/com.ss.android.ugc.aweme:miniappX: 17% user + 7.3% kernel / faults: 1762 minor
01-08 14:53:20.130  1074 32039 I AnrManager:   17% 4548/com.ss.android.ugc.aweme: 11% user + 5.9% kernel / faults: 2500 minor
01-08 14:53:20.130  1074 32039 I AnrManager:   11% 1074/system_server: 8% user + 3.6% kernel / faults: 6412 minor 1 major
//...
01-08 14:53:20.130  1074 32039 I AnrManager: 30% TOTAL: 21% user + 8.1% kernel + 0.1% iowait + 1% softirq
1
2
3
4
5
6
7
8
9
10
11

从上面日志片段可以看到整机负载并不高，且kswapd占比很低，排除系统因素的影响。

01-08 14:52:58.243  1074 32039 I am_anr  : [0,32613,com.sankuai.meituan,949501508,
Input dispatching timed out (c961943 com.sankuai.meituan/com.meituan.android.pt.homepage.activity.MainActivity 
(server) is not responding. Waited 8006ms for MotionEvent)]
1
2
3

时间点14:52:58   进程号32613

这份日志缺少anr文件，所以直接看系统日志，根据上面的时间点往前推(取决于该ANR类型对应的阈值时间)，找到案发最初的时间点。

这个案例中，我们在案发时间点附近，发现大量的GC片段且很多GC耗时都较长。

Clamp target GC heap from这行日志是在SetIdealFootprint即调整目标堆上限值时会打印，这块不太熟悉的话可以参见我们之前发表过的一篇文章。

上面这段日志说明当前应用堆使用已超出上限512M，为了满足新分配的对象内存需求，系统一直持续不断的对该应用进行阻塞GC(GC分为不同力度，阻塞GC说明应用此时内存情况比较糟糕)。

通过日志可以发现，尽管应用持续不断的阻塞GC，应用内存依旧没有降下来。

这种情况下很可能是出现了应用内存泄漏的情况。

关于应用内存使用不当，通常有如下几种情况

1. 频繁的生成临时对象导致堆内存增长迅速，达到下次堆GC触发阈值后便会触发Bg GC，进而导致回收线程跑大核和前台应用争抢CPU。
   另外GC回收阶段会存在一次锁堆，应用的主线程会被pause，这种情况下势必会造成应用使用卡顿甚至ANR。
2. 还有一种比较常见的情况是应用发生了较为严重的内存泄漏，导致GC一直无法回收足够的内存。
3. 应用申请大内存触发阻塞GC以便能够申请到足够的内存，这种情况通常会引起应用界面的黑屏或者明显的卡顿。
4. 我们知道系统低内存时会触发OnTrimMemory回调，如果应用在OnTrimMemory中并且是在主线程中直接调用显式GC接口即System.gc()，也容易引起应用卡顿，对于这个接口的使用需要谨慎。

上面这些情况虽不一定会导致ANR，但是应用操作上的卡顿可能在所难免。

结语

ANR是卡顿的一种严重表现形式，当我们遇到卡顿问题时，应趁早解决，防患于未然。

到这里，关于ANR的介绍到此为止，希望通过本文，在日后处理ANR问题时，能够多一些思路。

针对上述中所聊到的 ANR问题，方便大家往后遇到此类问题更好的解决，特此分享一个Android 性能优化的学习笔记，该笔记里面不仅记录了卡顿问题，还有启动优化、UI渲染优化、崩溃优化、内存优化、卡顿优化、存储优化、网络优化、耗电优化、多线程并发优化、体积包优化等。有需要参考学习的直接 点击这里查看获取方式传送门直达！