如果 Android 應用的界面線程處于阻塞狀态的時間過長，會觸發“應用無響應”(ANR) 錯誤。

如果應用位于前台，系統會向使用者顯示一個對話框。

-- https://developer.android.google.cn/

前言

網上關于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

......

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;

}

這種情況下，則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;
}
}

重置逾時時間

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

如果執行到這步的話，則說明本次findFocusedWindowTargetsLocked找到了非空的window，對于這種情況會resetNoFocusedWindowTimeoutLocked。

除此之外，系統還有多個場景下也會觸發該重置接口，比如

setFocusedApplicationLocked 目前focused應用發生變化
setInputDispatchMode 調用了分發模式
resetAndDropEverythingLocked這個接口存在多處會調用的場景，如stopFreezingDisplayLocked、performEnableScreen等場景。

其它視窗異常情況

如果目前window存在異常情況，也會做pending處理，同樣可能會成為造成ANR的原因。比如視窗處于paused狀态

if (focusedWindowHandle->getInfo()->paused) {

ALOGI("Waiting because %s is paused", focusedWindowHandle->getName().c_str());

return InputEventInjectionResult::PENDING;

}

還有其他情況也會導緻pending，如視窗未連接配接、視窗連接配接已滿、視窗連接配接死亡等，不一一列出。

這裡提到了造成消息pending的情況，我們自然會想到那什麼場景下消息會drop掉呢？

frameworks/native/services/inputflinger/dispatcher/InputDispatcher.cpp
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;
}
}

有如上幾種場景會造成消息drop，dropInboundEventLocked的觸發時機是在InputDispatcher::dispatchOnceInnerLocked中。

到這裡我們已經清楚了埋下逾時時間的流程，那麼什麼時候會檢查逾時時間有沒有到呢？

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


