愿历尽千帆 归来仍少年

ANR原理分析及常见案例

字数统计: 5,458阅读时长: 24 min
2022/02/10

最近看了下ANR代码,结合之前项目上的一些ANR案例,打算对ANR的原理以及常见案例做下小结,涉及的代码均基于Android S

画了一张图,列举了可能导致ANR的一些影响因素
ANR影响因素

原理机制

我们平时遇到的ANR问题大部分都是input ANR类型,所以以input ANR为例进行梳理,这块机制并不复杂,只梳理埋计时和check超时的代码部分。
正常输入事件的分发流程如下

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

findFocusedWindowTargetsLocked这个函数从字面很好理解: 查找有焦点window。
因函数较长,我们将其拆分开来进行梳理
Step1: 未找到focused的window,也没有找到focused的application,drop该事件

1
2
3
4
5
6
7
8
// 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;
}

Step2: 未找到focused的window,有focused的application,这是最为常见的情况

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

Step3: 重置超时时间

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

执行到这步,说明本次findFocusedWindowTargetsLocked找到了非空的window,这种情况下会resetNoFocusedWindowTimeoutLocked。
除此之外,系统还有多个场景下也会触发该重置接口,比如

  1. setFocusedApplicationLocked 当前focused应用发生变化
  2. setInputDispatchMode 调用了分发模式
  3. resetAndDropEverythingLocked 这个接口存在多处会调用,比如stopFreezingDisplayLocked解冻屏幕、performEnableScreen亮屏等场景

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

1
2
3
4
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

大致有如上几种场景会造成消息drop,dropInboundEventLocked的触发时机是在InputDispatcher::dispatchOnceInnerLocked中。
到这里我们已经清楚了埋下超时时间的流程,那么什么时候会检查超时时间有没有到呢?
InputDispatcher.cpp@dispatchOnce-> InputDispatcher.cpp@processAnrsLocked

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

1
2
3
4
5
6
7
8
9
10
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

runCommandsLockedInterruptible方法很简单,取出所有的Command执行一遍

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



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

分析步骤

Step1:系统环境因素
首先判断下是否受环境因素影响,这里所说的系统环境因素通常指的是整机负载/低内存/系统异常等,下面以高负载和低内存这两个场景为例进行说明
一. 受整机负载影响
搜索ANR in关键词

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
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. 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)
    ANR原因,通俗的解释是:输入事件落到了
    com.tencent.mm/.ui.LauncherUI这个窗口上,该窗口直到超时时间到了仍未响应输入事件,input超时时间系统默认是5s(我们客制化为8s)。
  3. Load: 31.7 / 33.43 / 30.98 前 1,前 5,前 15 分钟的负载,我们通常看变化趋势。
  4. 2022-01-29 06:21:47.589 to 2022-01-29 06:24:34.860 统计的时间区域
  5. 85% TOTAL: 42% user + 33% kernel + 0% iowait + 0% softirq
    这行是我们通常比较关注的,代表了整体的负载情况,85% TOTAL说明整机负载很高。
  6. 图中(4)-(5)之间的片段则是各个进程占据的CPU情况, 发生ANR的进程com.journeyui.calculator的CPU占用只有1.7%
    PS: 整机CPU loading很高转给系统同事分析

二. 整机内存
我们知道通常内存紧张的时候,kswapd线程会活跃起来进行回收内存
比如下面这个案例

通常认为kswapd的CPU占据排进top3的话,这个问题受系统低内存影响比较大。
为何低内存会可能和ANR扯上关系呢?
因为整机一旦陷入低内存,会表现的响应慢以及多场景下操作卡顿。
比如启动应用时间变长 、滑动列表会掉更多帧、LMKD活跃杀进程以释放更多内存。
PS: 这个时候如果现场还在的话,可以执行通过adb shell cat proc/meminfo查看下内存情况

