Android異常分析(轉)

 

關於異常

異常?

異常就是一種程序中沒有預料到的問題，既然是沒有預料到的，就可能不在原有邏輯處理範圍內,脫離了代碼控制,軟件可能會出現各類奇怪的現象。好比：android系統常見異常現象有應用無響應、應用中止運行、凍屏、重啓、死機等，這些異常系統有統一的異常處理機制，出現異常系統就會執行相應的操做，最終有相應的現象體現出來。另外，一些不在預料之中的界面顯示問題，操做問題，運行卡頓問題等也能夠歸於異常，只不過這種異常是人爲邏輯缺陷，對系統來講是正常的，但這些缺陷在異常現象中佔比卻至關大，直接體現出軟件的質量。

架構決定邏輯,邏輯決定異常多少

異常重要性

都說ISO比android系統好，iphone手機比android手機好，爲何呢？其實最基本緣由就是ISO系統穩定性和體驗作得好，不多出現異常，使用一段時間後運行仍是很穩健，且它的界面、操做、運行速度等體驗也作的很是好，因此才被你們承認。

異常關係一個軟件的穩定性

缺陷關係一個軟件的性能和體驗

打造精品，追求卓越，對軟件開發人員來講就是追求零異常、零缺陷。咱們作的軟件，負責的模塊應用質量怎麼樣，是否是精品都是經過異常數量和缺陷數量來體現的。這篇文檔主要講的是log分析，屬於過後處理，處理的是用戶的抱怨和不滿，處理的是咱們開發時埋下的雷或未挖掘出的雷，是被動的。因此，更重要的是軟件量產前開發工做中，怎樣去減小異常和缺陷，保證軟件質量。

(公司戰略,對研發部門要求)

異常分類

Android是一個龐大而複雜的系統，涉及多種語言，因此其異常也很複雜。根據android系統架構層次，咱們也把android異常層次化，分爲JE、NE、KE、EE、其餘類別

l JE (Java layer exception) 通常是在應用層和框架層發生的異常，一般是由Java代碼，XML代碼引發的。好比各類RuntimeException, ANR（Application Not Responding）、SWT（Software Watchdog Timeout）等

l NE (Native layer exception) 發生在Linux用戶空間的異常，一般是由C/C++代碼和庫文件引發的。好比內核發出的NE信號（SIGILL、 SIGABRT、 SIGBUS等）

l KE (Kernel layer execption) 一般指內核故障或內核錯誤，因爲在內核模式下出錯，這類異常是很是嚴重的，每每會致使重啓、死機或沒法開機等

l EE (External (Modem) exception) 從名字看就能猜到Modem這一部分是比較特殊的，獨立的。Modem有本身的內存空間和代碼，爲手機通信提供服務，一旦這一部分發生異常，須要MDlog，此log需用AEE-LogVie工具解析，解析是須要對應版本的數據文件，具體使用可參考《GAT_User_Guide(Customer).pdf》文檔

l 其餘 除了以上類型外，還有些異常可能沒有明顯的類別，例如一些由硬件引發的異常

Android系統架構圖

異常復現和日誌打印

異常復現

解決異常的關鍵之一就是復現異常。好比，對於偶現異常，若是能要找到必現路徑，那問題就變得容易多了。解決異常問題首先要了解異常，清楚異常怎麼發生的，什麼條件下發生的。下面是異常復現須要注意的地方。

異常復現注意點：

l 仔細閱讀異常描述，弄清楚異常產生步驟、異常機率、異常預置條件，並預判屬於哪一類異常

l 復現前，確認是否打LOG，若是是偶現問題，務必開啓此異常類型須要LOG

l 根據描述復現異常，若是是偶現問題，注意條件，儘可能找出異常必現路徑

l 若是沒有復現異常，和異常信息提供人溝通，再次復現

客戶報的異常多是正常的

日誌打印

解決異常的關鍵之二就是抓取有效的LOG。好比，ANR異常必須抓取bugreport或trace.txt文件，NE異常必須抓取aee_exp， EE異常必須抓取MDLog。根據不一樣異常類型抓取不一樣LOG，有針對性的分析。下面是異常日誌打印須要注意的地方。

一份錯誤的LOG是分析問題的, 發生了異常,沒有抓到正確的LOG, 就可能浪費掉一次補救機會

異常打印注意點：

l 抓LOG前，清除SD卡和內部存儲裏原有的LOG文件，減小沒必要要的LOG帶來的分析困擾

l 抓log前，設置好異常產生的預置條件，特別是須要對比的異常，確保預置條件同樣

