Merge "WindowTracing: fix snapshot scheduling race condition" into main (69b92e86) · Commits · e / os / android_frameworks_base

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

+7 −7

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

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

	private AtomicBoolean mScheduled = new AtomicBoolean(false);		private final AtomicBoolean mScheduled = new AtomicBoolean(false);


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

			private void onFrame() {
			log(WHERE_ON_FRAME);
			mScheduled.set(false);
			}

	/**		/**
	* Write the current frame to proto		* Write the current frame to proto
	*		*
	@@ -173,10 +177,6 @@ abstract class WindowTracing {
	} catch (Exception e) {		} catch (Exception e) {
	Log.wtf(TAG, "Exception while tracing state", e);		Log.wtf(TAG, "Exception while tracing state", e);
	} finally {		} finally {
	boolean isOnFrameLogEvent = where == WHERE_ON_FRAME;
	if (isOnFrameLogEvent) {
	mScheduled.set(false);
	}
	Trace.traceEnd(Trace.TRACE_TAG_WINDOW_MANAGER);		Trace.traceEnd(Trace.TRACE_TAG_WINDOW_MANAGER);
	}		}
	}		}

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

+42 −9

Original line number	Original line	Diff line number	Diff line
	@@ -50,6 +50,8 @@ import org.junit.AfterClass;
	import org.junit.Before;		import org.junit.Before;
	import org.junit.BeforeClass;		import org.junit.BeforeClass;
	import org.junit.Test;		import org.junit.Test;
			import org.mockito.ArgumentCaptor;
			import org.mockito.Captor;
	import org.mockito.Mockito;		import org.mockito.Mockito;

	import perfetto.protos.PerfettoConfig.WindowManagerConfig.LogFrequency;		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 final String TEST_DATA_SOURCE_NAME = "android.windowmanager.test";

	private static WindowManagerService sWmMock;		private static WindowManagerService sWmMock;
			private static Choreographer sChoreographerMock;
			@Captor
			ArgumentCaptor<Choreographer.FrameCallback> mFrameCallbackCaptor =
			ArgumentCaptor.forClass(Choreographer.FrameCallback.class);
	private static WindowTracing sWindowTracing;		private static WindowTracing sWindowTracing;
	private static Boolean sIsDataSourceRegisteredSuccessfully;		private static Boolean sIsDataSourceRegisteredSuccessfully;

	@@ -74,8 +80,9 @@ public class WindowTracingPerfettoTest {
	@BeforeClass		@BeforeClass
	public static void setUpOnce() throws Exception {		public static void setUpOnce() throws Exception {
	sWmMock = Mockito.mock(WindowManagerService.class);		sWmMock = Mockito.mock(WindowManagerService.class);
			sChoreographerMock = Mockito.mock(Choreographer.class);
	Mockito.doNothing().when(sWmMock).dumpDebugLocked(Mockito.any(), Mockito.anyInt());		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);		new WindowManagerGlobalLock(), TEST_DATA_SOURCE_NAME);
	}		}

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

	@Test		@Test
	public void isEnabled_returnsTrueAfterStartThenFalseAfterStop() throws IOException {		public void isEnabled_returnsTrueAfterStartThenFalseAfterStop() throws IOException {
	startTracing(false);		startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);
	assertTrue(sWindowTracing.isEnabled());		assertTrue(sWindowTracing.isEnabled());

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

	@Test		@Test
	public void trace_writesInitialStateSnapshot_whenTracingStarts() {		public void trace_writesInitialStateSnapshot_whenTracingStarts() {
	startTracing(false);		startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);
	verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));		verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));
	}		}

	@Test		@Test
	public void trace_writesStateSnapshot_onLogStateCall() {		public void trace_writesStateSnapshot_onLogStateCall() {
	startTracing(false);		startTracing(LogFrequency.LOG_FREQUENCY_TRANSACTION);
	sWindowTracing.logState("where");		sWindowTracing.logState("where");
	verify(sWmMock, times(2)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));		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		@Test
	public void dump_writesOneSingleStateSnapshot() {		public void dump_writesOneSingleStateSnapshot() {
	startTracing(true);		startTracing(LogFrequency.LOG_FREQUENCY_SINGLE_DUMP);
	sWindowTracing.logState("where");		sWindowTracing.logState("where");
	verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));		verify(sWmMock, times(1)).dumpDebugLocked(any(), eq(WindowTracingLogLevel.ALL));
	}		}

	private void startTracing(boolean isDump) {		private void startTracing(LogFrequency logFrequency) {
	if (isDump) {		if (logFrequency == LogFrequency.LOG_FREQUENCY_SINGLE_DUMP) {
	mTraceMonitor = PerfettoTraceMonitor		mTraceMonitor = PerfettoTraceMonitor
	.newBuilder()		.newBuilder()
	.enableWindowManagerDump(TEST_DATA_SOURCE_NAME)		.enableWindowManagerDump(TEST_DATA_SOURCE_NAME)
	@@ -160,8 +194,7 @@ public class WindowTracingPerfettoTest {
	} else {		} else {
	mTraceMonitor = PerfettoTraceMonitor		mTraceMonitor = PerfettoTraceMonitor
	.newBuilder()		.newBuilder()
	.enableWindowManagerTrace(LogFrequency.LOG_FREQUENCY_TRANSACTION,		.enableWindowManagerTrace(logFrequency, TEST_DATA_SOURCE_NAME)
	TEST_DATA_SOURCE_NAME)
	.build();		.build();
	}		}
	mTraceMonitor.start();		mTraceMonitor.start();