Adding extra logging for tiles distribution across pages

There are a few things:
- adding generic methods in QSLogger to be able to log simple messages without adding extra methods to it
- moving all logging in PagedTileLayout to using QSLogger
- for every case when we force tiles redistribution, we log reason why it is happening
- adding temp logs for when tiles are not redistributed but maybe they should be
- logging when split shade state has changed in QSPanelControllerBase

Bug: 255208946
Test: just adding logging
Change-Id: Ie0b165edbf1f79dfff78c55646e513d37cea67a3

10 files changed, 103 insertions, 39 deletions

diff --git a/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java b/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
index 74d50433b9a7..a83a232b7b3d 100644
--- a/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
+++ b/packages/SystemUI/src/com/android/systemui/log/dagger/LogModule.java
@@ -121,7 +121,7 @@ public class LogModule {
     @SysUISingleton
     @QSLog
     public static LogBuffer provideQuickSettingsLogBuffer(LogBufferFactory factory) {
-        return factory.create("QSLog", 500 /* maxSize */, false /* systrace */);
+        return factory.create("QSLog", 700 /* maxSize */, false /* systrace */);
     }
 
     /** Provides a logging buffer for {@link com.android.systemui.broadcast.BroadcastDispatcher} */
diff --git a/packages/SystemUI/src/com/android/systemui/qs/PagedTileLayout.java b/packages/SystemUI/src/com/android/systemui/qs/PagedTileLayout.java
index 8ceee1a950ea..7523d6e976ce 100644
--- a/packages/SystemUI/src/com/android/systemui/qs/PagedTileLayout.java
+++ b/packages/SystemUI/src/com/android/systemui/qs/PagedTileLayout.java
@@ -11,7 +11,6 @@ import android.content.Context;
 import android.content.res.Configuration;
 import android.os.Bundle;
 import android.util.AttributeSet;
-import android.util.Log;
 import android.view.LayoutInflater;
 import android.view.View;
 import android.view.ViewGroup;
@@ -31,6 +30,7 @@ import com.android.systemui.R;
 import com.android.systemui.plugins.qs.QSTile;
 import com.android.systemui.qs.QSPanel.QSTileLayout;
 import com.android.systemui.qs.QSPanelControllerBase.TileRecord;
+import com.android.systemui.qs.logging.QSLogger;
 
 import java.util.ArrayList;
 import java.util.List;
@@ -38,11 +38,9 @@ import java.util.Set;
 
 public class PagedTileLayout extends ViewPager implements QSTileLayout {
 
-    private static final boolean DEBUG = false;
     private static final String CURRENT_PAGE = "current_page";
     private static final int NO_PAGE = -1;
 
-    private static final String TAG = "PagedTileLayout";
     private static final int REVEAL_SCROLL_DURATION_MILLIS = 750;
     private static final float BOUNCE_ANIMATION_TENSION = 1.3f;
     private static final long BOUNCE_ANIMATION_DURATION = 450L;
@@ -55,6 +53,7 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
     private final ArrayList<TileRecord> mTiles = new ArrayList<>();
     private final ArrayList<TileLayout> mPages = new ArrayList<>();
 
+    private QSLogger mLogger;
     @Nullable
     private PageIndicator mPageIndicator;
     private float mPageIndicatorPosition;
@@ -146,9 +145,15 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
         }
         if (mLayoutOrientation != newConfig.orientation) {
             mLayoutOrientation = newConfig.orientation;
-            mDistributeTiles = true;
+            forceTilesRedistribution("orientation changed to " + mLayoutOrientation);
             setCurrentItem(0, false);
             mPageToRestore = 0;
+        } else {
+            // logging in case we missed redistribution because orientation was not changed
+            // while configuration changed, can be removed after b/255208946 is fixed
+            mLogger.d(
+                    "Orientation didn't change, tiles might be not redistributed, new config",
+                    newConfig);
         }
     }
 
@@ -226,7 +231,7 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
             // Keep on drawing until the animation has finished.
             postInvalidateOnAnimation();
         } catch (NullPointerException e) {
-            Log.e(TAG, "FakeDragBy called before begin", e);
+            mLogger.logException("FakeDragBy called before begin", e);
             // If we were trying to fake drag, it means we just added a new tile to the last
             // page, so animate there.
             final int lastPageNumber = mPages.size() - 1;
@@ -246,7 +251,7 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
             super.endFakeDrag();
         } catch (NullPointerException e) {
             // Not sure what's going on. Let's log it
-            Log.e(TAG, "endFakeDrag called without velocityTracker", e);
+            mLogger.logException("endFakeDrag called without velocityTracker", e);
         }
     }
 
