Question

I recently had plenty of crashes of my app and I don't understand the problem. The logcat output is:

02-16 18:47:44.839: D/dalvikvm(7264): JIT unchain all for threadid=1
02-16 18:47:45.589: W/dalvikvm(7264): threadid=14: spin on suspend #1 threadid=1 (pcf=0)
02-16 18:47:46.339: W/dalvikvm(7264): threadid=14: spin on suspend #2 threadid=1 (pcf=0)
02-16 18:47:46.340: I/dalvikvm(7264): "Thread-2069" prio=5 tid=14 RUNNABLE JIT
02-16 18:47:46.340: I/dalvikvm(7264):   | group="main" sCount=0 dsCount=0 obj=0x41f13920 self=0x5f259a38
02-16 18:47:46.340: I/dalvikvm(7264):   | sysTid=7715 nice=0 sched=0/0 cgrp=apps handle=1596300944
02-16 18:47:46.340: I/dalvikvm(7264):   | state=R schedstat=( 0 0 0 ) utm=7 stm=4 core=1
02-16 18:47:46.340: I/dalvikvm(7264):   at java.lang.CaseMapper.toLowerCase(CaseMapper.java:~67)
02-16 18:47:46.340: I/dalvikvm(7264):   at java.lang.String.toLowerCase(String.java:1496)
02-16 18:47:46.340: I/dalvikvm(7264):   at de.malaka.player.utils.DBUtils.getTracksFromFolderWithoutSubfolder(DBUtils.java:384)
02-16 18:47:46.340: I/dalvikvm(7264):   at de.malaka.player.fragment.FolderFragment$9.run(FolderFragment.java:615)
02-16 18:47:46.340: I/dalvikvm(7264): "main" prio=5 tid=1 RUNNABLE JIT
02-16 18:47:46.340: I/dalvikvm(7264):   | group="main" sCount=1 dsCount=0 obj=0x41619e40 self=0x4153a828
02-16 18:47:46.340: I/dalvikvm(7264):   | sysTid=7264 nice=0 sched=0/0 cgrp=apps handle=1073856852
02-16 18:47:46.340: I/dalvikvm(7264):   | state=R schedstat=( 0 0 0 ) utm=1482 stm=147 core=0
02-16 18:47:46.340: I/dalvikvm(7264):   at de.malaka.player.fragment.FolderFragment.finishFillPath(FolderFragment.java:~676)
02-16 18:47:46.340: I/dalvikvm(7264):   at de.malaka.player.fragment.FolderFragment.onBackClicked(FolderFragment.java:517)
02-16 18:47:46.340: I/dalvikvm(7264):   at de.malaka.player.MainActivity.onBackPressed(MainActivity.java:736)
02-16 18:47:46.340: I/dalvikvm(7264):   at android.app.Activity.onKeyUp(Activity.java:2201)
02-16 18:47:46.340: I/dalvikvm(7264):   at android.view.KeyEvent.dispatch(KeyEvent.java:2664)
02-16 18:47:46.340: I/dalvikvm(7264):   at android.app.Activity.dispatchKeyEvent(Activity.java:2431)
02-16 18:47:46.340: I/dalvikvm(7264):   at android.support.v7.app.ActionBarActivityDelegateICS$WindowCallbackWrapper.dispatchKeyEvent(ActionBarActivityDelegateICS.java:245)

I have got more than 100 lines of that ouput above and then at the end I have got this logcat output:

