一次ANR分析：CPU爆炸引起的ANR

(1)首先分析 trace文件

"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 obj=0x75058f60 self=0x558090fcd0
| sysTid=3803 nice=0 cgrp=default sched=0/0 handle=0x7f9c4b8fe8
| state=S schedstat=( 0 0 0 ) utm=5225 stm=848 core=3 HZ=100
| stack=0x7fca9fa000-0x7fca9fc000 stackSize=8MB
| held mutexes=
kernel: __switch_to+0x74/0x8c
kernel: futex_wait_queue_me+0xe8/0x178
kernel: futex_wait+0xe4/0x240
kernel: do_futex+0x198/0x9e0
kernel: SyS_futex+0x114/0x198
kernel: cpu_switch_to+0x48/0x4c
native: #00 pc 0000000000019900  /system/lib64/libc.so (syscall+28)
native: #01 pc 000000000013a654  /system/lib64/libart.so (art::ConditionVariable::Wait(art::Thread*)+136)
native: #02 pc 0000000000534848  /system/lib64/libart.so (art::GoToRunnable(art::Thread*)+680)
native: #03 pc 000000000011cdac  /system/lib64/libart.so (art::JniMethodEnd(unsigned int, art::Thread*)+24)
native: #04 pc 000000000048f960  /data/dalvik-cache/arm64/system@framework@boot.oat (Java_dalvik_system_VMDebug_countInstancesOfClass__Ljava_lang_Class_2Z+180)
at dalvik.system.VMDebug.countInstancesOfClass(Native method)
at android.os.StrictMode.decrementExpectedActivityCount(StrictMode.java:2260)
at android.app.ActivityThread.performDestroyActivity(ActivityThread.java:3838)
at android.app.ActivityThread.handleDestroyActivity(ActivityThread.java:3849)
at android.app.ActivityThread.-wrap5(ActivityThread.java:-1)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1398)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:148)
at android.app.ActivityThread.main(ActivityThread.java:5417)
at java.lang.reflect.Method.invoke!(Native method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:731)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:621)

(2)

"main" prio=5 tid=1 Native
| group="main" sCount=1 dsCount=0 obj=0x741edf60 self=0x55a02f2cd0
| sysTid=3098 nice=0 cgrp=default sched=0/0 handle=0x7fa3340fe8
| state=S schedstat=( 0 0 0 ) utm=385 stm=82 core=0 HZ=100
| stack=0x7fcf023000-0x7fcf025000 stackSize=8MB
| held mutexes=
kernel: __switch_to+0x74/0x8c
kernel: futex_wait_queue_me+0xe8/0x178
kernel: futex_wait+0xe4/0x240
kernel: do_futex+0x198/0x9e0
kernel: SyS_futex+0x114/0x198
kernel: cpu_switch_to+0x48/0x4c
native: #00 pc 0000000000019900  /system/lib64/libc.so (syscall+28)
native: #01 pc 000000000013a654  /system/lib64/libart.so (art::ConditionVariable::Wait(art::Thread*)+136)
native: #02 pc 000000000035f3a0  /system/lib64/libart.so (art::JNI::CallObjectMethod(_JNIEnv*, _jobject*, _jmethodID*, ...)+1124)
native: #03 pc 00000000000bc0f4  /system/lib64/libandroid_runtime.so (android::NativeDisplayEventReceiver::dispatchVsync(long, int, unsigned int)+48)
native: #04 pc 00000000000bc520  /system/lib64/libandroid_runtime.so (android::NativeDisplayEventReceiver::handleEvent(int, int, void*)+84)
native: #05 pc 000000000001b0a4  /system/lib64/libutils.so (android::Looper::pollInner(int)+960)
native: #06 pc 000000000001b154  /system/lib64/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+80)
native: #07 pc 00000000000d20a8  /system/lib64/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, _jobject*, int)+48)
native: #08 pc 000000000019e5ac  /data/dalvik-cache/arm64/system@framework@boot.oat (Java_android_os_MessageQueue_nativePollOnce__JI+144)
at android.os.MessageQueue.nativePollOnce(Native method)
at android.os.MessageQueue.next(MessageQueue.java:323)
at android.os.Looper.loop(Looper.java:135)
at android.app.ActivityThread.main(ActivityThread.java:5417)
at java.lang.reflect.Method.invoke!(Native method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:731)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:621)

之前没碰到过这样的问题：看到ActivityThread没什么反应

(3)当我看到CPU爆炸了，我知道了，我的线程出问题了..

[03-16-15-28-35]: 01-01 08:31:31.727  2082  2092 W art     : Suspending all threads took: 26.499ms
[03-16-15-28-35]: 01-01 08:31:32.154  2082  2092 I art     : Background sticky concurrent mark sweep GC freed 41722(2MB) AllocSpace objects, 21(728KB) LOS objects, 18% free, 10MB/12MB, paused 28.224ms total 1.606s
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: ANR in com.jrm.localmm (com.jrm.localmm/.ui.main.FileBrowserActivity)
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: PID: 3803
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: Reason: Input dispatching timed out (Waiting because the touched window's input channel is full.  Outbound queue length: 1.  Wait queue length: 54.)
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: Load: 36.76 / 33.27 / 22.26
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: CPU usage from 1026ms to -12219ms ago:
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   363% 3803/com.jrm.localmm: 361% user + 2.1% kernel / faults: 4612 minor 38 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   16% 2082/system_server: 5.3% user + 10% kernel / faults: 8932 minor 33 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   3.8% 1722/tvos: 1.7% user + 2.1% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 1658/debuggerd: 0% user + 0% kernel / faults: 7256 minor 19 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 1659/debuggerd64: 0% user + 0% kernel / faults: 6395 minor 6 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   1.8% 2279/com.android.systemui: 0.8% user + 0.9% kernel / faults: 2631 minor 4 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 2605/com.android.phone: 0% user + 0% kernel / faults: 2459 minor 1 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.1% 2292/com.mstar.tv.service: 0% user + 0% kernel / faults: 2276 minor
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.6% 1638/surfaceflinger: 0.3% user + 0.3% kernel / faults: 33 minor 3 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 2576/com.mediatek.autopair: 0% user + 0% kernel / faults: 1551 minor 1 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 2592/com.mstar.android.pppoe: 0% user + 0% kernel / faults: 3083 minor
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.2% 895/mmcqd/0: 0% user + 0.2% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.1% 8/rcu_preempt: 0% user + 0.1% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.1% 970/irq/202-scaler: 0% user + 0.1% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.1% 1587/logd: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0.1% 1666/livecap: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 651/kswapd0: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 985/T_sensor_Check: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 1661/mediaserver: 0% user + 0% kernel / faults: 14 minor 2 major
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 1664/logwrapper: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 1665/virtualkeypad: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 2225/android.process.media: 0% user + 0% kernel / faults: 17 minor
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   0% 7335/kworker/3:0: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:  +0% 7368/dumpsys: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:  +0% 7369/busybox: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:  +0% 7370/busybox: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:  +0% 7371/kworker/0:1: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:  +0% 7373/kworker/0:0: 0% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: 99% TOTAL: 93% user + 5.2% kernel + 0% iowait
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: CPU usage from 11555ms to 12128ms later:
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   373% 3803/com.jrm.localmm: 373% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     39% 4171/TaskThread 177: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     39% 4976/TaskThread 389: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     39% 5846/TaskThread 657: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     39% 6182/TaskThread 746: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     37% 5176/TaskThread 439: 37% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     18% 4862/TaskThread 364: 18% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     13% 6299/TaskThread 779: 13% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     9.8% 6835/TaskThread 915: 9.8% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 4413/TaskThread 225: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 4735/TaskThread 322: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 4810/TaskThread 341: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 5287/TaskThread 475: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 5406/TaskThread 514: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 5672/TaskThread 588: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 5722/TaskThread 610: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 6668/TaskThread 881: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     8.1% 7065/TaskThread 967: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 4280/TaskThread 203: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 4633/TaskThread 295: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 5061/TaskThread 412: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 5961/TaskThread 686: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 6400/TaskThread 807: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 6508/TaskThread 839: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 6978/TaskThread 944: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     6.5% 7149/TaskThread 989: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.6% 6074/TaskThread 717: 1.6% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.6% 7250/TaskThread 1009: 1.6% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   19% 2082/system_server: 10% user + 9% kernel / faults: 718 minor
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     9% 2087/Signal Catcher: 3.6% user + 5.4% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     5.4% 3053/Binder_B: 3.6% user + 1.8% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     3.6% 2092/HeapTaskDaemon: 3.6% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.8% 2089/ReferenceQueueD: 0% user + 1.8% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.8% 2090/FinalizerDaemon: 1.8% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.8% 2105/ActivityManager: 1.8% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:   3.6% 1722/tvos: 1.8% user + 1.8% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.8% 2065/AudioMonitor: 0% user + 1.8% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager:     1.8% 3098/VDEC_CALLBACK_T: 0% user + 1.8% kernel
[03-16-15-28-35]: 01-01 08:31:32.353  2082  2105 E ActivityManager: 100% TOTAL: 96% user + 3% kernel
[03-16-15-28-35]: 01-01 08:31:32.531  2082  2105 W ActivityManager: Activity destroy timeout for ActivityRecord{c82d7de u0 com.jrm.localmm/.ui.video.VideoPlayerActivity t129 f}
[03-16-15-28-35]: 01-01 08:31:32.993  2082  7382 D OpenGLRenderer: Use EGL_SWAP_BEHAVIOR_PRESERVED: false

你看CPU100%亮瞎我狗眼啊

(4)处理

找到引起CPU爆炸的线程TaskThread

[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: CPU usage from 11555ms to 12128ms later:
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 373% 3803/com.jrm.localmm: 373% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 39% 4171/TaskThread 177: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 39% 4976/TaskThread 389: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 39% 5846/TaskThread 657: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 39% 6182/TaskThread 746: 39% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 37% 5176/TaskThread 439: 37% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 18% 4862/TaskThread 364: 18% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 13% 6299/TaskThread 779: 13% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 9.8% 6835/TaskThread 915: 9.8% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 4413/TaskThread 225: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 4735/TaskThread 322: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 4810/TaskThread 341: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 5287/TaskThread 475: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 5406/TaskThread 514: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 5672/TaskThread 588: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 5722/TaskThread 610: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 6668/TaskThread 881: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 8.1% 7065/TaskThread 967: 8.1% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 4280/TaskThread 203: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 4633/TaskThread 295: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 5061/TaskThread 412: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 5961/TaskThread 686: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 6400/TaskThread 807: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 6508/TaskThread 839: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 6978/TaskThread 944: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 6.5% 7149/TaskThread 989: 6.5% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 1.6% 6074/TaskThread 717: 1.6% user + 0% kernel
[03-16-15-28-35]: 01-01 08:31:32.353 2082 2105 E ActivityManager: 1.6% 7250/TaskThread 1009: 1.6% user + 0% kernel

如果不是事先处理这个问题还真没办法找出来

root cause：一个线程里面while(true)没有sleep导致CPU爆炸了