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

Commit 54190607 authored by Kean Mariotti's avatar Kean Mariotti
Browse files

WindowTracing: fix snapshot scheduling race condition 

This is a fix to handle this flow:
1. ongoing WM tracing (frequency = frame)
2. Request to schedule WM snapshot on frame (set mScheduled = true)
3. Stop WM tracing (mScheduled remains true)
4. Start WM tracing (mScheduled is still true). Here mScheduled = true is an invalid state.
   There is no snapshot scheduled and it prevents subsequent snapshots to be scheduled).

Fix: 408175513
Test: atest com.android.server.wm.WindowTracingPerfettoTest
Flag: EXEMPT bugfix
Change-Id: I4101906a64b658748c68fa99efe6d9ab28a6d96a
parent ac3ef7d6

services/core/java/com/android/server/wm/WindowTracing.java

+7 −7
Original line number Diff line number Diff line
@@ -48,10 +48,9 @@ abstract class WindowTracing { 
    private final Choreographer mChoreographer;

    private final WindowManagerGlobalLock mGlobalLock;



    private final Choreographer.FrameCallback mFrameCallback = (frameTimeNanos) ->

            log(WHERE_ON_FRAME);

    private final Choreographer.FrameCallback mFrameCallback = (frameTimeNanos) -> onFrame();



    private AtomicBoolean mScheduled = new AtomicBoolean(false);

    private final AtomicBoolean mScheduled = new AtomicBoolean(false);





    static WindowTracing createDefaultAndStartLooper(WindowManagerService service,
@@ -150,6 +149,11 @@ abstract class WindowTracing { 
        mChoreographer.postFrameCallback(mFrameCallback);

    }



    private void onFrame() {

        log(WHERE_ON_FRAME);

        mScheduled.set(false);

    }



    /**

     * Write the current frame to proto

     *
@@ -173,10 +177,6 @@ abstract class WindowTracing { 
        } catch (Exception e) {

            Log.wtf(TAG, "Exception while tracing state", e);

        } finally {

            boolean isOnFrameLogEvent = where == WHERE_ON_FRAME;

            if (isOnFrameLogEvent) {

                mScheduled.set(false);

            }

            Trace.traceEnd(Trace.TRACE_TAG_WINDOW_MANAGER);

        }

    }

services/tests/wmtests/src/com/android/server/wm/WindowTracingPerfettoTest.java

+42 −9
Original line number Diff line number Diff line
@@ -50,6 +50,8 @@ import org.junit.AfterClass; 
import org.junit.Before;

import org.junit.BeforeClass;

import org.junit.Test;

import org.mockito.ArgumentCaptor;

import org.mockito.Captor;

import org.mockito.Mockito;



import perfetto.protos.PerfettoConfig.WindowManagerConfig.LogFrequency;
@@ -66,6 +68,10 @@ public class WindowTracingPerfettoTest { 
    private static final String TEST_DATA_SOURCE_NAME = "android.windowmanager.test";



    private static WindowManagerService sWmMock;

    private static Choreographer sChoreographerMock;

    @Captor

    ArgumentCaptor<Choreographer.FrameCallback> mFrameCallbackCaptor =

            ArgumentCaptor.forClass(Choreographer.FrameCallback.class);

    private static WindowTracing sWindowTracing;

    private static Boolean sIsDataSourceRegisteredSuccessfully;
@@ -74,8 +80,9 @@ public class WindowTracingPerfettoTest { 
    @BeforeClass

    public static void setUpOnce() throws Exception {

        sWmMock = Mockito.mock(WindowManagerService.class);

        sChoreographerMock = Mockito.mock(Choreographer.class);

        Mockito.doNothing().when(sWmMock).dumpDebugLocked(Mockito.any(), Mockito.anyInt());

        sWindowTracing = new WindowTracingPerfetto(sWmMock, Mockito.mock(Choreographer.class),

        sWindowTracing = new WindowTracingPerfetto(sWmMock, sChoreographerMock,

                new WindowManagerGlobalLock(), TEST_DATA_SOURCE_NAME);

    }
@@ -118,7 +125,7 @@ public class WindowTracingPerfettoTest { 


    @Test

    public void isEnabled_returnsTrueAfterStartThenFalseAfterStop() throws IOException {

        startTracing(false);

        startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);

        assertTrue(sWindowTracing.isEnabled());



        stopTracing();
@@ -133,26 +140,53 @@ public class WindowTracingPerfettoTest { 


    @Test

    public void trace_writesInitialStateSnapshot_whenTracingStarts() {

        startTracing(false);

        startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);

        verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

    }



    @Test

    public void trace_writesStateSnapshot_onLogStateCall() {

        startTracing(false);

        startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);

        sWindowTracing.logState("where");

        verify(sWmMock, times(2)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

    }



    @Test

    // This test case covers the race condition from b/408175513

    public void trace_FrameCallbackRaceCondition() throws IOException {

        Mockito.doNothing().when(sChoreographerMock)

                .postFrameCallback(mFrameCallbackCaptor.capture());



        startTracing(LogFrequency.LOG_FREQUENCY_FRAME);



        // Schedule snapshot (Choreographer#postFrameCallback)

        sWindowTracing.logState("where");

        verify(sChoreographerMock, times(1)).postFrameCallback(Mockito.any());



        // Stop tracing

        stopTracing();



        // Execute snapshot callback (but after tracing stopped)

        mFrameCallbackCaptor.getValue().doFrame(0);



        // Start tracing

        startTracing(LogFrequency.LOG_FREQUENCY_FRAME);



        // Schedule snapshot (Choreographer#postFrameCallback),

        // Expect scheduling even if previous snapshot callback executed after tracing stop.

        sWindowTracing.logState("where");

        verify(sChoreographerMock, times(2)).postFrameCallback(Mockito.any());

    }



    @Test

    public void dump_writesOneSingleStateSnapshot() {

        startTracing(true);

        startTracing(LogFrequency.LOG_FREQUENCY_SINGLE_DUMP);

        sWindowTracing.logState("where");

        verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));

    }



    private void startTracing(boolean isDump) {

        if (isDump) {

    private void startTracing(LogFrequency logFrequency) {

        if (logFrequency == LogFrequency.LOG_FREQUENCY_SINGLE_DUMP) {

            mTraceMonitor = PerfettoTraceMonitor

                    .newBuilder()

                    .enableWindowManagerDump(TEST_DATA_SOURCE_NAME)
@@ -160,8 +194,7 @@ public class WindowTracingPerfettoTest { 
        } else {

            mTraceMonitor = PerfettoTraceMonitor

                    .newBuilder()

                    .enableWindowManagerTrace(LogFrequency.LOG_FREQUENCY_TRANSACTION,

                            TEST_DATA_SOURCE_NAME)

                    .enableWindowManagerTrace(logFrequency, TEST_DATA_SOURCE_NAME)

                    .build();

        }

        mTraceMonitor.start();