如何分析解決Android ANR

[java]?view plaincopy
print?
  1. 來自:??
  2. http://blog.csdn.net/tjy1985/article/details/6777346??
  3. http://blog.csdn.net/tjy1985/article/details/6777355??
  4. http://blog.csdn.net/tjy1985/article/details/6777983??
  5. http://www.eoeandroid.com/forum.php?mod=viewthread&tid=165974??

?

?

=================================================================

?

?

一:什么是ANR

ANR:Application Not Responding,即應用無響應

?

二:ANR的類型

ANR一般有三種類型:

1:KeyDispatchTimeout(5 seconds) --主要類型

按鍵或觸摸事件在特定時間內無響應

2BroadcastTimeout(10 seconds)

BroadcastReceiver在特定時間內無法處理完成

3:ServiceTimeout(20 seconds) --小概率類型

Service在特定的時間內無法處理完成

?

三:KeyDispatchTimeout

Akey or touch event was not dispatched within the specified time(按鍵或觸摸事件在特定時間內無響應)

具體的超時時間的定義在framework下的

ActivityManagerService.java

//How long we wait until we timeout on key dispatching.

staticfinal int KEY_DISPATCHING_TIMEOUT = 5*1000

?

四:為什么會超時呢?

超時時間的計數一般是從按鍵分發給app開始。超時的原因一般有兩種

(1)當前的事件沒有機會得到處理(即UI線程正在處理前一個事件,沒有及時的完成或者looper被某種原因阻塞住了)

(2)當前的事件正在處理,但沒有及時完成

?

五:如何避免KeyDispatchTimeout

1UI線程盡量只做跟UI相關的工作

2:耗時的工作(比如數據庫操作,I/O,連接網絡或者別的有可能阻礙UI線程的操作)把它放入單獨的線程處理

3:盡量用Handler來處理UIthread和別的thread之間的交互

?

六:UI線程

說了那么多的UI線程,那么哪些屬于UI線程呢?

UI線程主要包括如下:

  1. Activity:onCreate(), onResume(), onDestroy(), onKeyDown(), onClick(),etc

  2. AsyncTask: onPreExecute(), onProgressUpdate(), onPostExecute(), onCancel,etc

  3. Mainthread handler: handleMessage(), post*(runnable r), etc

  4. other

七:如何去分析ANR

先看個LOG:

04-01?13:12:11.572?I/InputDispatcher(?220): Application is not responding:Window{2b263310com.android.email/com.android.email.activity.SplitScreenActivitypaused=false}.? 5009.8ms since event, 5009.5ms since waitstarted

04-0113:12:11.572 I/WindowManager( 220): Input event dispatching timedout sending tocom.android.email/com.android.email.activity.SplitScreenActivity

04-01?13:12:14.123?I/Process(? 220): Sending signal.?PID: 21404?SIG: 3---發生ANR的時間和生成trace.txt的時間

04-01?13:12:14.123?I/dalvikvm(21404):threadid=4: reacting to signal 3?

……

04-0113:12:15.872 E/ActivityManager(? 220): ANR in com.android.email(com.android.email/.activity.SplitScreenActivity)

04-0113:12:15.872 E/ActivityManager(? 220): Reason:keyDispatchingTimedOut

04-0113:12:15.872 E/ActivityManager(? 220): Load: 8.68 / 8.37 / 8.53

04-0113:12:15.872 E/ActivityManager(? 220):?CPUusage from?4361ms to 699ms ago?----CPU在ANR發生前的使用情況

?

04-0113:12:15.872 E/ActivityManager(? 220):?? 5.5%21404/com.android.email: 1.3% user + 4.1% kernel / faults: 10 minor

04-0113:12:15.872 E/ActivityManager(? 220):?? 4.3%220/system_server: 2.7% user + 1.5% kernel / faults: 11 minor 2 major

04-0113:12:15.872 E/ActivityManager(? 220):?? 0.9%52/spi_qsd.0: 0% user + 0.9% kernel

04-0113:12:15.872 E/ActivityManager(? 220):?? 0.5%65/irq/170-cyttsp-: 0% user + 0.5% kernel

04-0113:12:15.872 E/ActivityManager(? 220):?? 0.5%296/com.android.systemui: 0.5% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(? 220):?100%TOTAL: 4.8% user + 7.6% kernel + 87% iowait

04-0113:12:15.872 E/ActivityManager(? 220):?CPUusage from?3697ms to 4223ms?later:-- ANR后CPU的使用量

04-0113:12:15.872 E/ActivityManager(? 220):?? 25%21404/com.android.email: 25% user + 0% kernel / faults: 191 minor

