Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 69998eb7 authored by Chavi Weingarten's avatar Chavi Weingarten
Browse files

Add logs and traces when draw doesn't run

Add additional traces and logs that will provide more info on when a
draw doesn't proceed due to screen being turned off, content not
visible, or if draw is canceled.

Bug: 284687313
Bug: 305595315
Test: Logcat and perfetto traces
Change-Id: Ieacc78332716aa6628d67ca3227b6995ec7bb49e
parent fb0b1e0f
Loading
Loading
Loading
Loading
+49 −14
Original line number Diff line number Diff line
@@ -661,6 +661,10 @@ public final class ViewRootImpl implements ViewParent,
     */
    private boolean mCheckIfCanDraw = false;

    private boolean mWasLastDrawCanceled;
    private boolean mLastTraversalWasVisible = true;
    private boolean mLastDrawScreenOff;

    private boolean mDrewOnceForSync = false;

    int mSyncSeqId = 0;
@@ -1925,12 +1929,19 @@ public final class ViewRootImpl implements ViewParent,
    }

    void handleAppVisibility(boolean visible) {
        if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
            Trace.instant(Trace.TRACE_TAG_VIEW, TextUtils.formatSimple(
                    "%s visibilityChanged oldVisibility=%b newVisibility=%b", mTag,
                    mAppVisible, visible));
        }
        if (mAppVisible != visible) {
            final boolean previousVisible = getHostVisibility() == View.VISIBLE;
            mAppVisible = visible;
            final boolean currentVisible = getHostVisibility() == View.VISIBLE;
            // Root view only cares about whether it is visible or not.
            if (previousVisible != currentVisible) {
                Log.d(mTag, "visibilityChanged oldVisibility=" + previousVisible + " newVisibility="
                        + currentVisible);
                mAppVisibilityChanged = true;
                scheduleTraversals();
            }
@@ -3287,8 +3298,8 @@ public final class ViewRootImpl implements ViewParent,
                || mForceNextWindowRelayout) {
            if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
                Trace.traceBegin(Trace.TRACE_TAG_VIEW,
                        TextUtils.formatSimple("relayoutWindow#"
                                        + "first=%b/resize=%b/vis=%b/params=%b/force=%b",
                        TextUtils.formatSimple("%s-relayoutWindow#"
                                        + "first=%b/resize=%b/vis=%b/params=%b/force=%b", mTag,
                                mFirst, windowShouldResize, viewVisibilityChanged, params != null,
                                mForceNextWindowRelayout));
            }
@@ -3877,11 +3888,7 @@ public final class ViewRootImpl implements ViewParent,
        boolean cancelDueToPreDrawListener = mAttachInfo.mTreeObserver.dispatchOnPreDraw();
        boolean cancelAndRedraw = cancelDueToPreDrawListener
                 || (cancelDraw && mDrewOnceForSync);
        if (cancelAndRedraw) {
            Log.d(mTag, "Cancelling draw."
                    + " cancelDueToPreDrawListener=" + cancelDueToPreDrawListener
                    + " cancelDueToSync=" + (cancelDraw && mDrewOnceForSync));
        }

        if (!cancelAndRedraw) {
            // A sync was already requested before the WMS requested sync. This means we need to
            // sync the buffer, regardless if WMS wants to sync the buffer.
@@ -3905,6 +3912,9 @@ public final class ViewRootImpl implements ViewParent,
        }

        if (!isViewVisible) {
            if (mLastTraversalWasVisible) {
                logAndTrace("Not drawing due to not visible");
            }
            mLastPerformTraversalsSkipDrawReason = "view_not_visible";
            if (mPendingTransitions != null && mPendingTransitions.size() > 0) {
                for (int i = 0; i < mPendingTransitions.size(); ++i) {
@@ -3916,12 +3926,23 @@ public final class ViewRootImpl implements ViewParent,
            handleSyncRequestWhenNoAsyncDraw(mActiveSurfaceSyncGroup, mHasPendingTransactions,
                    mPendingTransaction, "view not visible");
        } else if (cancelAndRedraw) {
            if (!mWasLastDrawCanceled) {
                logAndTrace("Canceling draw."
                        + " cancelDueToPreDrawListener=" + cancelDueToPreDrawListener
                        + " cancelDueToSync=" + (cancelDraw && mDrewOnceForSync));
            }
            mLastPerformTraversalsSkipDrawReason = cancelDueToPreDrawListener
                ? "predraw_" + mAttachInfo.mTreeObserver.getLastDispatchOnPreDrawCanceledReason()
                : "cancel_" + cancelReason;
            // Try again
            scheduleTraversals();
        } else {
            if (mWasLastDrawCanceled) {
                logAndTrace("Draw frame after cancel");
            }
            if (!mLastTraversalWasVisible) {
                logAndTrace("Start draw after previous draw not visible");
            }
            if (mPendingTransitions != null && mPendingTransitions.size() > 0) {
                for (int i = 0; i < mPendingTransitions.size(); ++i) {
                    mPendingTransitions.get(i).startChangingAnimations();
@@ -3933,6 +3954,8 @@ public final class ViewRootImpl implements ViewParent,
                        mPendingTransaction, mLastPerformDrawSkippedReason);
            }
        }
        mWasLastDrawCanceled = cancelAndRedraw;
        mLastTraversalWasVisible = isViewVisible;

        if (mAttachInfo.mContentCaptureEvents != null) {
            notifyContentCaptureEvents();
@@ -4728,10 +4751,7 @@ public final class ViewRootImpl implements ViewParent,

                return didProduceBuffer -> {
                    if (!didProduceBuffer) {
                        Trace.instant(Trace.TRACE_TAG_VIEW,
                                "Transaction not synced due to no frame drawn-" + mTag);
                        Log.d(mTag, "Pending transaction will not be applied in sync with a draw "
                                + "because there was nothing new to draw");
                        logAndTrace("Transaction not synced due to no frame drawn");
                        mBlastBufferQueue.applyPendingTransactions(frame);
                    }
                };
@@ -4748,17 +4768,26 @@ public final class ViewRootImpl implements ViewParent,
        mLastPerformDrawSkippedReason = null;
        if (mAttachInfo.mDisplayState == Display.STATE_OFF && !mReportNextDraw) {
            mLastPerformDrawSkippedReason = "screen_off";
            if (!mLastDrawScreenOff) {
                logAndTrace("Not drawing due to screen off");
            }
            mLastDrawScreenOff = true;
            return false;
        } else if (mView == null) {
            mLastPerformDrawSkippedReason = "no_root_view";
            return false;
        }

        if (mLastDrawScreenOff) {
            logAndTrace("Resumed drawing after screen turned on");
            mLastDrawScreenOff = false;
        }

        final boolean fullRedrawNeeded = mFullRedrawNeeded || surfaceSyncGroup != null;
        mFullRedrawNeeded = false;

        mIsDrawing = true;
        Trace.traceBegin(Trace.TRACE_TAG_VIEW, "draw");
        Trace.traceBegin(Trace.TRACE_TAG_VIEW, mTag + "-draw");

        addFrameCommitCallbackIfNeeded();

@@ -11512,8 +11541,7 @@ public final class ViewRootImpl implements ViewParent,
    @Override
    public boolean applyTransactionOnDraw(@NonNull SurfaceControl.Transaction t) {
        if (mRemoved || !isHardwareEnabled()) {
            Trace.instant(Trace.TRACE_TAG_VIEW, "applyTransactionOnDraw applyImmediately-" + mTag);
            Log.d(mTag, "applyTransactionOnDraw: Applying transaction immediately");
            logAndTrace("applyTransactionOnDraw applyImmediately");
            t.apply();
        } else {
            Trace.instant(Trace.TRACE_TAG_VIEW, "applyTransactionOnDraw-" + mTag);
@@ -11990,4 +12018,11 @@ public final class ViewRootImpl implements ViewParent,
    public float getPreferredFrameRate() {
        return mPreferredFrameRate;
    }

    private void logAndTrace(String msg) {
        if (Trace.isTagEnabled(Trace.TRACE_TAG_VIEW)) {
            Trace.instant(Trace.TRACE_TAG_VIEW, mTag + "-" + msg);
        }
        Log.d(mTag, msg);
    }
}