/**
* 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> 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;
}

如果目前時間已經滿足逾時時間，則觸發onAnrLocked。

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

std::unique_ptr<CommandEntry> commandEntry = std::make_unique<CommandEntry>(
&InputDispatcher::doNotifyNoFocusedWindowAnrLockedInterruptible);
commandEntry->inputApplicationHandle = std::move(application);
postCommandLocked(std::move(commandEntry));
}

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;
}
//....
}

runCommandsLockedInterruptible函數作用其實比較簡單，就是取出所有的Command執行一遍

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

do {
std::unique_ptr<CommandEntry> 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;
}

這裡順便提一下，我們平時分析日志時經常會遇到類似這樣的片段

上面的日志片段其實是在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

ANR in com.journeyui.calculator ANR程序名
Reason: Input dispatching timed out (ActivityRecord{51e27ca u0 com.journeyui.calculator/.Calculator t1837} does not have a focused window)
Reason後面跟的是本次ANR原因，上面這個例子中通俗的解釋是：
事件落到com.tencent.mm/.ui.LauncherUI視窗上，不過該視窗直到逾時時間到了仍未響應輸入事件，input逾時時間系統預設是5s。
Load: 31.7 / 33.43 / 30.98
前 1，前 5，前 15 分鐘的負載，我們通常看變化趨勢。
2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860 統計的時間區域
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)的含義

線程運作狀态
nice值代表該線程優先級，nice的取值範圍為-20到19。
通常來說nice的值越大，程序的優先級就越低，獲得CPU調用的機會越少，nice值越小，程序的優先級則越高，獲得CPU調用的機會越多。
utm：該線程在使用者态所執行的時間(機關是jiffies）
stm：該線程在核心态所執行的時間
線程的cpu耗時是兩者相加(utm+stm)，utm,stm 機關換算成時間機關為 1 比 10ms。
core：後面的數字表示的跑在哪個核上，core=7表示列印這段日志時該線程跑在大核CPU7上。
函數調用堆棧，也是我們最為關心的部分。

典型案例

下面我們将介紹導緻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狀态這種常見的情況之外，還有一些比較少見的情況。

主線程處于waiting，說明其正在等待其他線程來notify它，堆棧同樣是等鎖，分析思路一樣。
主線程處于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

正如我們前面所講的政策，首先看下是否受系統環境影響。

從上面的日志片段可以看出，整機負載較高達到了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)]

根據時間戳找到對應的anr檔案

此時我們注意到堆棧落在了nativePollOnce上，前面說過落在nativePollOnce上，說明應用此時已經處于idle狀态了。

對于這種情況，說明耗時消息已埋沒在曆史消息中，曆史消息的耗時可能存在下面的幾種情況

應用主線程曆史排程中存在嚴重耗時的消息
應用主線程曆史排程中存在多個耗時的消息
應用主線程曆史排程中存在大量消息比如高頻發送消息
應用主線程本身并不耗時，而是受到系統環境因素影響(IO/低記憶體/高負載等)

那麼曆史排程中的耗時消息我們應該如何得知呢？

通常手機廠商會做日志增強，常見的思路如下:

對于主線程的binder transaction 耗時情況，超出設定門檻值則輸出調用資訊。
當線程等鎖時間超出設定門檻值，則輸出目前的持鎖狀态。
主線程的生命周期回調方法執行時間超出設定門檻值，則輸出相應資訊。
對于非異步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

從上面日志片段可以看到整機負載并不高，且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)]

時間點14:52:58 程序号32613

這份日志缺少anr檔案，是以直接看系統日志，根據上面的時間點往前推(取決于該ANR類型對應的門檻值時間)，找到案發最初的時間點。

這個案例中，我們在案發時間點附近，發現大量的GC片段且很多GC耗時都較長。

Clamp target GC heap from這行日志是在SetIdealFootprint即調整目标堆上限值時會列印，這塊不太熟悉的話可以參見我們之前發表過的一篇文章<Android S ART GC基礎篇>。

上面這段日志說明目前應用堆使用已超出上限512M，為了滿足新配置設定的對象記憶體需求，系統一直持續不斷的對該應用進行阻塞GC(GC分為不同力度，阻塞GC說明應用此時記憶體情況比較糟糕)。

通過日志可以發現，盡管應用持續不斷的阻塞GC，應用記憶體依舊沒有降下來。

這種情況下很可能是出現了應用記憶體洩漏的情況。

關于應用記憶體使用不當，通常有如下幾種情況

頻繁的生成臨時對象導緻堆記憶體增長迅速，達到下次堆GC觸發門檻值後便會觸發Bg GC，進而導緻回收線程跑大核和前台應用争搶CPU。
另外GC回收階段會存在一次鎖堆，應用的主線程會被pause，這種情況下勢必會造成應用使用卡頓甚至ANR。
還有一種比較常見的情況是應用發生了較為嚴重的記憶體洩漏，導緻GC一直無法回收足夠的記憶體。
應用申請大記憶體觸發阻塞GC以便能夠申請到足夠的記憶體，這種情況通常會引起應用界面的黑屏或者明顯的卡頓。
我們知道系統低記憶體時會觸發OnTrimMemory回調，如果應用在OnTrimMemory中并且是在主線程中直接調用顯式GC接口即System.gc()，也容易引起應用卡頓，對于這個接口的使用需要謹慎。

上面這些情況雖不一定會導緻ANR，但是應用操作上的卡頓可能在所難免。

結語

ANR是卡頓的一種嚴重表現形式，當我們遇到卡頓問題時，應趁早解決，防患于未然。

到這裡，關于ANR的介紹到此為止，希望通過本文，在日後處理ANR問題時，能夠多一些思路。

作者:執筆寫青春

來源-微信公衆号:酷派技術團隊

出處:https://mp.weixin.qq.com/s/40T6ITvJNWR8F42530k4DA

Android ANR|原了解析及常見案例

1.受整機負載影響

2. 受低記憶體影響