l 根據異常類型，打開必須的LOG。任何異常，mtklog都是必要的，重啓、死機異常，儘可能多抓LOG

l 抓LOG後，記錄下異常出現的手機顯示時間，必要時截圖，連同異常描述一塊兒備註在log裏

異常分析之ANR

ANR種類

l Key Dispatch Timeout (8s)

No response to an input event(e.g. key press, screen touch) within 8 seconds

l Broadcast Timeout

A BroadcastReceiver hasn’t finished executing within setting seconds

BROADCAST_FG_TIMEOUT: 10s

BROADCAST_BG_TIMEOUT: 60s

l Service Timeout （20s）

Request service failed within 20 seconds

按鍵或廣播等事件在特定時間內未響應，這裏特定時間在系統裏設定的，各平臺可能不同，上面的時間是KK平臺默認超時時間，通常定義在ActivityManagerService.java類中，如：

static final int KEY_DISPATCHING_TIMEOUT = 5*1000

ANR產生緣由

l 應用進程有一個主線程（main thread）和一個信息隊列(main message queue)main thead == activity thread

l 主線程負責處理像Draw、Listen、receive等UI事件

l 主線程負責從消息隊列中取出信息並分發它

l 主線程在完成當前信息處理以前，不會再取信息隊列中的信息

l 若是主線程在處理當前信息時卡住，沒有及時分發，ANR就會出現

如何避免ANR

l UI線程儘可能只作跟UI相關的工做

l 耗時的工做（好比數據庫操做，I/O，鏈接網絡或者別的有可能阻礙UI線程的操做）把它放入單獨的線程處理

l 儘可能用Handler來處理UI thread和別的thread之間的交互

ANR分析須要的LOG

l MTKlog，主要是其中的Aee_exp和MobileLog

l Trace.txt文件（data/anr目錄下）或者bugreport日誌（使用adb bugreport > bugreport.txt或者GAT工具輸出）

ANR分析流程

因爲ANR類型多，觸發ANR的條件也多，且LOG中沒有像RuntimeException異常那樣有明顯的關鍵字Fatal來準肯定位問題點，因此，ANR分析相對比較麻煩點，可是隻要有完整的LOG，按照方法去分析仍是很快的。下圖是MTK分析ANR的流程圖，經過ANR觸發類型一步一步查找排除

MTK分析ANR的流程圖

l 首先，檢查log中是否有ANR信息

events_log

00:28:19.999 544 564 I am_anr : [0,3003,com.example.test,11058758,keyDispatchingTimedOut]

main_log 或 Sys_log

00:28:31.193 544 564 E ANRManager: ANR in com.example.test (com.example.test/.MainActivity)

traces.txt

----- pid 3003 at 2013-06-01 00:28:20 -----

Cmd line: com.example.test

JNI: CheckJNI is off; workarounds are off; pins=0; globals=147

DALVIK THREADS:

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

"main" prio=5 tid=1 SUSPENDED

| group="main" sCount=1 dsCount=0 obj=0x40d5ea18 self=0x40d4e0d8

| sysTid=3003 nice=0 sched=0/0 cgrp=apps handle=1074645084

| state=S schedstat=( 16757266877 27764681051 104147 ) utm=1184 stm=491 core=0

#00 pc 0002746c /system/lib/libc.so (__futex_syscall3+8)

#01 pc 0000f694 /system/lib/libc.so (__pthread_cond_timedwait_relative+48)

………

#12 pc 00020580 [stack]

at libcore.io.Posix.strerror(Native Method)

at libcore.io.ForwardingOs.strerror(ForwardingOs.java:128)

at libcore.io.ErrnoException.getMessage(ErrnoException.java:52)

at java.lang.Throwable.getLocalizedMessage(Throwable.java:187)

at java.lang.Throwable.toString(Throwable.java:361)

at java.lang.Throwable.printStackTrace(Throwable.java:321)

at java.lang.Throwable.printStackTrace(Throwable.java:355)

at java.lang.Throwable.printStackTrace(Throwable.java:288)

at java.lang.Throwable.printStackTrace(Throwable.java:236)

at com.example.test.MainActivity.monitorANR(MainActivity.java:200)

at com.example.test.MainActivity$1.handleMessage(MainActivity.java:38)

at android.os.Handler.dispatchMessage(Handler.java:107)

at android.os.Looper.loop(Looper.java:194)

l 若是定位不到信息點，再看看CUP使用狀況

main_log

06-01 00:28:31.193 544 564 E ANRManager: ANR in com.example.test (com.example.test/.MainActivity)

06-01 00:28:31.193 544 564 E ANRManager: Reason: keyDispatchingTimedOut

