Random rare freezes - trying to figure out possible causes

Hi

This one has my puzzled. Some of my users are reporting intermittent app freezes (requiring them to kill the app and restart). So far I've not been able to determine any commonality to the freezes (I only got a few reports but enough to be concerned) and I'm still requesting more information from those users. But I wanted to ask around about common causes for a sudden app freeze.

I know I'm not performing long running stuff in the UI thread, I'm diligently updating anything that gets close to the UI in the UI thread, I'm not using any locks that could deadlock, I'm not running any tasks that could run amock using up all CPU time, so I'm wondering "what else?". Also, is there a way for a user to gather information as to where exactly the app got stuck (method/line) when they kill it?

Regards
Stephan

Posts

  • Just my luck - I actually saw one myself. But unlike my customers I've got an ANR log (my customer runs a locked down device in kiosk mode.. I'm wondering if that actually disables the the screen to kill a non responsive app). This is the output

    
    ----- pid 23146 at 2013-08-14 22:35:04 -----
    Cmd line: ch.sunrise.smartappmobile
    
    JNI: CheckJNI is off; workarounds are off; pins=0; globals=658
    
    DALVIK THREADS:
    (mutexes: tll=0 tsl=0 tscl=0 ghl=0)
    
    "main" prio=5 tid=1 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x41963578 self=0x414ca120
      | sysTid=23146 nice=0 sched=0/0 cgrp=apps handle=1073844220
      | state=S schedstat=( 0 0 0 ) utm=334 stm=46 core=1
      #00  pc 0001c5d0  /system/lib/libc.so (__futex_syscall3+8)
      #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
      #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
      #03  pc 000c6d3c  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so
      at smartappmobileandroid.BaseTabActivity.n_onOptionsItemSelected(Native Method)
      at smartappmobileandroid.BaseTabActivity.onOptionsItemSelected(BaseTabActivity.java:140)
      at android.app.Activity.onMenuItemSelected(Activity.java:2566)
      at com.android.internal.policy.impl.PhoneWindow.onMenuItemSelected(PhoneWindow.java:986)
      at com.android.internal.view.menu.MenuBuilder.dispatchMenuItemSelected(MenuBuilder.java:735)
      at com.android.internal.view.menu.MenuItemImpl.invoke(MenuItemImpl.java:152)
      at com.android.internal.view.menu.MenuBuilder.performItemAction(MenuBuilder.java:874)
      at com.android.internal.view.menu.MenuPopupHelper.onItemClick(MenuPopupHelper.java:156)
      at android.widget.AdapterView.performItemClick(AdapterView.java:298)
      at android.widget.AbsListView.performItemClick(AbsListView.java:1100)
      at android.widget.AbsListView$PerformClick.run(AbsListView.java:2788)
      at android.widget.AbsListView$1.run(AbsListView.java:3463)
      at android.os.Handler.handleCallback(Handler.java:730)
      at android.os.Handler.dispatchMessage(Handler.java:92)
      at android.os.Looper.loop(Looper.java:137)
      at android.app.ActivityThread.main(ActivityThread.java:5103)
      at java.lang.reflect.Method.invokeNative(Native Method)
      at java.lang.reflect.Method.invoke(Method.java:525)
      at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737)
      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553)
      at dalvik.system.NativeStart.main(Native Method)
    
    "Binder_3" prio=5 tid=19 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x42308e10 self=0x76b0ffc0
      | sysTid=24318 nice=0 sched=0/0 cgrp=apps handle=1991358440
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=1
      #00  pc 0001b300  /system/lib/libc.so (__ioctl+8)
      #01  pc 0002b77b  /system/lib/libc.so (ioctl+14)
      #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
      #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
      #04  pc 0001fae9  /system/lib/libbinder.so
      #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
      #06  pc 0004b631  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
      #07  pc 00011581  /system/lib/libutils.so
      #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
      #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
      at dalvik.system.NativeStart.run(Native Method)
    
    "pool-1-thread-1" prio=5 tid=12 WAIT
      | group="main" sCount=1 dsCount=0 obj=0x422e59a8 self=0x76b071d0
      | sysTid=23340 nice=0 sched=0/0 cgrp=apps handle=1991281072
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
      at java.lang.Object.wait(Native Method)
      - waiting on <0x42201ec8> (a java.lang.VMThread) held by tid=12 (pool-1-thread-1)
      at java.lang.Thread.parkFor(Thread.java:1205)
      at sun.misc.Unsafe.park(Unsafe.java:325)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
      at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
      at java.lang.Thread.run(Thread.java:841)
    
    "Thread-594" prio=5 tid=18 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x422f82a0 self=0x7a162368
      | sysTid=23216 nice=0 sched=0/0 cgrp=apps handle=2048234600
      | state=S schedstat=( 0 0 0 ) utm=24 stm=5 core=0
      #00  pc 0001c5d0  /system/lib/libc.so (__futex_syscall3+8)
      #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
      #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
      #03  pc 000c6d3c  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so
      at dalvik.system.NativeStart.run(Native Method)
    
    "Thread-593" prio=5 tid=17 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x422e85c8 self=0x791736f8
      | sysTid=23203 nice=0 sched=0/0 cgrp=apps handle=2031646216
      | state=S schedstat=( 0 0 0 ) utm=3 stm=0 core=0
      #00  pc 0001c5d4  /system/lib/libc.so (__futex_syscall3+12)
      #01  pc 0002cad7  /system/lib/libc.so (sem_timedwait+146)
      #02  pc 001e22b8  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so (mono_sem_timedwait+184)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Thread-592" prio=5 tid=16 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x422e83b0 self=0x79d184b0
      | sysTid=23202 nice=0 sched=0/0 cgrp=apps handle=2031649536
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=1
      #00  pc 0001c408  /system/lib/libc.so (epoll_wait+12)
      #01  pc 0015ee80  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so
      at dalvik.system.NativeStart.run(Native Method)
    
    "Thread-591" prio=5 tid=15 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x422e8198 self=0x79cf9890
      | sysTid=23201 nice=0 sched=0/0 cgrp=apps handle=2043645904
      | state=S schedstat=( 0 0 0 ) utm=21 stm=6 core=0
      #00  pc 0001c5d4  /system/lib/libc.so (__futex_syscall3+12)
      #01  pc 0002cad7  /system/lib/libc.so (sem_timedwait+146)
      #02  pc 001e22b8  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so (mono_sem_timedwait+184)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Thread-588" prio=5 tid=14 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x4220dfa0 self=0x77894d50
      | sysTid=23191 nice=0 sched=0/0 cgrp=apps handle=2005938464
      | state=S schedstat=( 0 0 0 ) utm=127 stm=15 core=0
      #00  pc 0001c5d4  /system/lib/libc.so (__futex_syscall3+12)
      #01  pc 0002cad7  /system/lib/libc.so (sem_timedwait+146)
      #02  pc 001e22b8  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so (mono_sem_timedwait+184)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Thread-587" prio=5 tid=13 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x42250540 self=0x778946f8
      | sysTid=23190 nice=0 sched=0/0 cgrp=apps handle=2005940000
      | state=S schedstat=( 0 0 0 ) utm=3 stm=0 core=0
      #00  pc 0001bbbc  /system/lib/libc.so (nanosleep+12)
      #01  pc 001d4a64  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so (SleepEx+124)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Thread-585" prio=5 tid=11 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x42210218 self=0x769a6c40
      | sysTid=23183 nice=0 sched=0/0 cgrp=apps handle=1989890016
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
      #00  pc 0001c5d0  /system/lib/libc.so (__futex_syscall3+8)
      #01  pc 0002ca37  /system/lib/libc.so (sem_wait+48)
      #02  pc 001e21c0  /data/app-lib/Mono.Android.DebugRuntime-1/libmonosgen-2.0.so (mono_sem_wait+16)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Binder_2" prio=5 tid=10 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x42204c00 self=0x70a22c40
      | sysTid=23158 nice=0 sched=0/0 cgrp=apps handle=1889675768
      | state=S schedstat=( 0 0 0 ) utm=0 stm=1 core=1
      #00  pc 0001b300  /system/lib/libc.so (__ioctl+8)
      #01  pc 0002b77b  /system/lib/libc.so (ioctl+14)
      #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
      #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
      #04  pc 0001fae9  /system/lib/libbinder.so
      #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
      #06  pc 0004b631  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
      #07  pc 00011581  /system/lib/libutils.so
      #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
      #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Binder_1" prio=5 tid=9 NATIVE
      | group="main" sCount=1 dsCount=0 obj=0x42204a60 self=0x70a21fd0
      | sysTid=23157 nice=0 sched=0/0 cgrp=apps handle=1889672584
      | state=S schedstat=( 0 0 0 ) utm=1 stm=0 core=1
      #00  pc 0001b300  /system/lib/libc.so (__ioctl+8)
      #01  pc 0002b77b  /system/lib/libc.so (ioctl+14)
      #02  pc 0001b539  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
      #03  pc 0001bcd7  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
      #04  pc 0001fae9  /system/lib/libbinder.so
      #05  pc 00011a8d  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
      #06  pc 0004b631  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
      #07  pc 00011581  /system/lib/libutils.so
      #08  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
      #09  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
      at dalvik.system.NativeStart.run(Native Method)
    
    "FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
      | group="system" sCount=1 dsCount=0 obj=0x422019a8 self=0x70a20bb0
      | sysTid=23156 nice=0 sched=0/0 cgrp=apps handle=1889670968
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
      at java.lang.Object.wait(Native Method)
      - waiting on <0x4196b6c0> (a java.lang.Daemons$FinalizerWatchdogDaemon)
      at java.lang.Object.wait(Object.java:364)
      at java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
      at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
      at java.lang.Thread.run(Thread.java:841)
    
    "FinalizerDaemon" daemon prio=5 tid=7 WAIT
      | group="system" sCount=1 dsCount=0 obj=0x422017f8 self=0x70a20288
      | sysTid=23155 nice=0 sched=0/0 cgrp=apps handle=1889666776
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
      at java.lang.Object.wait(Native Method)
      - waiting on <0x41954568> (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:170)
      at java.lang.Thread.run(Thread.java:841)
    
    "ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
      | group="system" sCount=1 dsCount=0 obj=0x42201690 self=0x70a1f9e8
      | sysTid=23154 nice=0 sched=0/0 cgrp=apps handle=1889664568
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
      at java.lang.Object.wait(Native Method)
      - waiting on <0x41954490> 
      at java.lang.Object.wait(Object.java:364)
      at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
      at java.lang.Thread.run(Thread.java:841)
    
    "Compiler" daemon prio=5 tid=5 VMWAIT
      | group="system" sCount=1 dsCount=0 obj=0x422015a0 self=0x70a1f598
      | sysTid=23153 nice=0 sched=0/0 cgrp=apps handle=1100232568
      | state=S schedstat=( 0 0 0 ) utm=12 stm=6 core=0
      #00  pc 0001c5d0  /system/lib/libc.so (__futex_syscall3+8)
      #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
      #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
      #03  pc 0007301b  /system/lib/libdvm.so
      #04  pc 000543ad  /system/lib/libdvm.so
      #05  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
      #06  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
      at dalvik.system.NativeStart.run(Native Method)
    
    "JDWP" daemon prio=5 tid=4 VMWAIT
      | group="system" sCount=1 dsCount=0 obj=0x422014b8 self=0x71f6fb78
      | sysTid=23152 nice=0 sched=0/0 cgrp=apps handle=1912011056
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=3
      #00  pc 0001c0a4  /system/lib/libc.so (recvmsg+8)
      #01  pc 000609fb  /system/lib/libdvm.so
      #02  pc 00060c2f  /system/lib/libdvm.so
      #03  pc 000638ff  /system/lib/libdvm.so
      #04  pc 000543ad  /system/lib/libdvm.so
      #05  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
      #06  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
      at dalvik.system.NativeStart.run(Native Method)
    
    "Signal Catcher" daemon prio=5 tid=3 RUNNABLE
      | group="system" sCount=0 dsCount=0 obj=0x422013c0 self=0x419421c8
      | sysTid=23151 nice=0 sched=0/0 cgrp=apps handle=1889652744
      | state=R schedstat=( 0 0 0 ) utm=1 stm=0 core=0
      at dalvik.system.NativeStart.run(Native Method)
    
    "GC" daemon prio=5 tid=2 VMWAIT
      | group="system" sCount=1 dsCount=0 obj=0x422012e0 self=0x70a117d8
      | sysTid=23150 nice=0 sched=0/0 cgrp=apps handle=1889651880
      | state=S schedstat=( 0 0 0 ) utm=15 stm=4 core=0
      #00  pc 0001c5d0  /system/lib/libc.so (__futex_syscall3+8)
      #01  pc 0000e6a8  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
      #02  pc 0000e708  /system/lib/libc.so (__pthread_cond_timedwait+64)
      #03  pc 00071cff  /system/lib/libdvm.so
      #04  pc 000543ad  /system/lib/libdvm.so
      #05  pc 0000ca58  /system/lib/libc.so (__thread_entry+72)
      #06  pc 0000cbd4  /system/lib/libc.so (pthread_create+208)
      at dalvik.system.NativeStart.run(Native Method)
    
    NATIVE THREADS:
    "GL updater" sysTid=24330 nice=-10 sched=0/0 cgrp=apps
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
    
    "GL updater" sysTid=24333 nice=-10 sched=0/0 cgrp=apps
      | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
    
    ----- end 23146 -----
    

    Sure enough, I pressed a menu option and that's where it immediately locked up (so I suspect something other than what my customers are reporting). Either way, looking through the code, I find straightforward code that eventually calls a webservice, and prior to that, it should dump parameters to the log... my log contains no such info so I know within a few lines of code, where things went wrong, but I can't figure out what could've possibly gone wrong. There's no way any of the code could block the UI.. it's a straightforward asynch httpwebrequest.

    Any ideas, anyone?

  • SaschaMatzSaschaMatz DEMember ✭✭

    Hey,
    did you find any solution to this, it seems i have the same problem with my long running program.

  • Yes, I haven't had any freezes reported since the last version. I can't quite put my finger on the exact line, but I went through my code line for line looking for instances, where I'd update a GUI element from a background thread. And I found perhaps 2 or 3 instances, where in rare circumstances, that scenario (background thread trying to update a GUI control) was possible.
    Unfortunately, this is long and tedious work. It would be helpful if Xamarin.Android could block this from happening in the first place. If you do the same in a desktop app, you get a nice exception telling you you can't update gui controls from the background thread. Meaning you get your culprit instantly (assuming you log all exceptions which obviously you'll want to anyway) and if you dump a stacktrace, it's an easy fix.

Sign In or Register to comment.