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 其他 除了以上類型外,還有些異常可能沒有明顯的類別,例如一些由硬件引起的異常

clip_image002

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觸發類型一步一步查找排除

clip_image004

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

clip_image005----- 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

clip_image007

l 結合log看代碼,找到原因

clip_image009

為了讓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 對應代碼

clip_image011

異常分析之OOM

OOM產生原因

Android應用內存管理機制是在Java內存管理機制基礎上改進的,所以造成OOM的原因兩者差不多,即所有對象都在堆上分配空間,堆是有大小限制的,當分配的對象不能被回收仍然占據堆空間,新分配的對象不能獲取足夠的堆空間時,就會OOM。為什么會這樣呢?這就是GC不足的地方,GC只能回收自己記錄(有向樹)里面不可達的對象,對可達對象認為是有用的,不會被回收。但是可達對象並非一定是有用對象,他們可能是廢棄對象(死對象、冗余對象、電燈泡,僵屍),但卻無法被GC回收,占據着進程堆空間,下面是網上的一個對象實例化簡圖

clip_image013

各種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

clip_image015

clip_image017

DDMS dump 出來的hprof文件需要經過SDK下hprof-conv(位於sdk/tools下)轉換后才能被MAT工具使用

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

然后使用MAT工具打開

1. Cache泄漏

多次插拔耳機后,發現內存一直在漲:

clip_image019點擊Details進入下面頁面

clip_image021 點擊Patch To GC Root

clip_image023發現一個靜態變量 sAnimators,此為懷疑的地方,查看代碼,加點log,編譯調試:

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

可以看出,插拔耳機操作后,sAnimators.size一直會增大。

處理方法:防止緩存過大,可以設置上限,也可以定期清理下!

clip_image025

clip_image027

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

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

后台播放音樂,不停切換主題,最后Launcher OOM

如下圖,5個AppsCustomizePagedView實例,明顯泄漏了:

clip_image029點擊clip_image031,選中一個實例,Path To GC Roots:

clip_image033 已經看到被CircleProgress.java的MyTimerTask持有:clip_image035

再看代碼,修改后,調試內存,正常:

clip_image037

這樣改內存泄露解決了, 但是后面引入了新的功能問題, 重新修改了。所以修改類似問題時多小心,確認生命周期已經完成后再執行回收

結束語:

這些問題大多是比較難解的問題,大部分都是隨機的,往往都是很難復現的,找出規律是很重要的!

另外,內存泄露不容易發現,一些輕微的泄露,可能要使用一個月才能發現,所以對自己的模塊,要自己去檢查有沒有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並啟動它

clip_image039

3. Watchdog線程向ServerThread線程發送一個MONITOR message,同時將mCompleted標志位置為false

clip_image041

4. 然后Watchdog線程Sleep 60秒(不包含系統睡眠的時間),如果mCompleted標志位不為true,則認為發生watchdog超時,之后Android就會重啟.

5. ServerThread收到這個消息后會依次執行之前每個Service Object的monitor()函數,當執行完后會將mCompleted標志位置為true.

clip_image043

SWT LOG分析

SWT也是一種ANR,普通ANR是某個AP的主線程在一段時間內沒有做完某件事情;SWT是SystemServer進程的ServerThread線程在一段時間內沒有做完某件事情。所以SWT的分析方法和ANR分析方法是一樣的,只是現象不一樣,發生SWT手機會重啟

分析方法:

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

clip_image045

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平台上,發送短信內容為‘==’時會重啟

clip_image047

雖然是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》中都有描述

clip_image049

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

clip_image051


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM