Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Add logs to handleClick methods in QSTileImpl

Browse Source 
This way, we can compare roundtrip time in the background handler to
understand delays.

Test: atest QSTileImplTest
Bug: 235706747
Change-Id: I664d573a4b77ef992d896949468d3d53af5f8cce
This commit is contained in:
Fabian Kozynski
2022-08-04 13:53:54 -04:00
parent e04531c84a
commit 7347ddbbb2
3 changed files with 115 additions and 21 deletions
Download Patch File Download Diff File Expand all files Collapse all files

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

@@ -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
str2 = StatusBarState.toString(statusBarState)
str3 = toStateString(state)
int1 = eventId
}, {
"[$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)
}
}
}

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

@@ -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);
mHandler.obtainMessage(H.SECONDARY_CLICK, view).sendToTarget();
mState.state, eventId);
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);
mHandler.obtainMessage(H.LONG_CLICK, view).sendToTarget();
final int eventId = mClickEventId++;
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";

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

@@ -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