- 什么是ANR?
ANR——Application Not Responding,就是应用程序无响应的意思,导致此错误通常是由于android主线程中的一个操作执行时间过长,当超过5秒不能响应用户操作时,便出现此异常。
- 如何调试ANR?(常规log + traces)
1. 根据log跟踪 ANR 错误是首先想到的方法,出现ANR错误时,在DDMS中键入 “ANR” 关键词,搜索到关键信息如下:
通过“ANR in com.android.mms (com.android.mms/.ui.ComposeMessageActivity)”这一句可以判断ANR发生在哪个类,但还无法具体到类中的哪个位置。
2. 通过traces进一步确定ANR在主线程代码段的位置。
从以上log中我们可以发现,其虚拟跟踪信息(traces)在/data/anr/traces.txt文件中,于是我们可以从android系统目录中pull 出traces信息,其中我们只需关注信息中的主线程部分,这里我们可以跟踪到ANR发生的所有代码段位置,关键信息如下:
----- pid 4643 at 2013-02-19 09:30:15 -----
Cmd line: com.android.mms
DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x40a41460 self=0x12830
| sysTid=4643 nice=0 sched=0/0 cgrp=default handle=1074484360
| schedstat=( 3046338809 1442990863 4584 ) utm=231 stm=73 core=0
at android.os.BinderProxy.transact(Native Method)
at android.content.ContentProviderProxy.delete(ContentProviderNative.java:477)
at android.content.ContentResolver.delete(ContentResolver.java:822)
at com.google.android.mms.util.SqliteWrapper.delete(SqliteWrapper.java:102)
at com.android.mms.util.pdu.PduPersister.updateParts(PduPersister.java:1136)
at com.android.mms.ui.ComposeMessageActivity.updateTemporaryMmsMessage(ComposeMessageActivity.java:5327)
at com.android.mms.ui.ComposeMessageActivity.onCreate(ComposeMessageActivity.java:1114)
at android.app.Activity.performCreate(Activity.java:4465)
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1049)
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:1920)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:1981)
at android.app.ActivityThread.access$600(ActivityThread.java:123)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1147)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:137)
at android.app.ActivityThread.main(ActivityThread.java:4424)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:511)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
at dalvik.system.NativeStart.main(Native Method)
"Binder Thread #3" prio=5 tid=11 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x413b8228 self=0x249850
| sysTid=4659 nice=0 sched=0/0 cgrp=default handle=2409128
| schedstat=( 14394770 31601688 74 ) utm=0 stm=1 core=1
at dalvik.system.NativeStart.run(Native Method)
"Binder Thread #2" prio=5 tid=10 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x4132d578 self=0x1d9c00
| sysTid=4655 nice=0 sched=0/0 cgrp=default handle=2036400
| schedstat=( 14471462 45496768 80 ) utm=1 stm=0 core=0
at dalvik.system.NativeStart.run(Native Method)
"Binder Thread #1" prio=5 tid=9 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x4132c310 self=0x1301f8
| sysTid=4654 nice=0 sched=0/0 cgrp=default handle=1820784
| schedstat=( 20176387 45620614 99 ) utm=0 stm=2 core=0
at dalvik.system.NativeStart.run(Native Method)
"FinalizerWatchdogDaemon" daemon prio=5 tid=8 TIMED_WAIT
| group="main" sCount=1 dsCount=0 obj=0x41329058 self=0x192d88
| sysTid=4653 nice=0 sched=0/0 cgrp=default handle=1820448
| schedstat=( 4016231 26680923 29 ) utm=0 stm=0 core=1
at java.lang.VMThread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:1031)
at java.lang.Thread.sleep(Thread.java:1013)
at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:213)
at java.lang.Thread.run(Thread.java:856)
"FinalizerDaemon" daemon prio=5 tid=7 WAIT
| group="main" sCount=1 dsCount=0 obj=0x41328f00 self=0x1e60e8
| sysTid=4652 nice=0 sched=0/0 cgrp=default handle=1954272
| schedstat=( 49894771 22048696 51 ) utm=4 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x40a375d0> (a java.lang.ref.ReferenceQueue)
at java.lang.Object.wait(Object.java:401)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:168)
at java.lang.Thread.run(Thread.java:856)
"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
| group="main" sCount=1 dsCount=0 obj=0x41328d98 self=0x1f3bc8
| sysTid=4651 nice=0 sched=0/0 cgrp=default handle=2004936
| schedstat=( 4019465 10248616 64 ) utm=0 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x40a374f8>
at java.lang.Object.wait(Object.java:364)
at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:128)
at java.lang.Thread.run(Thread.java:856)
"Compiler" daemon prio=5 tid=5 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x41328ca8 self=0x97c20
| sysTid=4650 nice=0 sched=0/0 cgrp=default handle=1987992
| schedstat=( 381418863 78958694 2470 ) utm=27 stm=11 core=0
at dalvik.system.NativeStart.run(Native Method)
"JDWP" daemon prio=5 tid=4 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x41328bc0 self=0x9aac8
| sysTid=4649 nice=0 sched=0/0 cgrp=default handle=1779192
| schedstat=( 3926772 18867998 15 ) utm=0 stm=0 core=1
at dalvik.system.NativeStart.run(Native Method)
"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
| group="system" sCount=0 dsCount=0 obj=0x41328ac8 self=0x1f09e8
| sysTid=4647 nice=0 sched=0/0 cgrp=default handle=1958480
| schedstat=( 463385 5608077 4 ) utm=0 stm=0 core=1
at dalvik.system.NativeStart.run(Native Method)
"GC" daemon prio=5 tid=2 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x413289e8 self=0xa6310
| sysTid=4645 nice=0 sched=0/0 cgrp=default handle=1957976
| schedstat=( 183059235 86740380 82 ) utm=16 stm=2 core=1
at dalvik.system.NativeStart.run(Native Method)
----- end 4643 -----
Cmd line: com.android.mms
DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x40a41460 self=0x12830
| sysTid=4643 nice=0 sched=0/0 cgrp=default handle=1074484360
| schedstat=( 3046338809 1442990863 4584 ) utm=231 stm=73 core=0
at android.os.BinderProxy.transact(Native Method)
at android.content.ContentProviderProxy.delete(ContentProviderNative.java:477)
at android.content.ContentResolver.delete(ContentResolver.java:822)
at com.google.android.mms.util.SqliteWrapper.delete(SqliteWrapper.java:102)
at com.android.mms.util.pdu.PduPersister.updateParts(PduPersister.java:1136)
at com.android.mms.ui.ComposeMessageActivity.updateTemporaryMmsMessage(ComposeMessageActivity.java:5327)
at com.android.mms.ui.ComposeMessageActivity.onCreate(ComposeMessageActivity.java:1114)
at android.app.Activity.performCreate(Activity.java:4465)
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1049)
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:1920)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:1981)
at android.app.ActivityThread.access$600(ActivityThread.java:123)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1147)
at android.os.Handler.dispatchMessage(Handler.java:99)
at android.os.Looper.loop(Looper.java:137)
at android.app.ActivityThread.main(ActivityThread.java:4424)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:511)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
at dalvik.system.NativeStart.main(Native Method)
"Binder Thread #3" prio=5 tid=11 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x413b8228 self=0x249850
| sysTid=4659 nice=0 sched=0/0 cgrp=default handle=2409128
| schedstat=( 14394770 31601688 74 ) utm=0 stm=1 core=1
at dalvik.system.NativeStart.run(Native Method)
"Binder Thread #2" prio=5 tid=10 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x4132d578 self=0x1d9c00
| sysTid=4655 nice=0 sched=0/0 cgrp=default handle=2036400
| schedstat=( 14471462 45496768 80 ) utm=1 stm=0 core=0
at dalvik.system.NativeStart.run(Native Method)
"Binder Thread #1" prio=5 tid=9 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x4132c310 self=0x1301f8
| sysTid=4654 nice=0 sched=0/0 cgrp=default handle=1820784
| schedstat=( 20176387 45620614 99 ) utm=0 stm=2 core=0
at dalvik.system.NativeStart.run(Native Method)
"FinalizerWatchdogDaemon" daemon prio=5 tid=8 TIMED_WAIT
| group="main" sCount=1 dsCount=0 obj=0x41329058 self=0x192d88
| sysTid=4653 nice=0 sched=0/0 cgrp=default handle=1820448
| schedstat=( 4016231 26680923 29 ) utm=0 stm=0 core=1
at java.lang.VMThread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:1031)
at java.lang.Thread.sleep(Thread.java:1013)
at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:213)
at java.lang.Thread.run(Thread.java:856)
"FinalizerDaemon" daemon prio=5 tid=7 WAIT
| group="main" sCount=1 dsCount=0 obj=0x41328f00 self=0x1e60e8
| sysTid=4652 nice=0 sched=0/0 cgrp=default handle=1954272
| schedstat=( 49894771 22048696 51 ) utm=4 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x40a375d0> (a java.lang.ref.ReferenceQueue)
at java.lang.Object.wait(Object.java:401)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:168)
at java.lang.Thread.run(Thread.java:856)
"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
| group="main" sCount=1 dsCount=0 obj=0x41328d98 self=0x1f3bc8
| sysTid=4651 nice=0 sched=0/0 cgrp=default handle=2004936
| schedstat=( 4019465 10248616 64 ) utm=0 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x40a374f8>
at java.lang.Object.wait(Object.java:364)
at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:128)
at java.lang.Thread.run(Thread.java:856)
"Compiler" daemon prio=5 tid=5 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x41328ca8 self=0x97c20
| sysTid=4650 nice=0 sched=0/0 cgrp=default handle=1987992
| schedstat=( 381418863 78958694 2470 ) utm=27 stm=11 core=0
at dalvik.system.NativeStart.run(Native Method)
"JDWP" daemon prio=5 tid=4 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x41328bc0 self=0x9aac8
| sysTid=4649 nice=0 sched=0/0 cgrp=default handle=1779192
| schedstat=( 3926772 18867998 15 ) utm=0 stm=0 core=1
at dalvik.system.NativeStart.run(Native Method)
"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
| group="system" sCount=0 dsCount=0 obj=0x41328ac8 self=0x1f09e8
| sysTid=4647 nice=0 sched=0/0 cgrp=default handle=1958480
| schedstat=( 463385 5608077 4 ) utm=0 stm=0 core=1
at dalvik.system.NativeStart.run(Native Method)
"GC" daemon prio=5 tid=2 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x413289e8 self=0xa6310
| sysTid=4645 nice=0 sched=0/0 cgrp=default handle=1957976
| schedstat=( 183059235 86740380 82 ) utm=16 stm=2 core=1
at dalvik.system.NativeStart.run(Native Method)
----- end 4643 -----