04-0113:12:15.872 E/ActivityManager(? 220):????16% 21603/__eas(par.hakan: 16% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(? 220):????7.2% 21406/GC: 7.2% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(? 220):????1.8% 21409/Compiler: 1.8% user + 0% kernel

04-0113:12:15.872 E/ActivityManager(? 220):?? 5.5%220/system_server: 0% user + 5.5% kernel / faults: 1 minor

04-0113:12:15.872 E/ActivityManager(? 220):????5.5% 263/InputDispatcher: 0% user + 5.5% kernel

04-0113:12:15.872 E/ActivityManager(? 220):?32%TOTAL: 28% user + 3.7% kernel

?

從LOG可以看出ANR的類型,CPU的使用情況,如果CPU使用量接近100%,說明當前設備很忙,有可能是CPU饑餓導致了ANR

如果CPU使用量很少,說明主線程被BLOCK了

如果IOwait很高,說明ANR有可能是主線程在進行I/O操作造成的

除了看LOG,解決ANR還得需要trace.txt文件,

如何獲取呢?可以用如下命令獲取

  1. $chmod 777 /data/anr

  2. $rm /data/anr/traces.txt

  3. $ps

  4. $kill -3?PID

  5. adbpull data/anr/traces.txt ./mytraces.txt

從trace.txt文件,看到最多的是如下的信息:

-----pid 21404 at?2011-04-01?13:12:14?----- ?
Cmdline: com.android.email

DALVIK THREADS:
(mutexes: tll=0tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1NATIVE
? | group="main" sCount=1 dsCount=0obj=0x2aad2248 self=0xcf70
? | sysTid=21404 nice=0 sched=0/0cgrp=[fopen-error:2] handle=1876218976
??atandroid.os.MessageQueue.nativePollOnce(Native Method)
? atandroid.os.MessageQueue.next(MessageQueue.java:119)
? atandroid.os.Looper.loop(Looper.java:110
)
?at android.app.ActivityThread.main(ActivityThread.java:3688)
?at java.lang.reflect.Method.invokeNative(Native Method)
? atjava.lang.reflect.Method.invoke(Method.java:507)
? atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
?at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:624)
?at dalvik.system.NativeStart.main(Native Method)

說明主線程在等待下條消息進入消息隊列

?

八:Thread狀態

?

[java]?view plaincopy
print?
  1. ThreadState?(defined?at?“dalvik/vm/thread.h?“)??
  2. THREAD_UNDEFINED?=?-1,?/*?makes?enum?compatible?with?int32_t?*/??
  3. THREAD_ZOMBIE?=?0,?/*?TERMINATED?*/??
  4. THREAD_RUNNING?=?1,?/*?RUNNABLE?or?running?now?*/??
  5. THREAD_TIMED_WAIT?=?2,?/*?TIMED_WAITING?in?Object.wait()?*/??
  6. THREAD_MONITOR?=?3,?/*?BLOCKED?on?a?monitor?*/??
  7. THREAD_WAIT?=?4,?/*?WAITING?in?Object.wait()?*/??
  8. THREAD_INITIALIZING=?5,?/*?allocated,?not?yet?running?*/??
  9. THREAD_STARTING?=?6,?/*?started,?not?yet?on?thread?list?*/??
  10. THREAD_NATIVE?=?7,?/*?off?in?a?JNI?native?method?*/??
  11. THREAD_VMWAIT?=?8,?/*?waiting?on?a?VM?resource?*/??
  12. THREAD_SUSPENDED?=?9,?/*?suspended,?usually?by?GC?or?debugger?*/??

?

?

九:如何調查并解決ANR

1:首先分析log

2:?從trace.txt文件查看調用stack.

3:?看代碼

4:仔細查看ANR的成因(iowait?block?memoryleak?)

?

?

十:案例

案例1:關鍵詞:ContentResolver in AsyncTask onPostExecute, high iowait

Process:com.android.email
Activity:com.android.email/.activity.MessageView
Subject:keyDispatchingTimedOut
CPU usage from 2550ms to -2814ms ago:
5%187/system_server: 3.5% user + 1.4% kernel / faults: 86 minor 20major
4.4% 1134/com.android.email: 0.7% user + 3.7% kernel /faults: 38 minor 19 major
4% 372/com.android.eventstream: 0.7%user + 3.3% kernel / faults: 6 minor
1.1% 272/com.android.phone:0.9% user + 0.1% kernel / faults: 33 minor
0.9%252/com.android.systemui: 0.9% user + 0% kernel
0%409/com.android.eventstream.telephonyplugin: 0% user + 0% kernel /faults: 2 minor
0.1% 632/com.android.devicemonitor: 0.1% user + 0%kernel
100%TOTAL: 6.9% user + 8.2% kernel +84%iowait


-----pid 1134 at 2010-12-17 17:46:51 -----
Cmd line:com.android.email

DALVIK THREADS:
(mutexes: tll=0 tsl=0tscl=0 ghl=0 hwl=0 hwll=0)
"main" prio=5 tid=1 WAIT
|group="main" sCount=1 dsCount=0 obj=0x2aaca180self=0xcf20
| sysTid=1134 nice=0 sched=0/0 cgrp=[fopen-error:2]handle=1876218976
at java.lang.Object.wait(Native Method)
-waiting on <0x2aaca218> (a java.lang.VMThread)
atjava.lang.Thread.parkFor(Thread.java:1424)
atjava.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48)
atsun.misc.Unsafe.park(Unsafe.java:337)
atjava.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
atjava.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:808)
atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:841)
atjava.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1171)
atjava.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:200)
atjava.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:261)
atandroid.database.sqlite.SQLiteDatabase.lock(SQLiteDatabase.java:378)
atandroid.database.sqlite.SQLiteCursor.<init>(SQLiteCursor.java:222)
atandroid.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:53)
atandroid.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1356)
atandroid.database.sqlite.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1235)
atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1189)
atandroid.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1271)
atcom.android.email.provider.EmailProvider.query(EmailProvider.java:1098)
atandroid.content.ContentProvider$Transport.query(ContentProvider.java:187)
atandroid.content.ContentResolver.query(ContentResolver.java:268)
atcom.android.email.provider.EmailContent$Message.restoreMessageWithId(EmailContent.java:648)
atcom.android.email.Controller.setMessageRead(Controller.java:658)
atcom.android.email.activity.MessageView.onMarkAsRead(MessageView.java:700)
atcom.android.email.activity.MessageView.access$2500(MessageView.java:98)
atcom.android.email.activity.MessageView$LoadBodyTask.onPostExecute(MessageView.java:1290)
atcom.android.email.activity.MessageView$LoadBodyTask.onPostExecute(MessageView.java:1255)
atandroid.os.AsyncTask.finish(AsyncTask.java:417)
atandroid.os.AsyncTask.access$300(AsyncTask.java:127)
atandroid.os.AsyncTask$InternalHandler.handleMessage(AsyncTask.java:429)
atandroid.os.Handler.dispatchMessage(Handler.java:99)
atandroid.os.Looper.loop(Looper.java:123)
atandroid.app.ActivityThread.main(ActivityThread.java:3652)
atjava.lang.reflect.Method.invokeNative(Native Method)
atjava.lang.reflect.Method.invoke(Method.java:507)
atcom.android.internal.os.ZygoteIn

原因:IOWait很高,說明當前系統在忙于I/O,因此數據庫操作被阻塞

