1. 程式人生 > >Android ANR Log分析

Android ANR Log分析

1)什麼引發了ANR?

在Android裡,應用程式的響應性是由Activity Manager和WindowManager系統服務監視的。當它監測到以下情況中的一個時,Android就會針對特定的應用程式顯示ANR:

在5秒內沒有響應輸入的事件(例如,按鍵按下,螢幕觸控)
BroadcastReceiver在10秒內沒有執行完畢

一個ANR對話方塊顯示給使用者

2)如何避免ANR?

考慮上面的ANR定義,讓我們來研究一下為什麼它會在Android應用程式裡發生和如何最佳構建應用程式來避免ANR。

Android應用程式通常是執行在一個單獨的執行緒(例如,main)裡。這意味著你的應用程式所做的事情如果在主執行緒裡佔用了太長的時間的話,就會引發ANR對話方塊,因為你的應用程式並沒有給自己機會來處理輸入事件或者Intent廣播。


因此,執行在主執行緒裡的任何方法都儘可能少做事情。特別是,Activity應該在它的關鍵生命週期方法(如onCreate()和onResume())裡儘可能少的去做建立操作。潛在的耗時操作,例如網路或資料庫操作,或者高耗時的計算如改變點陣圖尺寸,應該在子執行緒裡(或者以資料庫操作為例,通過非同步請求的方式)來完成。然而,不是說你的主執行緒阻塞在那裡等待子執行緒的完成——也不是呼叫Thread.wait()或是Thread.sleep()。替代的方法是,主執行緒應該為子執行緒提供一個Handler,以便完成時能夠提交給主執行緒。以這種方式設計你的應用程式,將能保證你的主執行緒保持對輸入的響應性並能避免由於5秒輸入事件的超時引發的ANR對話方塊。這種做法應該在其它顯示UI的執行緒裡效仿,因為它們都受相同的超時影響。

IntentReceiver執行時間的特殊限制意味著它應該做:在後臺裡做小的、瑣碎的工作如儲存設定或者註冊一個Notification。和在主執行緒裡呼叫的其它方法一樣,應用程式應該避免在BroadcastReceiver裡做耗時的操作或計算。但不再是在子執行緒裡做這些任務(因為BroadcastReceiver的生命週期短),替代的是,如果響應Intent廣播需要執行一個耗時的動作的話,應用程式應該啟動一個Service。順便提及一句,你也應該避免在IntentReceiver裡啟動一個Activity,因為它會建立一個新的畫面,並從當前使用者正在執行的程式上搶奪焦點。如果你的應用程式在響應Intent廣播時需要向用戶展示什麼,你應該使用Notification Manager來實現。


3)增強響應靈敏性

一般來說,在應用程式裡,100到200ms是使用者能感知阻滯的時間閾值。因此,這裡有一些額外的技巧來避免ANR,並有助於讓你的應用程式看起來有響應性。


如果你的應用程式為響應使用者輸入正在後臺工作的話,可以顯示工作的進度(ProgressBar和ProgressDialog對這種情況來說很有用)。
特別是遊戲,在子執行緒裡做移動的計算。
如果你的應用程式有一個耗時的初始化過程的話,考慮可以顯示一個SplashScreen或者快速顯示主畫面並非同步來填充這些資訊。在這兩種情況下,你都應該顯示正在進行的進度,以免使用者認為應用程式被凍結了。

15:59:37 I/ActivityManager(130): ANR in process: com.android.email(last in com.android.email)

=>frameworks\base\services\java\com\android\server\am\ActivityManagerService.java
=>提示輸出cpu資訊
Annotation: keyDispatchingTimedOut
CPU usage:

=>frameworks\base\services\java\com\android\server\ProcessStats.java
=>輸出cpu當前狀態
=>/proc/loadavg 顯示cpu負荷
=>1-分鐘平均負載 / 5-分鐘平均負載 / 15-分鐘平均負載
Load: 4.37 /4.55 / 3.97
=>cpu狀態的時間段
CPU usage from 10987ms to 27ms ago:
  =>/proc/state讀取cpu的使用情況
 =>http://linux.die.net/man/5/proc
  =>user
  =>kernel
  =>iowait
  =>irq ->0
  =>softirq ->0
  =>minor
  The number of minor faults the process has madewhich have not required loading a memory page fromdisk. 
  =>major
  The number of major faults the process has madewhich have required loading a memory page from disk.   system_server: 12% = 4% user + 7% kernel /faults: 1886 minor
  m.android.email: 12% = 6% user + 5% kernel /faults: 2716 minor
  sensorserver_ya: 7% = 0% user + 7%kernel
  breeze.launcher: 3% = 0% user + 3% kernel /faults: 94 minor
  ocess.msn.shell: 0% = 0% user + 0% kernel /faults: 38 minor
  m.android.phone: 0% = 0% user + 0%kernel
  alog: 0% = 0% user + 0% kernel
  rpcrotuer_smd_x: 0% = 0% user + 0%kernel
  rild: 0% = 0% user + 0% kernel
  alog: 0% = 0% user + 0% kernel
  events/0: 0% = 0% user + 0% kernel
  port-bridge: 0% = 0% user + 0% kernel