@@ -304,14 +309,14 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
     @Override
     public void addTile(TileRecord tile) {
         mTiles.add(tile);
-        mDistributeTiles = true;
+        forceTilesRedistribution("adding new tile");
         requestLayout();
     }
 
     @Override
     public void removeTile(TileRecord tile) {
         if (mTiles.remove(tile)) {
-            mDistributeTiles = true;
+            forceTilesRedistribution("removing tile");
             requestLayout();
         }
     }
@@ -367,19 +372,11 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
         final int tilesPerPageCount = mPages.get(0).maxTiles();
         int index = 0;
         final int totalTilesCount = mTiles.size();
-        if (DEBUG) {
-            Log.d(TAG, "Distributing tiles: "
-                    + "[tilesPerPageCount=" + tilesPerPageCount + "]"
-                    + "[totalTilesCount=" + totalTilesCount + "]"
-            );
-        }
+        mLogger.logTileDistributionInProgress(tilesPerPageCount, totalTilesCount);
         for (int i = 0; i < totalTilesCount; i++) {
             TileRecord tile = mTiles.get(i);
             if (mPages.get(index).mRecords.size() == tilesPerPageCount) index++;
-            if (DEBUG) {
-                Log.d(TAG, "Adding " + tile.tile.getClass().getSimpleName() + " to "
-                        + index);
-            }
+            mLogger.logTileDistributed(tile.tile.getClass().getSimpleName(), index);
             mPages.get(index).addTile(tile);
         }
     }
@@ -394,11 +391,11 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
             return;
         }
         while (mPages.size() < numPages) {
-            if (DEBUG) Log.d(TAG, "Adding page");
+            mLogger.d("Adding new page");
             mPages.add(createTileLayout());
         }
         while (mPages.size() > numPages) {
-            if (DEBUG) Log.d(TAG, "Removing page");
+            mLogger.d("Removing page");
             mPages.remove(mPages.size() - 1);
         }
         mPageIndicator.setNumPages(mPages.size());
@@ -417,8 +414,12 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
             changed |= mPages.get(i).updateResources();
         }
         if (changed) {
-            mDistributeTiles = true;
+            forceTilesRedistribution("resources in pages changed");
             requestLayout();
+        } else {
+            // logging in case we missed redistribution because number of column in updateResources
+            // was not changed, can be removed after b/255208946 is fixed
+            mLogger.d("resource in pages didn't change, tiles might be not redistributed");
         }
         return changed;
     }
@@ -430,7 +431,7 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
         for (int i = 0; i < mPages.size(); i++) {
             if (mPages.get(i).setMinRows(minRows)) {
                 changed = true;
-                mDistributeTiles = true;
+                forceTilesRedistribution("minRows changed in page");
             }
         }
         return changed;
@@ -443,7 +444,7 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
         for (int i = 0; i < mPages.size(); i++) {
             if (mPages.get(i).setMaxColumns(maxColumns)) {
                 changed = true;
-                mDistributeTiles = true;
+                forceTilesRedistribution("maxColumns in pages changed");
             }
         }
         return changed;