02-16 18:47:52.415: I/dalvikvm(7264): "Binder_2" prio=5 tid=10 NATIVE
02-16 18:47:52.415: I/dalvikvm(7264):   | group="main" sCount=1 dsCount=0 obj=0x41eecd98 self=0x5eca6008
02-16 18:47:52.415: I/dalvikvm(7264):   | sysTid=7276 nice=0 sched=0/0 cgrp=apps handle=1533152376
02-16 18:47:52.415: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
02-16 18:47:52.418: I/dalvikvm(7264):   #00  pc 00020660  /system/lib/libc.so (__ioctl+8)
02-16 18:47:52.418: I/dalvikvm(7264):   #01  pc 0002cdb7  /system/lib/libc.so (ioctl+14)
02-16 18:47:52.418: I/dalvikvm(7264):   #02  pc 0001d375  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
02-16 18:47:52.418: I/dalvikvm(7264):   #03  pc 0001da7f  /system/lib/libbinder.so (android::IPCThreadState::getAndExecuteCommand()+6)
02-16 18:47:52.418: I/dalvikvm(7264):   #04  pc 0001db15  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+48)
02-16 18:47:52.418: I/dalvikvm(7264):   #05  pc 00021939  /system/lib/libbinder.so
02-16 18:47:52.418: I/dalvikvm(7264):   #06  pc 0000ea75  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
02-16 18:47:52.418: I/dalvikvm(7264):   #07  pc 0004d091  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
02-16 18:47:52.418: I/dalvikvm(7264):   #08  pc 0000e59d  /system/lib/libutils.so
02-16 18:47:52.418: I/dalvikvm(7264):   #09  pc 0000d240  /system/lib/libc.so (__thread_entry+72)
02-16 18:47:52.418: I/dalvikvm(7264):   #10  pc 0000d3d8  /system/lib/libc.so (pthread_create+240)
02-16 18:47:52.418: I/dalvikvm(7264):   at dalvik.system.NativeStart.run(Native Method)
02-16 18:47:52.418: I/dalvikvm(7264): "Binder_1" prio=5 tid=9 NATIVE
02-16 18:47:52.418: I/dalvikvm(7264):   | group="main" sCount=1 dsCount=0 obj=0x41eecbb8 self=0x5b620250
02-16 18:47:52.418: I/dalvikvm(7264):   | sysTid=7275 nice=0 sched=0/0 cgrp=apps handle=1533149192
02-16 18:47:52.418: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
02-16 18:47:52.420: I/dalvikvm(7264):   #00  pc 00020660  /system/lib/libc.so (__ioctl+8)
02-16 18:47:52.420: I/dalvikvm(7264):   #01  pc 0002cdb7  /system/lib/libc.so (ioctl+14)
02-16 18:47:52.420: I/dalvikvm(7264):   #02  pc 0001d375  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
02-16 18:47:52.420: I/dalvikvm(7264):   #03  pc 0001da7f  /system/lib/libbinder.so (android::IPCThreadState::getAndExecuteCommand()+6)
02-16 18:47:52.420: I/dalvikvm(7264):   #04  pc 0001db15  /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+48)
02-16 18:47:52.420: I/dalvikvm(7264):   #05  pc 00021939  /system/lib/libbinder.so
02-16 18:47:52.421: I/dalvikvm(7264):   #06  pc 0000ea75  /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
02-16 18:47:52.421: I/dalvikvm(7264):   #07  pc 0004d091  /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
02-16 18:47:52.421: I/dalvikvm(7264):   #08  pc 0000e59d  /system/lib/libutils.so
02-16 18:47:52.421: I/dalvikvm(7264):   #09  pc 0000d240  /system/lib/libc.so (__thread_entry+72)
02-16 18:47:52.421: I/dalvikvm(7264):   #10  pc 0000d3d8  /system/lib/libc.so (pthread_create+240)
02-16 18:47:52.421: I/dalvikvm(7264):   at dalvik.system.NativeStart.run(Native Method)
02-16 18:47:52.421: I/dalvikvm(7264): "FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
02-16 18:47:52.421: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee99b8 self=0x5b51f330
02-16 18:47:52.421: I/dalvikvm(7264):   | sysTid=7274 nice=0 sched=0/0 cgrp=apps handle=1532098440
02-16 18:47:52.421: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Object.wait(Native Method)
02-16 18:47:52.421: I/dalvikvm(7264):   - waiting on <0x416234e8> (a java.lang.Daemons$FinalizerWatchdogDaemon)
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Object.wait(Object.java:364)
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Thread.run(Thread.java:841)
02-16 18:47:52.421: I/dalvikvm(7264): "FinalizerDaemon" daemon prio=5 tid=7 WAIT
02-16 18:47:52.421: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee9808 self=0x5e3e58c0
02-16 18:47:52.421: I/dalvikvm(7264):   | sysTid=7273 nice=0 sched=0/0 cgrp=apps handle=1581145368
02-16 18:47:52.421: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=7 stm=1 core=1
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Object.wait(Native Method)
02-16 18:47:52.421: I/dalvikvm(7264):   - waiting on <0x4160e7d8> (a java.lang.ref.ReferenceQueue)
02-16 18:47:52.421: I/dalvikvm(7264):   at java.lang.Object.wait(Object.java:401)
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.Thread.run(Thread.java:841)
02-16 18:47:52.422: I/dalvikvm(7264): "ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
02-16 18:47:52.422: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee96a0 self=0x5e3e5018
02-16 18:47:52.422: I/dalvikvm(7264):   | sysTid=7272 nice=0 sched=0/0 cgrp=apps handle=1581143152
02-16 18:47:52.422: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.Object.wait(Native Method)
02-16 18:47:52.422: I/dalvikvm(7264):   - waiting on <0x4160e700> 
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.Object.wait(Object.java:364)
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
02-16 18:47:52.422: I/dalvikvm(7264):   at java.lang.Thread.run(Thread.java:841)
02-16 18:47:52.422: I/dalvikvm(7264): "Compiler" daemon prio=5 tid=5 VMWAIT
02-16 18:47:52.422: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee95b0 self=0x5e3e49b8
02-16 18:47:52.422: I/dalvikvm(7264):   | sysTid=7271 nice=0 sched=0/0 cgrp=apps handle=1581139824
02-16 18:47:52.422: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=12 stm=7 core=0
02-16 18:47:52.423: I/dalvikvm(7264):   #00  pc 000219dc  /system/lib/libc.so (__futex_syscall3+8)
02-16 18:47:52.423: I/dalvikvm(7264):   #01  pc 0000ef94  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
02-16 18:47:52.423: I/dalvikvm(7264):   #02  pc 0000effc  /system/lib/libc.so (__pthread_cond_timedwait+64)
02-16 18:47:52.423: I/dalvikvm(7264):   #03  pc 00076e73  /system/lib/libdvm.so
02-16 18:47:52.423: I/dalvikvm(7264):   #04  pc 00057841  /system/lib/libdvm.so
02-16 18:47:52.423: I/dalvikvm(7264):   #05  pc 0000d240  /system/lib/libc.so (__thread_entry+72)
02-16 18:47:52.423: I/dalvikvm(7264):   #06  pc 0000d3d8  /system/lib/libc.so (pthread_create+240)
02-16 18:47:52.423: I/dalvikvm(7264):   at dalvik.system.NativeStart.run(Native Method)
02-16 18:47:52.423: I/dalvikvm(7264): "JDWP" daemon prio=5 tid=4 VMWAIT
02-16 18:47:52.423: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee94c8 self=0x5e3e4110
02-16 18:47:52.423: I/dalvikvm(7264):   | sysTid=7270 nice=0 sched=0/0 cgrp=apps handle=1096844008
02-16 18:47:52.423: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=2
02-16 18:47:52.424: I/dalvikvm(7264):   #00  pc 000207b0  /system/lib/libc.so (select+20)
02-16 18:47:52.424: I/dalvikvm(7264):   #01  pc 0006437b  /system/lib/libdvm.so
02-16 18:47:52.424: I/dalvikvm(7264):   #02  pc 00066ee1  /system/lib/libdvm.so
02-16 18:47:52.424: I/dalvikvm(7264):   #03  pc 00057841  /system/lib/libdvm.so
02-16 18:47:52.424: I/dalvikvm(7264):   #04  pc 0000d240  /system/lib/libc.so (__thread_entry+72)
02-16 18:47:52.424: I/dalvikvm(7264):   #05  pc 0000d3d8  /system/lib/libc.so (pthread_create+240)
02-16 18:47:52.424: I/dalvikvm(7264):   at dalvik.system.NativeStart.run(Native Method)
02-16 18:47:52.424: I/dalvikvm(7264): "Signal Catcher" daemon prio=5 tid=3 SUSPENDED
02-16 18:47:52.424: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee93d0 self=0x58572a58
02-16 18:47:52.424: I/dalvikvm(7264):   | sysTid=7269 nice=0 sched=0/0 cgrp=apps handle=1482106896
02-16 18:47:52.424: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=0 stm=0 core=0
02-16 18:47:52.426: I/dalvikvm(7264):   #00  pc 000219dc  /system/lib/libc.so (__futex_syscall3+8)
02-16 18:47:52.426: I/dalvikvm(7264):   #01  pc 0000ef94  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
02-16 18:47:52.426: I/dalvikvm(7264):   #02  pc 0000effc  /system/lib/libc.so (__pthread_cond_timedwait+64)
02-16 18:47:52.426: I/dalvikvm(7264):   #03  pc 0005658b  /system/lib/libdvm.so
02-16 18:47:52.426: I/dalvikvm(7264):   #04  pc 00056b4d  /system/lib/libdvm.so (dvmChangeStatus(Thread*, ThreadStatus)+34)
02-16 18:47:52.426: I/dalvikvm(7264):   #05  pc 00054cd7  /system/lib/libdvm.so
02-16 18:47:52.426: I/dalvikvm(7264):   #06  pc 00057841  /system/lib/libdvm.so
02-16 18:47:52.426: I/dalvikvm(7264):   #07  pc 0000d240  /system/lib/libc.so (__thread_entry+72)
02-16 18:47:52.426: I/dalvikvm(7264):   #08  pc 0000d3d8  /system/lib/libc.so (pthread_create+240)
02-16 18:47:52.426: I/dalvikvm(7264):   at dalvik.system.NativeStart.run(Native Method)
02-16 18:47:52.426: I/dalvikvm(7264): "GC" daemon prio=5 tid=2 VMWAIT
02-16 18:47:52.426: I/dalvikvm(7264):   | group="system" sCount=1 dsCount=0 obj=0x41ee92f0 self=0x5b64b258
02-16 18:47:52.426: I/dalvikvm(7264):   | sysTid=7268 nice=0 sched=0/0 cgrp=apps handle=1533323936
02-16 18:47:52.426: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=1 stm=9 core=1
02-16 18:47:52.428: I/dalvikvm(7264):   #00  pc 000219dc  /system/lib/libc.so (__futex_syscall3+8)
02-16 18:47:52.428: I/dalvikvm(7264):   #01  pc 0000ef94  /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
02-16 18:47:52.428: I/dalvikvm(7264):   #02  pc 0000effc  /system/lib/libc.so (__pthread_cond_timedwait+64)
02-16 18:47:52.428: I/dalvikvm(7264):   #03  pc 00075837  /system/lib/libdvm.so
02-16 18:47:52.428: I/dalvikvm(7264):   #04  pc 00057841  /system/lib/libdvm.so
02-16 18:47:52.428: I/dalvikvm(7264):   #05  pc 0000d240  /system/lib/libc.so (__thread_entry+72)
02-16 18:47:52.428: I/dalvikvm(7264):   #06  pc 0000d3d8  /system/lib/libc.so (pthread_create+240)
02-16 18:47:52.428: I/dalvikvm(7264):   at dalvik.system.NativeStart.run(Native Method)
02-16 18:47:52.428: I/dalvikvm(7264): NATIVE THREADS:
02-16 18:47:52.428: I/dalvikvm(7264): "GL updater" sysTid=7301 nice=-10 sched=0/0 cgrp=apps
02-16 18:47:52.428: I/dalvikvm(7264):   | state=S schedstat=( 0 0 0 ) utm=2 stm=12 core=0
02-16 18:47:52.428: E/dalvikvm(7264): threadid=14: stuck on threadid=1, giving up
02-16 18:47:52.429: D/dalvikvm(7264): threadid=14: sending two SIGSTKFLTs to threadid=1 (tid=7264) to cause debuggerd dump
02-16 18:47:52.431: A/libc(7264): Fatal signal 16 (SIGSTKFLT) at 0x00001c60 (code=-6), thread 7264 (e.malaka.player)

