MF99 coding 💻

keep learning; keep coding;

Android ANR 的 debug 方法

android android app dev tips

在做 Android Application 或是整合 system 的時候，常常會遇到的兩種問題就是 Crash 跟 ANR （Application-No-Response） Crash 通常很好解，只要透過 logcat 並尋找 AndroidRuntime 這個tag 就可以看到明確 crash 的 call stack，並找出發生 Exception 的位置。

另外一種則是 ANR，基本上發生的原因為程式的主執行緒（main thread 或是 UI thread）執行到某個地方，但是太久沒反應，導致使用者的Input event （touch / key event）太久都沒有反應 (通常是15秒～30秒左右)，系統就會跳出一個視窗問你是要繼續等，還是就 Kill 這個 process。

f:id:mouseface99:20191129171450p:plain

基本上網路上已經很多地方有在建議如何避免 ANR 的發生，但是有時候還是好死不死會遇到，或是說系統開發商有時候在Porting 的時候也會遇到，這時候就要想辦法來 trace 到底是哪個 function 做太久導致 ANR。

這邊可以在軟體發生ANR的當下利用 adb shell dumpstate 這個指令，把系統的狀態全部 dump 出來，出來的資料很多，這時候就要尋找關鍵字 Cmd line: xxx.xxx.xxx 其中 xxx.xxx.xxx 就是當下發生 ANR 軟體的 package name。

這時候裡面的資訊大概長這樣

...
----- pid 10780 at 2000-01-01 22:07:35 ----- 
Cmd line: com.sample.test

JNI: CheckJNI is off; workarounds are off; pins=0; globals=167 (plus 6 weak)

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4196d578 self=0x41958190
  | sysTid=10780 nice=0 sched=0/0 cgrp=apps/bg_non_interactive handle=1074196476
  | state=S schedstat=( 317946852 828179162 1473 ) utm=18 stm=13 core=0
  #00  pc 0001c3fc  /system/lib/libc.so (epoll_wait+12)
  #01  pc 00014f15  /system/lib/libutils.so (android::Looper::pollInner(int)+92)
 at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:132)
  at android.os.Looper.loop(Looper.java:124)
  at android.app.ActivityThread.main(ActivityThread.java:5103)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:525)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553)
  at dalvik.system.NativeStart.main(Native Method)
...

從 DALVIK THREADS 這邊以下會把這個 process 目前有的 Thread 狀態全部 dump 出來，所以第一步就是要找到 main thread，也就是這個 "main" prio=5 tid=1 NATIVE 接著下面會先 print 出一些相關的參數以及使用的 native library，然後再來就是 Java 的 call stack 了！

at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:132)
  at android.os.Looper.loop(Looper.java:124)
  at android.app.ActivityThread.main(ActivityThread.java:5103)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:525)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553)
  at dalvik.system.NativeStart.main(Native Method)

從這裡就可以看出目前 com.sample.test 這支 app 的 main thread 是停在 android.os.MessageQueue.nativePollOnce(Native Method) (這個是 Activity 正常的狀態，並不是 ANR) 如果是發生在 ANR 的話，就可能看到 call stack 會停在比方說 loadImage(...) 或是 read() 之類的 IO 相關動作。 這時候就可以針對這個 function 的內容來縮小 debug 的範圍了！

這邊雖然無法 trace native code 的 call stack，但是至少比要在 App 裡面打了一大堆 log 然後才發現是停在哪邊... 至少在 ANR 發生的當下就可以縮小範圍到某支特定的 Java 檔以及某個 function。