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

Commit c382b8d4 authored by Winson Chung's avatar Winson Chung
Browse files

Adding logs to help debug config issues 

- Convert DisplayImeController logs to protolog
- Add last-reported config log to simplify looking for config changes
  between last-reported and current, remove duplicate config diff log
- Add logs when calculating size-overrides & final computed
  configuration
- Add logs for setting task insets offsets

Bug: 402658128
Flag: EXEMPT log only update
Test: adb shell cmd protolog_configuration logcat enable WM_SHELL_IME_CONTROLLER WM_DEBUG_CONFIGURATION WM_DEBUG_WINDOW_ORGANIZER
Change-Id: Ibf35a48fc4c5c90ec2cdf3d83a52f9af652e3e4b
parent ad562932

libs/WindowManager/Shell/src/com/android/wm/shell/common/DisplayImeController.java

+33 −17
Original line number Diff line number Diff line
@@ -21,6 +21,8 @@ import static android.view.EventLogTags.IMF_IME_REMOTE_ANIM_END; 
import static android.view.EventLogTags.IMF_IME_REMOTE_ANIM_START;

import static android.view.inputmethod.ImeTracker.DEBUG_IME_VISIBILITY;



import static com.android.wm.shell.protolog.ShellProtoLogGroup.WM_SHELL_IME_CONTROLLER;



import android.animation.Animator;

import android.animation.AnimatorListenerAdapter;

import android.animation.ValueAnimator;
@@ -32,6 +34,7 @@ import android.content.res.Configuration; 
import android.graphics.Point;

import android.graphics.Rect;

import android.os.RemoteException;

import android.text.TextUtils;

import android.util.EventLog;

import android.util.Slog;

import android.util.SparseArray;
@@ -52,6 +55,7 @@ import android.view.inputmethod.InputMethodManagerGlobal; 
import androidx.annotation.VisibleForTesting;



import com.android.internal.inputmethod.SoftInputShowHideReason;

import com.android.internal.protolog.ProtoLog;

import com.android.wm.shell.shared.TransactionPool;

import com.android.wm.shell.sysui.ShellInit;
@@ -65,8 +69,6 @@ import java.util.concurrent.Executor; 
public class DisplayImeController implements DisplayController.OnDisplaysChangedListener {

    private static final String TAG = "DisplayImeController";



    private static final boolean DEBUG = false;



    // NOTE: All these constants came from InsetsController.

    public static final int ANIMATION_DURATION_SHOW_MS = 275;

    public static final int ANIMATION_DURATION_HIDE_MS = 340;
@@ -268,6 +270,7 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
            if (mInsetsState.equals(insetsState)) {

                return;

            }

            ProtoLog.d(WM_SHELL_IME_CONTROLLER, "Insets changed, state=%s", insetsState);