原來:

? ? ? ??finalMessagemessage=Message.restoreMessageWithId(mProviderContext,messageId);

? ? ? ??if(message==null){

? ? ? ? ? ?return;

? ? ? ??}

? ? ? ??Accountaccount=Account.restoreAccountWithId(mProviderContext,message.mAccountKey);

? ? ? ??if(account==null){

? ? ? ? ? ?return;//isMessagingController returns false for null, but let's make itclear.

? ? ? ??}

? ? ? ??if(isMessagingController(account)){

? ? ? ? ? ?newThread(){

? ? ? ? ? ?? ??@Override

? ? ? ? ? ?? ??publicvoidrun(){

? ? ? ? ? ?? ? ? ?mLegacyController.processPendingActions(message.mAccountKey);

? ? ? ? ? ?? ??}

? ? ? ? ? ?}.start();

? ? ? ??}

?

解決后:

newThread() {

? ? ? ??finalMessagemessage=Message.restoreMessageWithId(mProviderContext,messageId);

? ? ? ??if(message==null){

? ? ? ? ? ?return;

? ? ? ??}

? ? ? ??Accountaccount=Account.restoreAccountWithId(mProviderContext,message.mAccountKey);

? ? ? ??if(account==null){

? ? ? ? ? ?return;//isMessagingController returns false for null, but let's make itclear.

? ? ? ??}

? ? ? ??if(isMessagingController(account)) {

? ? ? ? ? ?? ? ? ?mLegacyController.processPendingActions(message.mAccountKey);

? ? ? ? ? ?? ?

? ? ? ? ? ?}

?

}.start();

關于AsyncTask:http://developer.android.com/reference/android/os/AsyncTask.html

?

案例2:關鍵詞:在UI線程進行網絡數據的讀寫

ANRin process: com.android.mediascape:PhotoViewer (last incom.android.mediascape:PhotoViewer)
Annotation:keyDispatchingTimedOut
CPU usage:
Load: 6.74 / 6.89 / 6.12
CPUusage from 8254ms to 3224ms ago:
ovider.webmedia: 4% = 4% user +0% kernel / faults: 68 minor
system_server: 2% = 1% user + 0%kernel / faults: 18 minor
re-initialized>: 0% = 0% user + 0%kernel / faults: 50 minor
events/0: 0% = 0% user + 0%kernel
TOTAL:7% = 6% user + 1% kernel

DALVIKTHREADS:
""main"" prio=5 tid=3 NATIVE
|group=""main"" sCount=1 dsCount=0 s=Yobj=0x4001b240 self=0xbda8
| sysTid=2579 nice=0 sched=0/0cgrp=unknown handle=-1343993184
atorg.apache.harmony.luni.platform.OSNetworkSystem.receiveStreamImpl(NativeMethod)
atorg.apache.harmony.luni.platform.OSNetworkSystem.receiveStream(OSNetworkSystem.java:478)
atorg.apache.harmony.luni.net.PlainSocketImpl.read(PlainSocketImpl.java:565)
atorg.apache.harmony.luni.net.SocketInputStream.read(SocketInputStream.java:87)
atorg.apache.harmony.luni.internal.net.www.protocol.http.HttpURLConnection$LimitedInputStream.read(HttpURLConnection.java:303)
atjava.io.InputStream.read(InputStream.java:133)
atjava.io.BufferedInputStream.fillbuf(BufferedInputStream.java:157)
atjava.io.BufferedInputStream.read(BufferedInputStream.java:346)
atandroid.graphics.BitmapFactory.nativeDecodeStream(Native Method)
atandroid.graphics.BitmapFactory.decodeStream(BitmapFactory.java:459)
atcom.android.mediascape.activity.PhotoViewerActivity.getPreviewImage(PhotoViewerActivity.java:4465)
atcom.android.mediascape.activity.PhotoViewerActivity.dispPreview(PhotoViewerActivity.java:4406)
atcom.android.mediascape.activity.PhotoViewerActivity.access$6500(PhotoViewerActivity.java:125)
atcom.android.mediascape.activity.PhotoViewerActivity$33$1.run(PhotoViewerActivity.java:4558)
atandroid.os.Handler.handleCallback(Handler.java:587)
atandroid.os.Handler.dispatchMessage(Handler.java:92)
atandroid.os.Looper.loop(Looper.java:123)
atandroid.app.ActivityThread.main(ActivityThread.java:4370)
atjava.lang.reflect.Method.invokeNative(Native Method)
atjava.lang.reflect.Method.invoke(Method.java:521)
atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868)
atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:626)
atdalvik.system.NativeStart.main(Native Method)

關于網絡連接,再設計的時候可以設置個timeout的時間或者放入獨立的線程來處理。

關于Handler的問題,可以參考:http://developer.android.com/reference/android/os/Handler.html

案例3:

關鍵詞:Memoryleak/Thread leak

11-1621:41:42.560 I/ActivityManager( 1190): ANR in process:android.process.acore (last in android.process.acore)
11-1621:41:42.560 I/ActivityManager( 1190): Annotation:keyDispatchingTimedOut
11-16 21:41:42.560 I/ActivityManager(1190): CPU usage:
11-16 21:41:42.560 I/ActivityManager( 1190):Load: 11.5 / 11.1 / 11.09
11-16 21:41:42.560 I/ActivityManager(1190): CPU usage from 9046ms to 4018ms ago:
11-16 21:41:42.560I/ActivityManager( 1190):?d.process.acore:98%= 97% user + 0% kernel / faults: 1134 minor
11-16 21:41:42.560I/ActivityManager( 1190): system_server: 0% = 0% user + 0% kernel /faults: 1 minor
11-16 21:41:42.560 I/ActivityManager( 1190): adbd:0% = 0% user + 0% kernel
11-16 21:41:42.560 I/ActivityManager(1190): logcat: 0% = 0% user + 0% kernel
11-16 21:41:42.560I/ActivityManager( 1190):?TOTAL:100% = 98% user + 1% kernel

