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.java
public 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.java
public 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=4347750
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 1ms, start=4347490
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 0ms, start=4340658
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: TRIM_MEMORY(140), 3ms, start=4329494
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: ENABLE_JIT(132), 0ms, start=4314825
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: CLEAN_UP_CONTEXT(119), 0ms, start=4305314
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: STOP_SERVICE(116), 1ms, start=4305313
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: SERVICE_ARGS(115), 12ms, start=4304875
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: CREATE_SERVICE(114), 58ms, start=4304817
21409 21419 E ActivityThread: MSG: Handler (android.app.ActivityThread$H) {43ad1bd0} null: BIND_APPLICATION(110), 335ms, start=4304482
21409 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 @bugreport
proc 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.