基于Android 13 进行测试
这个anr 产生的原因以及例子 , 之前的文章有写过一个非耗时操作Input ANR引发的思考, 可以查看之前写的文章 , 此文只做xcrash 和 matrix 对于此类anr的监控和排查.
anr 发生 xCrash 部分日志文件如下
`
Tombstone maker: ‘xCrash 3.1.0’Crash type: ‘anr’
Start time: ‘2023-07-04T10:05:50.997+0800’
Crash time: ‘2023-07-04T10:06:12.226+0800’
App ID: ‘xcrash.sample’
App version: ‘1.2.3-beta456-patch789’
Rooted: ‘No’
API level: ’33’
OS version: ’13’
Kernel version: ‘Linux version 5.10.149-android12-9-00001-gda3d81545d1d-ab9545656 #1 SMP PREEMPT Tue Jan 31 05:44:42 UTC 2023 (aarch64)’
ABI list: ‘arm64-v8a,armeabi-v7a,armeabi’
Manufacturer: ‘Xiaomi’
Brand: ‘Redmi’
Model: ‘Redmi Note 12 Turbo’
Build fingerprint: ‘Redmi/marble/marble:13/TKQ1.221114.001/V14.0.20.0.TMRCNXM:user/release-keys’
ABI: ‘arm64’
Heap: 86% free, 3706KB/26MB; 175828 objects
pid: 17680 >>> xcrash.sample <<<
“main” prio=5 tid=1 Native
| group=”main” sCount=1 ucsCount=0 flags=1 obj=0x723064d8 self=0xb40000721fe42c00
| sysTid=17680 nice=-10 cgrp=top-app sched=0/0 handle=0x72beebb4f8
| state=S schedstat=( 737089013 150968431 989 ) utm=62 stm=11 core=7 HZ=100
| stack=0x7fc9984000-0x7fc9986000 stackSize=8188KB
| held mutexes=
native: #00 pc 00000000000e1b9c /apex/com.android.runtime/lib64/bionic/libc.so (__epoll_pwait+12) (BuildId: 449f781894033dce6346794a1ee593e0)
native: #01 pc 0000000000017e40 /system/lib64/libutils.so (android::Looper::pollInner(int)+192) (BuildId: 104125701f0f8a41374b9998e94209e9)
native: #02 pc 0000000000017d1c /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+116) (BuildId: 104125701f0f8a41374b9998e94209e9)
native: #03 pc 00000000001688bc /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce(_JNIEnv*, _jobject*, long, int)+48) (BuildId: 5c9da975dbb315da13b16b1bdb77d79c)
at android.os.MessageQueue.nativePollOnce(Native method)
at android.os.MessageQueue.next(MessageQueue.java:341)
at android.os.Looper.loopOnce(Looper.java:169)
at android.os.Looper.loop(Looper.java:300)
at android.app.ActivityThread.main(ActivityThread.java:8395)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:559)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:954)`
…省略大部分不相关日志
通过主线程堆栈 , 可以看到当前主线程是空闲的 , 并且当前主线程回到native层去调用 nativePollOnce -> epoll_wait 进入等待阻塞状态, 如果仅凭xrash 这些日志 , 虽然知道有ANR了 , 但还是很难定位到问题去解决这类ANR问题.
anr 发生 matrix 部分日志文件如下
[at] visibleScene[xcrash.sample.SecondActivity] has detach focus!
[realRelease] timestamp:1688438955353
getTotalMemory cost:1, total_mem:11719024640, LowMemoryThresold:226492416, Memory Class:256
[getLevel] totalMemory:11719024640 coresNum:8
getLevel, cost:3, level:BEST
RandomAccessFile(Process Stat) reader fail, error: java.io.FileNotFoundException: /proc/stat: open failed: EACCES (Permission denied)
getAppCpuRate cost:3,rate:0.0
report issue content: tag[Trace_EvilMethod]type[0];key[null];content[{“machine”:”BEST”,”cpu_app”:0,”mem”:11719024640,”mem_free”:4767520,”detail”:”SIGNAL_ANR”,
“threadStack”:”android.os.MessageQueue.nativePollOnce(Native Method)\nandroid.os.MessageQueue.next(MessageQueue.java:341)\nandroid.os.Looper.loopOnce(Looper.java:169)\nandroid.os.Looper.loop(Looper.java:300)\nandroid.app.ActivityThread.main(ActivityThread.java:8395)\njava.lang.reflect.Method.invoke(Native Method)\ncom.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:559)\ncom.android.internal.os.ZygoteInit.main(ZygoteInit.java:954)\n”,”scene”:”xcrash.sample.SecondActivity”,”isProcessForeground”:true,”tag”:”Trace_EvilMethod”,”process”:”xcrash.sample”,”time”:1688438970396}]
matrix Hook socket 生成的 trace.txt 文件部分如下 ,这部分内容和xcrash 一致
但是matrix 把 error sate anr 原因打印了出来
有了这个信息的话 , 对于这类anr 就很好排查了
总结一下: 如果看到主线程堆栈调用nativePollOnce 说明主线程是空闲的, 并不是造成anr 的原因 , 对于这类anr , xcrash 和 matrix 都能监控到 , 并且都能把堆栈\内存\cpu信息打印出来 , 但是xcrash 并没有把anr 产生的原因打印出来 , 导致这类问题很难排查 , 所以此类anr 处理上 matrix更胜一筹 .
性能上matrix通过PLT Hook socket write()函数获取该日志 , 而xcrash 通过二次调用Runtime::DumpForSigQuit 方法 , 重定向fd 获取日志 , 每次调用Runtime::DumpForSigQuit 去dump堆栈也是比 Hook socket write() 相比更损耗性能.
至于主线程卡顿 \ 死锁产生的anr , 通过两个框架输出的日志都能很好的进行分析 , 这里就不多说了 .
通过ANR再谈Handler机制和事件分发机制
记得刚学android 的时候 事件分发机制和handler机制 无疑是听得最多的 , 看网上的文章分析 , 很多基本都是对事件分发机制的那三大方法(dispatchTouchEvent ,onInterceptTouchEvent , onTouchEvent)一顿分析 , 至于handler机制 , 很多都是对(MessageQueue ,Looper , Handler)源码的一顿分析. 深入学习了两年半 , 总结下这两个的关联以及ANR .
首先说下Handler机制 ,大伙都知道 android 基于linux 内核 , 其实无论什么内核 , 只要创建出进程 , 当进程内的代码跑完了进程就退出了 , 所以要想进程不退出就只有一个办法 , 一直死循环下去 。 但是一直死循环有个问题 , 那就是cpu一直在空转 , cpu是硬件会一直消耗电量啊 , 所以得想个办法让cpu只在这个线程有活干的时候才调度 , 没活干得时候就阻塞，让出cpu的使用权 。让出cpu的使用权啊 ， 这个简单，线程不是给我们提供了使用Thread.sleep(long millis) ， 我直接使用Thread.sleep(一年) 不就行了 ， 应用不可能存活一年吧 ， 但是这个不支持主动唤醒 ，所以Thread.sleep肯定是不行的。那有人会问不是还有Object.wait() 和 notify ，以及其他的方式吗 ， 用这些方法不行吗 ，没活干的时候我就wait() 阻塞，有活的时候我就调用notify 唤醒。
如果是那种翻盖非智能手机，只运行在java虚拟机上的话这样做肯定是没问题，但是android 是基于linux 内核的 ，每一个app应用都是zygote fork出来的 ，都有自己art 虚拟机，art虚拟机也只是一个so库而已，这个so库唯一作用就是用来执行经java文件转化而来的这些dex文件。事件从硬件到 linux 内核 再由内核分发给进程，进程唤醒主进程，最后在native主线程中通过 jni 调用Java 方法。可以看到这种做法相当麻烦，有什么什么比线程的阻塞系列方法更高效的？
android 基于linux ，linux中万物皆文件 ，比如dlopen 动态库会返回一个fd ， 打开binder驱动会返回一个fd ，读写文件会返回一个fd ，使用socket 会返回sockfd ，等等 。所有事件都和fd挂钩。有没有可以同时监控这些的fd的？当然是有的linux 提供了多路复用的epoll 就可以。handler 机制中使用epoll_wait 阻塞当前线程让出cpu使用权 ， 当监听到fd有变化时 epoll_wait会结束等待阻塞，恢复执行。
handler机制和事件分发有什么联系？ 那当然是有联系的，事件从硬件产生最终到应用层的主线程的looper.loop死循环中被处理 。应用进程通过binder 和 wms、ims 通信时，wms创建一对socket pair,用InputChannel封装，一个给app,一个给InputFlinger , 之后InputFlinger通过这个 socket fd把touch数据发给InputChannel 应用进程端。应用进程端 native 层通过jni调用到java层，事件分发到java层后 ， 大致流程ViewRootImpl——>DecorView——>Activity——>PhoneWindow——>DecorView——>ViewGroup /view -> ViewRootImpl $WindowInputEventReceiver#finishInputEvent -> native 层通过 socket 通信去把事件从 waitQueue 移除，从waitQueue移除表示已经处理完此次事件。
若窗口 waitQueue 非空 且 头事件分发超时 500ms, 则无法分发事件 ， 然后安放定时器, 默认 5s 之后重试，重试的时候, 若仍然分发失败, 则调用 onANRLocked 弹出 ANR 弹窗 。可以看到当handler 机制 中消息处理卡顿的时候，会导致事件不会及时从 waitQueue 中移除，然后无法分发新事件重试的时候还是无法分发便会弹ANR 。
