Merge "Sending display switch event even if something went wrong" into main (a2ed4a20) · Commits · e / os / android_frameworks_base

packages/SystemUI/multivalentTests/src/com/android/systemui/unfold/DisplaySwitchLatencyTrackerTest.kt

+65 −24

Original line number	Diff line number	Diff line
		@@ -173,15 +173,13 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		runCurrent()
		setDeviceState(UNFOLDED)

		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		val loggedEvent = loggerArgumentCaptor.value
		val expectedLoggedEvent =
		DisplaySwitchLatencyEvent(
		successfulEvent(
		latencyMs = 250,
		fromFoldableDeviceState = FOLDABLE_DEVICE_STATE_CLOSED,
		toFoldableDeviceState = FOLDABLE_DEVICE_STATE_HALF_OPEN,
		)
		assertThat(loggedEvent).isEqualTo(expectedLoggedEvent)
		assertThat(capturedLogEvent()).isEqualTo(expectedLoggedEvent)
		}
		}

		@@ -225,15 +223,13 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		runCurrent()
		setDeviceState(UNFOLDED)

		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		val loggedEvent = loggerArgumentCaptor.value
		val expectedLoggedEvent =
		DisplaySwitchLatencyEvent(
		successfulEvent(
		latencyMs = 50,
		fromFoldableDeviceState = FOLDABLE_DEVICE_STATE_CLOSED,
		toFoldableDeviceState = FOLDABLE_DEVICE_STATE_HALF_OPEN,
		)
		assertThat(loggedEvent).isEqualTo(expectedLoggedEvent)
		assertThat(capturedLogEvent()).isEqualTo(expectedLoggedEvent)
		}
		}

		@@ -258,15 +254,13 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		runCurrent()
		setDeviceState(UNFOLDED)

		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		val loggedEvent = loggerArgumentCaptor.value
		val expectedLoggedEvent =
		DisplaySwitchLatencyEvent(
		successfulEvent(
		latencyMs = 50,
		fromFoldableDeviceState = FOLDABLE_DEVICE_STATE_CLOSED,
		toFoldableDeviceState = FOLDABLE_DEVICE_STATE_HALF_OPEN,
		)
		assertThat(loggedEvent).isEqualTo(expectedLoggedEvent)
		assertThat(capturedLogEvent()).isEqualTo(expectedLoggedEvent)
		}
		}

		@@ -287,15 +281,13 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		powerInteractor.setScreenPowerState(SCREEN_ON)
		runCurrent()

		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		val loggedEvent = loggerArgumentCaptor.value
		val expectedLoggedEvent =
		DisplaySwitchLatencyEvent(
		successfulEvent(
		latencyMs = 200,
		fromFoldableDeviceState = FOLDABLE_DEVICE_STATE_HALF_OPEN,
		toFoldableDeviceState = FOLDABLE_DEVICE_STATE_CLOSED,
		)
		assertThat(loggedEvent).isEqualTo(expectedLoggedEvent)
		assertThat(capturedLogEvent()).isEqualTo(expectedLoggedEvent)
		}
		}

		@@ -317,16 +309,14 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		powerInteractor.setScreenPowerState(SCREEN_ON)
		runCurrent()

		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		val loggedEvent = loggerArgumentCaptor.value
		val expectedLoggedEvent =
		DisplaySwitchLatencyEvent(
		successfulEvent(
		latencyMs = 200,
		fromFoldableDeviceState = FOLDABLE_DEVICE_STATE_HALF_OPEN,
		toFoldableDeviceState = FOLDABLE_DEVICE_STATE_CLOSED,
		toState = SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TO_STATE__AOD,
		)
		assertThat(loggedEvent).isEqualTo(expectedLoggedEvent)
		assertThat(capturedLogEvent()).isEqualTo(expectedLoggedEvent)
		}
		}

		@@ -369,16 +359,14 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		powerInteractor.setScreenPowerState(SCREEN_OFF)
		runCurrent()

		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		val loggedEvent = loggerArgumentCaptor.value
		val expectedLoggedEvent =
		DisplaySwitchLatencyEvent(
		successfulEvent(
		latencyMs = 0,
		fromFoldableDeviceState = FOLDABLE_DEVICE_STATE_HALF_OPEN,
		toFoldableDeviceState = FOLDABLE_DEVICE_STATE_CLOSED,
		toState = SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TO_STATE__SCREEN_OFF,
		)
		assertThat(loggedEvent).isEqualTo(expectedLoggedEvent)
		assertThat(capturedLogEvent()).isEqualTo(expectedLoggedEvent)
		}
		}

		@@ -554,6 +542,23 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		}
		}

		@Test
		fun interruptedDisplaySwitchFinished_coolDownPassed_eventWithCorruptedResultSent() {
		testScope.runTest {
		startInFoldedState(displaySwitchLatencyTracker)

		startUnfolding()
		startFolding()
		systemClock.advanceTime(5000) // clock for measuring latency
		advanceTimeBy(COOL_DOWN_DURATION.plus(10.milliseconds)) // clock for triggering timeout

		val event = capturedLogEvent()
		assertThat(event.trackingResult)
		.isEqualTo(SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__CORRUPTED)
		assertThat(event.latencyMs).isEqualTo(5000)
		}
		}

		@Test
		fun displaySwitchInterrupted_coolDownExtendedByStartEvents() {
		testScope.runTest {
		@@ -604,6 +609,27 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		}
		}

		@Test
		fun displaySwitchTimedOut_eventLoggedWithTimeOut() {
		testScope.runTest {
		startInFoldedState(displaySwitchLatencyTracker)

		startUnfolding()
		advanceTimeBy(SCREEN_EVENT_TIMEOUT + 10.milliseconds)
		finishUnfolding()

		val event = capturedLogEvent()
		assertThat(event.trackingResult)
		.isEqualTo(SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__TIMED_OUT)
		assertThat(event.latencyMs).isEqualTo(SCREEN_EVENT_TIMEOUT.inWholeMilliseconds)
		}
		}

		private fun capturedLogEvent(): DisplaySwitchLatencyEvent {
		verify(displaySwitchLatencyLogger).log(capture(loggerArgumentCaptor))
		return loggerArgumentCaptor.value
		}

		@Test
		fun foldingStarted_screenStillOn_eventSentOnlyAfterScreenSwitches() {
		// can happen for both folding and unfolding (with animations off) but it's more likely to
		@@ -625,6 +651,21 @@ class DisplaySwitchLatencyTrackerTest : SysuiTestCase() {
		}
		}

		private fun successfulEvent(
		latencyMs: Int,
		fromFoldableDeviceState: Int,
		toFoldableDeviceState: Int,
		toState: Int = SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__FROM_STATE__UNKNOWN,
		): DisplaySwitchLatencyEvent {
		return DisplaySwitchLatencyEvent(
		latencyMs = latencyMs,
		fromFoldableDeviceState = fromFoldableDeviceState,
		toFoldableDeviceState = toFoldableDeviceState,
		toState = toState,
		trackingResult = SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__SUCCESS,
		)
		}

		private suspend fun TestScope.startInFoldedState(tracker: DisplaySwitchLatencyTracker) {
		setDeviceState(FOLDED)
		tracker.start()

packages/SystemUI/src/com/android/systemui/unfold/DisplaySwitchLatencyLogger.kt

+1 −0

Original line number	Diff line number	Diff line
		@@ -49,6 +49,7 @@ class DisplaySwitchLatencyLogger {
		hallSensorToDeviceStateChangeMs,
		onScreenTurningOnToOnDrawnMs,
		onDrawnToOnScreenTurnedOnMs,
		trackingResult,
		)
		}
		}

