Logo Questions Linux Laravel Mysql Ubuntu Git Menu
HTML CSS JAVASCRIPT SQL PYTHON PHP BOOTSTRAP JAVA JQUERY R React Kotlin
 

ANR in random usage of application

Tags:

android

android-activity

libc

android-anr-dialog

android-ndk-r5

I have an VOIP application and the engine part is C(NDK) Level.On random usage of application i end with an ANR pointing to " at android.os.MessageQueue.nativePollOnce(Native Method)".
Using android-ndk-r5

ANR Traces:

----- 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)

Edit on 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

Not sure which thread is stuck at this point. Whats going on here?

like image 861
NitZRobotKoder Avatar asked May 30 '13 14:05

NitZRobotKoder

People also ask

What is ANR used for in Android?

Application Not Responding (ANR) errors are triggered when the UI thread of the application is not responding for more than 5 seconds. You can read more about ANRs and diagnosing ANRs in the Android documentation. Additionally, Crashlytics can help pinpoint specific problematic threads.

What is ANR and how can a developer avoid it?

An ANR occurs when an app takes too long to process the broadcast message. An ANR occurs in the following cases: A broadcast receiver hasn't finished executing its onReceive() method within a considerable amount of time.

What is ANR and how it is different from crashes?

The difference between a crash and an ANR is that a crash is a code exception whereas an ANR is an ongoing state of nonresponsiveness. So when a crash happens, the app itself terminates. When an ANR happens, the user simply cannot do anything in the app and will eventually force quit it.

How do you investigate ANR?

A good way to try to detect the problem is by fetching the file /data/anr/traces. txt which is generated after a ANR happens on a device (beware that it is overridden after another ANR happens). That offers you a overview of what each thread was doing at the time of the ANR.

1 Answers

I think the most possible answer to your problem is that you are doing something with the surface in native code.

Especially if you are developing some SIP video call feature.

If the native code does not handle the locking of the canvas/surface correctly, you will have this problem.

Since you might not able to show your souce code here, I can only recommend you to check if any code is accessing the surface in native or other Java thread.

like image 120
Robin Avatar answered Sep 20 '22 21:09

Robin
Sign in to Comment

Related questions

How to Start the Vuforia AR sample App android?
CordovaWebView: TIMEOUT ERROR
Using SystemUiHider to keep the navigation bar hidden
How do I install APK using Android updater script
Android: extend Linearlayout, but need same for RelativeLayout. Duplicate code unavoidable?
In-app price format for Google Analytics
Singleton vs a static inner class for Database Helper class in Android
isItemChecked always returns the opposite of what it is supposed to when inside an onItemClickListener?
Intent.ACTION_VIEW - Multiple files
Android NumberPicker, DatePicker, TimePicker arrows are missing
irrlicht android on opengl es 2.0 driver
Importing Existing Android Project into Eclipse
Image in Widget
Loadmanager onLoadFinished not called
How to launch android application from URL in android?
Best practices for audio streaming
Google + Sign In: Activity won't start
Android Project - Something messed up my .classpath files (Eclipse 4.2? Eclipse 3.8?)
playing HLS on Android (compare alternatives)
How to get the qualifiers for a given resource (when using it)?

Donate For Us

If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!