06-01 00:28:31.193 544 564 E ANRManager: Load: 10.5 / 11.94 / 6.06

06-01 00:28:31.193 544 564 E ANRManager: Android time :[2013-06-01 00:28:31.176] [454.712]

06-01 00:28:31.193 544 564 E ANRManager: CPU usage from 0ms to 11736ms later:

06-01 00:28:31.193 544 564 E ANRManager: 34% 3003/com.example.test: 26% user + 8.4% kernel / faults: 708 minor 10 major

06-01 00:28:31.193 544 564 E ANRManager: 32% 3018/logcat: 10% user + 21% kernel / faults: 4143 minor

06-01 00:28:31.193 544 564 E ANRManager: 23% 379/mobile_log_d: 8.7% user + 14% kernel / faults: 10 minor 1 major

06-01 00:28:31.193 544 564 E ANRManager: 19% 171/adbd: 1.7% user + 17% kernel / faults: 423 minor

06-01 00:28:31.193 544 564 E ANRManager: 18% 544/system_server: 8.5% user + 9.8% kernel / faults: 899 minor 2 major

06-01 00:28:31.193 544 564 E ANRManager: 14% 132/mobile_log_d: 1.7% user + 13% kernel

……

06-01 00:28:31.193 544 564 E ANRManager: 96% TOTAL: 36% user + 60% kernel + 0% iowait

從CPU使用率能夠看出

若是CPU使用量接近100%，說明當前設備很忙(內存不足，循環處理等)

若是CPU使用量不多，說明主線程被BLOCK了（Activity超過5秒等）

若是IOwait很高，說明ANR有多是主線程在進行I/O操做形成的（數據庫操做、文件操做、網絡操做等）

l 根據CPU使用狀況，在main_log和event_log中查找有用信息

main_log

l 結合log看代碼，找到緣由

爲了讓ANR出現,在onClick裏面用了while(true),不斷的文件讀寫，報錯不斷打印（不要這樣打log）

等待鎖引發的ANR

l events_log

22:05:22.819934 732 755 I am_anr : [0,24992,com.example.test,8961606,Input dispatching timed out (Waiting because the touched window has not finished processing the input events that were previously delivered to it.)

l main_log或 Sys_log

01-01 22:05:22.857387 732 755 E ANRManager: ANR in com.example.test (com.example.test/.MainActivity)

01-01 22:05:22.857387 732 755 E ANRManager: Reason: Input dispatching timed out (Waiting because the touched window has not finished processing the input events that were previously delivered to it.)

l traces.txt

----- pid 29364 at 2014-01-01 22:05:22 ----- Cmd line: com.example.test

JNI: CheckJNI is off; workarounds are off; pins=0; globals=263

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

"main" prio=5 tid=1 MONITOR | group="main" sCount=1 dsCount=0 obj=0x419cede0 self=0x419bd8a8

| sysTid=29364 nice=0 sched=0/0 cgrp=apps handle=1074139524

| state=S schedstat=( 265882702 297191749 665 ) utm=19 stm=7 core=0

at com.example.test.MainActivity$ANRBroadcast.onReceive(MainActivity.java:~120)

- waiting to lock <0x41edc968> (a java.lang.Object) held by tid=11 (Thread-720) at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:798) at android.os.Handler.handleCallback(Handler.java:808)

l 對應代碼

異常分析之OOM

OOM產生緣由

Android應用內存管理機制是在Java內存管理機制基礎上改進的，因此形成OOM的緣由二者差很少，即全部對象都在堆上分配空間，堆是有大小限制的，當分配的對象不能被回收仍然佔據堆空間，新分配的對象不能獲取足夠的堆空間時，就會OOM。爲何會這樣呢？這就是GC不足的地方，GC只能回收本身記錄（有向樹）裏面不可達的對象，對可達對象認爲是有用的，不會被回收。可是可達對象並不是必定是有用對象，他們多是廢棄對象（死對象、冗餘對象、電燈泡，殭屍），但卻沒法被GC回收，佔據着進程堆空間，下面是網上的一個對象實例化簡圖

各類OOM情景

l 資源對象沒有回收，如cursor，bitmap等

一般關閉Cursor的方法：

Cursor cursor = mDownloadManager.query(new Query());

try {

if (cursor.moveToFirst()) {

do {

int index = cursor.getColumnIndex(DownloadManager.COLUMN_ID);

long downloadId = cursor.getLong(index);

ids.add(downloadId);

} while (cursor.moveToNext());

}

} finally {

cursor.close();

}

