如何分析解决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) --主要类型

按键或触摸事件在特定时间内无响应

2：BroadcastTimeout(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

1：UI线程尽量只做跟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.mzph.cn/news/260710.shtml

如若内容造成侵权/违法违规/事实不符，请联系多彩编程网进行投诉反馈email:809451989@qq.com，一经查实，立即删除！

相关文章

第4章 Python 数字图像处理(DIP) - 频率域滤波8 - 二维DFT和IDFT的一些性质 - 二维离散卷积定理

第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技术实战续集，最新技术全栈，值得收藏

jmeter中重定向多个正则表达式_2020年jmeter技术实战续集，最新技术全栈，值得收藏

在上一篇&#xff1a;主要介绍线程组、HTTP请求默认值、用户定义的变量、固定定时器的应用场景及实战。以下主要介绍正则表达式提取器、调式取样器(Debug Sampler)、响应断言、HTTP信息头管理器的应用场景及实战。一、正则表达式提取器1、使用场景从请求的响应结果中取到需要的…
阅读更多...
[置顶] 均衡音效

[置顶] 均衡音效

[置顶] 均衡音效 1均衡的作用 均衡器是一种可以分别调节各种频率成分电信号放大量的电子设备&#xff0c;通过对各种不同频率的电信号的调节来补偿扬声器和声场的缺陷&#xff0c;补偿和修饰各种声源及其它特殊作用。具体来说&#xff0c;它的作用如下&#xff1a; &#xff08…
阅读更多...
html5之web worker

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 - 频率域滤波基础、频率域的滤波过程、低通、高通

第4章 Python 数字图像处理(DIP) - 频率域滤波9 - 频率域滤波基础、频率域的滤波过程、低通、高通

目录频率域滤波基础频率域的其他特性频率域滤波基础知识频率域滤波步骤小结空间域和频率域滤波之间的对应关系频率域滤波基础 频率域的其他特性 频率域中的滤波过程如下&#xff1a; 首先修改傅里叶变换以在到特定目的然后计算IDFT&#xff0c;返回到空间域 # 频率域中的其…
阅读更多...
C# ：试玩EventLog

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

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

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进行地理定位

基于百度地图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#接口是一个让很多初学C#者容易迷糊的东西&#xff0c;用起来好像很简单&#xff0c;定义接口&#xff0c;里面包含方法&#xff0c;但没有方法具体实现的代码&#xff0c;然后在继承该接口的类里面要实现接口的所有方法的代码&#xff0c;但没有真正认识到接口的作用的时候就…
阅读更多...
gpio的8种工作模式_Stm32之GPIO工作模式简介

gpio的8种工作模式_Stm32之GPIO工作模式简介

GPIO的8种工作模式GPIO初始化结构体的时候&#xff0c;必须要配置合适的工作模式&#xff0c;这样才能使得IO口发挥应有的作用。工作模式大体上共分为输入输出两类&#xff0c;共8种&#xff0c;下面将介绍这8种工作模式。GPIO工作模式输入模式GPIO_Mode_AIN 模拟输入 GPIO_Mod…
阅读更多...
vagrant，流浪汉，我又来啦。

vagrant，流浪汉，我又来啦。

最近学个DEVOPS2.0&#xff0c;讲微服务&#xff0c;容器华&#xff0c;持续部署&#xff0c;很到位&#xff0c;就一个一个工具撸一撸。。。 vagrant&#xff0c;以前接触过&#xff0c;所以上手快&#xff0c;&#xff0c;哈哈&#xff0c;&#xff0c;用时再具体配置。 virt…
阅读更多...
dedecms最新版本修改任意管理员漏洞

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

此漏洞无视gpc转义&#xff0c;过80sec注入防御。 补充下&#xff0c;不用担心后台找不到。这只是一个demo&#xff0c;都能修改任意数据库了&#xff0c;还怕拿不到SHELL&#xff1f; 起因是全局变量$GLOBALS可以被任意修改&#xff0c;随便看了下&#xff0c;漏洞一堆&#x…
阅读更多...
第4章 Python 数字图像处理(DIP) - 频率域滤波10 - 使用低通频率域滤波器平滑图像 - 理想、高斯、巴特沃斯低通滤波器

第4章 Python 数字图像处理(DIP) - 频率域滤波10 - 使用低通频率域滤波器平滑图像 - 理想、高斯、巴特沃斯低通滤波器

目录使用低通频率域滤波器平滑图像理想低通滤波器(ILPF)高斯低通滤波器(GLPF)巴特沃斯低通滤波器低通滤波的例子使用低通频率域滤波器平滑图像 理想低通滤波器(ILPF) 在以原点为中心的一个圆内无衰减地通过所有频率&#xff0c;而在这个圆外“截止”所有的频率的二维低通滤波…
阅读更多...
vs2008中combox用法总结

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连接步骤说明_厂家详解旋片式真空泵使用说明

bluecam连接步骤说明_厂家详解旋片式真空泵使用说明

旋片式真空泵是有区分单双极高速直联结构的真空泵&#xff0c;是用来对密封容器抽除气体的基本设备之一。旋片式真空泵的泵与电机连轴&#xff0c;有着高转速、外型小、结构紧凑、流动性工作方便的优点。本文所使用旋片式真空泵使用说明资料&#xff0c;是台冠真空泵技术团队工…
阅读更多...
python函数中可变参数的传递方式是_Python函数可变参数定义及其参数传递方式实例详解...

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注解 JUnit4的测试类不用再继承TestCase类了。使用注解会方便很多。 Before&#xff1a;初始化方法After&#xff1a;释放资源Test&#xff1a;测试方法&#xff0c;在这里可以测试期望异常和超时时间Ignore&#xff1a;忽略的测试方法BeforeClass&#xff1a;针对所有测…
阅读更多...
第4章 Python 数字图像处理(DIP) - 频率域滤波11 - 使用高通滤波器锐化图像

第4章 Python 数字图像处理(DIP) - 频率域滤波11 - 使用高通滤波器锐化图像

目录使用高通滤波器锐化图像由低通滤波器得到理想、高斯和巴特沃斯高通滤波器指纹增强频域中的拉普拉斯钝化掩蔽、高提升滤波和高频强调滤波同态滤波使用高通滤波器锐化图像 由低通滤波器得到理想、高斯和巴特沃斯高通滤波器 HHP(u,v)1−HLP(u,v)(4.118)H_{HP}(u, v) 1 - H_{…
阅读更多...
最新文章

Copyright @ 2022~2023