ANR while playing a local video in Android-5.1.1

[Xueyuan Bai]

Hello community guys,

   Could you give me some guidance on this please? 
   Thank you in advance.

   Now we play a video file in stock MediaPlayer apk.
   And the issue is when playing, zoom it in or out, and right after that, rotate the phone. Do this operation continuously.
   Sometimes, it will hang there, without ANR dialog, yes, the ANR in developer option is enabled, and strict mode is enable too.
   From the logcat,  a while after hanging, the system will runtime reboot.
   I have spent a few days to investigate this.
   Actually I mainly work as a driver engineer in this company, but I want to know more about the framework, the system, so I take the charge to solve this problem.
   A little tough, but it seems it worthes.

   Now I actually focus on this path,

"android.ui" prio=5 tid=17 Native
  | group="main" sCount=1 dsCount=0 obj=0x12e2c970 self=0xb8dd7318
  | sysTid=1778 nice=-2 cgrp=default sched=0/0 handle=0xb8dd76f0
  | state=S schedstat=( 1496111349 524889519 15458 ) utm=100 stm=49 core=3 HZ=100
  | stack=0xa4efc000-0xa4efe000 stackSize=1036KB
  | held mutexes=
  kernel: (couldn't read /proc/self/task/1778/stack)
  native: #00 pc 0003905c  /system/lib/libc.so (__ioctl+8)
  native: #01 pc 0003fa1d  /system/lib/libc.so (ioctl+14)
  native: #02 pc 0001cb67  /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+138)
  native: #03 pc 0001d173  /system/lib/libbinder.so (android::IPCThreadState::waitForResponse(android::Parcel*, int*)+42)
  native: #04 pc 0001d315  /system/lib/libbinder.so (android::IPCThreadState::transact(int, unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+124)
  native: #05 pc 000185f3  /system/lib/libbinder.so (android::BpBinder::transact(unsigned int, android::Parcel const&, android::Parcel*, unsigned int)+30)
  native: #06 pc 000842f3  /system/lib/libandroid_runtime.so (???)
  native: #07 pc 01045b1d  /data/dalvik-cache/arm/system@framework@boot.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+144)
  at android.os.BinderProxy.transactNative(Native method)
  at android.os.BinderProxy.transact(Binder.java:496)
  at android.view.IWindow$Stub$Proxy.resized(IWindow.java:370)
  at com.android.server.wm.WindowState.reportResized(WindowState.java:1424)
  at com.android.server.wm.WindowManagerService.performLayoutAndPlaceSurfacesLockedInner(WindowManagerService.java:10083)
  at com.android.server.wm.WindowManagerService.performLayoutAndPlaceSurfacesLockedLoop(WindowManagerService.java:8845)
  at com.android.server.wm.WindowManagerService.performLayoutAndPlaceSurfacesLocked(WindowManagerService.java:8787)
  at com.android.server.wm.WindowManagerService.setNewConfiguration(WindowManagerService.java:3942)
  - locked <0x19c52058> (a java.util.HashMap)
  at com.android.server.am.ActivityManagerService.updateConfigurationLocked(ActivityManagerService.java:16881)
  at com.android.server.am.ActivityManagerService.updateConfiguration(ActivityManagerService.java:16764)
  - locked <0x24d9c5b1> (a com.android.server.am.ActivityManagerService)
  at com.android.server.wm.WindowManagerService.sendNewConfiguration(WindowManagerService.java:7080)
  at com.android.server.wm.WindowManagerService.updateRotationUnchecked(WindowManagerService.java:6442)
  at com.android.server.wm.WindowManagerService.updateRotation(WindowManagerService.java:6396)
  at com.android.internal.policy.impl.PhoneWindowManager.updateRotation(PhoneWindowManager.java:6530)
  at com.android.internal.policy.impl.PhoneWindowManager$MyOrientationListener.onProposedRotationChanged(PhoneWindowManager.java:829)
  at com.android.internal.policy.impl.WindowOrientationListener$SensorEventListenerImpl.onSensorChanged(WindowOrientationListener.java:632)
  at android.hardware.SystemSensorManager$SensorEventQueue.dispatchSensorEvent(SystemSensorManager.java:405)
  at android.os.MessageQueue.nativePollOnce(Native method)
  at android.os.MessageQueue.next(MessageQueue.java:143)
  at android.os.Looper.loop(Looper.java:122)
  at android.os.HandlerThread.run(HandlerThread.java:61)
  at com.android.server.ServiceThread.run(ServiceThread.java:46)

and

"Binder_1" prio=5 tid=11 Blocked
  | group="main" sCount=1 dsCount=0 obj=0x12cbe0a0 self=0xb8dc2690
  | sysTid=1750 nice=0 cgrp=default sched=0/0 handle=0xb8debd70
  | state=S schedstat=( 769082616 596299997 2341 ) utm=46 stm=30 core=0 HZ=100
  | stack=0xa5781000-0xa5783000 stackSize=1012KB
  | held mutexes=
  at com.android.server.wm.WindowManagerService.relayoutWindow(WindowManagerService.java:3020)
  - waiting to lock <0x19c52058> (a java.util.HashMap) held by thread 17
  at com.android.server.wm.Session.relayout(Session.java:197)
  at android.view.IWindowSession$Stub.onTransact(IWindowSession.java:273)
  at com.android.server.wm.Session.onTransact(Session.java:130)
  at android.os.Binder.execTransact(Binder.java:446)


 May I say that, for updating the configuration change, it gets the   <0x19c52058> (a java.util.HashMap)  in the binder client.
 And on the binder service side, a relayoutWindow needs to be done, but it needs the lock     <0x19c52058> (a java.util.HashMap), so it hangs, wait there and no return.

And the Android ui has no return, so it cannot release the lock <0x19c52058> (a java.util.HashMap)?
Right?

  Actually I', totally confused with the traces.txt, I mean I cannot get more and more from it.

   Could you guys show me the way please? 
   How do I investigate this kind of ANRs, what infos are needed to solve this kind of issues?

   Thank you so much in advance guys.

[Xueyuan Bai]

Also, I do a test.

For the function,
void reportResized() {
        try {
            if (DEBUG_RESIZE || DEBUG_ORIENTATION) Slog.v(TAG, "Reporting new frame to " + this
                    + ": " + mCompatFrame);
            boolean configChanged = isConfigChanged();
            if ((DEBUG_RESIZE || DEBUG_ORIENTATION || DEBUG_CONFIGURATION) && configChanged) {
                Slog.i(TAG, "Sending new config to window " + this + ": "
                        + mWinAnimator.mSurfaceW + "x" + mWinAnimator.mSurfaceH
                        + " / " + mService.mCurConfiguration);
            }
            setConfiguration(mService.mCurConfiguration);
            if (DEBUG_ORIENTATION && mWinAnimator.mDrawState == WindowStateAnimator.DRAW_PENDING)
                Slog.i(TAG, "Resizing " + this + " WITH DRAW PENDING");

            final Rect frame = mFrame;
            final Rect overscanInsets = mLastOverscanInsets;
            final Rect contentInsets = mLastContentInsets;
            final Rect visibleInsets = mLastVisibleInsets;
            final Rect stableInsets = mLastStableInsets;
            final boolean reportDraw = mWinAnimator.mDrawState == WindowStateAnimator.DRAW_PENDING;
            final Configuration newConfig = configChanged ? mConfiguration : null;
            Slog.v(TAG, "reportResized(): mAttrs.type " + mAttrs.type + " mClient instanceof IWindow.Stub " + (mClient instanceof IWindow.Stub));
/*
            if (mAttrs.type != WindowManager.LayoutParams.TYPE_APPLICATION_STARTING
                    && mClient instanceof IWindow.Stub) {
*/  <----------------------------------------------  comment this if expression, and make it always true as below, now after a simple test, no hangs during the test.
             if (true) {
                // To prevent deadlock simulate one-way call if win.mClient is a local object.
                mService.mH.post(new Runnable() {
                    @Override
                    public void run() {
                        try {
                            Slog.i(TAG, "reportResized(): post runnable task for resized operation, always running");
                            mClient.resized(frame, overscanInsets, contentInsets,
                                    visibleInsets, stableInsets,  reportDraw, newConfig);
                        } catch (RemoteException e) {
                            // Not a remote call, RemoteException won't be raised.
                        }
                    }
                });
            } else {
                Slog.i(TAG, "reportResized(): calling directly for resized operation");
           
                mClient.resized(frame, overscanInsets, contentInsets, visibleInsets, stableInsets,
                        reportDraw, newConfig);
            }
            Slog.i(TAG, "reportResized(): after Resizing");

            //TODO (multidisplay): Accessibility supported only for the default display.
            if (mService.mAccessibilityController != null
                    && getDisplayId() == Display.DEFAULT_DISPLAY) {
                mService.mAccessibilityController.onSomeWindowResizedOrMovedLocked();
            }

            mOverscanInsetsChanged = false;
            mContentInsetsChanged = false;
            mVisibleInsetsChanged = false;
            mStableInsetsChanged = false;
            mWinAnimator.mSurfaceResized = false;
        } catch (RemoteException e) {
            mOverscanInsetsChanged = false;
            mContentInsetsChanged = false;
            mVisibleInsetsChanged = false;
            mStableInsetsChanged = false;
            mWinAnimator.mSurfaceResized = false;
            mOrientationChanging = false;
            mLastFreezeDuration = (int)(SystemClock.elapsedRealtime()
                    - mService.mDisplayFreezeTime);

  native: #07 pc 01045b1d  /data/dalvik-cache/arm/system@fram...@boot.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+144)

[Adeel Ahmad]

Just wondering if you ever managed to figure this out? I am getting an ANR with the exact same logs in Android 6.0.1 which is causing a watch dog restart after 30 seconds.

I am not rotating anything, this is happening during booting up 

  native: #07 pc 01045b1d  /data/dalvik-cache/arm/system@fram...@boot.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+144)