Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 360c7f7a authored by Nicolo' Mazzucato's avatar Nicolo' Mazzucato
Browse files

Introduce latency tracking for shade display change 

This tracks the latency of moving the shade between displays, from the
trigger to the end of the first doFrame with the correct configuration.

Note that this is is not perfect: the ideal solution would be tracking
the time until the buffer having the new configuration is presented to
the display, but this would require an extensive rework of how
LatencyTracker works (as we receive the present timestamp, which will be
in the past), so it will be for a follow up cl.

Bug: 362719719
Bug: 378688537
Test: ShadeDisplayChangeLatencyTrackerTest
Flag: com.android.systemui.shade_window_goes_around
Change-Id: I09db08a9c602338c6720bb321806069d8c62e795
parent 9542969b

packages/SystemUI/multivalentTests/src/com/android/systemui/shade/ShadeDisplayChangeLatencyTrackerTest.kt

0 → 100644
+130 −0
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2024 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License.

 */



package com.android.systemui.shade



import androidx.test.ext.junit.runners.AndroidJUnit4

import androidx.test.filters.SmallTest

import com.android.internal.logging.latencyTracker

import com.android.systemui.SysuiTestCase

import com.android.systemui.common.ui.data.repository.fakeConfigurationRepository

import com.android.systemui.common.ui.view.fakeChoreographerUtils

import com.android.systemui.kosmos.testScope

import com.android.systemui.kosmos.useUnconfinedTestDispatcher

import com.android.systemui.testKosmos

import kotlin.test.Test

import kotlin.time.Duration.Companion.seconds

import kotlinx.coroutines.ExperimentalCoroutinesApi

import kotlinx.coroutines.test.advanceTimeBy

import kotlinx.coroutines.test.runTest

import org.junit.runner.RunWith

import org.mockito.Mockito.never

import org.mockito.Mockito.times

import org.mockito.Mockito.verify

import org.mockito.kotlin.any



@SmallTest

@RunWith(AndroidJUnit4::class)

class ShadeDisplayChangeLatencyTrackerTest : SysuiTestCase() {

    private val kosmos = testKosmos().useUnconfinedTestDispatcher()

    private val configurationRepository = kosmos.fakeConfigurationRepository

    private val latencyTracker = kosmos.latencyTracker

    private val testScope = kosmos.testScope

    private val choreographerUtils = kosmos.fakeChoreographerUtils



    private val underTest = kosmos.shadeDisplayChangeLatencyTracker



    @Test

    fun onShadeDisplayChanging_afterMovedToDisplayAndDoFrameCompleted_atomReported() =

        testScope.runTest {

            underTest.onShadeDisplayChanging(1)



            verify(latencyTracker).onActionStart(any())

            verify(latencyTracker, never()).onActionEnd(any())



            sendOnMovedToDisplay(1)

            choreographerUtils.completeDoFrame()



            verify(latencyTracker).onActionEnd(any())

        }



    @OptIn(ExperimentalCoroutinesApi::class)

    @Test

    fun onChange_doFrameTimesOut_previousCancelled() =

        testScope.runTest {

            underTest.onShadeDisplayChanging(1)



            verify(latencyTracker).onActionStart(any())

            verify(latencyTracker, never()).onActionEnd(any())



            sendOnMovedToDisplay(1)

            advanceTimeBy(100.seconds)



            verify(latencyTracker, never()).onActionEnd(any())

            verify(latencyTracker).onActionCancel(any())

        }



    @OptIn(ExperimentalCoroutinesApi::class)

    @Test

    fun onChange_onMovedToDisplayTimesOut_cancelled() =

        testScope.runTest {

            underTest.onShadeDisplayChanging(1)



            verify(latencyTracker).onActionStart(any())



            choreographerUtils.completeDoFrame()

            advanceTimeBy(100.seconds)



            verify(latencyTracker).onActionCancel(any())

        }



    @Test

    fun onChange_whilePreviousWasInProgress_previousCancelledAndNewStarted() =