            if (!android.view.inputmethod.Flags.refactorInsetsController()) {

                updateImeVisibility(insetsState.isSourceOrDefaultVisible(InsetsSource.ID_IME,
@@ -282,7 +285,8 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 


            mInsetsState.set(insetsState, true /* copySources */);

            if (mImeShowing && !Objects.equals(oldFrame, newFrame) && newSourceVisible) {

                if (DEBUG) Slog.d(TAG, "insetsChanged when IME showing, restart animation");

                ProtoLog.d(WM_SHELL_IME_CONTROLLER,

                        "insetsChanged when IME showing, restart animation");

                startAnimation(mImeShowing, true /* forceRestart */,

                        SoftInputShowHideReason.DISPLAY_INSETS_CHANGED);

            }
@@ -292,6 +296,9 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
        @VisibleForTesting

        public void insetsControlChanged(InsetsState insetsState,

                InsetsSourceControl[] activeControls) {

            ProtoLog.d(WM_SHELL_IME_CONTROLLER, "Insets control changed, state=%s controls=%s",

                    insetsState,

                    activeControls != null ? TextUtils.join(", ", activeControls) : "null");

            insetsChanged(insetsState);

            InsetsSourceControl imeSourceControl = null;

            if (activeControls != null) {
@@ -400,7 +407,8 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
            if ((types & WindowInsets.Type.ime()) == 0) {

                return;

            }

            if (DEBUG) Slog.d(TAG, "Got showInsets for ime");

            ProtoLog.d(WM_SHELL_IME_CONTROLLER, "Ime shown, statsToken=%s",

                    statsToken != null ? statsToken.getBinder() : "null");

            startAnimation(true /* show */, false /* forceRestart */, statsToken);

        }
@@ -410,7 +418,8 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
            if ((types & WindowInsets.Type.ime()) == 0) {

                return;

            }

            if (DEBUG) Slog.d(TAG, "Got hideInsets for ime");

            ProtoLog.d(WM_SHELL_IME_CONTROLLER, "Ime hidden, statsToken=%s",

                    statsToken != null ? statsToken.getBinder() : "null");

            startAnimation(false /* show */, false /* forceRestart */, statsToken);

        }
@@ -423,6 +432,9 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
        // TODO(b/335404678): pass control target

        public void setImeInputTargetRequestedVisibility(boolean visible,

                @NonNull ImeTracker.Token statsToken) {

            ProtoLog.d(WM_SHELL_IME_CONTROLLER,

                    "Input target requested visibility, visible=%b statsToken=%s",

                    visible, statsToken != null ? statsToken.getBinder() : "null");

            if (android.view.inputmethod.Flags.refactorInsetsController()) {

                ImeTracker.forLogging().onProgress(statsToken,

                        ImeTracker.PHASE_WM_DISPLAY_IME_CONTROLLER_SET_IME_REQUESTED_VISIBLE);
@@ -531,7 +543,7 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
        private void startAnimation(final boolean show, final boolean forceRestart,

                @NonNull final ImeTracker.Token statsToken) {

            if (mImeSourceControl == null || mImeSourceControl.getLeash() == null) {

                if (DEBUG) Slog.d(TAG, "No leash available, not starting the animation.");

                ProtoLog.d(WM_SHELL_IME_CONTROLLER, "No Ime leash for animation");

                return;

            }

            if (android.view.inputmethod.Flags.refactorInsetsController()) {
@@ -561,11 +573,13 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
                // Don't set a new frame if it's empty and hiding -- this maintains continuity

                mImeFrame.set(newFrame);

            }

            if (DEBUG) {

                Slog.d(TAG, "Run startAnim  show:" + show + "  was:"

                        + (mAnimationDirection == DIRECTION_SHOW ? "SHOW"

                        : (mAnimationDirection == DIRECTION_HIDE ? "HIDE" : "NONE")));

            }

            final String prevVisibility = mAnimationDirection == DIRECTION_SHOW

                    ? "SHOW"

                    : mAnimationDirection == DIRECTION_HIDE

                            ? "HIDE"

                            : "NONE";

            ProtoLog.d(WM_SHELL_IME_CONTROLLER, "Run Ime animation, show=%b was=%s",

                    show, prevVisibility);

            if ((!forceRestart && (mAnimationDirection == DIRECTION_SHOW && show))

                    || (mAnimationDirection == DIRECTION_HIDE && !show)) {

                ImeTracker.forLogging().onCancelled(
@@ -631,11 +645,12 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 
                    float value = (float) valueAnimator.getAnimatedValue();

                    SurfaceControl.Transaction t = mTransactionPool.acquire();

                    t.setPosition(animatingLeash, x, value);

                    if (DEBUG) {

                        Slog.d(TAG, "onAnimationStart d:" + mDisplayId + " top:"

                                + imeTop(hiddenY, defaultY) + "->" + imeTop(shownY, defaultY)

                                + " showing:" + (mAnimationDirection == DIRECTION_SHOW));

                    }



                    ProtoLog.d(WM_SHELL_IME_CONTROLLER,

                            "Ime animation start, d=%d top=%d->%d showing=%b",

                            mDisplayId, imeTop(hiddenY, defaultY), imeTop(shownY, defaultY),

                            (mAnimationDirection == DIRECTION_SHOW));



                    if (android.view.inputmethod.Flags.reportAnimatingInsetsTypes()) {

                        // Updating the animatingTypes when starting the animation is not the

                        // trigger to show the IME. Thus, not sending the statsToken here.
@@ -680,7 +695,8 @@ public class DisplayImeController implements DisplayController.OnDisplaysChanged 


                @Override

                public void onAnimationEnd(Animator animation) {

                    if (DEBUG) Slog.d(TAG, "onAnimationEnd " + mCancelled);

                    ProtoLog.d(WM_SHELL_IME_CONTROLLER, "Ime animation end, canceled=%b",

                            mCancelled);

                    SurfaceControl.Transaction t = mTransactionPool.acquire();

                    if (!mCancelled) {

                        t.setPosition(animatingLeash, x, endY);

libs/WindowManager/Shell/src/com/android/wm/shell/protolog/ShellProtoLogGroup.java

+2 −0
Original line number Diff line number Diff line
@@ -36,6 +36,8 @@ public enum ShellProtoLogGroup implements IProtoLogGroup { 
            Consts.TAG_WM_SHELL),

    WM_SHELL_TRANSITIONS(Consts.ENABLE_DEBUG, Consts.ENABLE_LOG_TO_PROTO_DEBUG, true,

            Consts.TAG_WM_SHELL),

    WM_SHELL_IME_CONTROLLER(Consts.ENABLE_DEBUG, Consts.ENABLE_LOG_TO_PROTO_DEBUG, false,

            "ShellIme"),

    WM_SHELL_RECENTS_TRANSITION(Consts.ENABLE_DEBUG, Consts.ENABLE_LOG_TO_PROTO_DEBUG, true,

            "ShellRecents"),

    WM_SHELL_DRAG_AND_DROP(Consts.ENABLE_DEBUG, Consts.ENABLE_LOG_TO_PROTO_DEBUG, true,

services/core/java/com/android/server/wm/ActivityRecord.java

+9 −10
Original line number Diff line number Diff line
@@ -8383,8 +8383,7 @@ final class ActivityRecord extends WindowToken { 
        if (isConfigurationDispatchPaused()) {

            Slog.wtf(TAG, "trying to update reported(client) config while dispatch is paused");

        }

        ProtoLog.v(WM_DEBUG_CONFIGURATION, "Ensuring correct "

                + "configuration: %s", this);

        ProtoLog.v(WM_DEBUG_CONFIGURATION, "Ensuring correct configuration: %s", this);



        final int newDisplayId = getDisplayId();

        final boolean displayChanged = mLastReportedDisplayId != newDisplayId;
@@ -8414,8 +8413,7 @@ final class ActivityRecord extends WindowToken { 
                !mLastReportedActivityWindowInfo.equals(newActivityWindowInfo);

        if (!displayChanged && !isActivityWindowInfoChanged

                && getConfiguration().equals(mTmpConfig)) {

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "Configuration & display "

                    + "unchanged in %s", this);

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "Configuration & display unchanged in %s", this);

            return true;

        }
@@ -8429,6 +8427,11 @@ final class ActivityRecord extends WindowToken { 
        // Update last reported values.

        final Configuration newMergedOverrideConfig = getMergedOverrideConfiguration();



        if (changes != 0) {

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "Last reported config=%s",

                    mLastReportedConfiguration);

        }



        setLastReportedConfiguration(getProcessGlobalConfiguration(), newMergedOverrideConfig);

        setLastReportedActivityWindowInfo(newActivityWindowInfo);
@@ -8442,8 +8445,7 @@ final class ActivityRecord extends WindowToken { 
        }



        if (changes == 0) {

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "Configuration no differences in %s",

                    this);

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "Configuration no differences in %s", this);

            // There are no significant differences, so we won't relaunch but should still deliver

            // the new configuration to the client process.

            if (displayChanged) {
@@ -8457,9 +8459,6 @@ final class ActivityRecord extends WindowToken { 
            return true;

        }



        ProtoLog.v(WM_DEBUG_CONFIGURATION, "Configuration changes for %s, "

                + "allChanges=%s", this, Configuration.configurationDiffToString(changes));



        // If the activity isn't currently running, just leave the new configuration and it will

        // pick that up next time it starts.

        if (!attachedToProcess()) {
@@ -8469,7 +8468,7 @@ final class ActivityRecord extends WindowToken { 


        // Figure out how to handle the changes between the configurations.

        ProtoLog.v(WM_DEBUG_CONFIGURATION, "Checking to restart %s: changed=%s, "

                + "handles=%s, not-handles=%s, mLastReportedConfiguration=%s", this,

                + "handles=%s, not-handles=%s, new config=%s", this,

                Configuration.configurationDiffToString(changes),

                Configuration.configurationDiffToString(info.getRealConfigChanged()),

                Configuration.configurationDiffToString(changes & ~(info.getRealConfigChanged())),

services/core/java/com/android/server/wm/ConfigurationContainer.java

+33 −0
Original line number Diff line number Diff line
@@ -41,6 +41,7 @@ import static android.content.res.Configuration.ORIENTATION_UNDEFINED; 
import static android.view.Surface.ROTATION_270;

import static android.view.Surface.ROTATION_90;



import static com.android.internal.protolog.WmProtoLogGroups.WM_DEBUG_CONFIGURATION;

import static com.android.server.wm.ConfigurationContainerProto.FULL_CONFIGURATION;

import static com.android.server.wm.ConfigurationContainerProto.MERGED_OVERRIDE_CONFIGURATION;

import static com.android.server.wm.ConfigurationContainerProto.OVERRIDE_CONFIGURATION;
@@ -58,6 +59,7 @@ import android.util.proto.ProtoOutputStream; 
import android.view.DisplayInfo;



import com.android.internal.annotations.VisibleForTesting;

import com.android.internal.protolog.ProtoLog;



import java.io.PrintWriter;

import java.util.ArrayList;
@@ -224,6 +226,7 @@ public abstract class ConfigurationContainer<E extends ConfigurationContainer> { 
        if (rotation == ROTATION_UNDEFINED && !hasFixedRotationTransform) {

            rotation = displayContent.getRotation();

        }



        if (!optsOutEdgeToEdge && (!useOverrideInsetsForConfig

                || hasCompatDisplayInsets

                || rotation == ROTATION_UNDEFINED)) {
@@ -236,9 +239,14 @@ public abstract class ConfigurationContainer<E extends ConfigurationContainer> { 
            // Floating window won't have any insets affect configuration. Skip the override.

            return;

        }

        ProtoLog.v(WM_DEBUG_CONFIGURATION,

                "Applying configuration size overrides, optsOutEdgeToEdge=%b overrideInsets=%b "

                        + "compatDisplayInsets=%b rotation=%d",

                optsOutEdgeToEdge, useOverrideInsetsForConfig, hasCompatDisplayInsets, rotation);

        // Make sure the orientation related fields will be updated by the override insets, because

        // fixed rotation has assigned the fields from display's configuration.

        if (hasFixedRotationTransform) {

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "\tHas fixed rotation transform");

            inOutConfig.windowConfiguration.setAppBounds(null);

            inOutConfig.screenWidthDp = Configuration.SCREEN_WIDTH_DP_UNDEFINED;

            inOutConfig.screenHeightDp = Configuration.SCREEN_HEIGHT_DP_UNDEFINED;
@@ -263,11 +271,17 @@ public abstract class ConfigurationContainer<E extends ConfigurationContainer> { 
                    newParentConfiguration.windowConfiguration.getBounds());

            outAppBounds = inOutConfig.windowConfiguration.getAppBounds();

            outConfigBounds.set(outAppBounds);

            ProtoLog.v(WM_DEBUG_CONFIGURATION, "\tInitial bounds app=%s config=%s",

                    outAppBounds, outConfigBounds);

            if (task != null) {

                task = task.getCreatedByOrganizerTask();

                if (task != null && (task.mOffsetYForInsets != 0 || task.mOffsetXForInsets != 0)) {

                    outAppBounds.offset(task.mOffsetXForInsets, task.mOffsetYForInsets);

                    outConfigBounds.offset(task.mOffsetXForInsets, task.mOffsetYForInsets);

                    ProtoLog.v(WM_DEBUG_CONFIGURATION,

                            "\tApplying task offsets for task=%s x=%d y=%d app=%s config=%s",

                            task, task.mOffsetXForInsets, task.mOffsetYForInsets,

                            outAppBounds, outConfigBounds);

                }

            }

            final DisplayPolicy.DecorInsets.Info decor =
@@ -280,17 +294,35 @@ public abstract class ConfigurationContainer<E extends ConfigurationContainer> { 
                if (inOutConfig.windowConfiguration.getWindowingMode()

                        == WINDOWING_MODE_MULTI_WINDOW) {

                    outAppBounds.inset(decor.mOverrideNonDecorInsets);

                    ProtoLog.v(WM_DEBUG_CONFIGURATION,

                            "\tInsetting app bounds by override non-decor insets=%s",

                            decor.mOverrideConfigInsets);

                }

            } else {

                ProtoLog.v(WM_DEBUG_CONFIGURATION,

                        "\tApp bounds intersects with override non-decor frame=%s bounds=%s",

                        decor.mOverrideNonDecorFrame, outAppBounds);

            }

            if (!outConfigBounds.intersect(decor.mOverrideConfigFrame)) {

                if (inOutConfig.windowConfiguration.getWindowingMode()

                        == WINDOWING_MODE_MULTI_WINDOW) {

                    outConfigBounds.inset(decor.mOverrideConfigInsets);

                    ProtoLog.v(WM_DEBUG_CONFIGURATION,

                            "\tInsetting config bounds by override config insets=%s",

                            decor.mOverrideConfigInsets);

                }

            } else {

                ProtoLog.v(WM_DEBUG_CONFIGURATION,

                        "\tConfig bounds intersects with override config frame=%s bounds=%s",

                        decor.mOverrideConfigFrame, outConfigBounds);

            }

            if (task != null && (task.mOffsetYForInsets != 0 || task.mOffsetXForInsets != 0)) {

                outAppBounds.offset(-task.mOffsetXForInsets, -task.mOffsetYForInsets);

                outConfigBounds.offset(-task.mOffsetXForInsets, -task.mOffsetYForInsets);

                ProtoLog.v(WM_DEBUG_CONFIGURATION,

                        "\tApplying inverse task offsets for x=%d y=%d app=%s config=%s",

                        -task.mOffsetXForInsets, -task.mOffsetYForInsets,

                        outAppBounds, outConfigBounds);

            }

        }

        float density = inOutConfig.densityDpi;
@@ -322,6 +354,7 @@ public abstract class ConfigurationContainer<E extends ConfigurationContainer> { 
                    ? ORIENTATION_PORTRAIT

                    : ORIENTATION_LANDSCAPE;

        }

        ProtoLog.v(WM_DEBUG_CONFIGURATION, "\tComputed size override config=%s", inOutConfig);

    }



    /** Returns {@code true} if requested override override configuration is not empty. */

services/core/java/com/android/server/wm/WindowOrganizerController.java

+9 −0
Original line number Diff line number Diff line
@@ -854,11 +854,20 @@ class WindowOrganizerController extends IWindowOrganizerController.Stub 
                                } else if (newBounds.right > display.right) {

                                    task.mOffsetXForInsets = display.right - newBounds.right;

                                }

                                ProtoLog.v(WM_DEBUG_WINDOW_ORGANIZER,

                                        "Applying inset offsets for task=%d offsetX=%d offsetY=%d",

                                        task.mTaskId, task.mOffsetXForInsets,

                                        task.mOffsetYForInsets);

                            } else {

                                task.mOffsetXForInsets = task.mOffsetYForInsets = 0;

                                ProtoLog.v(WM_DEBUG_WINDOW_ORGANIZER,

                                        "Resetting inset offsets for in-bounds task=%d",

                                        task.mTaskId);

                            }

                        } else {

                            task.mOffsetXForInsets = task.mOffsetYForInsets = 0;

                            ProtoLog.v(WM_DEBUG_WINDOW_ORGANIZER,

                                    "Resetting inset offsets for task=%d", task.mTaskId);

                        }

                    }

                }