Merge "Add logs to handleClick methods in QSTileImpl" into tm-qpr-dev

packages/SystemUI/src/com/android/systemui/qs/logging/QSLogger.kt

@@ -69,36 +69,63 @@ class QSLogger @Inject constructor(
         })
     }
 
-    fun logTileClick(tileSpec: String, statusBarState: Int, state: Int) {
+    fun logTileClick(tileSpec: String, statusBarState: Int, state: Int, eventId: Int) {
         log(DEBUG, {
             str1 = tileSpec
-            int1 = statusBarState
+            int1 = eventId
             str2 = StatusBarState.toString(statusBarState)
             str3 = toStateString(state)
         }, {
-            "[$str1] Tile clicked. StatusBarState=$str2. TileState=$str3"
+            "[$str1][$int1] Tile clicked. StatusBarState=$str2. TileState=$str3"
         })
     }
 
-    fun logTileSecondaryClick(tileSpec: String, statusBarState: Int, state: Int) {
+    fun logHandleClick(tileSpec: String, eventId: Int) {
         log(DEBUG, {
             str1 = tileSpec
-            int1 = statusBarState
+            int1 = eventId
-            str2 = StatusBarState.toString(statusBarState)
-            str3 = toStateString(state)
         }, {
-            "[$str1] Tile long clicked. StatusBarState=$str2. TileState=$str3"
+            "[$str1][$int1] Tile handling click."
         })
     }
 
-    fun logTileLongClick(tileSpec: String, statusBarState: Int, state: Int) {
+    fun logTileSecondaryClick(tileSpec: String, statusBarState: Int, state: Int, eventId: Int) {
         log(DEBUG, {
             str1 = tileSpec
-            int1 = statusBarState
+            int1 = eventId
             str2 = StatusBarState.toString(statusBarState)
             str3 = toStateString(state)
         }, {
-            "[$str1] Tile long clicked. StatusBarState=$str2. TileState=$str3"
+            "[$str1][$int1] Tile secondary clicked. StatusBarState=$str2. TileState=$str3"
+        })
+    }
+
+    fun logHandleSecondaryClick(tileSpec: String, eventId: Int) {
+        log(DEBUG, {
+            str1 = tileSpec
+            int1 = eventId
+        }, {
+            "[$str1][$int1] Tile handling secondary click."
+        })
+    }
+
+    fun logTileLongClick(tileSpec: String, statusBarState: Int, state: Int, eventId: Int) {
+        log(DEBUG, {
+            str1 = tileSpec
+            int1 = eventId
+            str2 = StatusBarState.toString(statusBarState)
+            str3 = toStateString(state)
+        }, {
+            "[$str1][$int1] Tile long clicked. StatusBarState=$str2. TileState=$str3"
+        })
+    }
+
+    fun logHandleLongClick(tileSpec: String, eventId: Int) {
+        log(DEBUG, {
+            str1 = tileSpec
+            int1 = eventId
+        }, {
+            "[$str1][$int1] Tile handling long click."
         })
     }
 
@@ -144,4 +171,4 @@ class QSLogger @Inject constructor(
     ) {
         buffer.log(TAG, logLevel, initializer, printer)
     }
-}
+}

packages/SystemUI/src/com/android/systemui/qs/tileimpl/QSTileImpl.java

@@ -105,6 +105,9 @@ public abstract class QSTileImpl<TState extends State> implements QSTile, Lifecy
     private final FalsingManager mFalsingManager;
     protected final QSLogger mQSLogger;
     private volatile int mReadyState;
+    // Keeps track of the click event, to match it with the handling in the background thread
+    // Only read and modified in main thread (where click events come through).
+    private int mClickEventId = 0;
 
     private final ArrayList<Callback> mCallbacks = new ArrayList<>();
     private final Object mStaleListener = new Object();
@@ -295,9 +298,11 @@ public abstract class QSTileImpl<TState extends State> implements QSTile, Lifecy
                         mStatusBarStateController.getState())));
         mUiEventLogger.logWithInstanceId(QSEvent.QS_ACTION_CLICK, 0, getMetricsSpec(),
                 getInstanceId());
