From e4b0f28a47097b7b0c04f3ae80507e2a15e3314f Mon Sep 17 00:00:00 2001 From: Jorim Jaggi Date: Wed, 17 May 2017 15:10:29 +0200 Subject: [PATCH] Enable starting window logging Also extend it to make sure we catch the bug! Test: Open a couple of cold/hot apps, make sure logs look accurate Bug: 37888853 Change-Id: Ied394969748d4d2d40359af15e0b491a2dc2b078 --- .../server/wm/AppWindowContainerController.java | 34 +++++++++++++++++----- .../java/com/android/server/wm/AppWindowToken.java | 5 +++- .../com/android/server/wm/TaskSnapshotSurface.java | 7 +++++ .../server/wm/WindowManagerDebugConfig.java | 3 +- .../java/com/android/server/wm/WindowState.java | 3 +- .../com/android/server/wm/WindowStateAnimator.java | 3 +- 6 files changed, 44 insertions(+), 11 deletions(-) diff --git a/services/core/java/com/android/server/wm/AppWindowContainerController.java b/services/core/java/com/android/server/wm/AppWindowContainerController.java index 5545e2b770ee..c982f081d624 100644 --- a/services/core/java/com/android/server/wm/AppWindowContainerController.java +++ b/services/core/java/com/android/server/wm/AppWindowContainerController.java @@ -19,6 +19,7 @@ package com.android.server.wm; import static android.content.pm.ActivityInfo.SCREEN_ORIENTATION_UNSPECIFIED; import static android.view.WindowManager.LayoutParams.FLAG_SHOW_WALLPAPER; import static com.android.server.wm.AppTransition.TRANSIT_UNSET; +import static com.android.server.wm.WindowManagerDebugConfig.DEBUG; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_ADD_REMOVE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_APP_TRANSITIONS; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_ORIENTATION; @@ -98,18 +99,27 @@ public class AppWindowContainerController private final Runnable mRemoveStartingWindow = () -> { StartingSurface surface = null; synchronized (mWindowMap) { - if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Remove starting " + mContainer - + ": startingWindow=" + mContainer.startingWindow - + " startingView=" + mContainer.startingSurface); if (mContainer == null) { + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "mContainer was null while trying to" + + " remove starting window"); return; } + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Remove starting " + mContainer + + ": startingWindow=" + mContainer.startingWindow + + " startingView=" + mContainer.startingSurface); if (mContainer.startingWindow != null) { surface = mContainer.startingSurface; mContainer.startingData = null; mContainer.startingSurface = null; mContainer.startingWindow = null; mContainer.startingDisplayed = false; + if (surface == null && DEBUG_STARTING_WINDOW) { + Slog.v(TAG_WM, "startingWindow was set but startingSurface==null, couldn't " + + "remove"); + } + } else if (DEBUG_STARTING_WINDOW) { + Slog.v(TAG_WM, "Tried to remove starting window but startingWindow was null:" + + mContainer); } } if (surface != null) { @@ -127,6 +137,8 @@ public class AppWindowContainerController synchronized (mWindowMap) { if (mContainer == null) { + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "mContainer was null while trying to" + + " add starting window"); return; } startingData = mContainer.startingData; @@ -135,6 +147,8 @@ public class AppWindowContainerController if (startingData == null) { // Animation has been canceled... do nothing. + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "startingData was nulled out before handling" + + " mAddStartingWindow: " + mContainer); return; } @@ -174,6 +188,8 @@ public class AppWindowContainerController if (abort) { surface.remove(); } + } else if (DEBUG_STARTING_WINDOW) { + Slog.v(TAG_WM, "Surface returned was null: " + mContainer); } }; @@ -450,7 +466,9 @@ public class AppWindowContainerController boolean allowTaskSnapshot, boolean activityCreated) { synchronized(mWindowMap) { if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "setAppStartingWindow: token=" + mToken - + " pkg=" + pkg + " transferFrom=" + transferFrom); + + " pkg=" + pkg + " transferFrom=" + transferFrom + " newTask=" + newTask + + " taskSwitch=" + taskSwitch + " processRunning=" + processRunning + + " allowTaskSnapshot=" + allowTaskSnapshot); if (mContainer == null) { Slog.w(TAG_WM, "Attempted to set icon of non-existing app token: " + mToken); @@ -536,7 +554,7 @@ public class AppWindowContainerController return false; } - if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Creating StartingData"); + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Creating SplashScreenStartingData"); mContainer.startingData = new SplashScreenStartingData(mService, pkg, theme, compatInfo, nonLocalizedLabel, labelRes, icon, logo, windowFlags, mContainer.getMergedOverrideConfiguration()); @@ -574,6 +592,7 @@ public class AppWindowContainerController return false; } + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Creating SnapshotStartingData"); mContainer.startingData = new SnapshotStartingData(mService, snapshot); scheduleAddStartingWindow(); return true; @@ -583,6 +602,8 @@ public class AppWindowContainerController synchronized (mWindowMap) { if (mHandler.hasCallbacks(mRemoveStartingWindow)) { // Already scheduled. + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Trying to remove starting window but " + + "already scheduled"); return; } @@ -597,8 +618,7 @@ public class AppWindowContainerController return; } - if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, Debug.getCallers(1) - + ": Schedule remove starting " + mContainer + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Schedule remove starting " + mContainer + " startingWindow=" + mContainer.startingWindow); mHandler.post(mRemoveStartingWindow); } diff --git a/services/core/java/com/android/server/wm/AppWindowToken.java b/services/core/java/com/android/server/wm/AppWindowToken.java index 52eb2fb01d79..17db253adb16 100644 --- a/services/core/java/com/android/server/wm/AppWindowToken.java +++ b/services/core/java/com/android/server/wm/AppWindowToken.java @@ -38,6 +38,7 @@ import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_FOCUS_LIGHT; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_LAYOUT_REPEATS; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_ORIENTATION; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW; +import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW_VERBOSE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_TOKEN_MOVEMENT; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_VISIBILITY; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_WINDOW_MOVEMENT; @@ -806,6 +807,8 @@ class AppWindowToken extends WindowToken implements WindowManagerService.AppFree } else if (mChildren.size() == 1 && startingSurface != null && !isRelaunching()) { // If this is the last window except for a starting transition window, // we need to get rid of the starting transition. + if (DEBUG_STARTING_WINDOW) Slog.v(TAG_WM, "Last window, removing starting window " + + win); if (getController() != null) { getController().removeStartingWindow(); } @@ -1372,7 +1375,7 @@ class AppWindowToken extends WindowToken implements WindowManagerService.AppFree * windows in this app token where not considered drawn as of the last pass. */ boolean updateDrawnWindowStates(WindowState w) { - if (DEBUG_STARTING_WINDOW && w == startingWindow) { + if (DEBUG_STARTING_WINDOW_VERBOSE && w == startingWindow) { Slog.d(TAG, "updateWindows: starting " + w + " isOnScreen=" + w.isOnScreen() + " allDrawn=" + allDrawn + " freezingScreen=" + mAppAnimator.freezingScreen); } diff --git a/services/core/java/com/android/server/wm/TaskSnapshotSurface.java b/services/core/java/com/android/server/wm/TaskSnapshotSurface.java index 5e71bcbe557e..3a116bb10d98 100644 --- a/services/core/java/com/android/server/wm/TaskSnapshotSurface.java +++ b/services/core/java/com/android/server/wm/TaskSnapshotSurface.java @@ -39,6 +39,7 @@ import static com.android.internal.policy.DecorView.STATUS_BAR_COLOR_VIEW_ATTRIB import static com.android.internal.policy.DecorView.getColorViewLeftInset; import static com.android.internal.policy.DecorView.getColorViewTopInset; import static com.android.internal.policy.DecorView.getNavigationBarRect; +import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW; import static com.android.server.wm.WindowManagerDebugConfig.TAG_WITH_CLASS_NAME; import static com.android.server.wm.WindowManagerDebugConfig.TAG_WM; @@ -232,10 +233,14 @@ class TaskSnapshotSurface implements StartingSurface { final long now = SystemClock.uptimeMillis(); if (mSizeMismatch && now - mShownTime < SIZE_MISMATCH_MINIMUM_TIME_MS) { mHandler.postAtTime(this::remove, mShownTime + SIZE_MISMATCH_MINIMUM_TIME_MS); + if (DEBUG_STARTING_WINDOW) { + Slog.v(TAG, "Defer removing snapshot surface in " + (now - mShownTime) + "ms"); + } return; } } try { + if (DEBUG_STARTING_WINDOW) Slog.v(TAG, "Removing snapshot surface"); mSession.remove(mWindow); } catch (RemoteException e) { // Local call. @@ -254,6 +259,8 @@ class TaskSnapshotSurface implements StartingSurface { private void drawSnapshot() { final GraphicBuffer buffer = mSnapshot.getSnapshot(); + if (DEBUG_STARTING_WINDOW) Slog.v(TAG, "Drawing snapshot surface sizeMismatch=" + + mSizeMismatch); if (mSizeMismatch) { // The dimensions of the buffer and the window don't match, so attaching the buffer // will fail. Better create a child window with the exact dimensions and fill the parent diff --git a/services/core/java/com/android/server/wm/WindowManagerDebugConfig.java b/services/core/java/com/android/server/wm/WindowManagerDebugConfig.java index 1b61fca5e25c..8279b5167766 100644 --- a/services/core/java/com/android/server/wm/WindowManagerDebugConfig.java +++ b/services/core/java/com/android/server/wm/WindowManagerDebugConfig.java @@ -51,7 +51,8 @@ public class WindowManagerDebugConfig { static final boolean DEBUG_APP_ORIENTATION = false; static final boolean DEBUG_CONFIGURATION = false; static final boolean DEBUG_APP_TRANSITIONS = false; - static final boolean DEBUG_STARTING_WINDOW = false; + static final boolean DEBUG_STARTING_WINDOW_VERBOSE = false; + static final boolean DEBUG_STARTING_WINDOW = DEBUG_STARTING_WINDOW_VERBOSE || true; static final boolean DEBUG_WALLPAPER = false; static final boolean DEBUG_WALLPAPER_LIGHT = false || DEBUG_WALLPAPER; static final boolean DEBUG_DRAG = false; diff --git a/services/core/java/com/android/server/wm/WindowState.java b/services/core/java/com/android/server/wm/WindowState.java index a69bc58e8d20..83e0551487d1 100644 --- a/services/core/java/com/android/server/wm/WindowState.java +++ b/services/core/java/com/android/server/wm/WindowState.java @@ -80,6 +80,7 @@ import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_ORIENTATION; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_POWER; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_RESIZE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW; +import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW_VERBOSE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_SURFACE_TRACE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_VISIBILITY; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_WALLPAPER_LIGHT; @@ -3785,7 +3786,7 @@ class WindowState extends WindowContainer implements WindowManagerP private void logPerformShow(String prefix) { if (DEBUG_VISIBILITY - || (DEBUG_STARTING_WINDOW && mAttrs.type == TYPE_APPLICATION_STARTING)) { + || (DEBUG_STARTING_WINDOW_VERBOSE && mAttrs.type == TYPE_APPLICATION_STARTING)) { Slog.v(TAG, prefix + this + ": mDrawState=" + mWinAnimator.drawStateToString() + " readyForDisplay=" + isReadyForDisplay() diff --git a/services/core/java/com/android/server/wm/WindowStateAnimator.java b/services/core/java/com/android/server/wm/WindowStateAnimator.java index e1c6bc39ca41..d75afcf357a8 100644 --- a/services/core/java/com/android/server/wm/WindowStateAnimator.java +++ b/services/core/java/com/android/server/wm/WindowStateAnimator.java @@ -30,6 +30,7 @@ import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_LAYERS; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_LAYOUT_REPEATS; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_ORIENTATION; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW; +import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_STARTING_WINDOW_VERBOSE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_SURFACE_TRACE; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_VISIBILITY; import static com.android.server.wm.WindowManagerDebugConfig.DEBUG_WALLPAPER; @@ -519,7 +520,7 @@ class WindowStateAnimator { // This must be called while inside a transaction. boolean commitFinishDrawingLocked() { - if (DEBUG_STARTING_WINDOW && + if (DEBUG_STARTING_WINDOW_VERBOSE && mWin.mAttrs.type == WindowManager.LayoutParams.TYPE_APPLICATION_STARTING) { Slog.i(TAG, "commitFinishDrawingLocked: " + mWin + " cur mDrawState=" + drawStateToString()); -- 2.11.0