Android ANR-ContentProvider

App can call “ContentProviderClient.setDetectNotResponding()” to enable this ANR mechanism, that’s used for App detecting the timeout of ContentProvider operations.
Mechanism

• ContentResolver process post a msg in main thread looper with a timeout, then ‘query’ ContentProvider process
• If timeout, then msg will be executed in main thread and ask AMS to trigger ContentProvider process’s ANR
• Else if the query completed before timeout, msg will be removed from ContentResolver’s main thread when the query done.

Code Review

• ContentResolver process ask enable this ANR mechanism

@/frameworks/base/packages/DocumentsUI/src/com/android/documentsui/DocumentsApplication.javapublic static ContentProviderClient acquireUnstableProviderOrThrow(        ContentResolver resolver, String authority) throws RemoteException {    final ContentProviderClient client = resolver.acquireUnstableContentProviderClient(authority);    if (client == null) {        throw new RemoteException("Failed to acquire provider for " + authority);    }    client.setDetectNotResponding(PROVIDER_ANR_TIMEOUT);    return client;}

• Monitoring in the main thread of ContentResolver process.

@/frameworks/base/core/java/android/content/ContentProviderClient.javapublic class ContentProviderClient {    /** {@hide} */    public void setDetectNotResponding(long timeoutMillis) {        synchronized (ContentProviderClient.class) {            mAnrTimeout = timeoutMillis;            if (timeoutMillis > 0) {                if (mAnrRunnable == null) {                    mAnrRunnable = new NotRespondingRunnable();                }                if (sAnrHandler == null) {                    sAnrHandler = new Handler(Looper.getMainLooper(), null, true /* async */);                }            } else {                mAnrRunnable = null;            }        }    }    /** See {@link ContentProvider#query ContentProvider.query} */    public Cursor query(Uri url, String[] projection, String selection, String[] selectionArgs,            String sortOrder, CancellationSignal cancellationSignal) throws RemoteException {        beforeRemote();    // post a ANR timeout in main thread        try {            ICancellationSignal remoteCancellationSignal = null;            if (cancellationSignal != null) {                cancellationSignal.throwIfCanceled();                remoteCancellationSignal = mContentProvider.createCancellationSignal();                cancellationSignal.setRemote(remoteCancellationSignal);            }            return mContentProvider.query(mPackageName, url, projection, selection, selectionArgs,                    sortOrder, remoteCancellationSignal);        } catch (DeadObjectException e) {            if (!mStable) {                mContentResolver.unstableProviderDied(mContentProvider);            }            throw e;        } finally {            afterRemote(); // remove the ANR timeout from main thread        }    }

• ANR happened, ContentResolver process will ask AMS to trigger ContentProvider process’s ANR.

@/frameworks/base/core/java/android/content/ContentProviderClient.java    private class NotRespondingRunnable implements Runnable {        @Override        public void run() {            Log.w(TAG, "Detected provider not responding: " + mContentProvider);            mContentResolver.appNotRespondingViaProvider(mContentProvider);        }    }

Case Study

Case: A11_CHL_K44_DESIRE_SENSE60 #991
ContentProvider ANR caused by emmc performance slow.

Log analysis:

• android.process.media(pid:21409) got ANR, but there is no any long duration message handler in main thread

21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 1ms, start=434775021409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 1ms, start=434749021409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 0ms, start=434065821409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 3ms, start=432949421409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: ENABLE_JIT(132), 0ms, start=431482521409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: CLEAN_UP_CONTEXT(119), 0ms, start=430531421409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: STOP_SERVICE(116), 1ms, start=430531321409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: SERVICE_ARGS(115), 12ms, start=430487521409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: CREATE_SERVICE(114), 58ms, start=430481721409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: BIND_APPLICATION(110), 335ms, start=430448221409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: SET_CORE_SETTINGS(138), 1ms, start=4304481----- pid 21409 at 2014-07-29 11:53:33 -----Cmd line: android.process.media"main" prio=5 tid=1 NATIVE  | group="main" sCount=1 dsCount=0 obj=0x436a8f30 self=0x415b49e0  | sysTid=21409 nice=0 sched=0/0 cgrp=apps handle=1074442648  | state=S schedstat=( 0 0 0 ) utm=1 stm=10 core=2  ...  at android.os.MessageQueue.nativePollOnce(Native Method)  at android.os.MessageQueue.next(MessageQueue.java:138)  at android.os.Looper.loop(Looper.java:134)  at android.app.ActivityThread.main(ActivityThread.java:5883)

• com.android.documentsui(pid:21818) detected provider ANR, and ask AMS trigger android.process.media(pid:21409) ANR

21818 21818 W ContentProviderClient: Detected provider not responding: android.content.ContentProviderProxy@43be24a0...21409 21419 E ActivityThread: MSG: Dump looper, process: android.process.media// binder transactions @bugreportproc 21409  thread 21444: l 01    incoming transaction 456079: e7a59100 from 21818:21962 to 21409:21444 code 17 flags 10 pri 10 r1 node 440055 size 548:4 data cf600028// callstack, the operation is accessing SD card.----- pid 21409 at 2014-07-29 11:53:33 -----Cmd line: android.process.media"Binder_3" prio=5 tid=12 NATIVE  | group="main" sCount=1 dsCount=0 obj=0x43c339c8 self=0x5b1e6328  | sysTid=21444 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1496402456  | state=S schedstat=( 0 0 0 ) utm=11 stm=3 core=0  (native backtrace unavailable)  at libcore.io.Posix.open(Native Method)  at libcore.io.BlockGuardOs.open(BlockGuardOs.java:110)  at libcore.io.IoBridge.open(IoBridge.java:393)  at java.io.FileInputStream.<init>(FileInputStream.java:78)  at java.io.FileInputStream.<init>(FileInputStream.java:105)  at android.media.ThumbnailUtils.createImageThumbnail(ThumbnailUtils.java:109)  at android.provider.MediaStore$InternalThumbnails.getThumbnail(MediaStore.java:836)  at android.provider.MediaStore$Images$Thumbnails.getThumbnail(MediaStore.java:1204)  at com.android.providers.media.MediaDocumentsProvider.openOrCreateImageThumbnailCleared(MediaDocumentsProvider.java:804)

Summary:

• The ContentResolver process is com.android.documentsui(pid:21818).
• The ContentProvider process is android.process.media(pid:21409), which is the ANR process.
• com.android.documentsui(pid:21818) query() android.process.media(pid:21409) in background thread, but can’t finish in 20sec timeout duration, so com.android.documentsui(pid:21818) ask AMS trigger android.process.media(pid:21409) ANR.
• Please note:
  
  • this query() operation is not executed in main thread, but still got ANR. It’s big different as traditional ANRs cases.
  • this ANR happened on ContentProvider process, but not caller process.