Cmdline: android.process.acore

DALVIK THREADS:
"main"prio=5 tid=3?VMWAIT
|group="main" sCount=1 dsCount=0 s=N obj=0x40026240self=0xbda8
| sysTid=1815 nice=0 sched=0/0 cgrp=unknownhandle=-1344001376
atdalvik.system.VMRuntime.trackExternalAllocation(NativeMethod)
atandroid.graphics.Bitmap.nativeCreate(Native Method)
atandroid.graphics.Bitmap.createBitmap(Bitmap.java:468)
atandroid.view.View.buildDrawingCache(View.java:6324)
atandroid.view.View.getDrawingCache(View.java:6178)
atandroid.view.ViewGroup.drawChild(ViewGroup.java:1541)
……
atcom.android.internal.policy.impl.PhoneWindow$DecorView.draw(PhoneWindow.java:1830)
atandroid.view.ViewRoot.draw(ViewRoot.java:1349)
atandroid.view.ViewRoot.performTraversals(ViewRoot.java:1114)
atandroid.view.ViewRoot.handleMessage(ViewRoot.java:1633)
atandroid.os.Handler.dispatchMessage(Handler.java:99)
atandroid.os.Looper.loop(Looper.java:123)
atandroid.app.ActivityThread.main(ActivityThread.java:4370)
atjava.lang.reflect.Method.invokeNative(Native Method)
atjava.lang.reflect.Method.invoke(Method.java:521)
atcom.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868)
atcom.android.internal.os.ZygoteInit.main(ZygoteInit.java:626)
atdalvik.system.NativeStart.main(Native Method)

"Thread-408"prio=5 tid=329 WAIT
|group="main" sCount=1 dsCount=0 s=N obj=0x46910d40self=0xcd0548
| sysTid=10602 nice=0 sched=0/0 cgrp=unknownhandle=15470792
at java.lang.Object.wait(Native Method)
-waiting on <0x468cd420> (a java.lang.Object)
atjava.lang.Object.wait(Object.java:288)
atcom.android.dialer.CallLogContentHelper$UiUpdaterExecutor$1.run(CallLogContentHelper.java:289)
atjava.lang.Thread.run(Thread.java:1096)

分析:

atdalvik.system.VMRuntime.trackExternalAllocation(NativeMethod)內存不足導致block在創建bitmap上

**MEMINFO in pid 1360 [android.process.acore] **
native dalvik other total
size: 17036?23111?N/A 40147
allocated: 16484 20675 N/A 37159
free: 296 2436 N/A 2732

解決:如果機器的內存族,可以修改虛擬機的內存為36M或更大,不過最好是復查代碼,查看哪些內存沒有釋放

?

?

========================================================================================

http://www.eoeandroid.com/forum.php?mod=viewthread&tid=165974

?

Log的產生大家都知道 , 大家也都知道通過DDMS來看log , 但什么時候會產生log文件呢 ?一般在如下幾種情況會產生log文件 。
1,程序異常退出 , uncaused exception
2,程序強制關閉 ,Force Closed (簡稱FC)
3,程序無響應 , Application No Response (簡稱ANR) , 順便,一般主線程超過5秒么有處理就會ANR
4,手動生成 。


拿到一個日志文件,要分成多段來看 。 log文件很長,其中包含十幾個小單元信息,但不要被嚇到 ,事實上他主要由三大塊兒組成 。

1,系統基本信息 ,包括 內存,CPU ,進程隊列 ,虛擬內存 , 垃圾回收等信息 。------ MEMORY INFO (/proc/meminfo) ------
------ CPU INFO (top -n 1 -d 1 -m 30 -t) ------
------ PROCRANK (procrank) ------
------ VIRTUAL MEMORY STATS (/proc/vmstat) ------
------ VMALLOC INFO (/proc/vmallocinfo) ------

格式如下:
------ MEMORY INFO (/proc/meminfo) ------
MemTotal:? ?? ?? ?347076 kB
MemFree:? ?? ?? ???56408 kB
Buffers:? ?? ?? ?? ?7192 kB
Cached:? ?? ?? ???104064 kB
SwapCached:? ?? ?? ?? ?0 kB
Active:? ?? ?? ???192592 kB
Inactive:? ?? ?? ? 40548 kB
Active(anon):? ???129040 kB
Inactive(anon):? ???1104 kB
Active(file):? ?? ?63552 kB
Inactive(file):? ? 39444 kB
Unevictable:? ?? ???7112 kB
Mlocked:? ?? ?? ?? ?? ?0 kB
SwapTotal:? ?? ?? ?? ? 0 kB
SwapFree:? ?? ?? ?? ???0 kB
Dirty:? ?? ?? ?? ?? ? 44 kB
Writeback:? ?? ?? ?? ? 0 kB
AnonPages:? ?? ???129028 kB
Mapped:? ?? ?? ?? ?73728 kB
Shmem:? ?? ?? ?? ???1148 kB
Slab:? ?? ?? ?? ???13072 kB
SReclaimable:? ?? ? 4564 kB
SUnreclaim:? ?? ?? ?8508 kB
KernelStack:? ?? ???3472 kB
PageTables:? ?? ???12172 kB
NFS_Unstable:? ?? ?? ? 0 kB
Bounce:? ?? ?? ?? ?? ? 0 kB
WritebackTmp:? ?? ?? ? 0 kB
CommitLimit:? ?? ?173536 kB
Committed_AS:? ? 7394524 kB
VmallocTotal:? ???319488 kB
VmallocUsed:? ?? ? 90752 kB
VmallocChunk:? ???181252 kB


2,時間信息 , 也是我們主要分析的信息 。
------ VMALLOC INFO (/proc/vmallocinfo) ------
------ EVENT INFO (/proc/vmallocinfo) ------