@@ -710,14 +711,14 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
     private final PagerAdapter mAdapter = new PagerAdapter() {
         @Override
         public void destroyItem(ViewGroup container, int position, Object object) {
-            if (DEBUG) Log.d(TAG, "Destantiating " + position);
+            mLogger.d("Destantiating page at", position);
             container.removeView((View) object);
             updateListening();
         }
 
         @Override
         public Object instantiateItem(ViewGroup container, int position) {
-            if (DEBUG) Log.d(TAG, "Instantiating " + position);
+            mLogger.d("Instantiating page at", position);
             if (isLayoutRtl()) {
                 position = mPages.size() - 1 - position;
             }
@@ -745,10 +746,15 @@ public class PagedTileLayout extends ViewPager implements QSTileLayout {
      * Force all tiles to be redistributed across pages.
      * Should be called when one of the following changes: rows, columns, number of tiles.
      */
-    public void forceTilesRedistribution() {
+    public void forceTilesRedistribution(String reason) {
+        mLogger.d("forcing tile redistribution across pages, reason", reason);
         mDistributeTiles = true;
     }
 
+    public void setLogger(QSLogger qsLogger) {
+        mLogger = qsLogger;
+    }
+
     public interface PageListener {
         int INVALID_PAGE = -1;
 
diff --git a/packages/SystemUI/src/com/android/systemui/qs/QSPanel.java b/packages/SystemUI/src/com/android/systemui/qs/QSPanel.java
index 6517ff33a49d..7067c220da87 100644
--- a/packages/SystemUI/src/com/android/systemui/qs/QSPanel.java
+++ b/packages/SystemUI/src/com/android/systemui/qs/QSPanel.java
@@ -43,6 +43,7 @@ import com.android.internal.logging.UiEventLogger;
 import com.android.internal.widget.RemeasuringLinearLayout;
 import com.android.systemui.R;
 import com.android.systemui.plugins.qs.QSTile;
+import com.android.systemui.qs.logging.QSLogger;
 import com.android.systemui.settings.brightness.BrightnessSliderController;
 import com.android.systemui.tuner.TunerService;
 import com.android.systemui.tuner.TunerService.Tunable;
@@ -106,6 +107,7 @@ public class QSPanel extends LinearLayout implements Tunable {
     private ViewGroup mMediaHostView;
     private boolean mShouldMoveMediaOnExpansion = true;
     private boolean mUsingCombinedHeaders = false;
+    private QSLogger mQsLogger;
 
     public QSPanel(Context context, AttributeSet attrs) {
         super(context, attrs);
@@ -122,7 +124,8 @@ public class QSPanel extends LinearLayout implements Tunable {
 
     }
 
-    void initialize() {
+    void initialize(QSLogger qsLogger) {
+        mQsLogger = qsLogger;
         mTileLayout = getOrCreateTileLayout();
 
         if (mUsingMediaPlayer) {
@@ -206,6 +209,7 @@ public class QSPanel extends LinearLayout implements Tunable {
         if (mTileLayout == null) {
             mTileLayout = (QSTileLayout) LayoutInflater.from(mContext)
                     .inflate(R.layout.qs_paged_tile_layout, this, false);
+            mTileLayout.setLogger(mQsLogger);
             mTileLayout.setSquishinessFraction(mSquishinessFraction);
         }
         return mTileLayout;
@@ -735,6 +739,8 @@ public class QSPanel extends LinearLayout implements Tunable {
         default void setExpansion(float expansion, float proposedTranslation) {}
 
         int getNumVisibleTiles();
+
+        default void setLogger(QSLogger qsLogger) { }
     }
 
     interface OnConfigurationChangedListener {
diff --git a/packages/SystemUI/src/com/android/systemui/qs/QSPanelController.java b/packages/SystemUI/src/com/android/systemui/qs/QSPanelController.java
index b2ca6b728113..cabe1daf16f4 100644
--- a/packages/SystemUI/src/com/android/systemui/qs/QSPanelController.java
+++ b/packages/SystemUI/src/com/android/systemui/qs/QSPanelController.java
@@ -122,9 +122,8 @@ public class QSPanelController extends QSPanelControllerBase<QSPanel> {
         }
         switchTileLayout(true);
         mBrightnessMirrorHandler.onQsPanelAttached();
-
-        ((PagedTileLayout) mView.getOrCreateTileLayout())
-                .setOnTouchListener(mTileLayoutTouchListener);
+        PagedTileLayout pagedTileLayout= ((PagedTileLayout) mView.getOrCreateTileLayout());
+        pagedTileLayout.setOnTouchListener(mTileLayoutTouchListener);
     }
 
     @Override
@@ -150,7 +149,8 @@ public class QSPanelController extends QSPanelControllerBase<QSPanel> {
 
     @Override
     protected void onSplitShadeChanged() {
-        ((PagedTileLayout) mView.getOrCreateTileLayout()).forceTilesRedistribution();
+        ((PagedTileLayout) mView.getOrCreateTileLayout())
+                .forceTilesRedistribution("Split shade state changed");
     }
 
     /** */
diff --git a/packages/SystemUI/src/com/android/systemui/qs/QSPanelControllerBase.java b/packages/SystemUI/src/com/android/systemui/qs/QSPanelControllerBase.java
index 60d2c177c7cd..7bb672ce5880 100644
--- a/packages/SystemUI/src/com/android/systemui/qs/QSPanelControllerBase.java
+++ b/packages/SystemUI/src/com/android/systemui/qs/QSPanelControllerBase.java
@@ -70,7 +70,7 @@ public abstract class QSPanelControllerBase<T extends QSPanel> extends ViewContr
     protected final MediaHost mMediaHost;
     protected final MetricsLogger mMetricsLogger;
     private final UiEventLogger mUiEventLogger;
-    private final QSLogger mQSLogger;
+    protected final QSLogger mQSLogger;
     private final DumpManager mDumpManager;
     protected final ArrayList<TileRecord> mRecords = new ArrayList<>();
     protected boolean mShouldUseSplitNotificationShade;
@@ -152,7 +152,7 @@ public abstract class QSPanelControllerBase<T extends QSPanel> extends ViewContr
 
     @Override
     protected void onInit() {
-        mView.initialize();
+        mView.initialize(mQSLogger);
         mQSLogger.logAllTilesChangeListening(mView.isListening(), mView.getDumpableTag(), "");
     }
 
@@ -430,6 +430,7 @@ public abstract class QSPanelControllerBase<T extends QSPanel> extends ViewContr
             pw.println("  horizontal layout: " + mUsingHorizontalLayout);
             pw.println("  last orientation: " + mLastOrientation);
         }
+        pw.println("  mShouldUseSplitNotificationShade: " + mShouldUseSplitNotificationShade);
     }
 
     public QSPanel.QSTileLayout getTileLayout() {
diff --git a/packages/SystemUI/src/com/android/systemui/qs/logging/QSLogger.kt b/packages/SystemUI/src/com/android/systemui/qs/logging/QSLogger.kt
index 9f6317fd931b..d682853f5fef 100644
--- a/packages/SystemUI/src/com/android/systemui/qs/logging/QSLogger.kt
+++ b/packages/SystemUI/src/com/android/systemui/qs/logging/QSLogger.kt
@@ -21,10 +21,13 @@ import com.android.systemui.log.dagger.QSLog
 import com.android.systemui.plugins.log.LogBuffer
 import com.android.systemui.plugins.log.LogLevel
 import com.android.systemui.plugins.log.LogLevel.DEBUG
+import com.android.systemui.plugins.log.LogLevel.ERROR
 import com.android.systemui.plugins.log.LogLevel.VERBOSE
+import com.android.systemui.plugins.log.LogLevel.WARNING
 import com.android.systemui.plugins.log.LogMessage
 import com.android.systemui.plugins.qs.QSTile
 import com.android.systemui.statusbar.StatusBarState
+import com.google.errorprone.annotations.CompileTimeConstant
 import javax.inject.Inject
 
 private const val TAG = "QSLog"
@@ -33,6 +36,26 @@ class QSLogger @Inject constructor(
     @QSLog private val buffer: LogBuffer
 ) {
 
+    fun d(@CompileTimeConstant msg: String) = buffer.log(TAG, DEBUG, msg)
+
+    fun e(@CompileTimeConstant msg: String) = buffer.log(TAG, ERROR, msg)
+
+    fun v(@CompileTimeConstant msg: String) = buffer.log(TAG, VERBOSE, msg)
+
+    fun w(@CompileTimeConstant msg: String) = buffer.log(TAG, WARNING, msg)
+
+    fun logException(@CompileTimeConstant logMsg: String, ex: Exception) {
+        buffer.log(TAG, ERROR, {}, { logMsg }, exception = ex)
+    }
+
+    fun v(@CompileTimeConstant msg: String, arg: Any) {
+        buffer.log(TAG, VERBOSE, { str1 = arg.toString() }, { "$msg: $str1" })
+    }
+
+    fun d(@CompileTimeConstant msg: String, arg: Any) {
+        buffer.log(TAG, DEBUG, { str1 = arg.toString() }, { "$msg: $str1" })
+    }
+
     fun logTileAdded(tileSpec: String) {
         log(DEBUG, {
             str1 = tileSpec
@@ -236,6 +259,24 @@ class QSLogger @Inject constructor(
         })
     }
 
+    fun logTileDistributionInProgress(tilesPerPageCount: Int, totalTilesCount: Int) {
+        log(DEBUG, {
+            int1 = tilesPerPageCount
+            int2 = totalTilesCount
+        }, {
+            "Distributing tiles: [tilesPerPageCount=$int1] [totalTilesCount=$int2]"
+        })
+    }
+
+    fun logTileDistributed(tileName: String, pageIndex: Int) {
+        log(DEBUG, {
+            str1 = tileName
+            int1 = pageIndex
+        }, {
+            "Adding $str1 to page number $int1"
+        })
+    }
+
     private fun toStateString(state: Int): String {
         return when (state) {
             Tile.STATE_ACTIVE -> "active"
diff --git a/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerBaseTest.java b/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerBaseTest.java
index caf8321949ca..5058373e39b0 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerBaseTest.java
+++ b/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerBaseTest.java
@@ -226,7 +226,8 @@ public class QSPanelControllerBaseTest extends SysuiTestCase {
                 + "    " + mockTileViewString + "\n"
                 + "  media bounds: null\n"
                 + "  horizontal layout: false\n"
-                + "  last orientation: 0\n";
+                + "  last orientation: 0\n"
+                + "  mShouldUseSplitNotificationShade: false\n";
         assertEquals(expected, w.getBuffer().toString());
     }
 
diff --git a/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerTest.kt b/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerTest.kt
index 5e082f686ea3..6cf642cb7fd2 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerTest.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelControllerTest.kt
@@ -135,10 +135,10 @@ class QSPanelControllerTest : SysuiTestCase() {
     fun configurationChange_onlySplitShadeConfigChanges_tileAreRedistributed() {
         testableResources.addOverride(R.bool.config_use_split_notification_shade, false)
         controller.mOnConfigurationChangedListener.onConfigurationChange(configuration)
-        verify(pagedTileLayout, never()).forceTilesRedistribution()
+        verify(pagedTileLayout, never()).forceTilesRedistribution(any())
 
         testableResources.addOverride(R.bool.config_use_split_notification_shade, true)
         controller.mOnConfigurationChangedListener.onConfigurationChange(configuration)
-        verify(pagedTileLayout).forceTilesRedistribution()
+        verify(pagedTileLayout).forceTilesRedistribution("Split shade state changed")
     }
 }
diff --git a/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelTest.kt b/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelTest.kt
index 7c930b196d68..d52b29642acf 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelTest.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/qs/QSPanelTest.kt
@@ -27,6 +27,7 @@ import androidx.test.filters.SmallTest
 import com.android.systemui.R
 import com.android.systemui.SysuiTestCase
 import com.android.systemui.plugins.qs.QSTile
+import com.android.systemui.qs.logging.QSLogger
 import com.android.systemui.qs.tileimpl.QSIconViewImpl
 import com.android.systemui.qs.tileimpl.QSTileViewImpl
 import com.google.common.truth.Truth.assertThat
@@ -34,6 +35,7 @@ import org.junit.After
 import org.junit.Before
 import org.junit.Test
 import org.junit.runner.RunWith
+import org.mockito.Mock
 import org.mockito.Mockito.mock
 import org.mockito.Mockito.verify
 import org.mockito.MockitoAnnotations
@@ -42,6 +44,9 @@ import org.mockito.MockitoAnnotations
 @RunWithLooper
 @SmallTest
 class QSPanelTest : SysuiTestCase() {
+
+    @Mock private lateinit var qsLogger: QSLogger
+
     private lateinit var testableLooper: TestableLooper
     private lateinit var qsPanel: QSPanel
 
@@ -57,7 +62,7 @@ class QSPanelTest : SysuiTestCase() {
             qsPanel = QSPanel(context, null)
             qsPanel.mUsingMediaPlayer = true
 
-            qsPanel.initialize()
+            qsPanel.initialize(qsLogger)
             // QSPanel inflates a footer inside of it, mocking it here
             footer = LinearLayout(context).apply { id = R.id.qs_footer }
             qsPanel.addView(footer, MATCH_PARENT, 100)
diff --git a/packages/SystemUI/tests/src/com/android/systemui/qs/QuickQSPanelTest.kt b/packages/SystemUI/tests/src/com/android/systemui/qs/QuickQSPanelTest.kt
index a6a584d2e622..3fba3938db19 100644
--- a/packages/SystemUI/tests/src/com/android/systemui/qs/QuickQSPanelTest.kt
+++ b/packages/SystemUI/tests/src/com/android/systemui/qs/QuickQSPanelTest.kt
@@ -7,10 +7,12 @@ import android.view.accessibility.AccessibilityNodeInfo
 import android.widget.FrameLayout
 import androidx.test.filters.SmallTest
 import com.android.systemui.SysuiTestCase
+import com.android.systemui.qs.logging.QSLogger
 import com.google.common.truth.Truth
 import org.junit.Before
 import org.junit.Test
 import org.junit.runner.RunWith
+import org.mockito.Mock
 import org.mockito.Mockito
 import org.mockito.MockitoAnnotations
 
@@ -19,6 +21,8 @@ import org.mockito.MockitoAnnotations
 @SmallTest
 class QuickQSPanelTest : SysuiTestCase() {
 
+    @Mock private lateinit var qsLogger: QSLogger
+
     private lateinit var testableLooper: TestableLooper
     private lateinit var quickQSPanel: QuickQSPanel
 
@@ -32,7 +36,7 @@ class QuickQSPanelTest : SysuiTestCase() {
 
         testableLooper.runWithLooper {
             quickQSPanel = QuickQSPanel(mContext, null)
-            quickQSPanel.initialize()
+            quickQSPanel.initialize(qsLogger)
 
             quickQSPanel.onFinishInflate()
             // Provides a parent with non-zero size for QSPanel