        testScope.runTest {

            underTest.onShadeDisplayChanging(1)



            verify(latencyTracker).onActionStart(any())



            underTest.onShadeDisplayChanging(2)



            verify(latencyTracker).onActionCancel(any())

            verify(latencyTracker, times(2)).onActionStart(any())

        }



    @Test

    fun onChange_multiple_multipleReported() =

        testScope.runTest {

            underTest.onShadeDisplayChanging(1)

            verify(latencyTracker).onActionStart(any())



            sendOnMovedToDisplay(1)

            choreographerUtils.completeDoFrame()



            verify(latencyTracker).onActionEnd(any())



            underTest.onShadeDisplayChanging(0)



            sendOnMovedToDisplay(0)

            choreographerUtils.completeDoFrame()



            verify(latencyTracker, times(2)).onActionStart(any())

            verify(latencyTracker, times(2)).onActionEnd(any())

        }



    private fun sendOnMovedToDisplay(displayId: Int) {

        configurationRepository.onMovedToDisplay(displayId)

    }

}

packages/SystemUI/multivalentTests/src/com/android/systemui/shade/domain/interactor/ShadeDisplaysInteractorTest.kt

+11 −0
Original line number Diff line number Diff line
@@ -45,6 +45,7 @@ class ShadeDisplaysInteractorTest : SysuiTestCase() { 
    private val positionRepository = kosmos.fakeShadeDisplaysRepository

    private val shadeContext = kosmos.mockedWindowContext

    private val resources = kosmos.mockResources

    private val latencyTracker = kosmos.mockedShadeDisplayChangeLatencyTracker

    private val configuration = mock<Configuration>()

    private val display = mock<Display>()
@@ -81,4 +82,14 @@ class ShadeDisplaysInteractorTest : SysuiTestCase() { 


        verify(shadeContext).reparentToDisplay(eq(1))

    }



    @Test

    fun start_shadeInWrongPosition_logsStartToLatencyTracker() {

        whenever(display.displayId).thenReturn(0)

        positionRepository.setDisplayId(1)



        underTest.start()



        verify(latencyTracker).onShadeDisplayChanging(eq(1))

    }

}

packages/SystemUI/src/com/android/systemui/shade/ShadeDisplayAwareModule.kt

+8 −0
Original line number Diff line number Diff line
@@ -30,6 +30,8 @@ import com.android.systemui.common.ui.data.repository.ConfigurationRepository 
import com.android.systemui.common.ui.data.repository.ConfigurationRepositoryImpl

import com.android.systemui.common.ui.domain.interactor.ConfigurationInteractor

import com.android.systemui.common.ui.domain.interactor.ConfigurationInteractorImpl

import com.android.systemui.common.ui.view.ChoreographerUtils

import com.android.systemui.common.ui.view.ChoreographerUtilsImpl

import com.android.systemui.dagger.SysUISingleton

import com.android.systemui.dagger.qualifiers.Main

import com.android.systemui.res.R
@@ -239,6 +241,12 @@ object ShadeDisplayAwareModule { 
        }

    }



    /**

     * Provided for making classes easier to test. In tests, a custom method to wait for the next

     * frame can be easily provided.

     */

    @Provides fun provideChoreographerUtils(): ChoreographerUtils = ChoreographerUtilsImpl



    @Provides

    @ShadeOnDefaultDisplayWhenLocked

    fun provideShadeOnDefaultDisplayWhenLocked(): Boolean = true

packages/SystemUI/src/com/android/systemui/shade/ShadeDisplayChangeLatencyTracker.kt

0 → 100644
+142 −0
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2024 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License.

 */

package com.android.systemui.shade



import android.util.Log

import android.view.Display

import com.android.app.tracing.coroutines.TrackTracer

import com.android.internal.util.LatencyTracker

import com.android.systemui.common.ui.data.repository.ConfigurationRepository

import com.android.systemui.common.ui.view.ChoreographerUtils

import com.android.systemui.dagger.SysUISingleton

import com.android.systemui.dagger.qualifiers.Background

import com.android.systemui.scene.ui.view.WindowRootView

import com.android.systemui.shade.ShadeDisplayChangeLatencyTracker.Companion.TIMEOUT