-        mQSLogger.logTileClick(mTileSpec, mStatusBarStateController.getState(), mState.state);
+        final int eventId = mClickEventId++;
+        mQSLogger.logTileClick(mTileSpec, mStatusBarStateController.getState(), mState.state,
+                eventId);
         if (!mFalsingManager.isFalseTap(FalsingManager.LOW_PENALTY)) {
-            mHandler.obtainMessage(H.CLICK, view).sendToTarget();
+            mHandler.obtainMessage(H.CLICK, eventId, 0, view).sendToTarget();
         }
     }
 
@@ -307,9 +312,10 @@ public abstract class QSTileImpl<TState extends State> implements QSTile, Lifecy
                         mStatusBarStateController.getState())));
         mUiEventLogger.logWithInstanceId(QSEvent.QS_ACTION_SECONDARY_CLICK, 0, getMetricsSpec(),
                 getInstanceId());
+        final int eventId = mClickEventId++;
         mQSLogger.logTileSecondaryClick(mTileSpec, mStatusBarStateController.getState(),
-                mState.state);
+                mState.state, eventId);
-        mHandler.obtainMessage(H.SECONDARY_CLICK, view).sendToTarget();
+        mHandler.obtainMessage(H.SECONDARY_CLICK, eventId, 0, view).sendToTarget();
     }
 
     @Override
@@ -319,8 +325,10 @@ public abstract class QSTileImpl<TState extends State> implements QSTile, Lifecy
                         mStatusBarStateController.getState())));
         mUiEventLogger.logWithInstanceId(QSEvent.QS_ACTION_LONG_PRESS, 0, getMetricsSpec(),
                 getInstanceId());
