1. 程式人生 > >android 常見宕機問題--log分析

android 常見宕機問題--log分析

1、程式異常退出 uncaused exception

2、程式強制關閉 Force Closed 
(簡稱FC)

3、程式無響應 Application No 
Response(簡稱ANR),一般主執行緒超過5秒麼有處理就會ANR4、手動生成進入控制檯輸入:logcat命令即可進行輸出第一部分1、分析工具介紹a、cat /proc/meminfo 
顯示基本的記憶體資訊------ MEMORY INFO (/proc/meminfo) ------MemTotal: 
285184 kBMemFree: 106360 kBBuffers: 0 
kBCached: 60036 kBSwapCached: 0 kBActive: 
98160 kBInactive: 49100 kBActive(anon): 87260 
kBInactive(anon): 288 kBActive(file): 10900 
kBInactive(file): 48812 kBUnevictable: 0 kBMlocked: 
0 kBSwapTotal: 0 kBSwapFree: 0 
kBDirty: 0 kBWriteback: 0 kBAnonPages: 
87240 kBMapped: 26500 kBShmem: 324 
kBSlab: 13340 kBSReclaimable: 1672 kBSUnreclaim: 
11668 kBKernelStack: 2160 kBPageTables: 5600 
kBNFS_Unstable: 0 kBBounce: 0 
kBWritebackTmp: 0 kBCommitLimit: 142592 
kBCommitted_AS: 1065600 kBVmallocTotal: 417792 kBVmallocUsed: 
137700 kBVmallocChunk: 254980 
kB重點關注這下面幾個值:MemTotal: 285184 kB 
//總計實體記憶體的大小MemFree: 106360 kB //可用記憶體有多少Buffers: 
0 kB//磁碟快取記憶體的大小Cached: 
60036 kB# freefreetotal used 
free shared buffersMem: 285184 178884 
106300 0 0Swap: 0 0 
0Total: 285184 178884 
106300在linux中有這麼一種思想,記憶體不用白不用,因此它儘可能的cache和buffer一些資料,以方便下次使用。但實際上這些記憶體也是可以立刻拿來使用的。所以空閒記憶體=free+buffers+cached=total-used還有幾個命令可使用:/proc/meminfo 
機器的記憶體使用資訊/proc/pid/maps pid為程序號,顯示當前程序所佔用的虛擬地址。/proc/pid/statm 
程序所佔用的記憶體b、檢視程序資訊------ CPU INFO (top -n 1 -d 1 
-m 30 -t) ------能夠實時顯示系統中各個程序的資源佔用狀況,類似於 Windows 的工作管理員c、android提供的一些操作工具------ PROCRANK 
(procrank) ------------ PROCMEM (procmem) ------------ SHOWMAP (showmap) 
------... 就不一一列舉了,有興趣的朋友可以去看看這此工具的程式碼位於android的 
/system/extrasd、虛擬記憶體的檢視工具------ VIRTUAL MEMORY STATS 
(/proc/vmstat) ------------ VMALLOC INFO (/proc/vmallocinfo) 
------2、時間資訊,也是我們主要分析的資訊格式如下:------ SYSTEM LOG 
(logcat -b system -v time -d *:v) ------$:logcat -b system -v time -d 
*:v01-02 08:00:02.570 I/SystemServer( 957): Notification 
Manager01-02 08:00:02.570 I/SystemServer( 957): Device Storage 
Monitor01-02 08:00:02.580 I/SystemServer( 957): Location Manager01-02 
08:00:02.580 I/SystemServer( 957): Search Service01-02 08:00:02.590 
I/SystemServer( 957): DropBox Service01-02 08:00:02.590 I/SystemServer( 
957): Wallpaper Service3、虛擬機器資訊,包括程序的,執行緒的跟蹤資訊,這是用來跟蹤程序和執行緒具體點的好地方 
。------ VM TRACES JUST NOW (/data/anr/traces.txt.bugreport: 
2011-01-15 16:49:02) ------------ VM TRACES AT LAST ANR 
(/data/anr/traces.txt: 2011-01-15 16:49:02) ------格式如下 :----- 
pid 1516 at 1970-01-02 08:03:07 -----Cmd line: 
com.ipanel.join.appstoreDALVIK 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=0x4001f188 self=0xd028| sysTid=1516 nice=0 
sched=3/0 cgrp=[fopen-error:2] handle=-1345017744

第二部分

