上一个ANR实例分析中有个关键信息：Looper: Slow dispatch took 10578ms main，可以看到主线程消息耗时比较多，导致ANR，这里有个问题需要再说一下，就是这个慢是系统导致的还是应用导致的，需要对log进行分析，需要看对应进程是哪些，有没有一直有个相同的进程在执行，如果没有，该关键信息的log又很多说明是系统慢了，需要系统分析，否则需要找到对应的应用进行分析。
这节继续分析ANR实例，应用被杀导致发生ANR。
trace 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 ----- pid 2345 at 2024-10-23 08:45:43.412217011+0800 ----- Cmd line: com.android.launcher Build fingerprint: 'xxxP:user/release-keys' ABI: 'arm64' Build type: optimized Debug Store: 1,0,147313907:: suspend all histogram: Sum: 2.277s 99% C.I. 41.098us-8178.670us Avg: 207.926us Max: 286810us DALVIK THREADS (49): "main" prio=5 tid=1 Native | group="main" sCount=1 ucsCount=0 flags=1 obj=0x736e04e8 self=0xb4000070a163bc00 | sysTid=2345 nice=-10 cgrp=top-app sched=1073741824/0 handle=0x717220fd20 | state=S schedstat=( 1056220603424 322551092667 4737685 ) utm=74953 stm=30668 core=6 HZ=100 | stack=0x7fd4715000-0x7fd4717000 stackSize=8188KB | held mutexes= native: #00 pc 001038c8 /apex/com.android.runtime/lib64/bionic/libc.so (__epoll_pwait+8) (BuildId: eb5750ffe9638eea6135b04ae605dac0) native: #01 pc 00014190 /system/lib64/libutils.so (android::Looper::pollOnce+208) (BuildId: 14a48628be4734141a2c310fa9150ab7) native: #02 pc 0018dc2c /system/lib64/libandroid_runtime.so (android::android_os_MessageQueue_nativePollOnce+44) (BuildId: d8398afd4576c970ccaa10ad4a0fd877) at android.os.MessageQueue.nativePollOnce(Native method) at android.os.MessageQueue.next(MessageQueue.java:346) at android.os.Looper.loopOnce(Looper.java:189) at android.os.Looper.loop(Looper.java:350) at android.app.ActivityThread.main(ActivityThread.java:8849) at java.lang.reflect.Method.invoke(Native method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:617) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1002) DumpLatencyMs: 45.9705
该trace信息和之前一样，状态Native，堆栈信息也一样，等待消息
AnrManager看负载 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 41 42 43 44 45 46 47 48 49 50 51 52 53 10-23 08:45:43.409 1574 25926 I AnrManager: startAnrDump 10-23 08:45:43.410 1574 25926 I AnrManager: isANRFlowSkipped() AnrFlow = 0 10-23 08:45:43.410 1574 25926 I AnrManager: enableTraceLog: false 10-23 08:45:43.668 1574 25926 I AnrManager: dumpStackTraces end! 10-23 08:45:43.673 1574 25926 I AnrManager: ANR in com.android.launcher (com.android.launcher/.uioverrides.TclQuickstepLauncher), time=147313899 10-23 08:45:43.673 1574 25926 I AnrManager: Reason: Input dispatching timed out (Application does not have a focused window). 10-23 08:45:43.673 1574 25926 I AnrManager: Load: 0.0 / 0.0 / 0.0 10-23 08:45:43.673 1574 25926 I AnrManager: ----- Output from /proc/pressure/memory ----- 10-23 08:45:43.673 1574 25926 I AnrManager: some avg10=3.85 avg60=5.39 avg300=4.47 total=5837680153 10-23 08:45:43.673 1574 25926 I AnrManager: full avg10=2.35 avg60=3.65 avg300=2.98 total=4176270082 10-23 08:45:43.673 1574 25926 I AnrManager: ----- End output from /proc/pressure/memory ----- 10-23 08:45:43.673 1574 25926 I AnrManager: ----- Output from /proc/pressure/cpu ----- 10-23 08:45:43.673 1574 25926 I AnrManager: some avg10=11.59 avg60=13.36 avg300=14.21 total=21437012063 10-23 08:45:43.673 1574 25926 I AnrManager: full avg10=0.00 avg60=0.00 avg300=0.00 total=0 10-23 08:45:43.673 1574 25926 I AnrManager: ----- End output from /proc/pressure/cpu ----- 10-23 08:45:43.673 1574 25926 I AnrManager: ----- Output from /proc/pressure/io ----- 10-23 08:45:43.673 1574 25926 I AnrManager: some avg10=1.43 avg60=2.89 avg300=2.72 total=4282982033 10-23 08:45:43.673 1574 25926 I AnrManager: full avg10=0.35 avg60=1.27 avg300=1.15 total=2055582305 10-23 08:45:43.673 1574 25926 I AnrManager: ----- End output from /proc/pressure/io ----- 10-23 08:45:43.673 1574 25926 I AnrManager: 10-23 08:45:43.673 1574 25926 I AnrManager: Android time :[2024-10-23 08:45:43.66] [147314.156] 10-23 08:45:43.673 1574 25926 I AnrManager: CPU usage from 177371ms to -1ms ago (2024-10-23 08:42:46.033 to 2024-10-23 08:45:43.405): 10-23 08:45:43.673 1574 25926 I AnrManager: 35% 1574/system_server: 20% user + 14% kernel / faults: 318790 minor 23644 major 10-23 08:45:43.673 1574 25926 I AnrManager: 21% 844/surfaceflinger: 13% user + 8.1% kernel / faults: 45140 minor 791 major 10-23 08:45:43.673 1574 25926 I AnrManager: 15% 92/kswapd0: 0% user + 15% kernel 10-23 08:45:43.673 1574 25926 I AnrManager: 11% 1952/com.android.systemui: 6.7% user + 4.6% kernel / faults: 43368 minor 17073 major 10-23 08:45:43.673 1574 25926 I AnrManager: 6.8% 786/android.hardware.graphics.composer@3.1-service: 2.6% user + 4.2% kernel / faults: 1771 minor 367 major 10-23 08:45:43.673 1574 25926 I AnrManager: 6.3% 424/logd: 2.3% user + 4% kernel / faults: 86247 minor 14700 major 10-23 08:45:43.673 1574 25926 I AnrManager: 5.9% 12875/com.google.android.googlequicksearchbox:search: 3.9% user + 2% kernel / faults: 56188 minor 54758 major 10-23 08:45:43.673 1574 25926 I AnrManager: 3.6% 16496/com.google.android.gms.ui: 2.5% user + 1.1% kernel / faults: 49770 minor 14880 major 10-23 08:45:43.673 1574 25926 I AnrManager: 4.6% 14172/com.netease.hyxd: 3.3% user + 1.2% kernel / faults: 8198 minor 5201 major 10-23 08:45:43.673 1574 25926 I AnrManager: 3.7% 785/android.hardware.graphics.allocator@4.0-service-mediatek: 0.1% user + 3.6% kernel / faults: 989 minor 2073 major 10-23 08:45:43.673 1574 25926 I AnrManager: 3.1% 6501/logcat: 1% user + 2% kernel / faults: 33 minor 14 major 10-23 08:45:43.673 1574 25926 I AnrManager: 3.1% 2345/com.android.launcher: 2.1% user + 0.9% kernel / faults: 46505 minor 24876 major 10-23 08:45:43.673 1574 25926 I AnrManager: 2.7% 2558/com.google.android.inputmethod.latin: 1.6% user + 1.1% kernel / faults: 38031 minor 34007 major 10-23 08:45:43.673 1574 25926 I AnrManager: 2.7% 2675/com.google.android.gms.persistent: 1.3% user + 1.3% kernel / faults: 36679 minor 36716 major 10-23 08:45:43.673 1574 25926 I AnrManager: 2.4% 14197/com.google.android.webview:sandboxed_process0:org.chromium.content.app.SandboxedProcessService0:0: 1.9% user + 0.4% kernel / faults: 14867 minor 4850 major 10-23 08:45:43.673 1574 25926 I AnrManager: 1.8% 809/vendor.mediatek.hardware.mtkpower@1.0-service: 0.7% user + 1% kernel / faults: 16 minor 45 major 10-23 08:45:43.673 1574 25926 I AnrManager: 1.5% 825/audioserver: 0.9% user + 0.6% kernel / faults: 4012 minor 637 major 10-23 08:45:43.673 1574 25926 I AnrManager: 1.5% 28391/com.google.android.gms: 0.7% user + 0.8% kernel / faults: 12851 minor 11848 major 10-23 08:45:43.673 1574 25926 I AnrManager: 1.3% 184/tee_worker/3: 0% user + 1.3% kernel 10-23 08:45:43.673 1574 25926 I AnrManager: 1.2% 1912/com.guard: 0.3% user + 0.9% kernel / faults: 5880 minor 2251 major 10-23 08:45:43.673 1574 25926 I AnrManager: 1.1% 15802/com.google.android.gms.unstable: 0.8% user + 0.3% kernel / faults: 47992 minor 4435 major 10-23 08:45:43.673 1574 25926 I AnrManager: 1% 776/android.hardware.audio.service.mediatek: 0.5% user + 0.4% kernel / faults: 820 minor 256 major 10-23 08:45:43.673 1574 25926 I AnrManager: 0.9% 763/netd: 0.2% user + 0.7% kernel / faults: 14239 minor 26 major 10-23 08:45:43.673 1574 25926 I AnrManager: 0.9% 84/kcompactd0: 0% user + 0.9% kernel ... 10-23 08:45:43.673 1574 25926 I AnrManager: 34% TOTAL: 16% user + 14% kernel + 1.3% iowait + 1.7% irq + 0.3% softirq 10-23 08:45:43.673 1574 25926 I AnrManager: CPU usage from 147313899ms to 147313899ms ago (1970-01-01 08:00:00.000 to 1970-01-01 08:00:00.000) with 0% awake: 10-23 08:45:43.673 1574 25926 I AnrManager: 0% TOTAL: 0% user + 0% kernel 10-23 08:45:43.673 1574 25926 I AnrManager: dumpAnrDebugInfo end: AnrDumpRecord{ Input dispatching timed out (Application does not have a focused window). ProcessRecord{4a59bc5 2345:com.android.launcher/u0a78} IsCompleted:true IsCancelled:false }, onlyDumpSelf = false , isSilentANR = true 10-23 08:45:43.673 1574 25926 I AnrManager: addErrorToDropBox app = ProcessRecord{4a59bc5 2345:com.android.launcher/u0a78} processName = com.android.launcher activityShortComponentName = com.android.launcher/.uioverrides.TclQuickstepLauncher parentShortComponentName = com.android.launcher/.uioverrides.TclQuickstepLauncher parentProcess = ProcessRecord{4a59bc5 2345:com.android.launcher/u0a78} annotation = Input dispatching timed out (Application does not have a focused window). mTracesFile = /data/anr/anr_2024-10-23-08-45-43-430 10-23 08:45:43.674 1574 25926 I AnrManager: controller = android.app.IActivityController$Stub$Proxy@12b0d67
从平均值或者总的负载看都不高，都在正常水平，说明负载没有问题。
这时我们需要看event log，看看ANR之前的最后一个input_focus是什么状态，是进入还是退出进入其他应用。
Event Log 1 2 3 4 10-23 08:45:37.990 1574 1777 I input_focus: [Focus leaving 36825b com.android.launcher/com.android.launcher.uioverrides.TclQuickstepLauncher (server),reason=NO_WINDOW] 10-23 08:45:38.050 1574 1658 I am_proc_start: [0,25903,10082,com.camera,preload application,{com.camera/com.android.camera.CameraLauncher}] 10-23 08:45:38.102 1574 1628 I am_kill : [0,25903,com.camera,-10000,perf_policy kill by empty process,20928] 10-23 08:45:43.405 1574 25926 I am_anr : [0,2345,com.android.launcher,751550021,Input dispatching timed out (Application does not have a focused window).]
这个是我过滤出来的信息，最后一个input_focus是离开Launcher，说明要进入另外一个应用，那么从下面log看到am_proc_start，正在启动camera，紧接着am_kill，camera被杀，后面有被杀原因-kil by empty process，此时时间是45:38，后面5s后发生ANR，ANR原因是Application does not have a focused window，报到Launcher应用中。
正常情况是camera启动，Launcher焦点切换到camera应用窗口上，但是camera被杀了，因此没有一个焦点窗口取承接这个焦点，焦点丢失了，因此出现ANR。
因此下一步就要去分析为什么Camera启动过程中被杀了，来解决这个问题。