packages/SystemUI/src/com/android/systemui/unfold/DisplaySwitchLatencyTracker.kt

+54 −16

Original line number	Diff line number	Diff line
		@@ -37,12 +37,16 @@ import com.android.systemui.power.shared.model.WakefulnessModel
		import com.android.systemui.power.shared.model.WakefulnessState
		import com.android.systemui.shared.system.SysUiStatsLog
		import com.android.systemui.unfold.DisplaySwitchLatencyTracker.DisplaySwitchLatencyEvent
		import com.android.systemui.unfold.DisplaySwitchLatencyTracker.TrackingResult.CORRUPTED
		import com.android.systemui.unfold.DisplaySwitchLatencyTracker.TrackingResult.SUCCESS
		import com.android.systemui.unfold.DisplaySwitchLatencyTracker.TrackingResult.TIMED_OUT
		import com.android.systemui.unfold.dagger.UnfoldSingleThreadBg
		import com.android.systemui.unfold.data.repository.UnfoldTransitionStatus.TransitionStarted
		import com.android.systemui.unfold.domain.interactor.UnfoldTransitionInteractor
		import com.android.systemui.util.Compile
		import com.android.systemui.util.Utils.isDeviceFoldable
		import com.android.systemui.util.animation.data.repository.AnimationStatusRepository
		import com.android.systemui.util.kotlin.WithPrev
		import com.android.systemui.util.kotlin.pairwise
		import com.android.systemui.util.kotlin.race
		import com.android.systemui.util.time.SystemClock
		@@ -56,7 +60,6 @@ import kotlinx.coroutines.FlowPreview
		import kotlinx.coroutines.TimeoutCancellationException
		import kotlinx.coroutines.asCoroutineDispatcher
		import kotlinx.coroutines.flow.Flow
		import kotlinx.coroutines.flow.collect
		import kotlinx.coroutines.flow.collectLatest
		import kotlinx.coroutines.flow.drop
		import kotlinx.coroutines.flow.filter
		@@ -116,10 +119,9 @@ constructor(
		latencyTracker.onActionStart(ACTION_SWITCH_DISPLAY_UNFOLD)
		instantForTrack(TAG) { "unfold latency tracking started" }
		}
		val event = DisplaySwitchLatencyEvent().withBeforeFields(previousState.toStatsInt())
		try {
		withTimeout(SCREEN_EVENT_TIMEOUT) {
		val event =
		DisplaySwitchLatencyEvent().withBeforeFields(previousState.toStatsInt())
		val displaySwitchTimeMs =
		measureTimeMillis(systemClock) {
		traceAsync(TAG, "displaySwitch") {
		@@ -134,27 +136,43 @@ constructor(
		} catch (e: TimeoutCancellationException) {
		instantForTrack(TAG) { "tracking timed out" }
		latencyTracker.onActionCancel(ACTION_SWITCH_DISPLAY_UNFOLD)
		logDisplaySwitchEvent(
		event = event,
		toFoldableDeviceState = newState,
		displaySwitchTimeMs = SCREEN_EVENT_TIMEOUT.inWholeMilliseconds,
		trackingResult = TIMED_OUT,
		)
		} catch (e: CancellationException) {
		instantForTrack(TAG) { "new state interrupted, entering cool down" }
		latencyTracker.onActionCancel(ACTION_SWITCH_DISPLAY_UNFOLD)
		startCoolDown()
		startCoolDown(event)
		}
		}
		}
		}

		@OptIn(FlowPreview::class)
		private fun startCoolDown() {
		private fun startCoolDown(event: DisplaySwitchLatencyEvent) {
		if (isCoolingDown) return
		isCoolingDown = true
		applicationScope.launch(context = backgroundDispatcher) {
		val startTime = systemClock.elapsedRealtime()
		var lastState: DeviceState? = null
		try {
		startOrEndEvent.timeout(COOL_DOWN_DURATION).collect()
		} catch (e: TimeoutCancellationException) {
		instantForTrack(TAG) {
		"cool down finished, lasted ${systemClock.elapsedRealtime() - startTime} ms"
		startOrEndEvent.timeout(COOL_DOWN_DURATION).collect {
		if (it is WithPrev<, >) {
		lastState = it.newValue as? DeviceState
		}
		}
		} catch (e: TimeoutCancellationException) {
		val totalCooldownTime = systemClock.elapsedRealtime() - startTime
		logDisplaySwitchEvent(
		event = event,
		toFoldableDeviceState = lastState ?: DeviceState.UNKNOWN,
		displaySwitchTimeMs = totalCooldownTime,
		trackingResult = CORRUPTED,
		)
		instantForTrack(TAG) { "cool down finished, lasted $totalCooldownTime ms" }
		isCoolingDown = false
		}
		}
		@@ -164,12 +182,14 @@ constructor(
		event: DisplaySwitchLatencyEvent,
		toFoldableDeviceState: DeviceState,
		displaySwitchTimeMs: Long,
		trackingResult: TrackingResult = SUCCESS,
		) {
		displaySwitchLatencyLogger.log(
		event.withAfterFields(
		toFoldableDeviceState.toStatsInt(),
		displaySwitchTimeMs.toInt(),
		toFoldableDeviceState,
		displaySwitchTimeMs,
		getCurrentState(),
		trackingResult,
		)
		)
		}
		@@ -183,6 +203,13 @@ constructor(
		else -> FOLDABLE_DEVICE_STATE_UNKNOWN
		}

		private fun TrackingResult.toStatsInt(): Int =
		when (this) {
		SUCCESS -> SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__SUCCESS
		CORRUPTED -> SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__CORRUPTED
		TIMED_OUT -> SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__TIMED_OUT
		}

		private suspend fun waitForDisplaySwitch(toFoldableDeviceState: Int) {
		val isTransitionEnabled =
		unfoldTransitionInteractor.isAvailable &&
		@@ -264,11 +291,13 @@ constructor(
		}

		private fun DisplaySwitchLatencyEvent.withAfterFields(
		toFoldableDeviceState: Int,
		displaySwitchTimeMs: Int,
		toFoldableDeviceState: DeviceState,
		displaySwitchTimeMs: Long,
		toState: Int,
		trackingResult: TrackingResult,
		): DisplaySwitchLatencyEvent {
		log {
		"trackingResult=$trackingResult, " +
		"toFoldableDeviceState=$toFoldableDeviceState, " +
		"toState=$toState, " +
		"latencyMs=$displaySwitchTimeMs"
		@@ -276,9 +305,10 @@ constructor(
		instantForTrack(TAG) { "toFoldableDeviceState=$toFoldableDeviceState, toState=$toState" }

		return copy(
		toFoldableDeviceState = toFoldableDeviceState,
		latencyMs = displaySwitchTimeMs,
		toFoldableDeviceState = toFoldableDeviceState.toStatsInt(),
		latencyMs = displaySwitchTimeMs.toInt(),
		toState = toState,
		trackingResult = trackingResult.toStatsInt(),
		)
		}

		@@ -312,8 +342,16 @@ constructor(
		val hallSensorToDeviceStateChangeMs: Int = VALUE_UNKNOWN,
		val onScreenTurningOnToOnDrawnMs: Int = VALUE_UNKNOWN,
		val onDrawnToOnScreenTurnedOnMs: Int = VALUE_UNKNOWN,
		val trackingResult: Int =
		SysUiStatsLog.DISPLAY_SWITCH_LATENCY_TRACKED__TRACKING_RESULT__UNKNOWN_RESULT,
		)

		enum class TrackingResult {
		SUCCESS,
		CORRUPTED,
		TIMED_OUT,
		}

		companion object {
		private const val VALUE_UNKNOWN = -1
		private const val TAG = "DisplaySwitchLatency"