From ef016832b2ac07c000ff81696b44864b04e2df31 Mon Sep 17 00:00:00 2001 From: andrewlewis Date: Wed, 4 Jan 2023 11:17:15 +0000 Subject: [PATCH] Reduce flakiness of GL release test Based on experimentation it seems that buffers can occasionally (roughly 1% of test runs) be dropped when rendering off-screen from EGL on the emulator. Specifically, in this test, sometimes after rendering three buffers with distinct timestamps only the first and third buffers' timestamps are handled in the `ImageReader`'s image available callback causing the assertion checking all frames rendered to fail. This behavior seems to be independent of the nanosecond presentation time attached to the buffers (as expected for off-screen rendering). Introducing a pause of 1 second between rendering each frame reduces the flake rate to around 1/2000. This increases the run time of some of the tests, so this change also removes the 5 second `FRAME_PROCESSING_WAIT_MS` (it seems to be unnecessary when rendering off-screen) and instead uses a latch to wait until the frame processor has handled 'end of stream'. PiperOrigin-RevId: 499440591 --- ...EffectsFrameProcessorFrameReleaseTest.java | 229 ++++++++++-------- .../effect/GlEffectsFrameProcessor.java | 7 + 2 files changed, 141 insertions(+), 95 deletions(-) diff --git a/libraries/effect/src/androidTest/java/androidx/media3/effect/GlEffectsFrameProcessorFrameReleaseTest.java b/libraries/effect/src/androidTest/java/androidx/media3/effect/GlEffectsFrameProcessorFrameReleaseTest.java index 9d68db77ae..523f75863f 100644 --- a/libraries/effect/src/androidTest/java/androidx/media3/effect/GlEffectsFrameProcessorFrameReleaseTest.java +++ b/libraries/effect/src/androidTest/java/androidx/media3/effect/GlEffectsFrameProcessorFrameReleaseTest.java @@ -18,10 +18,12 @@ package androidx.media3.effect; import static androidx.media3.common.util.Assertions.checkNotNull; import static androidx.test.core.app.ApplicationProvider.getApplicationContext; import static com.google.common.truth.Truth.assertThat; +import static java.util.concurrent.TimeUnit.MILLISECONDS; import android.graphics.PixelFormat; import android.media.Image; import android.media.ImageReader; +import androidx.annotation.Nullable; import androidx.media3.common.ColorInfo; import androidx.media3.common.DebugViewProvider; import androidx.media3.common.FrameInfo; @@ -32,14 +34,16 @@ import androidx.media3.common.util.GlUtil; import androidx.media3.common.util.Util; import androidx.test.ext.junit.runners.AndroidJUnit4; import com.google.common.collect.ImmutableList; +import com.google.common.primitives.Longs; import com.google.common.util.concurrent.MoreExecutors; import java.util.ArrayList; -import java.util.Queue; -import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.concurrent.CountDownLatch; import java.util.concurrent.Executor; +import java.util.concurrent.LinkedBlockingQueue; import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; +import org.checkerframework.checker.nullness.compatqual.NullableType; import org.checkerframework.checker.nullness.qual.EnsuresNonNull; import org.checkerframework.checker.nullness.qual.MonotonicNonNull; import org.junit.After; @@ -52,16 +56,19 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { private static final int WIDTH = 200; private static final int HEIGHT = 100; - private static final long FRAME_PROCESSING_WAIT_MS = 5000L; - private static final long MILLIS_TO_NANOS = 1_000_000L; + /** + * Time to wait between releasing frames to avoid frame drops between GL and the {@link + * ImageReader}. + */ + private static final long PER_FRAME_RELEASE_WAIT_TIME_MS = 1000L; + /** Maximum time to wait for each released frame to be notified. */ + private static final long PER_FRAME_TIMEOUT_MS = 5000L; + private static final long MICROS_TO_NANOS = 1000L; - private final AtomicReference frameProcessingException = - new AtomicReference<>(); - private final Queue outputReleaseTimesNs = new ConcurrentLinkedQueue<>(); + private final LinkedBlockingQueue outputReleaseTimesNs = new LinkedBlockingQueue<>(); private @MonotonicNonNull GlEffectsFrameProcessor glEffectsFrameProcessor; - private volatile @MonotonicNonNull Runnable produceBlankFramesTask; @After public void release() { @@ -74,53 +81,58 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { public void automaticFrameRelease_withOneFrame_reusesInputTimestamp() throws Exception { long originalPresentationTimeUs = 1234; AtomicLong actualPresentationTimeUs = new AtomicLong(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ new long[] {originalPresentationTimeUs}, /* onFrameAvailableListener= */ actualPresentationTimeUs::set, /* releaseFramesAutomatically= */ true); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); assertThat(actualPresentationTimeUs.get()).isEqualTo(originalPresentationTimeUs); - assertThat(outputReleaseTimesNs).containsExactly(MICROS_TO_NANOS * originalPresentationTimeUs); + ImmutableList actualReleaseTimesNs = + waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 1); + assertThat(actualReleaseTimesNs).containsExactly(MICROS_TO_NANOS * originalPresentationTimeUs); } @Test public void automaticFrameRelease_withThreeFrames_reusesInputTimestamps() throws Exception { long[] originalPresentationTimesUs = new long[] {1234, 3456, 4567}; ArrayList actualPresentationTimesUs = new ArrayList<>(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( originalPresentationTimesUs, - /* onFrameAvailableListener= */ actualPresentationTimesUs::add, + /* onFrameAvailableListener= */ presentationTimeUs -> { + actualPresentationTimesUs.add(presentationTimeUs); + try { + // TODO(b/264252759): Investigate output frames being dropped and remove sleep. + // Frames can be dropped silently between EGL and the ImageReader. Sleep after each call + // to swap buffers, to avoid this behavior. + Thread.sleep(PER_FRAME_RELEASE_WAIT_TIME_MS); + } catch (InterruptedException e) { + throw new IllegalStateException(e); + } + }, /* releaseFramesAutomatically= */ true); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); assertThat(actualPresentationTimesUs) .containsExactly( originalPresentationTimesUs[0], originalPresentationTimesUs[1], originalPresentationTimesUs[2]) .inOrder(); - assertThat(outputReleaseTimesNs) + ImmutableList actualReleaseTimesNs = + waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 3); + assertThat(actualReleaseTimesNs) .containsExactly( MICROS_TO_NANOS * originalPresentationTimesUs[0], MICROS_TO_NANOS * originalPresentationTimesUs[1], MICROS_TO_NANOS * originalPresentationTimesUs[2]) .inOrder(); - ; } @Test public void controlledFrameRelease_withOneFrame_usesGivenTimestamp() throws Exception { long originalPresentationTimeUs = 1234; - long releaseTimesNs = System.nanoTime() + MILLIS_TO_NANOS * FRAME_PROCESSING_WAIT_MS + 345678; + long releaseTimesNs = System.nanoTime() + 345678; AtomicLong actualPresentationTimeUs = new AtomicLong(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ new long[] {originalPresentationTimeUs}, /* onFrameAvailableListener= */ presentationTimeUs -> { actualPresentationTimeUs.set(presentationTimeUs); @@ -128,12 +140,9 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { }, /* releaseFramesAutomatically= */ false); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); - assertThat(actualPresentationTimeUs.get()).isEqualTo(originalPresentationTimeUs); - assertThat(outputReleaseTimesNs).containsExactly(releaseTimesNs); + ImmutableList actualReleaseTimesNs = + waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 1); + assertThat(actualReleaseTimesNs).containsExactly(releaseTimesNs); } @Test @@ -142,7 +151,7 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { long originalPresentationTimeUs = 1234; long releaseTimesNs = FrameProcessor.RELEASE_OUTPUT_FRAME_IMMEDIATELY; AtomicLong actualPresentationTimeUs = new AtomicLong(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ new long[] {originalPresentationTimeUs}, /* onFrameAvailableListener= */ presentationTimeUs -> { actualPresentationTimeUs.set(presentationTimeUs); @@ -150,13 +159,11 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { }, /* releaseFramesAutomatically= */ false); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); assertThat(actualPresentationTimeUs.get()).isEqualTo(originalPresentationTimeUs); // The actual release time is determined by the FrameProcessor when releasing the frame. - assertThat(outputReleaseTimesNs).hasSize(1); + ImmutableList actualReleaseTimesNs = + waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 1); + assertThat(actualReleaseTimesNs).hasSize(1); } @Test @@ -164,7 +171,7 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { long originalPresentationTimeUs = 1234; long releaseTimeBeforeCurrentTimeNs = System.nanoTime() - 345678; AtomicLong actualPresentationTimeUs = new AtomicLong(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ new long[] {originalPresentationTimeUs}, /* onFrameAvailableListener= */ presentationTimeUs -> { actualPresentationTimeUs.set(presentationTimeUs); @@ -172,21 +179,18 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { }, /* releaseFramesAutomatically= */ false); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); - assertThat(actualPresentationTimeUs.get()).isEqualTo(originalPresentationTimeUs); - assertThat(outputReleaseTimesNs).hasSize(1); + ImmutableList actualReleaseTimesNs = + waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 1); + assertThat(actualReleaseTimesNs).hasSize(1); // The actual release time is determined by the FrameProcessor when releasing the frame. - assertThat(outputReleaseTimesNs.remove()).isAtLeast(releaseTimeBeforeCurrentTimeNs); + assertThat(actualReleaseTimesNs.get(0)).isAtLeast(releaseTimeBeforeCurrentTimeNs); } @Test public void controlledFrameRelease_requestsFrameDropping_dropsFrame() throws Exception { long originalPresentationTimeUs = 1234; AtomicLong actualPresentationTimeUs = new AtomicLong(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ new long[] {originalPresentationTimeUs}, /* onFrameAvailableListener= */ presentationTimeNs -> { actualPresentationTimeUs.set(presentationTimeNs); @@ -195,75 +199,77 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { }, /* releaseFramesAutomatically= */ false); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); - assertThat(actualPresentationTimeUs.get()).isEqualTo(originalPresentationTimeUs); - assertThat(outputReleaseTimesNs).isEmpty(); + waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 0); } @Test public void controlledFrameRelease_withThreeIndividualFrames_usesGivenTimestamps() throws Exception { long[] originalPresentationTimesUs = new long[] {1234, 3456, 4567}; - long offsetNs = System.nanoTime() + MILLIS_TO_NANOS * FRAME_PROCESSING_WAIT_MS; + long offsetNs = System.nanoTime(); long[] releaseTimesNs = new long[] {offsetNs + 123456, offsetNs + 234567, offsetNs + 345678}; ArrayList actualPresentationTimesUs = new ArrayList<>(); AtomicInteger frameIndex = new AtomicInteger(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ originalPresentationTimesUs, /* onFrameAvailableListener= */ presentationTimeUs -> { actualPresentationTimesUs.add(presentationTimeUs); checkNotNull(glEffectsFrameProcessor) .releaseOutputFrame(releaseTimesNs[frameIndex.getAndIncrement()]); + try { + // TODO(b/264252759): Investigate output frames being dropped and remove sleep. + // Frames can be dropped silently between EGL and the ImageReader. Sleep after each call + // to swap buffers, to avoid this behavior. + Thread.sleep(PER_FRAME_RELEASE_WAIT_TIME_MS); + } catch (InterruptedException e) { + throw new IllegalStateException(e); + } }, /* releaseFramesAutomatically= */ false); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); - - assertThat(frameProcessingException.get()).isNull(); assertThat(actualPresentationTimesUs) .containsExactly( originalPresentationTimesUs[0], originalPresentationTimesUs[1], originalPresentationTimesUs[2]) .inOrder(); - assertThat(frameIndex.get()).isEqualTo(originalPresentationTimesUs.length); - assertThat(outputReleaseTimesNs) - .containsExactly(releaseTimesNs[0], releaseTimesNs[1], releaseTimesNs[2]) - .inOrder(); + int actualFrameCount = frameIndex.get(); + assertThat(actualFrameCount).isEqualTo(originalPresentationTimesUs.length); + long[] actualReleaseTimesNs = + Longs.toArray(waitForFrameReleaseAndGetReleaseTimesNs(actualFrameCount)); + assertThat(actualReleaseTimesNs).isEqualTo(releaseTimesNs); } @Test public void controlledFrameRelease_withThreeFramesAtOnce_usesGivenTimestamps() throws Exception { long[] originalPresentationTimesUs = new long[] {1234, 3456, 4567}; - long offsetNs = System.nanoTime() + MILLIS_TO_NANOS * 2 * FRAME_PROCESSING_WAIT_MS; + long offsetNs = System.nanoTime(); long[] releaseTimesNs = new long[] {offsetNs + 123456, offsetNs + 234567, offsetNs + 345678}; ArrayList actualPresentationTimesUs = new ArrayList<>(); - setupGlEffectsFrameProcessorWithBlankFrameProducer( + processFramesToEndOfStream( /* inputPresentationTimesUs= */ originalPresentationTimesUs, /* onFrameAvailableListener= */ actualPresentationTimesUs::add, /* releaseFramesAutomatically= */ false); - checkNotNull(produceBlankFramesTask).run(); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); + // TODO(b/264252759): Investigate output frames being dropped and remove sleep. + // Frames can be dropped silently between EGL and the ImageReader. Sleep after each call + // to swap buffers, to avoid this behavior. glEffectsFrameProcessor.releaseOutputFrame(releaseTimesNs[0]); + Thread.sleep(PER_FRAME_RELEASE_WAIT_TIME_MS); glEffectsFrameProcessor.releaseOutputFrame(releaseTimesNs[1]); + Thread.sleep(PER_FRAME_RELEASE_WAIT_TIME_MS); glEffectsFrameProcessor.releaseOutputFrame(releaseTimesNs[2]); - Thread.sleep(FRAME_PROCESSING_WAIT_MS); + Thread.sleep(PER_FRAME_RELEASE_WAIT_TIME_MS); - assertThat(frameProcessingException.get()).isNull(); assertThat(actualPresentationTimesUs) .containsExactly( originalPresentationTimesUs[0], originalPresentationTimesUs[1], originalPresentationTimesUs[2]) .inOrder(); - assertThat(outputReleaseTimesNs) - .containsExactly(releaseTimesNs[0], releaseTimesNs[1], releaseTimesNs[2]) - .inOrder(); + long[] actualReleaseTimesNs = + Longs.toArray(waitForFrameReleaseAndGetReleaseTimesNs(/* expectedFrameCount= */ 3)); + assertThat(actualReleaseTimesNs).isEqualTo(releaseTimesNs); } private interface OnFrameAvailableListener { @@ -271,20 +277,21 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { } @EnsuresNonNull("glEffectsFrameProcessor") - private void setupGlEffectsFrameProcessorWithBlankFrameProducer( + private void processFramesToEndOfStream( long[] inputPresentationTimesUs, OnFrameAvailableListener onFrameAvailableListener, boolean releaseFramesAutomatically) throws Exception { + AtomicReference<@NullableType FrameProcessingException> frameProcessingExceptionReference = + new AtomicReference<>(); + BlankFrameProducer blankFrameProducer = new BlankFrameProducer(); + CountDownLatch frameProcessingEndedCountDownLatch = new CountDownLatch(1); glEffectsFrameProcessor = checkNotNull( new GlEffectsFrameProcessor.Factory() .create( getApplicationContext(), - ImmutableList.of( - (GlEffect) - (context, useHdr) -> - new BlankFrameProducer(inputPresentationTimesUs, useHdr)), + ImmutableList.of((GlEffect) (context, useHdr) -> blankFrameProducer), DebugViewProvider.NONE, /* inputColorInfo= */ ColorInfo.SDR_BT709_LIMITED, /* outputColorInfo= */ ColorInfo.SDR_BT709_LIMITED, @@ -318,31 +325,60 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { @Override public void onFrameProcessingError(FrameProcessingException exception) { - frameProcessingException.set(exception); + frameProcessingExceptionReference.set(exception); + frameProcessingEndedCountDownLatch.countDown(); } @Override - public void onFrameProcessingEnded() {} + public void onFrameProcessingEnded() { + frameProcessingEndedCountDownLatch.countDown(); + } })); - glEffectsFrameProcessor.setInputFrameInfo( - new FrameInfo(WIDTH, HEIGHT, /* pixelWidthHeightRatio= */ 1, /* streamOffsetUs= */ 0)); - // A frame needs to be registered despite not queuing any external input to ensure that the - // frame processor knows about the stream offset. - glEffectsFrameProcessor.registerInputFrame(); + glEffectsFrameProcessor + .getTaskExecutor() + .submit( + () -> { + blankFrameProducer.configureGlObjects(); + checkNotNull(glEffectsFrameProcessor) + .setInputFrameInfo( + new FrameInfo( + WIDTH, HEIGHT, /* pixelWidthHeightRatio= */ 1, /* streamOffsetUs= */ 0)); + // A frame needs to be registered despite not queuing any external input to ensure + // that + // the frame processor knows about the stream offset. + glEffectsFrameProcessor.registerInputFrame(); + blankFrameProducer.produceBlankFramesAndQueueEndOfStream(inputPresentationTimesUs); + }); + frameProcessingEndedCountDownLatch.await(); + @Nullable Exception frameProcessingException = frameProcessingExceptionReference.get(); + if (frameProcessingException != null) { + throw frameProcessingException; + } + } + + private ImmutableList waitForFrameReleaseAndGetReleaseTimesNs(int expectedFrameCount) + throws Exception { + ImmutableList.Builder listBuilder = new ImmutableList.Builder<>(); + for (int i = 0; i < expectedFrameCount; i++) { + listBuilder.add(checkNotNull(outputReleaseTimesNs.poll(PER_FRAME_TIMEOUT_MS, MILLISECONDS))); + } + // This is a best-effort check because there's no guarantee that frames aren't added to the + // release times after this method has been called. + assertThat(outputReleaseTimesNs).isEmpty(); + return listBuilder.build(); } /** Produces blank frames with the given timestamps. */ - private final class BlankFrameProducer implements GlTextureProcessor { + private static final class BlankFrameProducer implements GlTextureProcessor { - private final TextureInfo blankTexture; - private final long[] presentationTimesUs; + private @MonotonicNonNull TextureInfo blankTexture; + private @MonotonicNonNull OutputListener outputListener; - public BlankFrameProducer(long[] presentationTimesUs, boolean useHdr) - throws FrameProcessingException { - this.presentationTimesUs = presentationTimesUs; + public void configureGlObjects() throws FrameProcessingException { try { - int texId = GlUtil.createTexture(WIDTH, HEIGHT, useHdr); + int texId = + GlUtil.createTexture(WIDTH, HEIGHT, /* useHighPrecisionColorComponents= */ false); int fboId = GlUtil.createFboForTexture(texId); blankTexture = new TextureInfo(texId, fboId, WIDTH, HEIGHT); GlUtil.focusFramebufferUsingCurrentContext(fboId, WIDTH, HEIGHT); @@ -352,17 +388,20 @@ public final class GlEffectsFrameProcessorFrameReleaseTest { } } + public void produceBlankFramesAndQueueEndOfStream(long[] presentationTimesUs) { + checkNotNull(outputListener); + for (long presentationTimeUs : presentationTimesUs) { + outputListener.onOutputFrameAvailable(checkNotNull(blankTexture), presentationTimeUs); + } + outputListener.onCurrentOutputStreamEnded(); + } + @Override public void setInputListener(InputListener inputListener) {} @Override public void setOutputListener(OutputListener outputListener) { - produceBlankFramesTask = - () -> { - for (long presentationTimeUs : presentationTimesUs) { - outputListener.onOutputFrameAvailable(blankTexture, presentationTimeUs); - } - }; + this.outputListener = outputListener; } @Override diff --git a/libraries/effect/src/main/java/androidx/media3/effect/GlEffectsFrameProcessor.java b/libraries/effect/src/main/java/androidx/media3/effect/GlEffectsFrameProcessor.java index 80e9467162..ca7f16fe88 100644 --- a/libraries/effect/src/main/java/androidx/media3/effect/GlEffectsFrameProcessor.java +++ b/libraries/effect/src/main/java/androidx/media3/effect/GlEffectsFrameProcessor.java @@ -25,6 +25,7 @@ import android.opengl.EGLContext; import android.opengl.EGLDisplay; import android.view.Surface; import androidx.annotation.Nullable; +import androidx.annotation.VisibleForTesting; import androidx.annotation.WorkerThread; import androidx.media3.common.C; import androidx.media3.common.ColorInfo; @@ -368,6 +369,12 @@ public final class GlEffectsFrameProcessor implements FrameProcessor { previousStreamOffsetUs = C.TIME_UNSET; } + /** Returns the task executor that runs frame processing tasks. */ + @VisibleForTesting + /* package */ FrameProcessingTaskExecutor getTaskExecutor() { + return frameProcessingTaskExecutor; + } + @Override public Surface getInputSurface() { return inputSurface;