-        mQSLogger.logTileLongClick(mTileSpec, mStatusBarStateController.getState(), mState.state);
+        final int eventId = mClickEventId++;
-        mHandler.obtainMessage(H.LONG_CLICK, view).sendToTarget();
+        mQSLogger.logTileLongClick(mTileSpec, mStatusBarStateController.getState(), mState.state,
+                eventId);
+        mHandler.obtainMessage(H.LONG_CLICK, eventId, 0, view).sendToTarget();
     }
 
     public LogMaker populate(LogMaker logMaker) {
@@ -590,13 +598,16 @@ public abstract class QSTileImpl<TState extends State> implements QSTile, Lifecy
                                 mContext, mEnforcedAdmin);
                         mActivityStarter.postStartActivityDismissingKeyguard(intent, 0);
                     } else {
+                        mQSLogger.logHandleClick(mTileSpec, msg.arg1);
                         handleClick((View) msg.obj);
                     }
                 } else if (msg.what == SECONDARY_CLICK) {
                     name = "handleSecondaryClick";
+                    mQSLogger.logHandleSecondaryClick(mTileSpec, msg.arg1);
                     handleSecondaryClick((View) msg.obj);
                 } else if (msg.what == LONG_CLICK) {
                     name = "handleLongClick";
+                    mQSLogger.logHandleLongClick(mTileSpec, msg.arg1);
                     handleLongClick((View) msg.obj);
                 } else if (msg.what == REFRESH_STATE) {
                     name = "handleRefreshState";

packages/SystemUI/tests/src/com/android/systemui/qs/tileimpl/QSTileImplTest.java

@@ -37,6 +37,7 @@ import static org.mockito.ArgumentMatchers.anyInt;
 import static org.mockito.ArgumentMatchers.anyString;
 import static org.mockito.ArgumentMatchers.eq;
 import static org.mockito.Matchers.argThat;
+import static org.mockito.Mockito.inOrder;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.verify;
 import static org.mockito.Mockito.when;
@@ -78,6 +79,7 @@ import org.junit.runner.RunWith;
 import org.mockito.ArgumentCaptor;
 import org.mockito.ArgumentMatcher;
 import org.mockito.Captor;
+import org.mockito.InOrder;
 import org.mockito.Mock;
 import org.mockito.MockitoAnnotations;
 
@@ -144,7 +146,25 @@ public class QSTileImplTest extends SysuiTestCase {
         when(mStatusBarStateController.getState()).thenReturn(StatusBarState.SHADE);
 
         mTile.click(null /* view */);
-        verify(mQsLogger).logTileClick(SPEC, StatusBarState.SHADE, Tile.STATE_ACTIVE);
+        verify(mQsLogger).logTileClick(eq(SPEC), eq(StatusBarState.SHADE), eq(Tile.STATE_ACTIVE),
+                anyInt());
+    }
+
+    @Test
+    public void testHandleClick_log() {
+        mTile.click(null);
+        mTile.click(null);
+        mTestableLooper.processAllMessages();
+        mTile.click(null);
+        mTestableLooper.processAllMessages();
+
+        InOrder inOrder = inOrder(mQsLogger);
+        inOrder.verify(mQsLogger).logTileClick(eq(SPEC), anyInt(), anyInt(), eq(0));
+        inOrder.verify(mQsLogger).logTileClick(eq(SPEC), anyInt(), anyInt(), eq(1));
+        inOrder.verify(mQsLogger).logHandleClick(SPEC, 0);
+        inOrder.verify(mQsLogger).logHandleClick(SPEC, 1);
+        inOrder.verify(mQsLogger).logTileClick(eq(SPEC), anyInt(), anyInt(), eq(2));
+        inOrder.verify(mQsLogger).logHandleClick(SPEC, 2);
     }
 
     @Test
@@ -183,7 +203,25 @@ public class QSTileImplTest extends SysuiTestCase {
         when(mStatusBarStateController.getState()).thenReturn(StatusBarState.SHADE);
 
         mTile.secondaryClick(null /* view */);
-        verify(mQsLogger).logTileSecondaryClick(SPEC, StatusBarState.SHADE, Tile.STATE_ACTIVE);
+        verify(mQsLogger).logTileSecondaryClick(eq(SPEC), eq(StatusBarState.SHADE),
+                eq(Tile.STATE_ACTIVE), anyInt());
+    }
+
+    @Test
+    public void testHandleSecondaryClick_log() {
+        mTile.secondaryClick(null);
+        mTile.secondaryClick(null);
+        mTestableLooper.processAllMessages();
+        mTile.secondaryClick(null);
+        mTestableLooper.processAllMessages();
+
+        InOrder inOrder = inOrder(mQsLogger);
+        inOrder.verify(mQsLogger).logTileSecondaryClick(eq(SPEC), anyInt(), anyInt(), eq(0));
+        inOrder.verify(mQsLogger).logTileSecondaryClick(eq(SPEC), anyInt(), anyInt(), eq(1));
+        inOrder.verify(mQsLogger).logHandleSecondaryClick(SPEC, 0);
+        inOrder.verify(mQsLogger).logHandleSecondaryClick(SPEC, 1);
+        inOrder.verify(mQsLogger).logTileSecondaryClick(eq(SPEC), anyInt(), anyInt(), eq(2));
+        inOrder.verify(mQsLogger).logHandleSecondaryClick(SPEC, 2);
     }
 
     @Test
@@ -210,7 +248,25 @@ public class QSTileImplTest extends SysuiTestCase {
         when(mStatusBarStateController.getState()).thenReturn(StatusBarState.SHADE);
 
         mTile.longClick(null /* view */);
-        verify(mQsLogger).logTileLongClick(SPEC, StatusBarState.SHADE, Tile.STATE_ACTIVE);
+        verify(mQsLogger).logTileLongClick(eq(SPEC), eq(StatusBarState.SHADE),
+                eq(Tile.STATE_ACTIVE), anyInt());
+    }
+
+    @Test
+    public void testHandleLongClick_log() {
+        mTile.longClick(null);
+        mTile.longClick(null);
+        mTestableLooper.processAllMessages();
+        mTile.longClick(null);
+        mTestableLooper.processAllMessages();
+
+        InOrder inOrder = inOrder(mQsLogger);
+        inOrder.verify(mQsLogger).logTileLongClick(eq(SPEC), anyInt(), anyInt(), eq(0));
+        inOrder.verify(mQsLogger).logTileLongClick(eq(SPEC), anyInt(), anyInt(), eq(1));
+        inOrder.verify(mQsLogger).logHandleLongClick(SPEC, 0);
+        inOrder.verify(mQsLogger).logHandleLongClick(SPEC, 1);
+        inOrder.verify(mQsLogger).logTileLongClick(eq(SPEC), anyInt(), anyInt(), eq(2));
+        inOrder.verify(mQsLogger).logHandleLongClick(SPEC, 2);
     }
 
     @Test