另外，在adapter中使用cursor時，需在cursor改變的時候先關閉原來的cursor， 但一般咱們都是用android提供的CursorAdapter，其changeCursor函數會將原來的Cursor釋放掉，並替換爲新的Cursor，因此你不用擔憂原來的Cursor沒有被關閉。

l 註冊沒有對應的去註冊，如各類監聽

l 生命週期問題引發的沒法回收，若是static、線程等

l 其餘

全部發生OOM情景最終均可以認爲是對象沒有被回收，如，cursor沒有close()，bitmap沒有recycle()，監聽沒有unregister…()等等都是由於對象沒有被回收，GC認爲這些對象是可達的、正在使用的，致使這些應該被回收的對象不能被回收，最終形成OOM。

大多數的回收方法，如close()、recycle()、unregister…()，其實都是把再也不使用的對象置爲null，這樣GC就能回收原來對象所佔空間。因此在編程的時候，對全局變量，特別是容器之類的對象和status 修飾對象，要關注其生命週期，再也不須要就及時置爲null或調用相應的回收方法

OOM LOG分析

發生OOM異常後，若是僅僅只有mtklog，只能從Log中知道發生了OOM，但怎麼發生的卻看不出來，因此一般須要OOM分析工具，下面以MAT工具爲例

在eclipse中，監視你須要分析OOM的進程，某種規律下，發現進程內存一直在漲，抓取hprof文件：

這裏的某種規律，是指某種操做下，不斷重複就會出現OOM。常常致使OOM的操做有來回切換界面、回來滑動list、不斷的點擊某個按鈕等，這些操做都是不斷更新界面，不斷的生產對象，生產的對象致使堆空間愈來愈大，最終發生OOM

DDMS dump 出來的hprof文件須要通過SDK下hprof-conv（位於sdk/tools下）轉換後才能被MAT工具使用

hprof-conv xxx.hprof d:/xxxold.hprof

而後使用MAT工具打開

1. Cache泄漏

屢次插拔耳機後，發現內存一直在漲：

點擊Details進入下面頁面：

點擊Patch To GC Root：

發現一個靜態變量 sAnimators，此爲懷疑的地方，查看代碼，加點log，編譯調試：

Log.d("CWW", "sAnimators.size() = " + sAnimators.size());

能夠看出，插拔耳機操做後，sAnimators.size一直會增大。

處理方法：防止緩存過大，能夠設置上限，也能夠按期清理下！

對內存敏感的應用，防止緩存過大，除了設置上限外，同時使用SoftReference，當內存吃緊時能夠回收緩存，這預防編程的一個技巧，可是使用SoftReference時，注意對null狀況的處理，由於獲取對象可能已經被回收，獲取返回就null

2. 線程未釋放致使的泄漏

後臺播放音樂，不停切換主題，最後Launcher OOM

以下圖，5個AppsCustomizePagedView實例，明顯泄漏了：

點擊，選中一個實例，Path To GC Roots：

已經看到被CircleProgress.java的MyTimerTask持有：

再看代碼，修改後，調試內存，正常：

這樣改內存泄露解決了, 可是後面引入了新的功能問題, 從新修改了。因此修改相似問題時多當心，確認生命週期已經完成後再執行回收

結束語：

這些問題大可能是比較難解的問題，大部分都是隨機的，每每都是很難復現的，找出規律是很重要的！

另外，內存泄露不容易發現，一些輕微的泄露，可能要使用一個月才能發現，因此對本身的模塊，要本身去檢查有沒有OOM，能夠下班時掛上monkey，有時候是能跑出來的

從OOM聯想到性能問題，性能問題不少是界面刷新、對象生命週期、冗餘操做、沒必要要的線程等引發的……

異常分析之SWT

認識SWT

SWT是指Android Watchdog Timeout，應用層看門狗超時，一般咱們說的WDT（Watchdog Timeout）是HWT，硬件看門狗超時。應用層Watchdog主要實現是在frameworks/base/services/java/com/android/server/Watchdog.java裏，其實現原理看看這個類就知道，主要邏輯是：

1. Watchdog是單例模式，監控系統幾個比較重要的Service，如：MountService、ActivityManagerService、InputManagerService等，這些Service在啓動時經過調用Watchdog.getInstance().addMonitor(this); 加入到Watchdog的監控列表中

2. 在SystemServer的 ServerThread線程中，初始化watchdog並啓動它

3. Watchdog線程向ServerThread線程發送一個MONITOR message，同時將mCompleted標誌位置爲false

4. 而後Watchdog線程Sleep 60秒(不包含系統睡眠的時間)，若是mCompleted標誌位不爲true，則認爲發生watchdog超時，以後Android就會重啓.

