Java – ANR input scheduling timed out on Android 4.4

ANR input scheduling timed out on Android 4.4… here is a solution to the problem.

ANR input scheduling timed out on Android 4.4

I found a bug. This is just part of it:

----- pid 6835 at 2014-08-02 05:42:34 -----
Cmd line: lesa.smscallfake

JNI: CheckJNI is off; workarounds are off; pins=0; globals=311

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 SUSPENDED
| group="main" sCount=1 dsCount=0 obj=0x4205ae88 self=0x420494d8
| sysTid=6835 nice=0 sched=0/0 cgrp=apps handle=1074774356
| state=S schedstat=( 15933846549 2450231013 14646 ) utm=1372 stm=221 core=3
at java.lang.String.<init>(String.java:~435)
at java.lang.AbstractStringBuilder.toString(AbstractStringBuilder.java:645)
at java.lang.StringBuilder.toString(StringBuilder.java:663)
at java.lang.Throwable.toString(Throwable.java:360)
at java.lang.Throwable.printStackTrace(Throwable.java:315)
at java.lang.Throwable.printStackTrace(Throwable.java:282)
at java.lang.Throwable.printStackTrace(Throwable.java:236)
at android.graphics.BitmapFactory.nativeDecodeStream(Native Method)
at android.graphics.BitmapFactory.decodeStreamInternal(BitmapFactory.java:620)
at android.graphics.BitmapFactory.decodeStream(BitmapFactory.java:596)
at android.graphics.BitmapFactory.decodeStream(BitmapFactory.java:634)
at activity. ChiamataEffettuataActivity.getPhotoUri(ChiamataEffettuataActivity.java:127)
at activity. ChiamataEffettuataActivity.onCreate(ChiamataEffettuataActivity.java:64)
at android.app.Activity.performCreate(Activity.java:5231)
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087)
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2201)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2286)
at android.app.ActivityThread.access$800(ActivityThread.java:144)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1246)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:212)
at android.app.ActivityThread.main(ActivityThread.java:5135)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:515)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:877)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:693)
at dalvik.system.NativeStart.main(Native Method)

"Binder_3" prio=5 tid=15 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x453fe1e0 self=0x78e073c8
| sysTid=7371 nice=0 sched=0/0 cgrp=apps handle=2034790416
| state=S schedstat=( 5824738 6848644 39 ) utm=0 stm=0 core=3
#00 pc 00020710 /system/lib/libc.so (__ioctl+8)
#01 pc 0002d02b /system/lib/libc.so (ioctl+14)
#02 pc 0001d75d /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
#03 pc 0001de97 /system/lib/libbinder.so (android::IPCThreadState::getAndExecuteCommand(bool)+18)
#04 pc 0001df3b /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+50)
#05 pc 00021da5 /system/lib/libbinder.so
#06 pc 0000ea5d /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
#07 pc 0004dde5 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
#08 pc 0000e58f /system/lib/libutils.so
#09 pc 0000d258 /system/lib/libc.so (__thread_entry+72)
#10 pc 0000d3f0 /system/lib/libc.so (pthread_create+240)
at dalvik.system.NativeStart.run(Native Method)

"AsyncTask #5" prio=5 tid=14 WAIT
| group="main" sCount=1 dsCount=0 obj=0x454062d0 self=0x7974f218
| sysTid=6933 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=2037708400
| state=S schedstat=( 942497 6026459 11 ) utm=0 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x45406428> (a java.lang.VMThread) held by tid=14 (AsyncTask #5)
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:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2017)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:410)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)

"AsyncTask #4" prio=5 tid=13 WAIT
| group="main" sCount=1 dsCount=0 obj=0x4537d608 self=0x719534c0
| sysTid=6855 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1905604888
| state=S schedstat=( 782915 2602712 11 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x4537d728> (a java.lang.VMThread) held by tid=13 (AsyncTask #4)
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:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2017)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:410)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)

"AsyncTask #3" prio=5 tid=12 WAIT
| group="main" sCount=1 dsCount=0 obj=0x4537d478 self=0x719520d8
| sysTid=6854 nice=0 sched=0/0 cgrp=apps handle=1905599792
| state=S schedstat=( 579063 812344 9 ) utm=0 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x4537d598> (a java.lang.VMThread) held by tid=12 (AsyncTask #3)
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:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2017)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:410)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)

"AsyncTask #2" prio=5 tid=11 WAIT
| group="main" sCount=1 dsCount=0 obj=0x4537d228 self=0x71951110
| sysTid=6853 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1905595752
| state=S schedstat=( 813803 354219 11 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x4537d3c0> (a java.lang.VMThread) held by tid=11 (AsyncTask #2)
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:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2017)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:410)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)

