android - ANR en el uso aleatorio de la aplicación
android-activity libc (1)
Tengo una aplicación VOIP y la parte del motor es C (NDK) Level. En el uso aleatorio de la aplicación, termino con un ANR que apunta a "at android.os.MessageQueue.nativePollOnce (Native Method)" .
Usando android-ndk-r5
Rastros de 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)
Editar en 05-06-2013 ADB Logs
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
No estoy seguro de qué hilo está atascado en este punto. ¿Que está pasando aqui?
Creo que la mejor respuesta posible a su problema es que está haciendo algo con la superficie en el código nativo.
Especialmente si está desarrollando alguna función de videollamada SIP.
Si el código nativo no maneja correctamente el bloqueo del lienzo / superficie, tendrá este problema.
Como es posible que no pueda mostrar aquí su código fuente, solo puedo recomendarle que compruebe si algún código está accediendo a la superficie en un hilo Java nativo u otro.