Where it occurs
I'm making a DB query to get all tracks within a subfolder and then I check if the file is in that particular folder and not in a subfolder with a regex. This is the code:

public static final String DATA = MediaStore.Audio.Media.DATA;

public static void getTracksFromFolderWithoutSubfolder(
        Context context, File f, ArrayList<TrackInfo> q, 
        int icon) {

    String pattern = Pattern.quote(f.getAbsolutePath().toLowerCase()) + "/[^/]*";
    Cursor mCursor = null;

    String selection = MediaStore.Audio.Media.IS_MUSIC + " != 0 AND " + DATA + " LIKE \"" + f.getAbsolutePath() + "/%\"";
    Uri contentUri = Media.getContentUriForPath(Environment.getExternalStorageDirectory().getPath());
    String projection[] = new String[]{DATA};

    mCursor = context.getContentResolver().query(contentUri, projection, selection, null, DATA);

    String data, fileName[];
    while(mCursor.moveToNext()){

        data = mCursor.getString(0);    
        if(data.toLowerCase().matches(pattern)){ // this is the line the logcat refers to
            fileName = data.split("/");
            q.add(new TrackInfo(fileName[fileName.length-1], null, data, null, -1, icon, false));
        }


    }

    mCursor.close();

}

The error only seems to occur if I call this method with the File f as the main folder for music on my device (about 1200 music files including subfolders). But it does not occur every time. In fact, it occurs about two or three times in ten calls.