格式如下:
------ SYSTEM LOG (logcat -b system -v time -d *:v) ------
01-15 16:41:43.671 W/PackageManager( 2466): Unknown permission com.wsomacp.permission.PROVIDER in package com.android.mms
01-15 16:41:43.671 I/ActivityManager( 2466): Force stopping package com.android.mms uid=10092
01-15 16:41:43.675 I/UsageStats( 2466): Something wrong here, didn't expect com.sec.android.app.twlauncher to be paused
01-15 16:41:44.108 I/ActivityManager( 2466): Start proc com.sec.android.widgetapp.infoalarm for service com.sec.android.widgetapp.infoalarm/.engine.DataService: pid=20634 uid=10005 gids={3003, 1015, 3002}
01-15 16:41:44.175 W/ActivityManager( 2466): Activity pause timeout for HistoryRecord{48589868 com.sec.android.app.twlauncher/.Launcher}
01-15 16:41:50.864 I/KeyInputQueue( 2466): Input event
01-15 16:41:50.866 D/KeyInputQueue( 2466): screenCaptureKeyFlag setting 0
01-15 16:41:50.882 I/PowerManagerService( 2466): Ulight 0->7|0
01-15 16:41:50.882 I/PowerManagerService( 2466): Setting target 2: cur=0.0 target=70 delta=4.6666665 nominalCurrentValue=0
01-15 16:41:50.882 I/PowerManagerService( 2466): Scheduling light animator!
01-15 16:41:51.706 D/PowerManagerService( 2466): enableLightSensor true
01-15 16:41:51.929 I/KeyInputQueue( 2466): Input event
01-15 16:41:51.933 W/WindowManager( 2466): No focus window, dropping: KeyEvent{action=0 code=26 repeat=0 meta=0 scancode=26 mFlags=9}



3,虛擬機信息 , 包括進程的,線程的跟蹤信息,這是用來跟蹤進程和線程具體點的好地方 。?
------ 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 21161 at 2011-01-15 16:49:01 -----
Cmd line: com.android.mms

DALVIK THREADS:
"main" prio=5 tid=1 NATIVE
??| group="main" sCount=1 dsCount=0 s=N obj=0x4001d8d0 self=0xccc8
??| sysTid=21161 nice=0 sched=0/0 cgrp=default handle=-1345017808
??| schedstat=( 4151552996 5342265329 10995 )
??at android.media.MediaPlayer._reset(Native Method)
??at android.media.MediaPlayer.reset(MediaPlayer.java:1218)
??at android.widget.VideoView.release(VideoView.java:499)
??at android.widget.VideoView.access$2100(VideoView.java:50)
??at android.widget.VideoView$6.surfaceDestroyed(VideoView.java:489)
??at android.view.SurfaceView.reportSurfaceDestroyed(SurfaceView.java:572)
??at android.view.SurfaceView.updateWindow(SurfaceView.java:476)
??at android.view.SurfaceView.onWindowVisibilityChanged(SurfaceView.java:206)
??at android.view.View.dispatchDetachedFromWindow(View.java:6082)
??at android.view.ViewGroup.dispatchDetachedFromWindow(ViewGroup.java:1156)
??at android.view.ViewGroup.removeAllViewsInLayout(ViewGroup.java:2296)
??at android.view.ViewGroup.removeAllViews(ViewGroup.java:2254)
??at com.android.mms.ui.SlideView.reset(SlideView.java:687)
??at com.android.mms.ui.SlideshowPresenter.presentSlide(SlideshowPresenter.java:189)
??at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
??at android.os.Handler.handleCallback(Handler.java:587)
??at android.os.Handler.dispatchMessage(Handler.java:92)
??at android.os.Looper.loop(Looper.java:123)
??at android.app.ActivityThread.main(ActivityThread.java:4627)
??at java.lang.reflect.Method.invokeNative(Native Method)
??at java.lang.reflect.Method.invoke(Method.java:521)
??at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
??at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
??at dalvik.system.NativeStart.main(Native Method)

---------------------------------------------------------------------------------------------------------------------------------------
閑話少說, 我總結了觀察log文件的基本步驟 。 1,如果是ANR問題 , 則搜索“ANR”關鍵詞 。 快速定位到關鍵事件信息 。
2,如果是ForceClosed 和其它異常退出信息,則搜索"Fatal" 關鍵詞, 快速定位到關鍵事件信息 。
3,定位到關鍵事件信息后 , 如果信息不夠明確的,再去搜索應用程序包的虛擬機信息 ,查看具體的進程和線程跟蹤的日志,來定位到代碼 。?

用這種方法,出現問題,根本不需要斷點調試 , 直接定位到問題,屢試不爽 。?
下面,我們就開始來分析這個例子的log 。

打開log文件 , 由于是ANR錯誤,因此搜索"ANR " , 為何要加空格呢,你加上和去掉比較一下就知道了 。 可以屏蔽掉不少保存到anr.log文件的無效信息 。?

定位到關鍵的事件信息如下:
01-15 16:49:02.433 E/ActivityManager( 2466): ANR in com.android.mms (com.android.mms/.ui.SlideshowActivity)
01-15 16:49:02.433 E/ActivityManager( 2466): Reason: keyDispatchingTimedOut
01-15 16:49:02.433 E/ActivityManager( 2466): Load: 0.6 / 0.61 / 0.42
01-15 16:49:02.433 E/ActivityManager( 2466): CPU usage from 1337225ms to 57ms ago:
01-15 16:49:02.433 E/ActivityManager( 2466):? ?sensorserver_ya: 8% = 0% user + 8% kernel / faults: 40 minor
......


01-15 16:49:02.433 E/ActivityManager( 2466):??-com.android.mms: 0% = 0% user + 0% kernel
01-15 16:49:02.433 E/ActivityManager( 2466):??-flush-179:8: 0% = 0% user + 0% kernel
01-15 16:49:02.433 E/ActivityManager( 2466): TOTAL: 25% = 10% user + 14% kernel + 0% iowait + 0% irq + 0% softirq
01-15 16:49:02.436 I/? ?? ???( 2466): dumpmesg > "/data/log/dumpstate_app_anr.log"