如何分析log資訊1、查詢錯誤資訊的關鍵字眼"error" "failxx" "E/" 等的錯誤資訊將這些問題先行解決掉2、動態庫宕機檢視類似的“Build fingerprint:”這些關鍵字I/DEBUG ( 692): *** *** *** *** *** *** *** *** *** 
*** *** *** *** *** *** ***I/DEBUG ( 
692): Build fingerprint: 
'generic/generic/generic:2.3.1/GRH78/eng.userdev-rd6-input.20120221.113348:eng/test-keys'I/DEBUG ( 692): pid: 694, tid: 694 >>> 
/system/bin/mediaserver <<<I/DEBUG ( 692): signal 11 (SIGSEGV), code 1 
(SEGV_MAPERR), fault addr 00000input module init -->010對於這此資訊,可以檢視動態庫的分析:http://blog.csdn.net/andyhuabing/article/details/70749793、解決java拋異常的問題解決E/UsbObserver( 957): 
java.lang.NullPointerExceptionE/UsbObserver( 957): at 
com.android.server.UsbObserver.init(UsbObserver.java:131)E/UsbObserver( 957): at 
com.android.server.UsbObserver.<init>(UsbObserver.java:65)E/UsbObserver( 957): at 
com.android.server.ServerThread.run(SystemServer.java:419)I/SystemServer( 957): UI Mode Manager 
Service這個直接找到java程式碼,分析其實現即可解決4、ANR問題搜尋“ANR”關鍵詞,快速定位到關鍵事件資訊 。定位到關鍵的事件資訊如下:I/dalvikvm( 1014): Wrote stack traces to 
'/data/anr/traces.txt'I/Process ( 
957): Sending signal. PID: 1124 SIG: 9E/ActivityManager( 957): ANR in 
com.ipanel.join.appstoreE/ActivityManager( 957): Reason: Broadcast of Intent { 
act=android.appwidget.action.APPWIDGET_UPDATE 
cmp=com.ipanel.join.appstore/.widget.SmallWidget1 (has extras) }E/ActivityManager( 957): Load: 1.57 / 0.38 / 
0.13E/ActivityManager( 957): CPU usage 
from 6290ms to 0ms ago:E/ActivityManager( 957): 70% 957/system_server: 1.1% 
user + 69% kernel / faults: 204 minorE/ActivityManager( 957): 8.7% 
1014/com.ipanel.join.home.jelly: 7.7% user + 0.9% kernel / faults: 899 
minorE/ActivityManager( 957): 0.3% 
687/yaffs-bg-1: 0% user + 0.3% kernelE/ActivityManager( 957): 0.3% 688/yaffs-bg-1: 0% user 
+ 0.3% kernelE/ActivityManager( 957): 
0.3% 935/irkeyservice: 0% user + 0.3% kernelE/ActivityManager( 957): 0% 890/galcore daemon : 0% 
user + 0% kernelE/ActivityManager( 
957): 0.1% 1076/com.ipanel.join.browser: 0.1% user + 0% 
kernelE/ActivityManager( 957): 0.1% 
1124/com.ipanel.join.appstore: 0.1% user + 0% kernelE/ActivityManager( 957): 75% TOTAL: 4.7% user + 70% 
kernelE/ActivityManager( 957): CPU 
usage from 622ms to 1169ms later:E/ActivityManager( 957): 71% 957/system_server: 0% 
user + 71% kernel / faults: 2 minorE/ActivityManager( 957): 67% 965/SurfaceFlinger: 0%
user + 67% kernelE/ActivityManager( 
957): 1.9% 973/ActivityManager: 1.9% user + 0% kernelE/ActivityManager( 957): 1.9% 991/CursorMove: 0% 
user + 1.9% kernelE/ActivityManager( 
957): 7.6% 1014/com.ipanel.join.home.jelly: 7.6% user + 0% kernel / faults: 
31 minorE/ActivityManager( 957): 
5.7% 1119/Thread-13: 5.7% user + 0% kernelE/ActivityManager( 957): 1.9% 1123/Thread-13: 1.9% 
user + 0% kernelE/ActivityManager( 
957): 76% TOTAL: 1.8% user + 72% kernel + 1.8% softirq指定哪個java包出問題E/ActivityManager( 957): ANR in 
com.ipanel.join.appstore程序號為957發生瞭如下錯誤:com.ipanel.join.appstore 包下面 
Broadcast問題ANR原因:E/ActivityManager( 957): Reason: Broadcast of Intent { 
act=android.appwidget.action.APPWIDGET_UPDATE 
cmp=com.ipanel.join.appstore/.widget.SmallWidget1 (has extras) 
}這是ANR的堆疊呼叫檔案I/dalvikvm( 1014): Wrote stack traces to 
'/data/anr/traces.txt'通過上面的log資訊分析,應該是接收一個廣播訊息時超時了我們再分析虛擬機器資訊 ,開啟/data/anr/traces.txt,可有通過adb pull 
/data/anr/traces.txt .這裡每一段都是一個執行緒 
,當然我們還是看執行緒號為1的主執行緒了。通過分析發現關鍵問題是這樣:搜尋“DALVIK THREADS”關鍵詞,快速定位到本應用程式的虛擬機器資訊日誌----- pid 1516 
at 1970-01-02 08:03:07 -----Cmd line: 
com.ipanel.join.appstoreDALVIK 
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=0x4001f188 self=0xd028| 
sysTid=1516 nice=0 sched=3/0 cgrp=[fopen-error:2] 
handle=-1345017744at 
org.apache.harmony.luni.platform.OSNetworkSystem.connect(Native 
Method)at 
dalvik.system.BlockGuard$WrappedNetworkSystem.connect(BlockGuard.java:357)at 
org.apache.harmony.luni.net.PlainSocketImpl.connect(PlainSocketImpl.java:204)at 
org.apache.harmony.luni.net.PlainSocketImpl.connect(PlainSocketImpl.java:437)at 
java.net.Socket.connect(Socket.java:983)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:74)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection.<init>(HttpConnection.java:48)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnection$Address.connect(HttpConnection.java:298)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpConnectionPool.get(HttpConnectionPool.java:89)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getHttpConnection(HttpURLConnectionImpl.java:285)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.makeConnection(HttpURLConnectionImpl.java:267)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.retrieveResponse(HttpURLConnectionImpl.java:1018)at 
org.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:726)at 
com.ipanel.join.appstore.http.DefaultHttpRequest.doGet(DefaultHttpRequest.java:35)at 
com.ipanel.join.appstore.widget.AbsSmallWidget.requestApps(AbsSmallWidget.java:117)at 
com.ipanel.join.appstore.widget.AbsSmallWidget.getRemoteViews(AbsSmallWidget.java:56)其實從這句話:at 
org.apache.harmony.luni.platform.OSNetworkSystem.connect(Native 
Method)基本上確認是 socket ->connect 
連線超時了,導致主執行緒5s內沒有響應從而產生ANR錯誤。預設的connect連線timeout時間是75s其實解決辦法就是利用非阻塞方式進行連線即可。從CPU佔用率上也可以看出是在kernel中執行堵塞住了E/ActivityManager( 957): 75% TOTAL: 4.7% user + 70% 
kernel5、執行DexOpt錯誤W/dalvikvm( 1803): DexOpt: --- END 
'SettingsProvider.apk' --- status=0x000a, process failedE/dalvikvm( 1803): Unable to extract+optimize DEX from 
'/system/app/SettingsProvider.apk'E/SystemServer( 1803): Failure starting Input Manager 
ServiceE/SystemServer( 1803): 
java.lang.RuntimeException: Unable to get provider 
com.android.providers.settings.SettingsProvider: 
java.lang.ClassNotFoundException: 
com.android.providers.settings.SettingsProvider in loader 
dalvik.system.PathClassLoader[/system/app/SettingsProvider.apk]E/SystemServer( 1803): at 
android.app.ActivityThread.installProvider(ActivityThread.java:3557)E/SystemServer( 1803): at 
android.app.ActivityThread.getProvider(ActivityThread.java:3356)從上面的列印看,是在解壓或優化extract+optimize 
DEX的apk檔案時出錯了1、沒有出現magic 
number錯誤,這個原因與原子操作無關(這是一快速的加鎖和解鎖的輕量級操作函式)2、執行dexopt出錯查明是伺服器硬碟沒空間了,導致引導檔案系統的時候沒有空間進行解壓而失敗6、系統啟動後預設其妙或隨機宕機情況出現這種錯誤:12-01 
08:11:56.027: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed 
out (identity=19, status=0). CPU may be pegged. trying again.12-01 08:11:57.315: WARN/SharedBufferStack(312): 
waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be 
pegged. trying again.12-01 
08:11:59.318: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed 
out (identity=19, status=0). CPU may be pegged. trying again.12-01 08:12:03.332: WARN/SharedBufferStack(312): 
waitForCondition(LockCondition) timed out (identity=19, status=0). CPU may be 
pegged. trying again.12-01 
08:12:05.329: WARN/SharedBufferStack(312): waitForCondition(LockCondition) timed 
out (identity=19, status=0). CPU may be pegged. trying again.12-01 08:12:07.216: WARN/KeyCharacterMap(312): No 
keyboard for id 012-01 08:12:07.216: 
WARN/KeyCharacterMap(312): Using default keymap: 
/system/usr/keychars/qwerty.kcm.bin

檢視記憶體: cat /proc/meminfo 
發現空閒記憶體只剩下幾M空間了。請加大android系統的記憶體即可解決問題

還有一種情況是實現gralloc模組時有死鎖的情況,請查明即可。