低内存对整机性能的影响

  1. 从过往分析的Systrace来看,低内存会出现大量的Uninterruptible Sleep | WakeKill - Block I/O block信息都是wait_on_page_bit_killable.
    它的链路是do_page_fault —> lock_page_or_retry -> wait_on_page_bit_killable,由于低内存可能触发的fast path 回收 \ kswapd 回收 \ direct reclaim 回收 \ LMK杀进程回收等行为,造成do_page_fault 高频发生。
    当出现大量的 IO 操作的时候,应用主线程的 Uninterruptible Sleep 也会变多,此时涉及到 io 操作(比如 view ,读文件,读配置文件、读 odex 文件),都会触发 Uninterruptible Sleep , 导致整个操作的时间变长,这就解释了为何低内存下为何应用响应卡顿。
  2. 另外低内存的时候,kswapd0和HeapTaskDaemon线程会非常活跃,从我们过往的分析来看,低内存时kswapd0和HeapTaskDaemon线程会跑在大核,占据很多的CPU资源,并且会和前台应用争抢CPU资源,这就可能会出现前台进程得不到足够的CPU资源而出现响应卡顿。
  3. 低内存时查杀进程,有些进程被kill后会立刻restart,我们之前项目上遇到过低内存时,persistent服务进程被kill立马restart,陷入了一种”死循环”,导致整机严重卡顿以及发烫。
    所以,如果分析ANR问题遇到这种kswapd占据很高(通常认为排到top3内),基本可以认为该问题是由于系统环境因素导致。
    另外这个时候,如果搜索”lowmemorykiller”关键词,可以看到问题时间区域会有较多的查杀进程行为,我们通常看”lowmemorykiller”这一行杀的进程adj值,adj值越低,说明当前系统内存越吃紧。

小结:如果出现了整机高负载或者低内存的情况,ANR的进程可能只是充当了受害者的角色。

Step2: 分析堆栈
如果前面已经排除了系统环境影响因素的话,那么接下来就要分析具体的callstack了
搜索”am_anr”关键字

时间点: 01-25 14:40:44,进程号是17728
根据时间戳找到anr文件下对应的trace文件

文件头部看下进程号再次确认下

搜索关键字”sysTid=17728”, 这里的17728就是上面”am_anr”中包含的进程号也是主线程号

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

典型案例

主线程耗时操作

这种情况是最为常见一种类型
比如下面这个案例,是com.tencent.qqlive的ANR,callstack如下

通常来说,如果打印的堆栈是ANR进程的堆栈,业务验证证实这段代码确实存在耗时的可能,那么根据callstack位置找到代码修改即可。

主线程 Blocked/waiting/Sleeping

主线程当前的状态是(1)Blocked, 原因是它在等锁(2) 0x06573567,而0x06573567被(3)线程13所持有

看下tid=13线程 CallStack,在该份trace文件中搜索关键字”0x06573567”找到线程13的堆栈。

除了主线程陷入Blocked这种比较常见的情况之外,通常是由于真正持有锁的线程在做繁琐的事务或是发生了死锁,除此之外还有一些少见的情况

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

这种情况比较常见,比如A进程在主线程中向B进程发起binder请求,B进程因为一些原因比如正在处理耗时消息或网络异常等原因,无法及时响应A进程的binder的请求,造成A进程一直阻塞等待binder的返回结果最终ANR。
比如下面这个案例

keyguard模块做native层的binder通信,阻塞等待对端结果返回。
涉及一个问题:我们该如何快速找到binder对端信息?
对于mtk平台而言,anr文件下的binderinfo会打印出binder交互的信息
搜索关键字”outgoing transaction” 表示的是当前线程扮演的是Client角色,向其它进程发起binder。

28444这个进程中28536这个线程向22767这个进程发起了binder请求。
需要注意一点的是:22767:0这里0代表的是server端当前没有可用binder线程。
如果binderinfo文件中没有找到的话,也可以在kernel日志中搜索”binder : release”关键词,这行日志通常是binder所在进程结束时会吐出来。

Binder 池耗尽

应用的Binder池最多支持16个binder线程,SystemServer比较特殊支持最多32个binder线程。
那么什么样的场景下可能会出现Binder 池耗尽的情况呢?
比如进程A发送太多重复binder请求给进程B,那么就会导致短时间内接收端进程B的binder线程池被占满,从而处理不了A进程发过来的binder请求。
比如下面这段日志

