Log LPNH abandon times at least 200ms.
Restricting to 200ms+ to reduce the spamminess of these logs.
The idea is to log the latency of LPNH abandons to see the effect
of prewarming at x ms.
Bug: 397484410
Flag: EXEMPT logging
Test: Manual and updated NavHandleLongPressInputConsumerTest.
Change-Id: I93f94ed0757508b68fcb48d61bdd194564dcc573
diff --git a/quickstep/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumer.java b/quickstep/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumer.java
index afe988d..a703c23 100644
--- a/quickstep/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumer.java
+++ b/quickstep/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumer.java
@@ -19,6 +19,7 @@
import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_DEEP_PRESS_STASHED_TASKBAR;
import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_LONG_PRESS_NAVBAR;
import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_LONG_PRESS_STASHED_TASKBAR;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON;
import static com.android.launcher3.util.Executors.MAIN_EXECUTOR;
import static com.android.launcher3.util.LogConfig.NAV_HANDLE_LONG_PRESS;
@@ -30,6 +31,7 @@
import androidx.annotation.VisibleForTesting;
import com.android.launcher3.Utilities;
+import com.android.launcher3.logging.InstanceIdSequence;
import com.android.launcher3.logging.StatsLogManager;
import com.android.launcher3.util.DisplayController;
import com.android.quickstep.DeviceConfigWrapper;
@@ -49,6 +51,8 @@
private static final String TAG = "NavHandleLongPressIC";
private static final boolean DEBUG_NAV_HANDLE = Utilities.isPropertyEnabled(
NAV_HANDLE_LONG_PRESS);
+ // Minimum time between touch down and abandon to log.
+ @VisibleForTesting static final long MIN_TIME_TO_LOG_ABANDON_MS = 200;
private NavHandleLongPressHandler mNavHandleLongPressHandler;
private final float mNavHandleWidth;
@@ -62,11 +66,12 @@
private final int mOuterLongPressTimeout;
private final boolean mDeepPressEnabled;
private final NavHandle mNavHandle;
- private final StatsLogManager mStatsLogManager;
+ private StatsLogManager mStatsLogManager;
private final TopTaskTracker mTopTaskTracker;
private final GestureState mGestureState;
- private MotionEvent mCurrentDownEvent;
+ private MotionEvent mCurrentDownEvent; // Down event that started the current gesture.
+ private MotionEvent mCurrentMotionEvent; // Most recent motion event.
private boolean mDeepPressLogged; // Whether deep press has been logged for the current touch.
public NavHandleLongPressInputConsumer(Context context, InputConsumer delegate,
@@ -125,6 +130,10 @@
@Override
public void onMotionEvent(MotionEvent ev) {
+ if (mCurrentMotionEvent != null) {
+ mCurrentMotionEvent.recycle();
+ }
+ mCurrentMotionEvent = MotionEvent.obtain(ev);
if (mDelegate.allowInterceptByParent()) {
handleMotionEvent(ev);
} else if (MAIN_EXECUTOR.getHandler().hasCallbacks(mTriggerLongPress)) {
@@ -244,6 +253,15 @@
if (DEBUG_NAV_HANDLE) {
Log.d(TAG, "cancelLongPress: " + reason);
}
+ // Log LPNH abandon latency if we didn't trigger but were still prepared to.
+ long latencyMs = mCurrentMotionEvent.getEventTime() - mCurrentDownEvent.getEventTime();
+ if (mState != STATE_ACTIVE && MAIN_EXECUTOR.getHandler().hasCallbacks(mTriggerLongPress)
+ && latencyMs >= MIN_TIME_TO_LOG_ABANDON_MS) {
+ mStatsLogManager.latencyLogger()
+ .withInstanceId(new InstanceIdSequence().newInstanceId())
+ .withLatency(latencyMs)
+ .log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
+ }
mGestureState.setIsInExtendedSlopRegion(false);
MAIN_EXECUTOR.getHandler().removeCallbacks(mTriggerLongPress);
mNavHandleLongPressHandler.onTouchFinished(mNavHandle, reason);
@@ -274,4 +292,9 @@
void setNavHandleLongPressHandler(NavHandleLongPressHandler navHandleLongPressHandler) {
mNavHandleLongPressHandler = navHandleLongPressHandler;
}
+
+ @VisibleForTesting
+ void setStatsLogManager(StatsLogManager statsLogManager) {
+ mStatsLogManager = statsLogManager;
+ }
}
diff --git a/quickstep/tests/multivalentTests/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumerTest.java b/quickstep/tests/multivalentTests/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumerTest.java
index 7776351..de6920b 100644
--- a/quickstep/tests/multivalentTests/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumerTest.java
+++ b/quickstep/tests/multivalentTests/src/com/android/quickstep/inputconsumers/NavHandleLongPressInputConsumerTest.java
@@ -24,6 +24,8 @@
import static androidx.test.core.app.ApplicationProvider.getApplicationContext;
+import static com.android.launcher3.logging.StatsLogManager.LauncherEvent.LAUNCHER_LONG_PRESS_NAVBAR;
+import static com.android.launcher3.logging.StatsLogManager.LauncherLatencyEvent.LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON;
import static com.android.launcher3.util.Executors.MAIN_EXECUTOR;
import static com.android.quickstep.DeviceConfigWrapper.DEFAULT_LPNH_TIMEOUT_MS;
@@ -33,9 +35,11 @@
import static org.junit.Assert.assertTrue;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.anyBoolean;
+import static org.mockito.ArgumentMatchers.anyLong;
import static org.mockito.Mockito.never;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.verifyNoMoreInteractions;
import static org.mockito.Mockito.when;
import android.os.SystemClock;
@@ -47,6 +51,7 @@
import com.android.launcher3.dagger.LauncherAppComponent;
import com.android.launcher3.dagger.LauncherAppSingleton;
+import com.android.launcher3.logging.StatsLogManager;
import com.android.launcher3.util.AllModulesForTest;
import com.android.launcher3.util.DisplayController;
import com.android.launcher3.util.MainThreadInitializedObject.SandboxContext;
@@ -83,6 +88,7 @@
private NavHandleLongPressInputConsumer mUnderTest;
private SandboxContext mContext;
private float mScreenWidth;
+ private long mDownTimeMs;
@Mock InputConsumer mDelegate;
@Mock InputMonitorCompat mInputMonitor;
@Mock RecentsAnimationDeviceState mDeviceState;
@@ -91,6 +97,9 @@
@Mock NavHandleLongPressHandler mNavHandleLongPressHandler;
@Mock TopTaskTracker mTopTaskTracker;
@Mock TopTaskTracker.CachedTaskInfo mTaskInfo;
+ @Mock StatsLogManager mStatsLogManager;
+ @Mock StatsLogManager.StatsLogger mStatsLogger;
+ @Mock StatsLogManager.StatsLatencyLogger mStatsLatencyLogger;
@Before
public void setup() {
@@ -100,6 +109,11 @@
when(mDelegate.allowInterceptByParent()).thenReturn(true);
mLongPressTriggered.set(false);
when(mNavHandleLongPressHandler.getLongPressRunnable(any())).thenReturn(mLongPressRunnable);
+ when(mStatsLogger.withPackageName(any())).thenReturn(mStatsLogger);
+ when(mStatsLatencyLogger.withInstanceId(any())).thenReturn(mStatsLatencyLogger);
+ when(mStatsLatencyLogger.withLatency(anyLong())).thenReturn(mStatsLatencyLogger);
+ when(mStatsLogManager.logger()).thenReturn(mStatsLogger);
+ when(mStatsLogManager.latencyLogger()).thenReturn(mStatsLatencyLogger);
initializeObjectUnderTest();
}
@@ -124,17 +138,24 @@
assertThat(mUnderTest.mState).isEqualTo(DelegateInputConsumer.STATE_INACTIVE);
verify(mNavHandleLongPressHandler, never()).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogManager);
+ verifyNoMoreInteractions(mStatsLogger);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
}
@Test
public void testDelegateDisallowsTouchInterceptAfterTouchDown() {
+ // Touch down and wait the minimum abandonment time.
mUnderTest.onMotionEvent(generateCenteredMotionEvent(ACTION_DOWN));
+ SystemClock.sleep(NavHandleLongPressInputConsumer.MIN_TIME_TO_LOG_ABANDON_MS);
+ InstrumentationRegistry.getInstrumentation().waitForIdleSync();
// Delegate should still get touches unless long press is triggered.
verify(mDelegate).onMotionEvent(any());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ // Child delegate blocks us from intercepting further motion events.
when(mDelegate.allowInterceptByParent()).thenReturn(false);
mUnderTest.onMotionEvent(generateCenteredMotionEvent(ACTION_MOVE));
@@ -144,6 +165,9 @@
assertThat(mUnderTest.mState).isEqualTo(DelegateInputConsumer.STATE_INACTIVE);
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ // Because we handled touch down before the child blocked additional events, log abandon.
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
}
@Test
@@ -156,6 +180,12 @@
assertTrue(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verify(mStatsLogger).log(LAUNCHER_LONG_PRESS_NAVBAR);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
+
+ // Ensure abandon latency is still not logged after long press.
+ mUnderTest.onMotionEvent(generateCenteredMotionEvent(ACTION_UP));
+ verifyNoMoreInteractions(mStatsLatencyLogger);
}
@Test
@@ -170,6 +200,8 @@
assertTrue(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verify(mStatsLogger).log(LAUNCHER_LONG_PRESS_NAVBAR);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
}
@Test
@@ -184,6 +216,8 @@
assertTrue(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verify(mStatsLogger).log(LAUNCHER_LONG_PRESS_NAVBAR);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
}
@Test
@@ -215,6 +249,8 @@
assertTrue(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verify(mStatsLogger).log(LAUNCHER_LONG_PRESS_NAVBAR);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
} catch (Exception e) {
throw new RuntimeException(e);
}
@@ -235,6 +271,8 @@
assertTrue(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verify(mStatsLogger).log(LAUNCHER_LONG_PRESS_NAVBAR);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
} catch (Exception e) {
throw new RuntimeException(e);
}
@@ -258,6 +296,8 @@
assertFalse(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
}
@Test
@@ -278,6 +318,8 @@
assertFalse(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
}
@Test
@@ -299,6 +341,8 @@
assertFalse(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
}
@Test
@@ -320,6 +364,8 @@
assertFalse(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
}
@Test
@@ -354,6 +400,8 @@
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
// Touch cancelled.
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
} catch (Exception e) {
throw new RuntimeException(e);
}
@@ -391,6 +439,8 @@
verify(mNavHandleLongPressHandler, times(1)).onTouchStarted(any());
// Touch cancelled.
verify(mNavHandleLongPressHandler, times(1)).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogger);
+ verify(mStatsLatencyLogger).log(LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON);
} catch (Exception e) {
throw new RuntimeException(e);
}
@@ -408,6 +458,9 @@
assertFalse(mLongPressTriggered.get());
verify(mNavHandleLongPressHandler, never()).onTouchStarted(any());
verify(mNavHandleLongPressHandler, never()).onTouchFinished(any(), any());
+ verifyNoMoreInteractions(mStatsLogManager);
+ verifyNoMoreInteractions(mStatsLogger);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
}
@Test
@@ -422,6 +475,21 @@
mUnderTest.onHoverEvent(generateCenteredMotionEvent(ACTION_HOVER_ENTER));
verify(mDelegate, times(2)).onHoverEvent(any());
+
+ verifyNoMoreInteractions(mStatsLogManager);
+ verifyNoMoreInteractions(mStatsLogger);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
+ }
+
+ @Test
+ public void testNoLogsForShortTouch() {
+ mUnderTest.onMotionEvent(generateCenteredMotionEvent(ACTION_DOWN));
+ SystemClock.sleep(10);
+ InstrumentationRegistry.getInstrumentation().waitForIdleSync();
+ mUnderTest.onMotionEvent(generateCenteredMotionEvent(ACTION_UP));
+ verifyNoMoreInteractions(mStatsLogManager);
+ verifyNoMoreInteractions(mStatsLogger);
+ verifyNoMoreInteractions(mStatsLatencyLogger);
}
private void initializeObjectUnderTest() {
@@ -437,6 +505,8 @@
mUnderTest = new NavHandleLongPressInputConsumer(mContext, mDelegate, mInputMonitor,
mDeviceState, mNavHandle, mGestureState);
mUnderTest.setNavHandleLongPressHandler(mNavHandleLongPressHandler);
+ mUnderTest.setStatsLogManager(mStatsLogManager);
+ mDownTimeMs = 0;
}
/** Generate a motion event centered horizontally in the screen. */
@@ -449,8 +519,12 @@
return generateMotionEvent(motionAction, mScreenWidth / 2f, y);
}
- private static MotionEvent generateMotionEvent(int motionAction, float x, float y) {
- return MotionEvent.obtain(0, 0, motionAction, x, y, 0);
+ private MotionEvent generateMotionEvent(int motionAction, float x, float y) {
+ if (motionAction == ACTION_DOWN) {
+ mDownTimeMs = SystemClock.uptimeMillis();
+ }
+ long eventTime = SystemClock.uptimeMillis();
+ return MotionEvent.obtain(mDownTimeMs, eventTime, motionAction, x, y, 0);
}
private static AutoCloseable overrideTwoStageFlag(boolean value) {
diff --git a/src/com/android/launcher3/logging/StatsLogManager.java b/src/com/android/launcher3/logging/StatsLogManager.java
index 9a1c874..2f1af68 100644
--- a/src/com/android/launcher3/logging/StatsLogManager.java
+++ b/src/com/android/launcher3/logging/StatsLogManager.java
@@ -905,6 +905,10 @@
@UiEvent(doc = "Time passed between Contextual Search runnable creation and execution. This"
+ " ensures that Recent animations have finished before Contextual Search starts.")
LAUNCHER_LATENCY_OMNI_RUNNABLE(1546),
+
+ @UiEvent(doc = "Time passed between nav handle touch down and cancellation without "
+ + "triggering Contextual Search")
+ LAUNCHER_LATENCY_CONTEXTUAL_SEARCH_LPNH_ABANDON(2171),
;
private final int mId;