5. ServerThread收到這個消息後會依次執行以前每一個Service Object的monitor()函數，當執行完後會將mCompleted標誌位置爲true.

SWT LOG分析

SWT也是一種ANR，普通ANR是某個AP的主線程在一段時間內沒有作完某件事情；SWT是SystemServer進程的ServerThread線程在一段時間內沒有作完某件事情。因此SWT的分析方法和ANR分析方法是同樣的，只是現象不同，發生SWT手機會重啓

分析方法：

1. 從eventlog中以watchdog爲關鍵字搜索，記錄下這個時刻。

2. 而後分析全部Service Object的monitor()爲什麼在這個時刻以前1分鐘內沒有作完。具體信息主要查找log文件有sys_log和mtklog\aee_exp\db.fatal.00.SWT\db.fatal.00.SWT.dbg.DEC

3. 後面具體的分析方法和ANR同樣

重啓死機

重啓

從異常分類來看，重啓異常大多數和NE、KE和硬件問題有關，JE方面引發重啓死機大可能是和系統進程有關，如system_process進程發生了Crash、SWT、JVM Error，AP應用通常是不會引發重啓死機的，但偶爾也會

72平臺上，發送短信內容爲‘==’時會重啓

雖然是Mms引發的，但最終也是System_process掛掉了，致使重啓

重啓異常分析步驟（JE）：

1. 確認異常類型（用QAAT跑一下作初步判斷，若是是NE、KE讓驅動人員幫忙解決）

2. 找到第一時間發生錯誤的地方，由於後面的錯誤多半是由於前面錯誤引發的，那就沒有意義

3. 根據JE類型，結合對應工具分析LOG

死機

這裏說的死機就是凍屏，停留在一個界面沒反應。死機問題不多遇到，且大多不是一個用層問題，下面簡單說下可能形成死機的緣由和分析須要信息

死機可能緣由：

1. 輸入系統或者輸入驅動問題

2. 系統邏輯問題或阻塞

3. Surfacefinger問題

4. 顯示系統或LCM驅動問題

相關信息和抓log：

1. 確認adb是否可用

2. 抓取bugreport，adb bugreport > d:/bugreport.txt

3. 抓取dumpstate信息，adb shell dumpstate > d:/dumpstate.txt

4. 抓取CPU信息，adb shell top –t –m 5 > d:/cpu.txt

5. 確認是否能夠撥打電話，adb shell am start –a android.intent.action.CALL tel:10086(看界面是否可以更新)

6. 查看按鍵和觸屏報點，adb shell getevent

7. 抓取Surfacefinger進程信息，先adb shell ps –p找出pid，而後使用adb shell rtt –f bt –p pid > rtt.txt

LOG相關工具

MTK提供了多種抓取和查看LOG的工具, 如:mtklogger，GAT，Catcher，LogView，QAAT等，這些工具在文檔《MediaTek_Logging_SOP.pdf》中都有描述

Mtklogger:

Mtklogger是抓取log的apk，整合了ModemLog，MobileLog，NetworkLog and SystemLogger，在工程模式操做就能夠打相關log了。

GAT：

基於SDK調試開發的GUI工具，新增了Log Recoder，Debug Configuration Setting，DBpuller，adb command，Process Information view，Profiling Tools，LogView，Plug-in Script。是調試和抓log的神器，使用說明閱讀文檔《GAT_User_Guide(Customer).pdf》

工具獲取路徑（以W1444版本爲例）：

\\192.168.1.75\rd\MTK_TOOL\AndroidTool\W1444\W1444_full.zip\Debugging Tools (Binary)\GAT

Catcher：

是抓取和解析ModemLog的PC端工具，咱們常用來查看ModemLog，使用說明閱讀文檔《Catcher_User_Manual_for_Customer.pdf》

工具獲取路徑：

\\192.168.1.75\rd\MTK_TOOL\AndroidTool\W1444\W1444_full.zip\Catcher

LogView：

能夠查看APlog，Taglog，MTKlog，但最經常使用的是用來查看NE時產生的AEE DB文件裏的log，具體使用參考《GAT_User_Guide(Customer).pdf》

工具獲取路徑：

此工具已集成到GAT

QAAT：

快速分析log的工具，涵蓋錯誤類型較廣，不少地方均可以用，其實他的原理就是過濾關鍵字，把各類類型的錯誤過濾出來，是一個分析LOG很是便捷的工具，具體使用參考《MediaTek_Logging_SOP.pdf》

工具獲取路徑：

附件或者\\192.168.1.75\rd\MTK_TOOL\AndroidTool