"AsyncTask #1" prio=5 tid=10 WAIT
| group="main" sCount=1 dsCount=0 obj=0x4537c920 self=0x7193dd18
| sysTid=6852 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1905519696
| state=S schedstat=( 1232138 19486042 17 ) utm=0 stm=0 core=1
at java.lang.Object.wait(Native Method)
- waiting on <0x4537cab8> (a java.lang.VMThread) held by tid=10 (AsyncTask #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:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2017)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:410)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
at java.lang.Thread.run(Thread.java:841)

"Binder_2" prio=5 tid=9 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x451f8698 self=0x7176fac0
| sysTid=6848 nice=0 sched=0/0 cgrp=apps handle=1903622264
| state=S schedstat=( 10446143 19545574 79 ) utm=1 stm=0 core=3
#00 pc 00020710 /system/lib/libc.so (__ioctl+8)
#01 pc 0002d02b /system/lib/libc.so (ioctl+14)
#02 pc 0001d75d /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
#03 pc 0001de97 /system/lib/libbinder.so (android::IPCThreadState::getAndExecuteCommand(bool)+18)
#04 pc 0001df3b /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+50)
#05 pc 00021da5 /system/lib/libbinder.so
#06 pc 0000ea5d /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
#07 pc 0004dde5 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
#08 pc 0000e58f /system/lib/libutils.so
#09 pc 0000d258 /system/lib/libc.so (__thread_entry+72)
#10 pc 0000d3f0 /system/lib/libc.so (pthread_create+240)
at dalvik.system.NativeStart.run(Native Method)

"Binder_1" prio=5 tid=8 NATIVE
| group="main" sCount=1 dsCount=0 obj=0x451f84b8 self=0x7176f008
| sysTid=6847 nice=0 sched=0/0 cgrp=apps handle=1903541152
| state=S schedstat=( 9909064 13567240 78 ) utm=0 stm=0 core=3
#00 pc 00020710 /system/lib/libc.so (__ioctl+8)
#01 pc 0002d02b /system/lib/libc.so (ioctl+14)
#02 pc 0001d75d /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140)
#03 pc 0001de97 /system/lib/libbinder.so (android::IPCThreadState::getAndExecuteCommand(bool)+18)
#04 pc 0001df3b /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+50)
#05 pc 00021da5 /system/lib/libbinder.so
#06 pc 0000ea5d /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216)
#07 pc 0004dde5 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68)
#08 pc 0000e58f /system/lib/libutils.so
#09 pc 0000d258 /system/lib/libc.so (__thread_entry+72)
#10 pc 0000d3f0 /system/lib/libc.so (pthread_create+240)
at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=7 TIMED_WAIT
| group="system" sCount=1 dsCount=0 obj=0x451f3bc8 self=0x7164b358
| sysTid=6845 nice=0 sched=0/0 cgrp=apps handle=1902426032
| state=S schedstat=( 469635 7594584 14 ) utm=0 stm=0 core=3
at java.lang.VMThread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:1013)
at java.lang.Thread.sleep(Thread.java:995)
at java.lang.Daemons$FinalizerWatchdogDaemon.sleepFor(Daemons.java:248)
at java.lang.Daemons$FinalizerWatchdogDaemon.waitForFinalization(Daemons.java:258)
at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:212)
at java.lang.Thread.run(Thread.java:841)

