1 /*
2  * Copyright (C) 2020 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 com.android.cts.graphics.framerateoverride;
18 
19 import static org.junit.Assert.assertTrue;
20 
21 import android.app.Activity;
22 import android.graphics.Canvas;
23 import android.graphics.Color;
24 import android.hardware.display.DisplayManager;
25 import android.os.Bundle;
26 import android.os.Handler;
27 import android.os.Looper;
28 import android.util.Log;
29 import android.view.Choreographer;
30 import android.view.Surface;
31 import android.view.SurfaceHolder;
32 import android.view.SurfaceView;
33 import android.view.ViewGroup;
34 
35 import java.util.ArrayList;
36 
37 /**
38  * An Activity to help with frame rate testing.
39  */
40 public class FrameRateOverrideTestActivity extends Activity {
41     private static final String TAG = "FrameRateOverrideTestActivity";
42     private static final long FRAME_RATE_SWITCH_GRACE_PERIOD_NANOSECONDS = 2 * 1_000_000_000L;
43     private static final long STABLE_FRAME_RATE_WAIT_NANOSECONDS = 1 * 1_000_000_000L;
44     private static final long POST_BUFFER_INTERVAL_NANOSECONDS = 500_000_000L;
45     private static final int PRECONDITION_WAIT_MAX_ATTEMPTS = 5;
46     private static final long PRECONDITION_WAIT_TIMEOUT_NANOSECONDS = 20 * 1_000_000_000L;
47     private static final long PRECONDITION_VIOLATION_WAIT_TIMEOUT_NANOSECONDS = 3 * 1_000_000_000L;
48     private static final float FRAME_RATE_TOLERANCE = 0.01f;
49     private static final float FPS_TOLERANCE_FOR_FRAME_RATE_OVERRIDE = 5;
50     private static final long FRAME_RATE_MIN_WAIT_TIME_NANOSECONDS = 1 * 1_000_000_000L;
51     private static final long FRAME_RATE_MAX_WAIT_TIME_NANOSECONDS = 10 * 1_000_000_000L;
52 
53     private DisplayManager mDisplayManager;
54     private SurfaceView mSurfaceView;
55     private Handler mHandler = new Handler(Looper.getMainLooper());
56     private Object mLock = new Object();
57     private Surface mSurface = null;
58     private float mReportedDisplayRefreshRate;
59     private float mReportedDisplayModeRefreshRate;
60     private ArrayList<Float> mRefreshRateChangedEvents = new ArrayList<Float>();
61 
62     private long mLastBufferPostTime;
63 
64     SurfaceHolder.Callback mSurfaceHolderCallback = new SurfaceHolder.Callback() {
65         @Override
66         public void surfaceCreated(SurfaceHolder holder) {
67             synchronized (mLock) {
68                 mSurface = holder.getSurface();
69                 mLock.notify();
70             }
71         }
72 
73         @Override
74         public void surfaceDestroyed(SurfaceHolder holder) {
75             synchronized (mLock) {
76                 mSurface = null;
77                 mLock.notify();
78             }
79         }
80 
81         @Override
82         public void surfaceChanged(SurfaceHolder holder, int format, int width, int height) {
83         }
84     };
85 
86     DisplayManager.DisplayListener mDisplayListener = new DisplayManager.DisplayListener() {
87         @Override
88         public void onDisplayAdded(int displayId) {
89         }
90 
91         @Override
92         public void onDisplayChanged(int displayId) {
93             synchronized (mLock) {
94                 float refreshRate = getDisplay().getRefreshRate();
95                 float displayModeRefreshRate = getDisplay().getMode().getRefreshRate();
96                 if (refreshRate != mReportedDisplayRefreshRate
97                         || displayModeRefreshRate != mReportedDisplayModeRefreshRate) {
98                     Log.i(TAG, String.format("Frame rate changed: (%.2f, %.2f) --> (%.2f, %.2f)",
99                                     mReportedDisplayModeRefreshRate,
100                                     mReportedDisplayRefreshRate,
101                                     displayModeRefreshRate,
102                                     refreshRate));
103                     mReportedDisplayRefreshRate = refreshRate;
104                     mReportedDisplayModeRefreshRate = displayModeRefreshRate;
105                     mRefreshRateChangedEvents.add(refreshRate);
106                     mLock.notify();
107                 }
108             }
109         }
110 
111         @Override
112         public void onDisplayRemoved(int displayId) {
113         }
114     };
115 
116     private static class PreconditionViolatedException extends RuntimeException { }
117 
118     private static class FrameRateTimeoutException extends RuntimeException {
FrameRateTimeoutException(float appRequestedFrameRate, float deviceRefreshRate)119         FrameRateTimeoutException(float appRequestedFrameRate, float deviceRefreshRate) {
120             this.appRequestedFrameRate = appRequestedFrameRate;
121             this.deviceRefreshRate = deviceRefreshRate;
122         }
123 
124         public float appRequestedFrameRate;
125         public float deviceRefreshRate;
126     }
127 
postBufferToSurface(int color)128     public void postBufferToSurface(int color) {
129         mLastBufferPostTime = System.nanoTime();
130         Canvas canvas = mSurface.lockCanvas(null);
131         canvas.drawColor(color);
132         mSurface.unlockCanvasAndPost(canvas);
133     }
134 
135     @Override
onCreate(Bundle savedInstanceState)136     protected void onCreate(Bundle savedInstanceState) {
137         super.onCreate(savedInstanceState);
138         synchronized (mLock) {
139             mDisplayManager = getSystemService(DisplayManager.class);
140             mReportedDisplayRefreshRate = getDisplay().getRefreshRate();
141             mReportedDisplayModeRefreshRate = getDisplay().getMode().getRefreshRate();
142             mDisplayManager.registerDisplayListener(mDisplayListener, mHandler);
143             mSurfaceView = new SurfaceView(this);
144             mSurfaceView.setWillNotDraw(false);
145             setContentView(mSurfaceView,
146                     new ViewGroup.LayoutParams(ViewGroup.LayoutParams.MATCH_PARENT,
147                             ViewGroup.LayoutParams.MATCH_PARENT));
148             mSurfaceView.getHolder().addCallback(mSurfaceHolderCallback);
149         }
150     }
151 
152     @Override
onDestroy()153     protected void onDestroy() {
154         super.onDestroy();
155         mDisplayManager.unregisterDisplayListener(mDisplayListener);
156         synchronized (mLock) {
157             mLock.notify();
158         }
159     }
160 
frameRatesEqual(float frameRate1, float frameRate2)161     private static boolean frameRatesEqual(float frameRate1, float frameRate2) {
162         return Math.abs(frameRate1 - frameRate2) <= FRAME_RATE_TOLERANCE;
163     }
164 
frameRatesMatchesOverride(float frameRate1, float frameRate2)165     private static boolean frameRatesMatchesOverride(float frameRate1, float frameRate2) {
166         return Math.abs(frameRate1 - frameRate2) <= FPS_TOLERANCE_FOR_FRAME_RATE_OVERRIDE;
167     }
168 
169     // Waits until our SurfaceHolder has a surface and the activity is resumed.
waitForPreconditions()170     private void waitForPreconditions() throws InterruptedException {
171         assertTrue(
172                 "Activity was unexpectedly destroyed", !isDestroyed());
173         if (mSurface == null || !isResumed()) {
174             Log.i(TAG, String.format(
175                     "Waiting for preconditions. Have surface? %b. Activity resumed? %b.",
176                             mSurface != null, isResumed()));
177         }
178         long nowNanos = System.nanoTime();
179         long endTimeNanos = nowNanos + PRECONDITION_WAIT_TIMEOUT_NANOSECONDS;
180         while (mSurface == null || !isResumed()) {
181             long timeRemainingMillis = (endTimeNanos - nowNanos) / 1_000_000;
182             assertTrue(String.format("Timed out waiting for preconditions. Have surface? %b."
183                             + " Activity resumed? %b.",
184                     mSurface != null, isResumed()),
185                     timeRemainingMillis > 0);
186             mLock.wait(timeRemainingMillis);
187             assertTrue("Activity was unexpectedly destroyed", !isDestroyed());
188             nowNanos = System.nanoTime();
189         }
190     }
191 
192     // Returns true if we encounter a precondition violation, false otherwise.
waitForPreconditionViolation()193     private boolean waitForPreconditionViolation() throws InterruptedException {
194         assertTrue("Activity was unexpectedly destroyed", !isDestroyed());
195         long nowNanos = System.nanoTime();
196         long endTimeNanos = nowNanos + PRECONDITION_VIOLATION_WAIT_TIMEOUT_NANOSECONDS;
197         while (mSurface != null && isResumed()) {
198             long timeRemainingMillis = (endTimeNanos - nowNanos) / 1_000_000;
199             if (timeRemainingMillis <= 0) {
200                 break;
201             }
202             mLock.wait(timeRemainingMillis);
203             assertTrue("Activity was unexpectedly destroyed", !isDestroyed());
204             nowNanos = System.nanoTime();
205         }
206         return mSurface == null || !isResumed();
207     }
208 
verifyPreconditions()209     private void verifyPreconditions() {
210         if (mSurface == null || !isResumed()) {
211             throw new PreconditionViolatedException();
212         }
213     }
214 
215     // Returns true if we reached waitUntilNanos, false if some other event occurred.
waitForEvents(long waitUntilNanos)216     private boolean waitForEvents(long waitUntilNanos)
217             throws InterruptedException {
218         mRefreshRateChangedEvents.clear();
219         long nowNanos = System.nanoTime();
220         while (nowNanos < waitUntilNanos) {
221             long surfacePostTime = mLastBufferPostTime + POST_BUFFER_INTERVAL_NANOSECONDS;
222             long timeoutNs = Math.min(waitUntilNanos, surfacePostTime) - nowNanos;
223             long timeoutMs = timeoutNs / 1_000_000L;
224             int remainderNs = (int) (timeoutNs % 1_000_000L);
225             // Don't call wait(0, 0) - it blocks indefinitely.
226             if (timeoutMs > 0 || remainderNs > 0) {
227                 mLock.wait(timeoutMs, remainderNs);
228             }
229             nowNanos = System.nanoTime();
230             verifyPreconditions();
231             if (!mRefreshRateChangedEvents.isEmpty()) {
232                 return false;
233             }
234             if (nowNanos >= surfacePostTime) {
235                 postBufferToSurface(Color.RED);
236             }
237         }
238         return true;
239     }
240 
waitForRefreshRateChange(float expectedRefreshRate)241     private void waitForRefreshRateChange(float expectedRefreshRate) throws InterruptedException {
242         Log.i(TAG, "Waiting for the refresh rate to change");
243         long nowNanos = System.nanoTime();
244         long gracePeriodEndTimeNanos =
245                 nowNanos + FRAME_RATE_SWITCH_GRACE_PERIOD_NANOSECONDS;
246         while (true) {
247             // Wait until we switch to the expected refresh rate
248             while (!frameRatesEqual(mReportedDisplayRefreshRate, expectedRefreshRate)
249                     && !waitForEvents(gracePeriodEndTimeNanos)) {
250                 // Empty
251             }
252             nowNanos = System.nanoTime();
253             if (nowNanos >= gracePeriodEndTimeNanos) {
254                 throw new FrameRateTimeoutException(expectedRefreshRate,
255                         mReportedDisplayRefreshRate);
256             }
257 
258             // We've switched to a compatible frame rate. Now wait for a while to see if we stay at
259             // that frame rate.
260             long endTimeNanos = nowNanos + STABLE_FRAME_RATE_WAIT_NANOSECONDS;
261             while (endTimeNanos > nowNanos) {
262                 if (waitForEvents(endTimeNanos)) {
263                     Log.i(TAG, String.format("Stable frame rate %.2f verified",
264                             mReportedDisplayRefreshRate));
265                     return;
266                 }
267                 nowNanos = System.nanoTime();
268                 if (!mRefreshRateChangedEvents.isEmpty()) {
269                     break;
270                 }
271             }
272         }
273     }
274 
275     interface FrameRateObserver {
observe(float initialRefreshRate, float expectedFrameRate, String condition)276         void observe(float initialRefreshRate, float expectedFrameRate, String condition)
277                 throws InterruptedException;
278     }
279 
280     class BackpressureFrameRateObserver implements FrameRateObserver {
281         @Override
observe(float initialRefreshRate, float expectedFrameRate, String condition)282         public void observe(float initialRefreshRate, float expectedFrameRate, String condition) {
283             long startTime = System.nanoTime();
284             int totalBuffers = 0;
285             float fps = 0;
286             while (System.nanoTime() - startTime <= FRAME_RATE_MAX_WAIT_TIME_NANOSECONDS) {
287                 postBufferToSurface(Color.BLACK + totalBuffers);
288                 totalBuffers++;
289                 if (System.nanoTime() - startTime >= FRAME_RATE_MIN_WAIT_TIME_NANOSECONDS) {
290                     float testDuration = (System.nanoTime() - startTime) / 1e9f;
291                     fps = totalBuffers / testDuration;
292                     if (frameRatesMatchesOverride(fps, expectedFrameRate)) {
293                         Log.i(TAG,
294                                 String.format("%s: backpressure observed refresh rate %.2f",
295                                         condition,
296                                         fps));
297                         return;
298                     }
299                 }
300             }
301 
302             assertTrue(String.format(
303                     "%s: backpressure observed refresh rate doesn't match the current refresh "
304                             + "rate. "
305                             + "expected: %.2f observed: %.2f", condition, expectedFrameRate, fps),
306                     frameRatesMatchesOverride(fps, expectedFrameRate));
307         }
308     }
309 
310     class ChoreographerFrameRateObserver implements FrameRateObserver {
311         class ChoreographerThread extends Thread implements Choreographer.FrameCallback {
312             Choreographer mChoreographer;
313             long mStartTime;
314             public Handler mHandler;
315             Looper mLooper;
316             int mTotalCallbacks = 0;
317             long mEndTime;
318             float mExpectedRefreshRate;
319             String mCondition;
320 
ChoreographerThread(float expectedRefreshRate, String condition)321             ChoreographerThread(float expectedRefreshRate, String condition)
322                     throws InterruptedException {
323                 mExpectedRefreshRate = expectedRefreshRate;
324                 mCondition = condition;
325             }
326 
327             @Override
run()328             public void run() {
329                 Looper.prepare();
330                 mChoreographer = Choreographer.getInstance();
331                 mHandler = new Handler();
332                 mLooper = Looper.myLooper();
333                 mStartTime = System.nanoTime();
334                 mChoreographer.postFrameCallback(this);
335                 Looper.loop();
336             }
337 
338             @Override
doFrame(long frameTimeNanos)339             public void doFrame(long frameTimeNanos) {
340                 mTotalCallbacks++;
341                 mEndTime = System.nanoTime();
342                 if (mEndTime - mStartTime <= FRAME_RATE_MIN_WAIT_TIME_NANOSECONDS) {
343                     mChoreographer.postFrameCallback(this);
344                     return;
345                 } else if (frameRatesMatchesOverride(mExpectedRefreshRate, getFps())
346                         || mEndTime - mStartTime > FRAME_RATE_MAX_WAIT_TIME_NANOSECONDS) {
347                     mLooper.quitSafely();
348                     return;
349                 }
350                 mChoreographer.postFrameCallback(this);
351             }
352 
verifyFrameRate()353             public void verifyFrameRate() throws InterruptedException {
354                 float fps = getFps();
355                 Log.i(TAG,
356                         String.format("%s: choreographer observed refresh rate %.2f",
357                                 mCondition,
358                                 fps));
359                 assertTrue(String.format(
360                         "%s: choreographer observed refresh rate doesn't match the current "
361                                 + "refresh rate. expected: %.2f observed: %.2f",
362                         mCondition, mExpectedRefreshRate, fps),
363                         frameRatesMatchesOverride(mExpectedRefreshRate, fps));
364             }
365 
getFps()366             private float getFps() {
367                 return mTotalCallbacks / ((mEndTime - mStartTime) / 1e9f);
368             }
369         }
370 
371         @Override
observe(float initialRefreshRate, float expectedFrameRate, String condition)372         public void observe(float initialRefreshRate, float expectedFrameRate, String condition)
373                 throws InterruptedException {
374             ChoreographerThread thread = new ChoreographerThread(expectedFrameRate, condition);
375             thread.start();
376             thread.join();
377             thread.verifyFrameRate();
378         }
379     }
380 
381     class DisplayGetRefreshRateFrameRateObserver implements FrameRateObserver {
382         @Override
observe(float initialRefreshRate, float expectedFrameRate, String condition)383         public void observe(float initialRefreshRate, float expectedFrameRate, String condition) {
384             Log.i(TAG,
385                     String.format("%s: Display.getRefreshRate() returned refresh rate %.2f",
386                             condition, mReportedDisplayRefreshRate));
387             assertTrue(String.format("%s: Display.getRefreshRate() doesn't match the "
388                             + "current refresh. expected: %.2f observed: %.2f", condition,
389                     expectedFrameRate, mReportedDisplayRefreshRate),
390                     frameRatesMatchesOverride(mReportedDisplayRefreshRate, expectedFrameRate));
391         }
392     }
393 
394     class DisplayModeGetRefreshRateFrameRateObserver implements FrameRateObserver {
395         private final boolean mDisplayModeReturnsPhysicalRefreshRateEnabled;
396 
DisplayModeGetRefreshRateFrameRateObserver( boolean displayModeReturnsPhysicalRefreshRateEnabled)397         DisplayModeGetRefreshRateFrameRateObserver(
398                 boolean displayModeReturnsPhysicalRefreshRateEnabled) {
399             mDisplayModeReturnsPhysicalRefreshRateEnabled =
400                     displayModeReturnsPhysicalRefreshRateEnabled;
401         }
402 
403         @Override
observe(float initialRefreshRate, float expectedFrameRate, String condition)404         public void observe(float initialRefreshRate, float expectedFrameRate, String condition) {
405             float expectedDisplayModeRefreshRate =
406                     mDisplayModeReturnsPhysicalRefreshRateEnabled ? initialRefreshRate
407                             : expectedFrameRate;
408             Log.i(TAG,
409                     String.format(
410                             "%s: Display.getMode().getRefreshRate() returned refresh rate %.2f",
411                             condition, mReportedDisplayModeRefreshRate));
412             assertTrue(String.format("%s: Display.getMode().getRefreshRate() doesn't match the "
413                             + "current refresh. expected: %.2f observed: %.2f", condition,
414                     expectedDisplayModeRefreshRate, mReportedDisplayModeRefreshRate),
415                     frameRatesMatchesOverride(mReportedDisplayModeRefreshRate,
416                             expectedDisplayModeRefreshRate));
417         }
418     }
419 
testFrameRateOverrideBehavior(FrameRateObserver frameRateObserver, float initialRefreshRate)420     private void testFrameRateOverrideBehavior(FrameRateObserver frameRateObserver,
421             float initialRefreshRate) throws InterruptedException {
422         Log.i(TAG, "Staring testFrameRateOverride");
423         float halfFrameRate = initialRefreshRate / 2;
424 
425         waitForRefreshRateChange(initialRefreshRate);
426         frameRateObserver.observe(initialRefreshRate, initialRefreshRate, "Initial");
427 
428         Log.i(TAG, String.format("Setting Frame Rate to %.2f with default compatibility",
429                 halfFrameRate));
430         mSurface.setFrameRate(halfFrameRate, Surface.FRAME_RATE_COMPATIBILITY_DEFAULT,
431                 Surface.CHANGE_FRAME_RATE_ONLY_IF_SEAMLESS);
432         waitForRefreshRateChange(halfFrameRate);
433         frameRateObserver.observe(initialRefreshRate, halfFrameRate, "setFrameRate(default)");
434 
435         Log.i(TAG, String.format("Setting Frame Rate to %.2f with fixed source compatibility",
436                 halfFrameRate));
437         mSurface.setFrameRate(halfFrameRate, Surface.FRAME_RATE_COMPATIBILITY_FIXED_SOURCE,
438                 Surface.CHANGE_FRAME_RATE_ONLY_IF_SEAMLESS);
439         waitForRefreshRateChange(halfFrameRate);
440         frameRateObserver.observe(initialRefreshRate, halfFrameRate, "setFrameRate(fixed source)");
441 
442         Log.i(TAG, "Resetting Frame Rate setting");
443         mSurface.setFrameRate(0, Surface.FRAME_RATE_COMPATIBILITY_DEFAULT,
444                 Surface.CHANGE_FRAME_RATE_ONLY_IF_SEAMLESS);
445         waitForRefreshRateChange(initialRefreshRate);
446         frameRateObserver.observe(initialRefreshRate, initialRefreshRate, "Reset");
447     }
448 
449     // The activity being intermittently paused/resumed has been observed to
450     // cause test failures in practice, so we run the test with retry logic.
testFrameRateOverride(FrameRateObserver frameRateObserver, float initialRefreshRate)451     public void testFrameRateOverride(FrameRateObserver frameRateObserver, float initialRefreshRate)
452             throws InterruptedException {
453         synchronized (mLock) {
454             Log.i(TAG, "testFrameRateOverride started");
455             int attempts = 0;
456             boolean testPassed = false;
457             try {
458                 while (!testPassed) {
459                     waitForPreconditions();
460                     try {
461                         testFrameRateOverrideBehavior(frameRateObserver, initialRefreshRate);
462                         testPassed = true;
463                     } catch (PreconditionViolatedException exc) {
464                         // The logic below will retry if we're below max attempts.
465                     } catch (FrameRateTimeoutException exc) {
466                         // Sometimes we get a test timeout failure before we get the
467                         // notification that the activity was paused, and it was the pause that
468                         // caused the timeout failure. Wait for a bit to see if we get notified
469                         // of a precondition violation, and if so, retry the test. Otherwise
470                         // fail.
471                         assertTrue(
472                                 String.format(
473                                         "Timed out waiting for a stable and compatible frame"
474                                                 + " rate. requested=%.2f received=%.2f.",
475                                         exc.appRequestedFrameRate, exc.deviceRefreshRate),
476                                 waitForPreconditionViolation());
477                     }
478 
479                     if (!testPassed) {
480                         Log.i(TAG,
481                                 String.format("Preconditions violated while running the test."
482                                                 + " Have surface? %b. Activity resumed? %b.",
483                                         mSurface != null,
484                                         isResumed()));
485                         attempts++;
486                         assertTrue(String.format(
487                                 "Exceeded %d precondition wait attempts. Giving up.",
488                                 PRECONDITION_WAIT_MAX_ATTEMPTS),
489                                 attempts < PRECONDITION_WAIT_MAX_ATTEMPTS);
490                     }
491                 }
492             } finally {
493                 String passFailMessage = String.format(
494                         "%s", testPassed ? "Passed" : "Failed");
495                 if (testPassed) {
496                     Log.i(TAG, passFailMessage);
497                 } else {
498                     Log.e(TAG, passFailMessage);
499                 }
500             }
501 
502         }
503     }
504 }
505