1 /* 2 * Copyright (C) 2013 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package android.media.cts; 18 19 import android.opengl.GLES20; 20 import android.os.Handler; 21 import android.os.Looper; 22 import android.os.Message; 23 import android.os.Trace; 24 import android.platform.test.annotations.AppModeFull; 25 import android.test.ActivityInstrumentationTestCase2; 26 import android.test.suitebuilder.annotation.Suppress; 27 import android.util.Log; 28 import android.view.Choreographer; 29 import android.view.SurfaceHolder; 30 31 32 /** 33 * Tests synchronized frame presentation. 34 * 35 * SurfaceFlinger allows a "desired presentation time" value to be passed along with buffers of 36 * data. This exercises that feature. 37 */ 38 @AppModeFull(reason = "TODO: evaluate and port to instant") 39 public class PresentationSyncTest extends ActivityInstrumentationTestCase2<MediaStubActivity> 40 implements SurfaceHolder.Callback { 41 private static final String TAG = "PresentationSyncTest"; 42 private static final boolean VERBOSE = false; // lots of logging 43 private static final int FRAME_COUNT = 128; // ~2 sec @ 60fps 44 45 // message values 46 private static final int START_TEST = 0; 47 private static final int END_TEST = 1; 48 49 // width and height of the Surface we're given to draw on 50 private int mWidth; 51 private int mHeight; 52 53 public PresentationSyncTest() { 54 super(MediaStubActivity.class); 55 } 56 57 /** 58 * Tests whether the output frame rate can be limited by the presentation time. 59 * <p> 60 * Generates and displays the same series of images three times. The first run uses "now" 61 * as the desired presentation time to establish an estimate of the refresh time. Later 62 * runs set the presentation time to (start_time + frame_number * refresh_time * multiplier), 63 * with the expectation that a multiplier of 2 will cause the animation to render at 64 * half speed. 65 * <p> 66 * This test does not use Choreographer. The longer the test runs, the farther out of 67 * phase the test will become with respect to the actual vsync timing. 68 * <p> 69 * Setting the presentation time for a frame is most easily done through an EGL extension, 70 * so we render each frame through GL. 71 * 72 * @throws Exception 73 */ 74 public void testThroughput() throws Exception { 75 // Get the Surface from the SurfaceView. 76 // TODO: is it safe to assume that it's ready? 77 SurfaceHolder holder = getActivity().getSurfaceHolder(); 78 holder.addCallback(this); 79 80 // We use the width/height to render a simple series of patterns. If we get this 81 // wrong it shouldn't really matter -- some driver optimizations might make things 82 // faster, but it shouldn't affect how long it takes the frame to be displayed. 83 // 84 // We can get this from the View or from the EGLSurface. We don't have easy direct 85 // access to any of those things, so just ask our InputSurface to get it from EGL, 86 // since that's where we're drawing. 87 // 88 // Note: InputSurface was intended for a different purpose, but it's 99% right for our 89 // needs. Maybe rename it to "RecordableSurface"? Or trivially wrap it with a 90 // subclass that suppresses the EGL_RECORDABLE_ANDROID flag? 91 InputSurface output = new InputSurface(holder.getSurface()); 92 mWidth = output.getWidth(); 93 mHeight = output.getHeight(); 94 Log.d(TAG, "Surface w=" + mWidth + " h=" + mHeight); 95 output.makeCurrent(); 96 97 // Run a test with no presentation times specified. Assuming nothing else is 98 // fighting us for resources, all frames should display as quickly as possible, 99 // and we can estimate the refresh rate of the device. 100 long baseTimeNsec = runThroughputTest(output, 0L, -1.0f); 101 long refreshNsec = baseTimeNsec / FRAME_COUNT; 102 Log.i(TAG, "Using " + refreshNsec + "ns as refresh rate"); 103 104 // Run tests with times specified, at 1.3x, 1x, 1/2x, and 1/4x speed. 105 // 106 // One particular device is overly aggressive at reducing clock frequencies, and it 107 // will slow things to the point where we can't push frames quickly enough in the 108 // faster test. By adding an artificial workload in a second thread we can make the 109 // system run faster. (This could have a detrimental effect on a single-core CPU, 110 // so it's a no-op there.) 111 CpuWaster cpuWaster = new CpuWaster(); 112 try { 113 cpuWaster.start(); 114 // Tests with mult < 1.0f are flaky, for two reasons: 115 // 116 // (a) They assume that the GPU can render the test scene in less than mult*refreshNsec. 117 // It's a simple scene, but CTS/CDD don't currently require being able to do more 118 // than a full-screen clear in refreshNsec. 119 // 120 // (b) More importantly, it assumes that the only rate-limiting happening is 121 // backpressure from the buffer queue. If the EGL implementation is doing its own 122 // rate-limiting (to limit the amount of work queued to the GPU at any time), then 123 // depending on how that's implemented the buffer queue may not have two frames 124 // pending very often. So the consumer won't be able to drop many frames, and the 125 // throughput won't be much better than with mult=1.0. 126 // 127 // runThroughputTest(output, refreshNsec, 0.75f); 128 cpuWaster.stop(); 129 runThroughputTest(output, refreshNsec, 1.0f); 130 runThroughputTest(output, refreshNsec, 2.0f); 131 runThroughputTest(output, refreshNsec, 4.0f); 132 } finally { 133 cpuWaster.stop(); 134 } 135 136 output.release(); 137 } 138 139 /** 140 * Runs the throughput test on the provided surface with the specified time values. 141 * <p> 142 * If mult is -1, the test runs in "training" mode, rendering frames as quickly as 143 * possible. This can be used to establish a baseline. 144 * <p> 145 * @return the test duration, in nanoseconds 146 */ 147 private long runThroughputTest(InputSurface output, long frameTimeNsec, float mult) { 148 Log.d(TAG, "runThroughputTest: " + mult); 149 150 // Sleep briefly. This is strangely necessary on some devices to allow the GPU to 151 // catch up (b/10898363). It also provides an easily-visible break in the systrace 152 // output. 153 try { Thread.sleep(50); } 154 catch (InterruptedException ignored) {} 155 156 long startNsec = System.nanoTime(); 157 long showNsec = 0; 158 159 if (true) { 160 // Output a frame that creates a "marker" in the --latency output 161 drawFrame(0, mult); 162 output.setPresentationTime(startNsec - 16700000L * 100); 163 Trace.beginSection("TEST BEGIN"); 164 output.swapBuffers(); 165 Trace.endSection(); 166 startNsec = System.nanoTime(); 167 } 168 169 for (int frameNum = 0; frameNum < FRAME_COUNT; frameNum++) { 170 if (mult != -1.0f) { 171 showNsec = startNsec + (long) (frameNum * frameTimeNsec * mult); 172 } 173 drawFrame(frameNum, mult); 174 output.setPresentationTime(showNsec); 175 Trace.beginSection("swapbuf " + frameNum); 176 output.swapBuffers(); 177 Trace.endSection(); 178 } 179 180 long endNsec = System.nanoTime(); 181 long actualNsec = endNsec - startNsec; 182 183 if (mult != -1) { 184 // Some variation is inevitable, but we should be within a few percent of expected. 185 long expectedNsec = (long) (frameTimeNsec * FRAME_COUNT * mult); 186 long deltaNsec = Math.abs(expectedNsec - actualNsec); 187 double delta = (double) deltaNsec / expectedNsec; 188 final double MAX_DELTA = 0.05; 189 if (delta > MAX_DELTA) { 190 throw new RuntimeException("Time delta exceeds tolerance (" + MAX_DELTA + 191 "): mult=" + mult + ": expected=" + expectedNsec + 192 " actual=" + actualNsec + " p=" + delta); 193 194 } else { 195 Log.d(TAG, "mult=" + mult + ": expected=" + expectedNsec + 196 " actual=" + actualNsec + " p=" + delta); 197 } 198 } 199 return endNsec - startNsec; 200 } 201 202 203 /** 204 * Exercises the test code, driving it off of Choreographer. The animation is driven at 205 * full speed, but with rendering requested at a future time. With each run the distance 206 * into the future is increased. 207 * <p> 208 * Loopers can't be reused once they quit, so it's easiest to create a new thread for 209 * each run. 210 * <p> 211 * (This isn't exactly a test -- it's primarily a way to exercise the code. Evaluate the 212 * results with "dumpsys SurfaceFlinger --latency SurfaceView" for each multiplier. 213 * The idea is to see frames where the desired-present is as close as possible to the 214 * actual-present, while still minimizing frame-ready. If we go too far into the future 215 * the BufferQueue will start to back up.) 216 * <p> 217 * @throws Exception 218 */ 219 public void suppressed_testChoreographed() throws Throwable { 220 // Get the Surface from the SurfaceView. 221 // TODO: is it safe to assume that it's ready? 222 SurfaceHolder holder = getActivity().getSurfaceHolder(); 223 holder.addCallback(this); 224 225 InputSurface output = new InputSurface(holder.getSurface()); 226 mWidth = output.getWidth(); 227 mHeight = output.getHeight(); 228 Log.d(TAG, "Surface w=" + mWidth + " h=" + mHeight); 229 230 for (int i = 1; i < 5; i++) { 231 ChoreographedWrapper.runTest(this, output, i); 232 } 233 234 output.release(); 235 } 236 237 /** 238 * Shifts the test to a new thread, so we can manage our own Looper. Any exception 239 * thrown on the new thread is propagated to the caller. 240 */ 241 private static class ChoreographedWrapper implements Runnable { 242 private final PresentationSyncTest mTest; 243 private final InputSurface mOutput; 244 private final int mFrameDelay; 245 private Throwable mThrowable; 246 247 private ChoreographedWrapper(PresentationSyncTest test, InputSurface output, 248 int frameDelay) { 249 mTest = test; 250 mOutput = output; 251 mFrameDelay = frameDelay; 252 } 253 254 @Override 255 public void run() { 256 try { 257 mTest.runChoreographedTest(mOutput, mFrameDelay); 258 } catch (Throwable th) { 259 mThrowable = th; 260 } 261 } 262 263 /** Entry point. */ 264 public static void runTest(PresentationSyncTest obj, InputSurface output, 265 int frameDelay) throws Throwable { 266 ChoreographedWrapper wrapper = new ChoreographedWrapper(obj, output, frameDelay); 267 Thread th = new Thread(wrapper, "sync test"); 268 th.start(); 269 th.join(); 270 if (wrapper.mThrowable != null) { 271 throw wrapper.mThrowable; 272 } 273 } 274 } 275 276 /** 277 * Runs the test, driven by callbacks from the Looper we define here. 278 */ 279 private void runChoreographedTest(InputSurface output, int frameDelay) { 280 Log.d(TAG, "runChoreographedTest"); 281 282 output.makeCurrent(); 283 final ChoRunner chore = new ChoRunner(output); 284 285 Looper.prepare(); 286 Handler handler = new Handler() { 287 @Override 288 public void handleMessage(Message msg) { 289 switch (msg.what) { 290 case START_TEST: 291 Log.d(TAG, "Starting test"); 292 chore.start(this, msg.arg1 /*frameDelay*/); 293 break; 294 case END_TEST: 295 Log.d(TAG, "Ending test"); 296 Looper.myLooper().quitSafely(); 297 break; 298 default: 299 Log.d(TAG, "unknown message " + msg.what); 300 break; 301 } 302 } 303 }; 304 305 handler.sendMessage(Message.obtain(handler, START_TEST, frameDelay, 0)); 306 307 Log.d(TAG, "looping (frameDelay=" + frameDelay + ")"); 308 long startNanos = System.nanoTime(); 309 Trace.beginSection("TEST BEGIN fd=" + frameDelay); 310 Looper.loop(); 311 Trace.endSection(); 312 long durationNanos = System.nanoTime() - startNanos; 313 Log.d(TAG, "loop exiting after " + durationNanos + 314 " (" + durationNanos / FRAME_COUNT + "ns)"); 315 316 output.makeUnCurrent(); 317 } 318 319 320 private class ChoRunner implements Choreographer.FrameCallback { 321 private final InputSurface mOutput; 322 private int mFrameDelay; 323 private Handler mHandler; 324 private int mCurFrame; 325 private Choreographer mChocho; 326 private long mPrevFrameTimeNanos; 327 private long mFrameDiff; 328 329 public ChoRunner(InputSurface output) { 330 mOutput = output; 331 } 332 333 public void start(Handler handler, int frameDelay) { 334 mHandler = handler; 335 mFrameDelay = frameDelay; 336 337 mCurFrame = 0; 338 mChocho = Choreographer.getInstance(); 339 mChocho.postFrameCallback(this); 340 } 341 342 @Override 343 public void doFrame(long frameTimeNanos) { 344 if (mPrevFrameTimeNanos != 0) { 345 // Update our vsync rate guess every frame so that, if we start with a 346 // stutter, we don't carry it for the whole test. 347 assertTrue(frameTimeNanos > mPrevFrameTimeNanos); 348 long prevDiff = frameTimeNanos - mPrevFrameTimeNanos; 349 if (mFrameDiff == 0 || mFrameDiff > prevDiff) { 350 mFrameDiff = prevDiff; 351 Log.d(TAG, "refresh rate approx " + mFrameDiff + "ns"); 352 } 353 354 // If the current diff is >= 2x the expected frame time diff, we stuttered 355 // and need to drop a frame. (We might even need to drop more than one 356 // frame; ignoring that for now.) 357 if (prevDiff > mFrameDiff * 1.9) { 358 Log.d(TAG, "skip " + mCurFrame + " diff=" + prevDiff); 359 mCurFrame++; 360 } 361 } 362 mPrevFrameTimeNanos = frameTimeNanos; 363 364 if (mFrameDiff != 0) { 365 // set desired display time to N frames in the future, rather than ASAP. 366 // 367 // Note this is a "don't open until Xmas" feature. If vsyncs are happening 368 // at times T1, T2, T3, and we want the frame to appear onscreen when the 369 // buffers flip at T2, then we can theoretically request any time value 370 // in [T1, T2). 371 mOutput.setPresentationTime(frameTimeNanos + (mFrameDiff * mFrameDelay)); 372 } 373 374 drawFrame(mCurFrame, mFrameDelay); 375 Trace.beginSection("swapbuf " + mCurFrame); 376 mOutput.swapBuffers(); 377 Trace.endSection(); 378 379 if (++mCurFrame < FRAME_COUNT) { 380 mChocho.postFrameCallback(this); 381 } else { 382 mHandler.sendMessage(Message.obtain(mHandler, END_TEST)); 383 } 384 } 385 } 386 387 /** 388 * Draws a frame with GLES in the current context. 389 */ 390 private void drawFrame(int num, float mult) { 391 num %= 64; 392 float colorVal; 393 394 if (mult > 0) { 395 colorVal = 1.0f / mult; 396 } else { 397 colorVal = 0.1f; 398 } 399 400 int startX, startY; 401 startX = (num % 16) * (mWidth / 16); 402 startY = (num / 16) * (mHeight / 4); 403 if ((num >= 16 && num < 32) || (num >= 48)) { 404 // reverse direction 405 startX = (mWidth - mWidth/16) - startX; 406 } 407 408 // clear screen 409 GLES20.glClearColor(0.2f, 0.2f, 0.2f, 1.0f); 410 GLES20.glClear(GLES20.GL_COLOR_BUFFER_BIT); 411 412 // draw rect 413 GLES20.glEnable(GLES20.GL_SCISSOR_TEST); 414 GLES20.glScissor(startX, startY, mWidth / 16, mHeight / 4); 415 GLES20.glClearColor(colorVal, 1 - colorVal, 0.0f, 1.0f); 416 GLES20.glClear(GLES20.GL_COLOR_BUFFER_BIT); 417 GLES20.glDisable(GLES20.GL_SCISSOR_TEST); 418 } 419 420 @Override 421 public void surfaceCreated(SurfaceHolder holder) { 422 Log.d(TAG, "surfaceCreated"); 423 } 424 425 @Override 426 public void surfaceChanged(SurfaceHolder holder, int format, int width, 427 int height) { 428 // This doesn't seem to happen in practice with current test framework -- Surface is 429 // already created before we start, and the orientation is locked. 430 Log.d(TAG, "surfaceChanged f=" + format + " w=" + width + " h=" + height); 431 mWidth = width; 432 mHeight = height; 433 } 434 435 @Override 436 public void surfaceDestroyed(SurfaceHolder holder) { 437 Log.d(TAG, "surfaceDestroyed"); 438 } 439 440 441 /** 442 * Wastes CPU time. 443 * <p> 444 * The start() and stop() methods must be called from the same thread. 445 */ 446 private static class CpuWaster { 447 volatile boolean mRunning = false; 448 449 public void start() { 450 if (mRunning) { 451 throw new IllegalStateException("already running"); 452 } 453 454 if (Runtime.getRuntime().availableProcessors() < 2) { 455 return; 456 } 457 458 mRunning = true; 459 460 new Thread("Stupid") { 461 @Override 462 public void run() { 463 while (mRunning) { /* spin! */ } 464 } 465 }.start(); 466 467 // sleep briefly while the system re-evaluates its load (might want to spin) 468 try { Thread.sleep(10); } 469 catch (InterruptedException ignored) {} 470 } 471 472 public void stop() { 473 if (mRunning) { 474 mRunning = false; 475 476 // give the system a chance to slow back down 477 try { Thread.sleep(10); } 478 catch (InterruptedException ignored) {} 479 } 480 } 481 } 482 } 483