Can anybody tell me where this might come from? Maybe I'm missing to release some resources or something like that..
I'm currently working with a Moto G, Android 4.4

Thanks

Was it helpful?

Solution

So to close the question:

Combining these logcat lines:
from second output

02-16 18:47:52.429: D/dalvikvm(7264): threadid=14: sending two SIGSTKFLTs to threadid=1 (tid=7264) to cause debuggerd dump 

from first output

02-16 18:47:46.340: I/dalvikvm(7264): "main" prio=5 tid=1 RUNNABLE JIT
02-16 18:47:46.340: I/dalvikvm(7264):   | group="main" sCount=1 dsCount=0 obj=0x41619e40 self=0x4153a828
02-16 18:47:46.340: I/dalvikvm(7264):   | sysTid=7264 nice=0 sched=0/0 cgrp=apps handle=1073856852
02-16 18:47:46.340: I/dalvikvm(7264):   | state=R schedstat=( 0 0 0 ) utm=1482 stm=147 core=0
02-16 18:47:46.340: I/dalvikvm(7264):   at de.malaka.player.fragment.FolderFragment.finishFillPath(FolderFragment.java:~676)

I had a closer look a the FolderFragment.finishFillPath(FolderFragment.java:~676). There I found a piece of code making the UIThread waiting actively for a background Thread to finish. I introduced this line for debugging reasons and forgot to remove it.

So in my case, the following line (from second output):

02-16 18:47:52.428: E/dalvikvm(7264): threadid=14: stuck on threadid=1, giving up

Indicated that the UI thread was waiting too long..

@Gabe Sechan
Thanks for the help

Licensed under: CC-BY-SA with attribution
Not affiliated with StackOverflow
scroll top