和上面binder block同样的分析策略,找到对端是谁以及对端的callstack即可,不再详细展开。

陷阱堆栈

何为陷阱堆栈,即出现的callstack并非真正的凶手,比如我们最为常见的CallStack落在nativePollOnce上,这种情况说明当前主线程的消息队列是空闲的,在等待处理下一个msg,打印日志时真正的block消息已经走完了。
以下面这个计算器的anr案例

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
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

整机负载很高,但是前台进程com.journeyui.calculator占用只有1.7%,top5中没有kswapd的身影,排除低内存的影响。
PS: SystemServer占据如果稍高可能是正常的,Dump Trace时需要获取系统整体及各进程 CPU 使用情况,短时间内会造成SystemServer升高。
接着event日志中搜索”am_anr”关键字

1
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文件

callstack落在了nativePollOnce上
我们前面说过落在nativePollOnce上,说明应用已经idle了
那么什么情况下会出现落在nativePollOnce上呢?

  1. 应用主线程历史调度中存在严重耗时的消息
  2. 应用主线程历史调度中存在多个耗时的消息
  3. 应用主线程历史调度中存在大量消息比如高频发送消息
  4. 应用主线程本身并不耗时,而是受到系统环境因素影响(IO/低内存/高负载等)
    那么历史调度中的耗时消息我们应该如何得知?
    谷歌本身在系统多处都加有耗时消息打印,比如我们常见的日志Looper : Slow dispatch等。

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

  1. 监控主线程的binder transaction的耗时情况, 超过阈值时输出相应的目标调用信息。
  2. 当某个线程等待lock的时间blocked超过阈值,则输出当前的持锁状态。
  3. 主线程的生命周期回调方法执行时间超过阈值,则输出相应信息。
  4. 当system_server等进程的线程池使用完, 无空闲线程时, 则binder通信都处于饥饿状态, 则饥饿状态超过一定阈值则输出信息。
  5. 当任意进程的非oneway的Binder调用耗时超过一定阈值的时候,输出Slow Binder信息。
  6. 当SystemServer进程响应其它任意Java进程的非oneway的Binder调用,耗时超过一定阈值的时候,输出Slow Binder信息

一些头部应用厂商如字节跳动有自研的Raster消息监控平台,出现这种落在nativePollOnce上查找历史耗时消息即可。
除了落在nativePollOnce的情况,还有一种情况则更加隐蔽,也更容易将我们带偏分析的方向。
那就是callstack打印出来确实是应用自身的堆栈,但是根据callstack找到对应代码后发现根本不可能会出现耗时,说明真正的”凶手”藏身在历史消息中。

应用内存问题

我们平时也会经常遇到这样的情况:应用自身内存使用不当导致的ANR
比如下面的美团ANR案例

1
2
3
4
5
6
7
8
9
10
11
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占比很低,基本可以排除系统环境影响

1
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文件,所以我们直接看系统日志
在案发时间点附近,我们发现出现有大量的GC片段

Clamp target GC heap from这行日志是在SetIdealFootprint即调整目标堆上限值时会打印,这块不太熟悉的话可以参见我们之前发表过的一篇文章
日志说明当前应用堆使用已超出上限512M,为了分配新的对象,一直持续的阻塞GC再尝试分配。
通过日志我们可以发现,尽管应用持续的阻塞GC,但是内存依旧没有降下来。
对于应用内存使用问题,通常有如下几种情况

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

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

写在最后

通常ANR是卡顿的一种严重表现形式,所以遇到卡顿问题时应趁早解决,防患于未然。

参考文献

https://www.androidperformance.com/
https://blog.csdn.net/feelabclihu/article/details/120574383

CATALOG
  1. 1. 原理机制
  2. 2. 分析步骤
  3. 3. 典型案例
    1. 3.1. 主线程耗时操作
    2. 3.2. 主线程 Blocked/waiting/Sleeping
    3. 3.3. Binder block
    4. 3.4. Binder 池耗尽
    5. 3.5. 陷阱堆栈
    6. 3.6. 应用内存问题
  4. 4. 写在最后
  5. 5. 参考文献