import com.android.systemui.shade.data.repository.ShadeDisplaysRepository

import com.android.systemui.util.kotlin.getOrNull

import java.util.Optional

import java.util.concurrent.CancellationException

import javax.inject.Inject

import kotlin.time.Duration.Companion.seconds

import kotlinx.coroutines.CoroutineScope

import kotlinx.coroutines.Job

import kotlinx.coroutines.cancel

import kotlinx.coroutines.flow.SharingStarted

import kotlinx.coroutines.flow.StateFlow

import kotlinx.coroutines.flow.filter

import kotlinx.coroutines.flow.first

import kotlinx.coroutines.flow.stateIn

import kotlinx.coroutines.launch

import kotlinx.coroutines.withTimeout



/**

 * Tracks the time it takes to move the shade from one display to another.

 * - The start event is when [ShadeDisplaysRepository] propagates the new display ID.

 * - The end event is one frame after the shade configuration controller receives a new

 *   configuration change.

 *

 * Note that even in the unlikely case the configuration of the new display is the same,

 * onConfigurationChange is called anyway as is is triggered by

 * [NotificationShadeWindowView.onMovedToDisplay].

 */

@SysUISingleton

class ShadeDisplayChangeLatencyTracker

@Inject

constructor(

    optionalShadeRootView: Optional<WindowRootView>,

    @ShadeDisplayAware private val configurationRepository: ConfigurationRepository,

    private val latencyTracker: LatencyTracker,

    @Background private val bgScope: CoroutineScope,

    private val choreographerUtils: ChoreographerUtils,

) {



    private val shadeRootView =

        optionalShadeRootView.getOrNull()

            ?: error(

                """

            ShadeRootView must be provided for ShadeDisplayChangeLatencyTracker to work.

            If it is not, it means this is being instantiated in a SystemUI variant that shouldn't.

            """

                    .trimIndent()

            )

    /**

     * We need to keep this always up to date eagerly to avoid delays receiving the new display ID.

     */

    private val onMovedToDisplayFlow: StateFlow<Int> =

        configurationRepository.onMovedToDisplay.stateIn(

            bgScope,

            SharingStarted.Eagerly,

            Display.DEFAULT_DISPLAY,

        )



    private var previousJob: Job? = null



    /**

     * Called before the display change begins.

     *

     * It is guaranteed that context and resources are still associated to the "old" display id, and

     * that onMovedToDisplay has not been received yet on the notification shade window root view.

     *

     * IMPORTANT: this shouldn't be refactored to use [ShadePositionRepository], otherwise there is

     * no guarantees of event order (as the shade could be reparented before the event is propagated

     * to this class, breaking the assumption that [onMovedToDisplayFlow] didn't emit with the new

     * display id yet.

     */

    @Synchronized

    fun onShadeDisplayChanging(displayId: Int) {

        previousJob?.cancel(CancellationException("New shade move in progress"))

        previousJob = bgScope.launch { onShadeDisplayChangingAsync(displayId) }

    }



    private suspend fun onShadeDisplayChangingAsync(displayId: Int) {

        try {

            latencyTracker.onActionStart(SHADE_MOVE_ACTION)

            waitForOnMovedToDisplayDispatchedToView(displayId)

            waitUntilNextDoFrameDone()

            latencyTracker.onActionEnd(SHADE_MOVE_ACTION)

        } catch (e: Exception) {

            val reason =

                when (e) {

                    is CancellationException ->

                        "Shade move cancelled as a new move is being done " +

                            "before the previous one finished."



                    else -> "Shade move cancelled."

                }

            Log.e(TAG, reason, e)

            latencyTracker.onActionCancel(SHADE_MOVE_ACTION)

        }

    }



    private suspend fun waitForOnMovedToDisplayDispatchedToView(newDisplayId: Int) {

        t.traceAsync({ "waitForOnMovedToDisplayDispatchedToView(newDisplayId=$newDisplayId)" }) {

            withTimeout(TIMEOUT) { onMovedToDisplayFlow.filter { it == newDisplayId }.first() }

            t.instant { "onMovedToDisplay received with $newDisplayId" }

        }

    }



    private suspend fun waitUntilNextDoFrameDone(): Unit =

        t.traceAsync("waitUntilNextDoFrameDone") {

            withTimeout(TIMEOUT) { choreographerUtils.waitUntilNextDoFrameDone(shadeRootView) }

        }



    private companion object {

        const val TAG = "ShadeDisplayLatency"

        val t = TrackTracer(trackName = TAG)

        val TIMEOUT = 3.seconds

        const val SHADE_MOVE_ACTION = LatencyTracker.ACTION_SHADE_WINDOW_DISPLAY_CHANGE

    }

}