我們用自然語言來描述一下日志,這也算是一種能力吧 。?
01-15 16:49:02.433 E/ActivityManager( 2466): ANR in com.android.mms (com.android.mms/.ui.SlideshowActivity)
翻譯:在16:49分2秒433毫秒的時候 ActivityManager (進程號為2466) 發生了如下錯誤:com.android.mms包下面的.ui.SlideshowActivity 無響應 。

01-15 16:49:02.433 E/ActivityManager( 2466): Reason: keyDispatchingTimedOut
翻譯:原因 , keyDispatchingTimeOut - 按鍵分配超時?

01-15 16:49:02.433 E/ActivityManager( 2466): Load: 0.6 / 0.61 / 0.42
翻譯:5分鐘,10分鐘,15分鐘內的平均負載分別為:0.6 , 0.61 , 0.42

在這里我們大概知道問題是什么了,結合我們之前的操作流程,我們知道問題是在點擊按鈕某時候可能處理不過來按鈕事件,導致超時無響應 。那么現在似乎已經可以進行工作了 。 我們知道Activity中是通過重載dispatchTouchEvent(MotionEvent ev)來處理點擊屏幕事件??。 然后我們可以順藤摸瓜,一點點分析去查找原因 。 但這樣夠了么 ?
其實不夠 , 至少我們不能準確的知道到底問題在哪兒 , 只是猜測 ,比如這個應用程序中,我就在順藤摸瓜的時候發現了多個IO操作的地方都在主線程中,可能引起問題,但不好判斷到底是哪個??,所以我們目前掌握的信息還不夠 。?

于是我們再分析虛擬機信息 , 搜索“Dalvik Thread”關鍵詞,快速定位到本應用程序的虛擬機信息日志,如下:
----- pid 2922 at 2011-01-13 13:51:07 -----
Cmd line: com.android.mms

DALVIK THREADS:
"main" prio=5 tid=1 NATIVE
??| group="main" sCount=1 dsCount=0 s=N obj=0x4001d8d0 self=0xccc8
??| sysTid=2922 nice=0 sched=0/0 cgrp=default handle=-1345017808
??| schedstat=( 3497492306 15312897923 10358 )
??at android.media.MediaPlayer._release(Native Method)
??at android.media.MediaPlayer.release(MediaPlayer.java:1206)
??at android.widget.VideoView.stopPlayback(VideoView.java:196)
??at com.android.mms.ui.SlideView.stopVideo(SlideView.java:640)
??at com.android.mms.ui.SlideshowPresenter.presentVideo(SlideshowPresenter.java:443)
??at com.android.mms.ui.SlideshowPresenter.presentRegionMedia(SlideshowPresenter.java:219)
??at com.android.mms.ui.SlideshowPresenter$4.run(SlideshowPresenter.java:516)
??at android.os.Handler.handleCallback(Handler.java:587)
??at android.os.Handler.dispatchMessage(Handler.java:92)
??at android.os.Looper.loop(Looper.java:123)
??at android.app.ActivityThread.main(ActivityThread.java:4627)
??at java.lang.reflect.Method.invokeNative(Native Method)
??at java.lang.reflect.Method.invoke(Method.java:521)
??at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:858)
??at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
??at dalvik.system.NativeStart.main(Native Method)

"Binder Thread #3" prio=5 tid=11 NATIVE
??| group="main" sCount=1 dsCount=0 s=N obj=0x4837f808 self=0x242280
??| sysTid=3239 nice=0 sched=0/0 cgrp=default handle=2341032
??| schedstat=( 32410506 932842514 164 )
??at dalvik.system.NativeStart.run(Native Method)

"AsyncQueryWorker" prio=5 tid=9 WAIT
??| group="main" sCount=1 dsCount=0 s=N obj=0x482f4b80 self=0x253e10
??| sysTid=3236 nice=0 sched=0/0 cgrp=default handle=2432120
??| schedstat=( 3225061 26561350 27 )
??at java.lang.Object.wait(Native Method)
??- waiting on <0x482f4da8> (a android.os.MessageQueue)
??at java.lang.Object.wait(Object.java:288)
??at android.os.MessageQueue.next(MessageQueue.java:146)
??at android.os.Looper.loop(Looper.java:110)
??at android.os.HandlerThread.run(HandlerThread.java:60)

"Thread-9" prio=5 tid=8 WAIT
??| group="main" sCount=1 dsCount=0 s=N obj=0x4836e2b0 self=0x25af70
??| sysTid=2929 nice=0 sched=0/0 cgrp=default handle=2370896
??| schedstat=( 130248 4389035 2 )
??at java.lang.Object.wait(Native Method)
??- waiting on <0x4836e240> (a java.util.ArrayList)
??at java.lang.Object.wait(Object.java:288)
??at com.android.mms.data.Contact$ContactsCache$TaskStack$1.run(Contact.java:488)
??at java.lang.Thread.run(Thread.java:1096)

"Binder Thread #2" prio=5 tid=7 NATIVE
??| group="main" sCount=1 dsCount=0 s=N obj=0x482f8ca0 self=0x130fd0
??| sysTid=2928 nice=0 sched=0/0 cgrp=default handle=1215968
??| schedstat=( 40610049 1837703846 195 )
??at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=6 NATIVE
??| group="main" sCount=1 dsCount=0 s=N obj=0x482f4a78 self=0x128a50
??| sysTid=2927 nice=0 sched=0/0 cgrp=default handle=1201352
??| schedstat=( 40928066 928867585 190 )
??at dalvik.system.NativeStart.run(Native Method)

"Compiler" daemon prio=5 tid=5 VMWAIT
??| group="system" sCount=1 dsCount=0 s=N obj=0x482f1348 self=0x118960
??| sysTid=2926 nice=0 sched=0/0 cgrp=default handle=1149216
??| schedstat=( 753021350 3774113668 6686 )
??at dalvik.system.NativeStart.run(Native Method)

