我有一个 VOIP 应用程序,引擎部分是 C(NDK) 级别。在随机使用应用程序时,我以指向“在 android.os.MessageQueue.nativePollOnce(Native Method)”的 ANR 结束。
使用android-ndk-r5
ANR 跟踪:
----- pid 13735 at 2013-05-23 15:56:47 -----
Cmd line: com.myapp.voip
DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x41315508 self=0x413058e8
| sysTid=13735 nice=0 sched=0/0 cgrp=apps handle=1074442032
| schedstat=( 23115964360 3706387400 21258 ) utm=1651 stm=660 core=3
#00 pc 0000da70 /system/lib/libc.so (epoll_wait+12)
#01 pc 00014899 /system/lib/libutils.so (android::Looper::pollInner(int)+96)
#02 pc 00014b01 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
#03 pc 00063443 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
#04 pc 0001de70 /system/lib/libdvm.so (dvmPlatformInvoke+112)
#05 pc 0004d0c3 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394)
#06 pc 000272a0 /system/lib/libdvm.so
#07 pc 0002bba8 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+180)
#08 pc 0005faf7 /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+374)
#09 pc 0006709d /system/lib/libdvm.so
#10 pc 000272a0 /system/lib/libdvm.so
#11 pc 0002bba8 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+180)
#12 pc 0005f831 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
#13 pc 000496b3 /system/lib/libdvm.so
#14 pc 0004c451 /system/lib/libandroid_runtime.so
#15 pc 0004d557 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+390)
#16 pc 00000dcf /system/bin/app_process
#17 pc 00017123 /system/lib/libc.so (__libc_init+38)
#18 pc 00000b34 /system/bin/app_process
at android.os.MessageQueue.nativePollOnce(Native Method)
at android.os.MessageQueue.next(MessageQueue.java:125)
at android.os.Looper.loop(Looper.java:124)
at android.app.ActivityThread.main(ActivityThread.java:4898)
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:1006)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:773)
at dalvik.system.NativeStart.main(Native Method)
编辑于 2013 年 5 月 6 日亚行日志
05-23 15:56:27.704 E/BufferQueue( 1900): [com.myapp.voip/com.myapp.voip.SettingsActivity] dequeueBuffer: SurfaceTexture has been abandoned!
05-23 15:56:27.704 E/SurfaceTextureClient(13735): dequeueBuffer failed (No such device)
05-23 15:56:27.719 E/ViewRootImpl(13735): Could not lock surface
05-23 15:56:27.719 E/ViewRootImpl(13735): java.lang.IllegalArgumentException
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.Surface.lockCanvasNative(Native Method)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.Surface.lockCanvas(Surface.java:88)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.ViewRootImpl.drawSoftware(ViewRootImpl.java:2312)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.ViewRootImpl.draw(ViewRootImpl.java:2275)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.ViewRootImpl.performDraw(ViewRootImpl.java:2143)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.ViewRootImpl.performTraversals(ViewRootImpl.java:1954)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.ViewRootImpl.doTraversal(ViewRootImpl.java:1110)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.ViewRootImpl$TraversalRunnable.run(ViewRootImpl.java:4470)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.Choreographer$CallbackRecord.run(Choreographer.java:725)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.Choreographer.doCallbacks(Choreographer.java:555)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.Choreographer.doFrame(Choreographer.java:525)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:711)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.os.Handler.handleCallback(Handler.java:615)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.os.Handler.dispatchMessage(Handler.java:92)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.os.Looper.loop(Looper.java:137)
05-23 15:56:27.719 E/ViewRootImpl(13735): at android.app.ActivityThread.main(ActivityThread.java:4898)
05-23 15:56:27.719 E/ViewRootImpl(13735): at java.lang.reflect.Method.invokeNative(Native Method)
05-23 15:56:27.719 E/ViewRootImpl(13735): at java.lang.reflect.Method.invoke(Method.java:511)
05-23 15:56:27.719 E/ViewRootImpl(13735): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1006)
05-23 15:56:27.719 E/ViewRootImpl(13735): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:773)
05-23 15:56:27.719 E/ViewRootImpl(13735): at dalvik.system.NativeStart.main(Native Method)
05-23 15:56:27.869 D/STATUSBAR-NetworkController( 2535): onDataActivity: direction=3
05-23 15:56:27.874 D/STATUSBAR-NetworkController( 2535): refreshSignalCluster:2
05-23 15:56:27.874 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:27.879 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:27.879 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:45.014 D/STATUSBAR-NetworkController( 2535): onDataActivity: direction=0
05-23 15:56:45.019 D/STATUSBAR-NetworkController( 2535): refreshSignalCluster:2
05-23 15:56:45.019 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:45.024 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:45.024 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:46.024 D/STATUSBAR-NetworkController( 2535): onDataActivity: direction=2
05-23 15:56:46.029 D/STATUSBAR-NetworkController( 2535): refreshSignalCluster:2
05-23 15:56:46.029 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:46.029 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:46.029 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:46.674 I/InputReader( 2272): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1171 ]
05-23 15:56:46.729 I/InputReader( 2272): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=]
05-23 15:56:46.854 I/InputReader( 2272): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1172 ]
05-23 15:56:46.899 I/InputReader( 2272): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=]
05-23 15:56:47.004 I/InputReader( 2272): Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1173 ]
05-23 15:56:47.029 D/STATUSBAR-NetworkController( 2535): onDataActivity: direction=0
05-23 15:56:47.029 D/STATUSBAR-NetworkController( 2535): refreshSignalCluster:2
05-23 15:56:47.029 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:47.029 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:47.029 D/STATUSBAR-SignalClusterView( 2535): mSeparateMobileGroup=0
05-23 15:56:47.044 I/InputReader( 2272): Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=]
05-23 15:56:47.074 I/InputDispatcher( 2272): Application is not responding. It has been 20018.8ms since event, 20018.4ms since wait started. Reason: Waiting because there is no touchable window that can handle the event but there is focused application that may eventually add a new window when it finishes starting up.
05-23 15:56:47.149 I/Process ( 2272): Sending signal. PID: 13735 SIG: 3
05-23 15:56:47.149 I/dalvikvm(13735): threadid=3: reacting to signal 3
05-23 15:56:47.189 I/dalvikvm(13735): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:47.189 I/Process ( 2272): Sending signal. PID: 2272 SIG: 3
05-23 15:56:47.189 I/dalvikvm( 2272): threadid=3: reacting to signal 3
05-23 15:56:47.779 E/uevent.c( 2272): !@uevent_next_event: poll - nr=-1, fds.revents=0x0
05-23 15:56:47.869 E/Sensors ( 2272): poll() failed (Interrupted system call)
05-23 15:56:47.889 I/Process ( 2272): Sending signal. PID: 2719 SIG: 3
05-23 15:56:47.889 I/dalvikvm( 2719): threadid=3: reacting to signal 3
05-23 15:56:47.899 I/dalvikvm( 2272): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:47.899 I/Process ( 2272): Sending signal. PID: 2535 SIG: 3
05-23 15:56:47.899 I/dalvikvm( 2535): threadid=3: reacting to signal 3
05-23 15:56:47.984 I/dalvikvm( 2535): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:47.984 I/Process ( 2272): Sending signal. PID: 2556 SIG: 3
05-23 15:56:47.984 I/dalvikvm( 2556): threadid=3: reacting to signal 3
05-23 15:56:47.994 I/dalvikvm( 2719): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:47.994 I/Process ( 2272): Sending signal. PID: 2736 SIG: 3
05-23 15:56:47.994 I/dalvikvm( 2736): threadid=3: reacting to signal 3
05-23 15:56:48.024 I/dalvikvm( 2736): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:48.024 I/Process ( 2272): Sending signal. PID: 2751 SIG: 3
05-23 15:56:48.024 I/dalvikvm( 2751): threadid=3: reacting to signal 3
05-23 15:56:48.024 I/dalvikvm( 2556): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:48.024 I/Process ( 2272): Sending signal. PID: 2765 SIG: 3
05-23 15:56:48.024 I/dalvikvm( 2765): threadid=3: reacting to signal 3
05-23 15:56:48.049 I/dalvikvm( 2751): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:48.059 I/dalvikvm( 2765): Wrote stack traces to '/data/anr/traces.txt'
05-23 15:56:48.459 D/dalvikvm( 2272): GC_CONCURRENT freed 2075K, 7% free 94406K/100551K, paused 23ms+36ms, total 240ms
05-23 15:56:48.459 D/dalvikvm( 2272): WAIT_FOR_CONCURRENT_GC blocked 201ms
05-23 15:56:48.594 D/dalvikvm( 2272): WAIT_FOR_CONCURRENT_GC blocked 0ms
05-23 15:56:48.824 D/dalvikvm( 2272): GC_EXPLICIT freed 737K, 6% free 94612K/100551K, paused 5ms+38ms, total 227ms
05-23 15:56:49.409 W/PowerManagerService( 2272): Timer 0x3->0x3|0x0
05-23 15:56:49.409 D/PowerManagerService( 2272): setTimeoutLocked::SmartSleep : after589500
05-23 15:56:49.414 E/android.os.Debug( 2272): !@Dumpstate > dumpstate -k -t -z -d -o /data/log/dumpstate_app_anr
不确定此时哪个线程卡住了。这里发生了什么?