TOTAL: 81% = 13% user + 25% kernel + 42% iowait

15:59:37 I/ActivityManager(130): Removing old ANR trace file from/data/anr/traces.txt

Android ANR這個錯誤大家並不陌生,但是從Android2.2開始出錯的ANR資訊會自動上傳給Google進行系統分析改進,當然了你的應用ANR錯誤其實儲存在一個檔案中,在/data/anr/traces.txt檔案中.
下面一起來分析下錯誤吧,第一行為出錯的時間,第二行都會寫上發生ANR的packageName,下文是com.android.systemui這個包,裡面的部分執行緒出了問題,通過下面的的xxx方法以及對應的java檔案,後面的數字為xxx.java檔案的第幾行,是不是很方便呢?

----- pid 125 at 2011-02-22 05:18:01 -----
Cmd line: com.android.systemui

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4001f1a8self=0xce48
  | sysTid=125 nice=0 sched=0/0 cgrp=defaulthandle=-1345006528
  | schedstat=( 981213067 8042604425 151 )
  at android.os.BinderProxy.transact(NativeMethod)
  atandroid.os.storage.IMountService$Stub$Proxy.isUsbMassStorageConnected(IMountService.java:95)
  atandroid.os.storage.StorageManager.isUsbMassStorageConnected(StorageManager.java:385)
  atcom.android.systemui.usb.StorageNotification.<init>(StorageNotification.java:71)
  atcom.android.systemui.statusbar.policy.StatusBarPolicy.<init>(StatusBarPolicy.java:412)
  atcom.android.systemui.statusbar.StatusBarService.onCreate(StatusBarService.java:239)
  atandroid.app.ActivityThread.handleCreateService(ActivityThread.java:1920)
  atandroid.app.ActivityThread.access$2500(ActivityThread.java:117)
  atandroid.app.ActivityThread$H.handleMessage(ActivityThread.java:982)
  atandroid.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:123)
  atandroid.app.ActivityThread.main(ActivityThread.java:3647)
  at java.lang.reflect.Method.invokeNative(NativeMethod)
  atjava.lang.reflect.Method.invoke(Method.java:507)
  atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:839)
  atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:597)
  at dalvik.system.NativeStart.main(NativeMethod)

"Binder Thread #2" prio=5 tid=8 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x40511270self=0x1c1100
  | sysTid=153 nice=0 sched=0/0 cgrp=defaulthandle=1141608
  | schedstat=( 27181321 64708345 5 )
  at dalvik.system.NativeStart.run(NativeMethod)

"Binder Thread #1" prio=5 tid=7 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x405111a8self=0x1349c8
  | sysTid=152 nice=0 sched=0/0 cgrp=defaulthandle=1264008
  | schedstat=( 31857510 74284459 5 )
  at dalvik.system.NativeStart.run(NativeMethod)

"Compiler" daemon prio=5 tid=6 VMWAIT
  | group="system" sCount=1 dsCount=0obj=0x4050dd10 self=0x116538
  | sysTid=144 nice=0 sched=0/0 cgrp=defaulthandle=982520
  | schedstat=( 7319346 103454345 12 )
  at dalvik.system.NativeStart.run(NativeMethod)

"JDWP" daemon prio=5 tid=5 VMWAIT
  | group="system" sCount=1 dsCount=0obj=0x4050dc60 self=0x116400
  | sysTid=142 nice=0 sched=0/0 cgrp=defaulthandle=986536
  | schedstat=( 32876840 393298925 20 )
  at dalvik.system.NativeStart.run(NativeMethod)

"Signal Catcher" daemon prio=5 tid=4 RUNNABLE
  | group="system" sCount=0 dsCount=0obj=0x4050dba0 self=0x253ab0
  | sysTid=141 nice=0 sched=0/0 cgrp=defaulthandle=2439792
  | schedstat=( 94447996 796994478 19 )
  at dalvik.system.NativeStart.run(NativeMethod)

"GC" daemon prio=5 tid=3 VMWAIT
  | group="system" sCount=1 dsCount=0obj=0x4050daf8 self=0x8fd40
  | sysTid=128 nice=0 sched=0/0 cgrp=defaulthandle=2439592
  | schedstat=( 103352102 819201761 21 )
  at dalvik.system.NativeStart.run(NativeMethod)

"HeapWorker" daemon prio=5 tid=2 VMWAIT
  | group="system" sCount=1 dsCount=0obj=0x4050da40 self=0xf0c70
  | sysTid=127 nice=0 sched=0/0 cgrp=defaulthandle=2439528
  | schedstat=( 971134410 6445300652 103 )
  at dalvik.system.NativeStart.run(NativeMethod)