"JDWP" daemon prio=5 tid=4 VMWAIT
??| group="system" sCount=1 dsCount=0 s=N obj=0x482f12a0 self=0x132940
??| sysTid=2925 nice=0 sched=0/0 cgrp=default handle=1255680
??| schedstat=( 2827103 29553323 19 )
??at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
??| group="system" sCount=0 dsCount=0 s=N obj=0x482f11e8 self=0x135988
??| sysTid=2924 nice=0 sched=0/0 cgrp=default handle=1173688
??| schedstat=( 11793815 12456169 7 )
??at dalvik.system.NativeStart.run(Native Method)

"HeapWorker" daemon prio=5 tid=2 VMWAIT
??| group="system" sCount=1 dsCount=0 s=N obj=0x45496028 self=0x135848
??| sysTid=2923 nice=0 sched=0/0 cgrp=default handle=1222608
??| schedstat=( 79049792 1520840200 95 )
??at dalvik.system.NativeStart.run(Native Method)

----- end 2922 -----

每一段都是一個線程 ,當然我們還是看線程號為1的主線程了。通過分析發現關鍵問題是這樣:
??at com.android.mms.ui.SlideshowPresenter$3.run(SlideshowPresenter.java:531)
定位到代碼:
mHandler.post(new Runnable() {
? ?? ?? ?? ?? ?? ???public void run() {
? ?? ?? ?? ?? ?? ?? ?? ?try {
? ?? ?? ?? ?? ?? ?? ?? ?? ? presentRegionMedia(view, (RegionMediaModel) model, dataChanged);
? ?? ?? ?? ?? ?? ?? ?? ?} catch (OMADRMException e) {
? ?? ?? ?? ?? ?? ?? ?? ?? ? Log.e(TAG, e.getMessage(), e);
? ?? ?? ?? ?? ?? ?? ?? ?? ? Toast.makeText(mContext,
? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?mContext.getString(R.string.insufficient_drm_rights),
? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?Toast.LENGTH_SHORT).show();
? ?? ?? ?? ?? ?? ?? ?? ?} catch (IOException e){
? ?? ?? ?? ?? ?? ?? ?? ?? ? Log.e(TAG, e.getMessage(), e);
? ?? ?? ?? ?? ?? ?? ?? ?? ? Toast.makeText(mContext,
? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?mContext.getString(R.string.insufficient_drm_rights),
? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?Toast.LENGTH_SHORT).show();
? ?? ?? ?? ?? ?? ?? ?? ?

? ?? ?? ?? ?? ?? ?? ?? ?}
? ?? ?? ?? ?? ?? ???}



很清楚了, Handler.post 方法之后執行時間太長的問題 。 繼續看presentRegionMedia(view, (RegionMediaModel) model, dataChanged);方法 , 發現最終是調用的framework 中MediaPlayer.stop方法 。
至此,我們的日志分析算是告一段落 。 可以開始思考解決辦法了

轉載于:https://www.cnblogs.com/ts-develpoer/p/5832776.html

本文來自互聯網用戶投稿,該文觀點僅代表作者本人,不代表本站立場。本站僅提供信息存儲空間服務,不擁有所有權,不承擔相關法律責任。
如若轉載,請注明出處:http://www.pswp.cn/news/260710.shtml
繁體地址,請注明出處:http://hk.pswp.cn/news/260710.shtml
英文地址,請注明出處:http://en.pswp.cn/news/260710.shtml

如若內容造成侵權/違法違規/事實不符,請聯系多彩編程網進行投訴反饋email:809451989@qq.com,一經查實,立即刪除!

相關文章

第4章 Python 數字圖像處理(DIP) - 頻率域濾波8 - 二維DFT和IDFT的一些性質 - 二維離散卷積定理

目錄二維DFT和IDFT的一些性質二維離散卷積定理二維離散傅里葉變換性質的小結二維DFT和IDFT的一些性質 二維離散卷積定理 二維循環卷積表達式&#xff1a; (f?h)(x,y)∑m0M?1∑n0N?1f(m,n)h(x?m,y?n)(4.94)(f \star h)(x, y) \sum_{m0}^{M-1} \sum_{n0}^{N-1} f(m,n)h(x…

jmeter中重定向多個正則表達式_2020年jmeter技術實戰續集,最新技術全棧,值得收藏

在上一篇&#xff1a;主要介紹線程組、HTTP請求默認值、用戶定義的變量、固定定時器的應用場景及實戰。以下主要介紹正則表達式提取器、調式取樣器(Debug Sampler)、響應斷言、HTTP信息頭管理器的應用場景及實戰。一、正則表達式提取器1、使用場景從請求的響應結果中取到需要的…

[置頂] 均衡音效

[置頂] 均衡音效 1均衡的作用 均衡器是一種可以分別調節各種頻率成分電信號放大量的電子設備&#xff0c;通過對各種不同頻率的電信號的調節來補償揚聲器和聲場的缺陷&#xff0c;補償和修飾各種聲源及其它特殊作用。具體來說&#xff0c;它的作用如下&#xff1a; &#xff08…

html5之web worker

Web Worker 在本文中 與 Web Worker 進行雙向通信WindowTimers在 IE10 Platform Preview 4 中對 Web Worker 的更新API 參考示例和教程有關 Internet Explorer 的 Test Drive 演示IEBlog 文章規范相關主題Internet Explorer 10 和使用 JavaScript 的 Windows 應用商店應用引入了…

第4章 Python 數字圖像處理(DIP) - 頻率域濾波9 - 頻率域濾波基礎、頻率域的濾波過程、低通、高通

目錄頻率域濾波基礎頻率域的其他特性頻率域濾波基礎知識頻率域濾波步驟小結空間域和頻率域濾波之間的對應關系頻率域濾波基礎 頻率域的其他特性 頻率域中的濾波過程如下&#xff1a; 首先修改傅里葉變換以在到特定目的然后計算IDFT&#xff0c;返回到空間域 # 頻率域中的其…

C# :試玩EventLog

1. 專門創建Source的Log   創建了Source&#xff0c;log顯示在 Event viewer/Applications and Services logs/ 自定義Source 中&#xff0c;待遇比較高&#xff0c;專門顯示的。 創建Source需要管理員身份&#xff0c;否則Crash。 如果已經打開了 Computer Management,請關閉…

css 宋體_Java前端基礎(一)之html/css

1.1 htmlHTML:超文本標記語言(Hyper Text Markup Language)&#xff0c;標準通用標記語言下的一個應用。HTML 不是一種編程語言&#xff0c;而是一種標記語言 (markup language)&#xff0c;是網頁制作所必備的WEB開發工具&#xff1a;hbuilder/webstorm/vs code/eclpise最簡單…

View Controller Programming Guide for iOS---(七)---Resizing the View Controller’s Views

Resizing the View Controller’s Views A view controller owns its own view and manages the view’s contents. In the process, the view controller also manages the view’s subviews. But in most cases, the view’s frame is not set directly by the view controll…

基于百度地圖js進行地理定位

http://www.mengxiangchaoren.com/jquery.select.position.min.js 使用方法 $("#myCity").renderSelect({posByGps:true,bdAk:BD_AK});轉載于:https://www.cnblogs.com/Brose/p/jquery_select_position.html

C#接口-接口作用

C#接口是一個讓很多初學C#者容易迷糊的東西&#xff0c;用起來好像很簡單&#xff0c;定義接口&#xff0c;里面包含方法&#xff0c;但沒有方法具體實現的代碼&#xff0c;然后在繼承該接口的類里面要實現接口的所有方法的代碼&#xff0c;但沒有真正認識到接口的作用的時候就…

gpio的8種工作模式_Stm32之GPIO工作模式簡介

GPIO的8種工作模式GPIO初始化結構體的時候&#xff0c;必須要配置合適的工作模式&#xff0c;這樣才能使得IO口發揮應有的作用。工作模式大體上共分為輸入輸出兩類&#xff0c;共8種&#xff0c;下面將介紹這8種工作模式。GPIO工作模式輸入模式GPIO_Mode_AIN 模擬輸入 GPIO_Mod…

vagrant,流浪漢,我又來啦。

最近學個DEVOPS2.0&#xff0c;講微服務&#xff0c;容器華&#xff0c;持續部署&#xff0c;很到位&#xff0c;就一個一個工具擼一擼。。。 vagrant&#xff0c;以前接觸過&#xff0c;所以上手快&#xff0c;&#xff0c;哈哈&#xff0c;&#xff0c;用時再具體配置。 virt…

dedecms最新版本修改任意管理員漏洞

此漏洞無視gpc轉義&#xff0c;過80sec注入防御。 補充下&#xff0c;不用擔心后臺找不到。這只是一個demo&#xff0c;都能修改任意數據庫了&#xff0c;還怕拿不到SHELL&#xff1f; 起因是全局變量$GLOBALS可以被任意修改&#xff0c;隨便看了下&#xff0c;漏洞一堆&#x…

第4章 Python 數字圖像處理(DIP) - 頻率域濾波10 - 使用低通頻率域濾波器平滑圖像 - 理想、高斯、巴特沃斯低通濾波器

目錄使用低通頻率域濾波器平滑圖像理想低通濾波器(ILPF)高斯低通濾波器(GLPF)巴特沃斯低通濾波器低通濾波的例子使用低通頻率域濾波器平滑圖像 理想低通濾波器(ILPF) 在以原點為中心的一個圓內無衰減地通過所有頻率&#xff0c;而在這個圓外“截止”所有的頻率的二維低通濾波…

vs2008中combox用法總結

1、判斷是否為空 m_CheckPoint.GetCurSel()-1; 2、清空 m_CheckPoint.ResetContent(); 3、添加 m_CheckPoint.AddString(str); 4、獲取某一索引的值 m_CheckPoint.GetLBText(j,str1);//j為索引&#xff0c;str1為存儲變量 5、刪除某一索引的值 m_CheckPoint.DeleteString(j);//…

bluecam連接步驟說明_廠家詳解旋片式真空泵使用說明

旋片式真空泵是有區分單雙極高速直聯結構的真空泵&#xff0c;是用來對密封容器抽除氣體的基本設備之一。旋片式真空泵的泵與電機連軸&#xff0c;有著高轉速、外型小、結構緊湊、流動性工作方便的優點。本文所使用旋片式真空泵使用說明資料&#xff0c;是臺冠真空泵技術團隊工…

python函數中可變參數的傳遞方式是_Python函數可變參數定義及其參數傳遞方式實例詳解...

本文實例講述了Python函數可變參數定義及其參數傳遞方式。分享給大家供大家參考。具體分析如下&#xff1a; python中 函數不定參數的定義形式如下&#xff1a; 1、func(*args) 傳入的參數為以元組形式存在args中&#xff0c;如&#xff1a; def func(*args): print args >&…

加載中做法

一個網頁在加載時&#xff0c;可給靜態部分加個加載中&#xff0c;而動態部分也即是真正內容用jq來改&#xff0c;這樣就有那個效果了轉載于:https://www.cnblogs.com/yedeying/p/3618815.html

Junit4常用注解

Junit4注解 JUnit4的測試類不用再繼承TestCase類了。使用注解會方便很多。 Before&#xff1a;初始化方法After&#xff1a;釋放資源Test&#xff1a;測試方法&#xff0c;在這里可以測試期望異常和超時時間Ignore&#xff1a;忽略的測試方法BeforeClass&#xff1a;針對所有測…

第4章 Python 數字圖像處理(DIP) - 頻率域濾波11 - 使用高通濾波器銳化圖像

目錄使用高通濾波器銳化圖像由低通濾波器得到理想、高斯和巴特沃斯高通濾波器指紋增強頻域中的拉普拉斯鈍化掩蔽、高提升濾波和高頻強調濾波同態濾波使用高通濾波器銳化圖像 由低通濾波器得到理想、高斯和巴特沃斯高通濾波器 HHP(u,v)1?HLP(u,v)(4.118)H_{HP}(u, v) 1 - H_{…