ANR的定义
- 系统通过交互组件和用户交互进行超时监控,主要用来判断应用进程是否存在卡死或者响应过慢的问题。
导致ANR的原因
应用层导致ANR:
- 函数阻塞:死循环,主线程IO,处理大数据,
- 锁出错:主线程等待子线程的锁。
- 内存紧张:系统分配给一个应用的内存是有上限的,长期处于内存紧张,会导致频繁内存交换,导致操作超时。
系统导致ANR: - CPU被抢占:一般来说,前台会抢占后台的,导致后台应用紧张被抢占。
- 系统服务无法及时响应:系统的服务都是Binder机制,服务能力也是有限的,有可能系统服务长时间不响应导致ANR。
- 其他应用占用大量内存。
线下拿ANR日志
- adb pull /data/anr/
- adb bugreport
导入ANR生成的文件遇到的问题: - adb: error: failed to stat remote object 'data/anr/traces.txt': No such file or directory 这是因为厂商对这块做了优化, 以前anr一直放在traces文件中,多次出现会有覆盖的问题,高版本厂商做了优化,会根据时间戳分别生成一个文件,打包到处。
- adb bugreport 会导出一个zip压缩包。
线上ANR监控方案
线上可以通过FileObsever监控上述ANR信息文件的变化,如果文件发生了变化,可以把他上传到服务器。
ANR dunp主要流程
ANR流程基本都是在system_server 系统进程完成的,系统进程的行为我们很难监控到。
不管是怎么发生的ANR,最后都会走到appNotResponding.
例如:输入超时的路径
ActivityManagerService#inputDispatchingTimeOut->AnrHelper#appNotResponding->AnrConsumerThread#run->AnrRecord#NotResponding->ProcessRecord#appNotResponding.
//com.android.server.am.ProcessRecord.java
void appNotResponding(String activityShortComponentName, ApplicationInfo aInfo,
String parentShortComponentName, WindowProcessController parentProcess,
boolean aboveSystem, String annotation, boolean onlyDumpSelf) {
ArrayList<Integer> firstPids = new ArrayList<>(5);
SparseArray<Boolean> lastPids = new SparseArray<>(20);
mWindowProcessController.appEarlyNotResponding(annotation, () -> kill("anr",
ApplicationExitInfo.REASON_ANR, true));
long anrTime = SystemClock.uptimeMillis();
if (isMonitorCpuUsage()) {
mService.updateCpuStatsNow();
}
final boolean isSilentAnr;
synchronized (mService) {
//注释1
// PowerManager.reboot() can block for a long time, so ignore ANRs while shutting down.
//正在重启
if (mService.mAtmInternal.isShuttingDown()) {
Slog.i(TAG, "During shutdown skipping ANR: " + this + " " + annotation);
return;
} else if (isNotResponding()) {
//已经处于ANR流程中
Slog.i(TAG, "Skipping duplicate ANR: " + this + " " + annotation);
return;
} else if (isCrashing()) {
//正在crash的状态
Slog.i(TAG, "Crashing app skipping ANR: " + this + " " + annotation);
return;
} else if (killedByAm) {
//app已经被killed
Slog.i(TAG, "App already killed by AM skipping ANR: " + this + " " + annotation);
return;
} else if (killed) {
//app已经死亡了
Slog.i(TAG, "Skipping died app ANR: " + this + " " + annotation);
return;
}
// In case we come through here for the same app before completing
// this one, mark as anring now so we will bail out.
//做个标记
setNotResponding(true);
// Log the ANR to the event log.
EventLog.writeEvent(EventLogTags.AM_ANR, userId, pid, processName, info.flags,
annotation);
// Dump thread traces as quickly as we can, starting with "interesting" processes.
firstPids.add(pid);
// Don't dump other PIDs if it's a background ANR or is requested to only dump self.
//注释2
//沉默的anr : 这里表示后台anr
isSilentAnr = isSilentAnr();
if (!isSilentAnr && !onlyDumpSelf) {
int parentPid = pid;
if (parentProcess != null && parentProcess.getPid() > 0) {
parentPid = parentProcess.getPid();
}
if (parentPid != pid) firstPids.add(parentPid);
if (MY_PID != pid && MY_PID != parentPid) firstPids.add(MY_PID);
//选择需要dump的进程
for (int i = getLruProcessList().size() - 1; i >= 0; i--) {
ProcessRecord r = getLruProcessList().get(i);
if (r != null && r.thread != null) {
int myPid = r.pid;
if (myPid > 0 && myPid != pid && myPid != parentPid && myPid != MY_PID) {
if (r.isPersistent()) {
firstPids.add(myPid);
if (DEBUG_ANR) Slog.i(TAG, "Adding persistent proc: " + r);
} else if (r.treatLikeActivity) {
firstPids.add(myPid);
if (DEBUG_ANR) Slog.i(TAG, "Adding likely IME: " + r);
} else {
lastPids.put(myPid, Boolean.TRUE);
if (DEBUG_ANR) Slog.i(TAG, "Adding ANR proc: " + r);
}
}
}
}
}
}
......
int[] pids = nativeProcs == null ? null : Process.getPidsForCommands(nativeProcs);
ArrayList<Integer> nativePids = null;
if (pids != null) {
nativePids = new ArrayList<>(pids.length);
for (int i : pids) {
nativePids.add(i);
}
}
// For background ANRs, don't pass the ProcessCpuTracker to
// avoid spending 1/2 second collecting stats to rank lastPids.
StringWriter tracesFileException = new StringWriter();
// To hold the start and end offset to the ANR trace file respectively.
final long[] offsets = new long[2];
//注释4
File tracesFile = ActivityManagerService.dumpStackTraces(firstPids,
isSilentAnr ? null : processCpuTracker, isSilentAnr ? null : lastPids,
nativePids, tracesFileException, offsets);
......
}
- 正在重启、已经处于ANR流程中、正在crash、app已经被killed和app已经死亡了,不用处理ANR,直接return。
- isSilentAnr是表示当前是否为一个后台ANR,后台ANR跟前台ANR表现不同,前台ANR会弹出无响应的Dialog,后台ANR会直接杀死进程.
- 在上面注释3中 需要dump的进程,发生ANR dump 很多信息到trace文件中,dump的进程分为3类:
- firstPids:firstPids是需要首先dump的重要进程,发生ANR的进程无论如何是一定要被dump的,也是首先被dump的,所以第一个被加到firstPids中。如果是SilentAnr(即后台ANR),不用再加入任何其他的进程。如果不是,需要进一步添加其他的进程:如果发生ANR的进程不是system_server进程的话,需要添加system_server进程;接下来轮询AMS维护的一个LRU的进程List,如果最近访问的进程包含了persistent的进程,或者带有 BIND_TREAT_LIKE_ACTVITY 标签的进程,都添加到firstPids中。
- extraPids:LRU进程List中的其他进程,都会首先添加到lastPids中,然后lastPids会进一步被选出最近CPU使用率高的进程,进一步组成extraPids。
- nativePids:nativePids最为简单,是一些固定的native的系统进程,定义在WatchDog.java中
拿到需要dump的所有进程pid后,AMS开始按照firstPids,nativePids,extraPids的顺序dump这些进程的堆栈,这里我们可以跟进去看一下。
public static Pair<Long, Long> dumpStackTraces(String tracesFile, ArrayList<Integer> firstPids,
ArrayList<Integer> nativePids, ArrayList<Integer> extraPids) {
// 最多dump 20秒
long remainingTime = 20 * 1000;
// First collect all of the stacks of the most important pids.
if (firstPids != null) {
int num = firstPids.size();
for (int i = 0; i < num; i++) {
final int pid = firstPids.get(i);
final long timeTaken = dumpJavaTracesTombstoned(pid, tracesFile, remainingTime);
remainingTime -= timeTaken;
if (remainingTime <= 0) {
Slog.e(TAG, "Aborting stack trace dump (current firstPid=" + pid
+ "); deadline exceeded.");
return firstPidStart >= 0 ? new Pair<>(firstPidStart, firstPidEnd) : null;
}
}
}
......
}
这里有一个重要的操作就是一个进程有很多线程,更别说这么多进程了,所以这里规定了最长dump时间为20S,超过就会返回。这里确保ANR弹窗可以及时弹出,经过一系列的逻辑:ActivityManagerService#dumpJavaTracesTombstoned() → Debug#dumpJavaBacktraceToFileTimeout() → android_os_Debug#android_os_Debug_dumpJavaBacktraceToFileTimeout() → android_os_Debug#dumpTraces() → debuggerd_client#dump_backtrace_to_file_timeout() → debuggerd_client#debuggerd_trigger_dump()。
bool debuggerd_trigger_dump(pid_t tid, DebuggerdDumpType dump_type, unsigned int timeout_ms, unique_fd output_fd) {
//pid是从AMS那边传过来的,即需要dump堆栈的进程
pid_t pid = tid;
//......
// Send the signal.
//从android_os_Debug_dumpJavaBacktraceToFileTimeout过来的,dump_type为kDebuggerdJavaBacktrace
const int signal = (dump_type == kDebuggerdJavaBacktrace) ? SIGQUIT : BIONIC_SIGNAL_DEBUGGER;
sigval val = {.sival_int = (dump_type == kDebuggerdNativeBacktrace) ? 1 : 0};
//sigqueue:在队列中向指定进程发送一个信号和数据,成功返回0
if (sigqueue(pid, signal, val) != 0) {
log_error(output_fd, errno, "failed to send signal to pid %d", pid);
return false;
}
//......
LOG(INFO) << TAG "done dumping process " << pid;
return true;
}
这里就是AMS进程间接给需要dump堆栈那个进程发送了一个SIGQUIT信号,那个进程就会收到SIGQUIT信号之后开始dump,当一个进程发生ANR的时候,就会收到SIGQUIT信号。
关于信号处理这里再说一下,除了Zygote进程外,每个进程都会创建一个SignalCatcher守护线程,用于捕获SIGQUIT,SIGUSR1信号,并采取相应的行为。
//art/runtime/signal_catcher.cc
void* SignalCatcher::Run(void* arg) {
SignalCatcher* signal_catcher = reinterpret_cast<SignalCatcher*>(arg);
CHECK(signal_catcher != nullptr);
Runtime* runtime = Runtime::Current();
//检查当前线程是否依附到Android Runtime
CHECK(runtime->AttachCurrentThread("Signal Catcher", true, runtime->GetSystemThreadGroup(), !runtime->IsAotCompiler()));
Thread* self = Thread::Current();
DCHECK_NE(self->GetState(), kRunnable);
{
MutexLock mu(self, signal_catcher->lock_);
signal_catcher->thread_ = self;
signal_catcher->cond_.Broadcast(self);
}
SignalSet signals;
signals.Add(SIGQUIT); //添加对信号SIGQUIT的处理
signals.Add(SIGUSR1); //添加对信号SIGUSR1的处理
//死循环,不断等待监听2个信号的dao'l
while (true) {
//等待信号到来,这是个阻塞操作
int signal_number = signal_catcher->WaitForSignal(self, signals);
//当信号捕获需要停止时,则取消当前线程跟Android Runtime的关联。
if (signal_catcher->ShouldHalt()) {
runtime->DetachCurrentThread();
return nullptr;
}
switch (signal_number) {
case SIGQUIT:
signal_catcher->HandleSigQuit(); //输出线程trace
break;
case SIGUSR1:
signal_catcher->HandleSigUsr1(); //强制GC
break;
default:
LOG(ERROR) << "Unexpected signal %d" << signal_number;
break;
}
}
}
在SignalCatcher线程里面,死循环通过WaitForSignal监听SIGQUIT和SIGUSR1信号的到来,前面系统进程system_server进行发送的信号也就是在这里被监听到开始dump堆栈。
监控SIGQUIT信号
前面我们提到了除Zygote进程以外的其他进程都有个Signal Catcher线程在不断地通过sigwait监听SIGQUIT信号,当收到SIGQUIT信号时开始dump线程堆栈。我们需要拦截或者监听SIGQUIT信号,首先需要了解信号处理的相关函数,如kill、signal、sigaction、sigwait、pthread_sigmask等。
void signalHandler(int sig, siginfo_t *info, void *uc) {
__android_log_print(ANDROID_LOG_DEBUG, "xfhy_anr", "我监听到SIGQUIT信号了,可能发生anr了");
//在这里去dump主线程堆栈
}
extern "C"
JNIEXPORT jboolean JNICALL
Java_com_xfhy_watchsignaldemo_MainActivity_startWatch(JNIEnv *env, jobject thiz) {
sigset_t set, old_set;
sigemptyset(&set);
sigaddset(&set, SIGQUIT);
/*
* 这里需要调用SIG_UNBLOCK,因为目标进程被Zogyte fork出来的时候,主线程继承了
* Zogyte的主线程的信号屏蔽关系,Zogyte主线程在初始化的时候,通过
* pthread_sigmask SIG_BLOCK把SIGQUIT的信号给屏蔽了,因此我们需要在自己进程的主线程,
* 设置pthread_sigmask SIG_UNBLOCK ,这会导致原来的SignalCatcher sigwait将失效,
* 原因是SignalCatcher 线程会对SIGQUIT 信号处理
*/
int r = pthread_sigmask(SIG_UNBLOCK, &set, &old_set);
if (0 != r) {
return false;
}
struct sigaction sa{};
sa.sa_sigaction = signalHandler;
sa.sa_flags = SA_ONSTACK | SA_SIGINFO | SA_RESTART;
return sigaction(SIGQUIT, &sa, nullptr) == 0;
}
Android默认把SIGQUIT设置成了BLOCKED,所以只会响应Signal Catcher线程的sigwait监听SIGQUIT信号,我们用sigaction监听的则收不到,所以这里还需要处理一下。我们通过pthread_sigmask或者sigprocmask把SIGQUIT设置为UNBLOCK,那么再次收到SIGQUIT时,就一定会进入到我们的signalHandler方法中。
我们用sigaction抢了Signal Catcher线程的SIGQUIT信号,那Signal Catcher线程就收不到该信号了,那原本的系统dump堆栈的流程就没了,这是不太合适的。所以我们需要将该信号重新发送出去,让Signal Catcher线程接收到该信号。
int tid = getSignalCatcherThreadId(); //遍历/proc/[pid]目录,找到SignalCatcher线程的tid
tgkill(getpid(), tid, SIGQUIT);
发生ANR的进程一定会收到SIGQUIT信号;但是收到SIGQUIT信号的进程并不一定发生了ANR。
此时我们可以通过主线程释放处于卡顿状态来判断,怎么快速的知道主线程是否卡住了?可以通过Looper的mMessage对象,该对象的when变量,表示的是当前正在处理的消息入队的时间,我们可以通过when变量减去当前时间,得到的就是等待时间,如果等待时间过长,就说明主线程是处于卡住的状态
private static boolean isMainThreadStuck(){
try {
MessageQueue mainQueue = Looper.getMainLooper().getQueue();
Field field = mainQueue.getClass().getDeclaredField("mMessages");
field.setAccessible(true);
final Message mMessage = (Message) field.get(mainQueue);
if (mMessage != null) {
long when = mMessage.getWhen();
if(when == 0) {
return false;
}
long time = when - SystemClock.uptimeMillis();
long timeThreshold = BACKGROUND_MSG_THRESHOLD;
if (foreground) {
timeThreshold = FOREGROUND_MSG_THRESHOLD;
}
return time < timeThreshold;
}
} catch (Exception e){
return false;
}
return false;
}
获取ANR Trace
Signal Catcher线程写Trace也是一个边界,它是通过socket的write方法来写trace的。那我们可以直接hook这里的write,就能直接拿到系统dump的ANR Trace内容。这个内容非常全面,包括了所有线程的各种状态、锁和堆栈(包括native堆栈),对于我们排查问题十分有用,尤其是一些native问题和死锁等问题。native hook采用PLT Hook方案,稳得很,这种方案已经在微信上验证了其稳定性。
int (*original_connect)(int __fd, const struct sockaddr* __addr, socklen_t __addr_length);
int my_connect(int __fd, const struct sockaddr* __addr, socklen_t __addr_length) {
if (strcmp(__addr->sa_data, "/dev/socket/tombstoned_java_trace") == 0) {
isTraceWrite = true;
signalCatcherTid = gettid();
}
return original_connect(__fd, __addr, __addr_length);
}
int (*original_open)(const char *pathname, int flags, mode_t mode);
int my_open(const char *pathname, int flags, mode_t mode) {
if (strcmp(pathname, "/data/anr/traces.txt") == 0) {
isTraceWrite = true;
signalCatcherTid = gettid();
}
return original_open(pathname, flags, mode);
}
ssize_t (*original_write)(int fd, const void* const __pass_object_size0 buf, size_t count);
ssize_t my_write(int fd, const void* const buf, size_t count) {
if(isTraceWrite && signalCatcherTid == gettid()) {
isTraceWrite = false;
signalCatcherTid = 0;
char *content = (char *) buf;
printAnrTrace(content);
}
return original_write(fd, buf, count);
}
void hookAnrTraceWrite() {
int apiLevel = getApiLevel();
if (apiLevel < 19) {
return;
}
if (apiLevel >= 27) {
plt_hook("libcutils.so", "connect", (void *) my_connect, (void **) (&original_connect));
} else {
plt_hook("libart.so", "open", (void *) my_open, (void **) (&original_open));
}
if (apiLevel >= 30 || apiLevel == 25 || apiLevel ==24) {
plt_hook("libc.so", "write", (void *) my_write, (void **) (&original_write));
} else if (apiLevel == 29) {
plt_hook("libbase.so", "write", (void *) my_write, (void **) (&original_write));
} else {
plt_hook("libart.so", "write", (void *) my_write, (void **) (&original_write));
}
}
总结
总结一下,该方案通过去监听SIGQUIT信号,从而感知当前进程可能发生了ANR,需配合当前进程是否处于NOT_RESPONDING状态以及主线程是否卡顿来进行甄别,以免误判。注册监听SIGQUIT信号之后,系统原来的Signal Catcher线程就监听不到这个信号了,需要把该信号转发出去,让它接收到,以免影响。当前进程的Signal Catcher线程要dump堆栈的时候,会通过socket的write向system server进程进行传输dump好的数据,我们可以hook这个write,从而拿到系统dump好的ANR Trace内容,相当于我们并没有影响系统的任何流程,还拿到了想要拿到的东西。这个方案完全是在系统的正常dump anr trace的过程中获取信息,所以能拿到的东西更加全面,但是系统的dump过程其实是对性能影响比较大的,时间也比较久。
ANR 文件分析
----- pid 7761 at 2022-11-02 07:02:26 -----
Cmd line: com.xfhy.watchsignaldemo
Build fingerprint: 'HUAWEI/LYA-AL00/HWLYA:10/HUAWEILYA-AL00/10.1.0.163C00:user/release-keys'
ABI: 'arm64'
Build type: optimized
Zygote loaded classes=11918 post zygote classes=729
Dumping registered class loaders
#0 dalvik.system.PathClassLoader: [], parent #1
#1 java.lang.BootClassLoader: [], no parent
#2 dalvik.system.PathClassLoader: [/system/app/FeatureFramework/FeatureFramework.apk], no parent
#3 dalvik.system.PathClassLoader: [/data/app/com.xfhy.watchsignaldemo-4tkKMWojrpHAf-Q3iecaHQ==/base.apk:/data/app/com.xfhy.watchsignaldemo-4tkKMWojrpHAf-Q3iecaHQ==/base.apk!classes2.dex:/data/app/com.xfhy.watchsignaldemo-4tkKMWojrpHAf-Q3iecaHQ==/base.apk!classes4.dex:/data/app/com.xfhy.watchsignaldemo-4tkKMWojrpHAf-Q3iecaHQ==/base.apk!classes3.dex], parent #1
Done dumping class loaders
Intern table: 44132 strong; 436 weak
JNI: CheckJNI is off; globals=681 (plus 67 weak)
Libraries: /data/app/com.xfhy.watchsignaldemo-4tkKMWojrpHAf-Q3iecaHQ==/lib/arm64/libwatchsignaldemo.so libandroid.so libcompiler_rt.so libhitrace_jni.so libhiview_jni.so libhwapsimpl_jni.so libiAwareSdk_jni.so libimonitor_jni.so libjavacore.so libjavacrypto.so libjnigraphics.so libmedia_jni.so libopenjdk.so libsoundpool.so libwebviewchromium_loader.so (15)
//已分配堆内存大小26M,其中2442kb医用,总分配74512个对象
Heap: 90% free, 2442KB/26MB; 74512 objects
Total number of allocations 120222 //进程创建到现在一共创建了多少对象
Total bytes allocated 10MB //进程创建到现在一共申请了多少内存
Total bytes freed 8173KB //进程创建到现在一共释放了多少内存
Free memory 23MB //不扩展堆的情况下可用的内存
Free memory until GC 23MB //GC前的可用内存
Free memory until OOME 381MB //OOM之前的可用内存,这个值很小的话,说明已经处于内存紧张状态,app可能是占用了过多的内存
Total memory 26MB //当前总内存(已用+可用)
Max memory 384MB //进程最多能申请的内存
.....//省略GC相关信息
//当前进程共17个线程
DALVIK THREADS (17):
//Signal Catcher线程调用栈
"Signal Catcher" daemon prio=5 tid=4 Runnable
| group="system" sCount=0 dsCount=0 flags=0 obj=0x18c84570 self=0x7252417800
| sysTid=7772 nice=0 cgrp=default sched=0/0 handle=0x725354ad50
| state=R schedstat=( 16273959 1085938 5 ) utm=0 stm=1 core=4 HZ=100
| stack=0x7253454000-0x7253456000 stackSize=991KB
| held mutexes= "mutator lock"(shared held)
native: #00 pc 000000000042f8e8 /apex/com.android.runtime/lib64/libart.so (art::DumpNativeStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, int, BacktraceMap*, char const*, art::ArtMethod*, void*, bool)+140)
native: #01 pc 0000000000523590 /apex/com.android.runtime/lib64/libart.so (art::Thread::DumpStack(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool, BacktraceMap*, bool) const+508)
native: #02 pc 000000000053e75c /apex/com.android.runtime/lib64/libart.so (art::DumpCheckpoint::Run(art::Thread*)+844)
native: #03 pc 000000000053735c /apex/com.android.runtime/lib64/libart.so (art::ThreadList::RunCheckpoint(art::Closure*, art::Closure*)+504)
native: #04 pc 0000000000536744 /apex/com.android.runtime/lib64/libart.so (art::ThreadList::Dump(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, bool)+1048)
native: #05 pc 0000000000536228 /apex/com.android.runtime/lib64/libart.so (art::ThreadList::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits<char>>&)+884)
native: #06 pc 00000000004ee4d8 /apex/com.android.runtime/lib64/libart.so (art::Runtime::DumpForSigQuit(std::__1::basic_ostream<char, std::__1::char_traits<char>>&)+196)
native: #07 pc 000000000050250c /apex/com.android.runtime/lib64/libart.so (art::SignalCatcher::HandleSigQuit()+1356)
native: #08 pc 0000000000501558 /apex/com.android.runtime/lib64/libart.so (art::SignalCatcher::Run(void*)+268)
native: #09 pc 00000000000cf7c0 /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+36)
native: #10 pc 00000000000721a8 /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64)
(no managed stack frames)
"main" prio=5 tid=1 Sleeping
| group="main" sCount=1 dsCount=0 flags=1 obj=0x73907540 self=0x725f010800
| sysTid=7761 nice=-10 cgrp=default sched=1073741825/2 handle=0x72e60080d0
| state=S schedstat=( 281909898 5919799 311 ) utm=20 stm=7 core=4 HZ=100
| stack=0x7fca180000-0x7fca182000 stackSize=8192KB
| held mutexes=
at java.lang.Thread.sleep(Native method)
- sleeping on <0x00f895d9> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:443)
- locked <0x00f895d9> (a java.lang.Object)
at java.lang.Thread.sleep(Thread.java:359)
at android.os.SystemClock.sleep(SystemClock.java:131)
at com.xfhy.watchsignaldemo.MainActivity.makeAnr(MainActivity.kt:35)
at java.lang.reflect.Method.invoke(Native method)
at androidx.appcompat.app.AppCompatViewInflater$DeclaredOnClickListener.onClick(AppCompatViewInflater.java:441)
at android.view.View.performClick(View.java:7317)
at com.google.android.material.button.MaterialButton.performClick(MaterialButton.java:1219)
at android.view.View.performClickInternal(View.java:7291)
at android.view.View.access$3600(View.java:838)
at android.view.View$PerformClick.run(View.java:28247)
at android.os.Handler.handleCallback(Handler.java:900)
at android.os.Handler.dispatchMessage(Handler.java:103)
at android.os.Looper.loop(Looper.java:219)
at android.app.ActivityThread.main(ActivityThread.java:8668)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:513)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1109)
... //此处省略剩余的N个线程
"Signal Catcher" daemon prio=5 tid=4 Runnable
| group="system" sCount=0 dsCount=0 flags=0 obj=0x18c84570 self=0x7252417800
| sysTid=7772 nice=0 cgrp=default sched=0/0 handle=0x725354ad50
| state=R schedstat=( 16273959 1085938 5 ) utm=0 stm=1 core=4 HZ=100
| stack=0x7253454000-0x7253456000 stackSize=991KB
| held mutexes= "mutator lock"(shared held)
"Signal Catcher" daemon prio=5 tid=4 Runnable
- Signal Catcher" daemon : 线程名,有daemon表示守护线程
- prio:线程优先级
- tid:线程内部id
-
线程状态:Runnable
|group="system" sCount=0 dsCount=0 flags=0 obj=0x18c84570 self=0x7252417800
- group:线程所属的线程组
- sCount:线程挂起次数
- dsCount:用于调试的线程挂起次数
- obj:当前线程关联的Java线程对象
- self:当前线程地址
| sysTid=7772 nice=0 cgrp=default sched=0/0 handle=0x725354ad50
- sysTid:线程真正意义上的tid
- nice:调度优先级,值越小则优先级越高
- cgrp:进程所属的进程调度组
- sched:调度策略
- handle:函数处理地址
state=R schedstat=( 16273959 1085938 5 ) utm=0 stm=1 core=4 HZ=100
- state:线程状态
- schedstat:CPU调度时间统计(schedstat括号中的3个数字依次是Running、Runable、Switch,Running时间:CPU运行的时间,单位ns,Runable时间:RQ队列的等待时间,单位ns,Switch次数:CPU调度切换次数)
- utm/stm:用户态/内核态的CPU时间
- core:该线程的最后运行所在核
- HZ:时钟频率
| stack=0x7253454000-0x7253456000 stackSize=991KB
- stack:线程栈的地址区间
- stackSize:栈的大小
held mutexes= "mutator lock"(shared held)
- mutex:所持有mutex类型,有独占锁exclusive和共享锁shared两类
ANR具体案例分析
- CPU被抢占
CPU usage from 0ms to 10625ms later (2020-03-09 14:38:31.633 to 2020-03-09 14:38:42.257):
543% 2045/com.test.demo: 54% user + 89% kernel / faults: 4608 minor 1 major //注意看这里
99% 674/android.hardware.camera.provider@2.4-service: 81% user + 18% kernel / faults: 403 minor
24% 32589/com.wang.test: 22% user + 1.4% kernel / faults: 7432 minor 1 major
......
进程占据CPU高达543%,抢占了大部分CPU资源,因为导致发生ANR,这种ANR与我们的app无关。
- 内存紧张导致ANR
如果一份ANR日志的CPU和堆栈都很正常,可以考虑是内存紧张。看一下ANR日志里面的内存相关部分。还可以去日志里面搜一下onTrimMemory,如果dump ANR日志的时间附近有相关日志,可能是内存比较紧张了。
10-31 22:37:19.749 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:37:33.458 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:38:00.153 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:38:58.731 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
10-31 22:39:02.816 20733 20733 E Runtime : onTrimMemory level:80,pid:com.xxx.xxx:Launcher0
3.系统服务超时导致ANR
系统服务超时一般会包含BinderProxy.transactNative关键字,来看一段日志:
"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x727851e8 self=0x78d7060e00
| sysTid=4894 nice=0 cgrp=default sched=0/0 handle=0x795cc1e9a8
| state=S schedstat=( 8292806752 1621087524 7167 ) utm=707 stm=122 core=5 HZ=100
| stack=0x7febb64000-0x7febb66000 stackSize=8MB
| held mutexes=
kernel: __switch_to+0x90/0xc4
kernel: binder_thread_read+0xbd8/0x144c
kernel: binder_ioctl_write_read.constprop.58+0x20c/0x348
kernel: binder_ioctl+0x5d4/0x88c
kernel: do_vfs_ioctl+0xb8/0xb1c
kernel: SyS_ioctl+0x84/0x98
kernel: cpu_switch_to+0x34c/0x22c0
native: #00 pc 000000000007a2ac /system/lib64/libc.so (__ioctl+4)
native: #01 pc 00000000000276ec /system/lib64/libc.so (ioctl+132)
native: #02 pc 00000000000557d4 /system/lib64/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+252)
native: #03 pc 0000000000056494 /system/lib64/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel*, int*)+60)
native: #04 pc 00000000000562d0 /system/lib64/libbinder.so (android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+216)
native: #05 pc 000000000004ce1c /system/lib64/libbinder.so (android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+72)
native: #06 pc 00000000001281c8 /system/lib64/libandroid_runtime.so (???)
native: #07 pc 0000000000947ed4 /system/framework/arm64/boot-framework.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+196)
at android.os.BinderProxy.transactNative(Native method) ————————————————关键行!!!
at android.os.BinderProxy.transact(Binder.java:804)
at android.net.IConnectivityManager$Stub$Proxy.getActiveNetworkInfo(IConnectivityManager.java:1204)—关键行!
at android.net.ConnectivityManager.getActiveNetworkInfo(ConnectivityManager.java:800)
at com.xiaomi.NetworkUtils.getNetworkInfo(NetworkUtils.java:2)
at com.xiaomi.frameworkbase.utils.NetworkUtils.getNetWorkType(NetworkUtils.java:1)
at com.xiaomi.frameworkbase.utils.NetworkUtils.isWifiConnected(NetworkUtils.java:1)
从日志堆栈中可以看到是获取网络信息发生了ANR:getActiveNetworkInfo。系统的服务都是Binder机制(16个线程),服务能力也是有限的,有可能系统服务长时间不响应导致ANR。如果其他应用占用了所有Binder线程,那么当前应用只能等待。可进一步搜索:blockUntilThreadAvailable关键字:
at android.os.Binder.blockUntilThreadAvailable(Native method)
如果有发现某个线程的堆栈,包含此字样,可进一步看其堆栈,确定是调用了什么系统服务。此类ANR也是属于系统环境的问题,如果某类型手机上频繁发生此问题,应用层可以考虑规避策略。