packages/SystemUI/src/com/android/systemui/shade/domain/interactor/ShadeDisplaysInteractor.kt

+20 −15
Original line number Diff line number Diff line
@@ -25,14 +25,13 @@ import com.android.systemui.CoreStartable 
import com.android.systemui.dagger.SysUISingleton

import com.android.systemui.dagger.qualifiers.Background

import com.android.systemui.dagger.qualifiers.Main

import com.android.systemui.scene.ui.view.WindowRootView

import com.android.systemui.shade.ShadeDisplayAware

import com.android.systemui.shade.ShadeDisplayChangeLatencyTracker

import com.android.systemui.shade.ShadeTraceLogger.logMoveShadeWindowTo

import com.android.systemui.shade.ShadeTraceLogger.traceReparenting

import com.android.systemui.shade.data.repository.ShadeDisplaysRepository

import com.android.systemui.shade.shared.flag.ShadeWindowGoesAround

import com.android.systemui.util.kotlin.getOrNull

import java.util.Optional

import com.android.window.flags.Flags

import javax.inject.Inject

import kotlin.coroutines.CoroutineContext

import kotlinx.coroutines.CoroutineScope
@@ -43,23 +42,13 @@ import kotlinx.coroutines.withContext 
class ShadeDisplaysInteractor

@Inject

constructor(

    optionalShadeRootView: Optional<WindowRootView>,

    private val shadePositionRepository: ShadeDisplaysRepository,

    @ShadeDisplayAware private val shadeContext: WindowContext,

    @Background private val bgScope: CoroutineScope,

    @Main private val mainThreadContext: CoroutineContext,

    private val shadeDisplayChangeLatencyTracker: ShadeDisplayChangeLatencyTracker,

) : CoreStartable {



    private val shadeRootView =

        optionalShadeRootView.getOrNull()

            ?: error(

                """

            ShadeRootView must be provided for this ShadeDisplayInteractor to work.

            If it is not, it means this is being instantiated in a SystemUI variant that shouldn't.

            """

                    .trimIndent()

            )



    override fun start() {

        ShadeWindowGoesAround.isUnexpectedlyInLegacyMode()

        bgScope.launchTraced(TAG) {
@@ -87,7 +76,11 @@ constructor( 
        }

        try {

            withContext(mainThreadContext) {

                traceReparenting { reparentToDisplayId(id = destinationId) }

                traceReparenting {

                    shadeDisplayChangeLatencyTracker.onShadeDisplayChanging(destinationId)

                    reparentToDisplayId(id = destinationId)

                }

                checkContextDisplayMatchesExpected(destinationId)

            }

        } catch (e: IllegalStateException) {

            Log.e(
@@ -98,6 +91,18 @@ constructor( 
        }

    }



    private fun checkContextDisplayMatchesExpected(destinationId: Int) {

        if (shadeContext.displayId != destinationId) {

            Log.wtf(

                TAG,

                "Shade context display id doesn't match the expected one after the move. " +

                    "actual=${shadeContext.displayId} expected=$destinationId. " +

                    "This means something wrong happened while trying to move the shade. " +

                    "Flag reparentWindowTokenApi=${Flags.reparentWindowTokenApi()}",

            )

        }

    }



    @UiThread

    private fun reparentToDisplayId(id: Int) {

        traceSection({ "reparentToDisplayId(id=$id)" }) { shadeContext.reparentToDisplay(id) }