"FinalizerDaemon" daemon prio=5 tid=6 WAIT
| group="system" sCount=1 dsCount=0 obj=0x451f3a70 self=0x7164aa28
| sysTid=6844 nice=0 sched=0/0 cgrp=apps handle=1902423680
| state=S schedstat=( 24290203 25912501 258 ) utm=2 stm=0 core=3
at java.lang.Object.wait(Native Method)
- waiting on <0x4204f7d8> (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=5 WAIT
| group="system" sCount=1 dsCount=0 obj=0x451f3908 self=0x7164a180
| sysTid=6843 nice=0 sched=0/0 cgrp=apps handle=1902421464
| state=S schedstat=( 7857403 2493957 162 ) utm=0 stm=0 core=0
at java.lang.Object.wait(Native Method)
- waiting on <0x4204f700> 
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=4 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x451f3818 self=0x71649b20
| sysTid=6842 nice=0 sched=0/0 cgrp=apps handle=1902418136
| state=S schedstat=( 146295056 73149476 1499 ) utm=9 stm=5 core=3
#00 pc 00021a8c /system/lib/libc.so (__futex_syscall3+8)
#01 pc 0000f04c /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 0000f0ac /system/lib/libc.so (__pthread_cond_timedwait+64)
#03 pc 00076d13 /system/lib/libdvm.so
#04 pc 00057815 /system/lib/libdvm.so
#05 pc 0000d258 /system/lib/libc.so (__thread_entry+72)
#06 pc 0000d3f0 /system/lib/libc.so (pthread_create+240)
at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
| group="system" sCount=0 dsCount=0 obj=0x451f3720 self=0x74066780
| sysTid=6841 nice=0 sched=0/0 cgrp=apps handle=1946576184
| state=R schedstat=( 12132237 6684635 28 ) utm=0 stm=1 core=3
at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=2 VMWAIT
| group="system" sCount=1 dsCount=0 obj=0x451f3640 self=0x716401f8
| sysTid=6839 nice=0 sched=0/0 cgrp=apps handle=1899029304
| state=S schedstat=( 1629483125 206446831 793 ) utm=150 stm=12 core=3
#00 pc 00021a90 /system/lib/libc.so (__futex_syscall3+12)
#01 pc 0000f04c /system/lib/libc.so (__pthread_cond_timedwait_relative+48)
#02 pc 0000f0ac /system/lib/libc.so (__pthread_cond_timedwait+64)
#03 pc 00055785 /system/lib/libdvm.so (dvmRelativeCondWait(pthread_cond_t*, pthread_mutex_t*, long long, int)+24)
#04 pc 000756cb /system/lib/libdvm.so
#05 pc 00057815 /system/lib/libdvm.so
#06 pc 0000d258 /system/lib/libc.so (__thread_entry+72)
#07 pc 0000d3f0 /system/lib/libc.so (pthread_create+240)
at dalvik.system.NativeStart.run(Native Method)

NATIVE THREADS:
"zygote" sysTid=6846 nice=0 sched=0/0 cgrp=apps
| state=S schedstat=( 267760 3741614 5 ) utm=0 stm=0 core=0

"GL updater" sysTid=7480 nice=-10 sched=0/0 cgrp=apps
| state=S schedstat=( 14861196 12149217 394 ) utm=0 stm=1 core=0

----- end 6835 -----

----- pid 999 at 2014-08-02 05:42:34 -----
Cmd line: system_server

JNI: CheckJNI is off; workarounds are off; pins=5; globals=2142 (plus 322 weak)

The method of the class is like this:

private Bitmap getPhotoUri(String idContact) {
        try {
            Cursor cur = getApplicationContext().getContentResolver().query(
                    ContactsContract.Data.CONTENT_URI,
                    null,
                    ContactsContract.Data.CONTACT_ID + "=" + idContact + " AND "
                            + ContactsContract.Data.MIMETYPE + "='"
                            + ContactsContract.CommonDataKinds.Photo.CONTENT_ITEM_TYPE + "'", null,
                    null);
            if (cur != null) {
                if (!cur.moveToFirst()) {
                    return null;  no photo
                }
            } else {
                return null;  error in cursor process
            }
        } catch (Exception e) {
            e.printStackTrace();
            return null;
        }
        Bitmap bitmap = null;
        if (Build.VERSION.SDK_INT < 14) {
            Uri person = ContentUris.withAppendedId(ContactsContract.Contacts.CONTENT_URI, Long.parseLong(idContact));
            try {
                bitmap = MediaStore.Images.Media.getBitmap(getContentResolver(), Uri.withAppendedPath(person, ContactsContract.Contacts.Photo.CONTENT_DIRECTORY));
            } catch (FileNotFoundException e) {
            } catch (IOException e) {
            }
        } else {
             Uri my_contact_Uri = Uri.withAppendedPath(ContactsContract.Contacts.CONTENT_URI, String.valueOf(idContact));
             InputStream photo_stream = ContactsContract.Contacts.openContactPhotoInputStream(getContentResolver(), my_contact_Uri, true);
             BufferedInputStream buf = new BufferedInputStream(photo_stream);
             bitmap = BitmapFactory.decodeStream(buf);
             try {
                buf.close();
            } catch (IOException e) {
            }
        }
        return bitmap;
    }

The issue has been found on phones running Android 4.4. In many other cases, the method works fine on other operating system versions.

Solution

For anyone who still has such error issues, here’s my conclusion :

After a lot of searching and trying everything I could find online, I fixed it myself. I used DDMS to look at the threads currently running on my device and found that there was an ASyncTask that ran for a long time and never stopped.

It appears to be accessing “something” that the main thread is accessing, and after accessing that “something” for some time, two threads collide causing the application to hang, resulting in an ANR exception.

What I did was remove ASyncTask and instead do this “one-off” operation at the start of the application (when it starts) to ensure it only runs once and not again.

I really recommend using DDMS to see the current thread, as ANRs are often caused by synchronization/concurrency issues. ANR p>

If you receive this error, please feel free to contact me privately.

Related Problems and Solutions