• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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.internal.jank;
18 
19 import static android.view.SurfaceControl.JankData.DISPLAY_HAL;
20 import static android.view.SurfaceControl.JankData.JANK_APP_DEADLINE_MISSED;
21 import static android.view.SurfaceControl.JankData.JANK_NONE;
22 import static android.view.SurfaceControl.JankData.JANK_SURFACEFLINGER_DEADLINE_MISSED;
23 import static android.view.SurfaceControl.JankData.JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED;
24 import static android.view.SurfaceControl.JankData.PREDICTION_ERROR;
25 import static android.view.SurfaceControl.JankData.SURFACE_FLINGER_SCHEDULING;
26 
27 import static com.android.internal.jank.InteractionJankMonitor.ACTION_SESSION_CANCEL;
28 import static com.android.internal.jank.InteractionJankMonitor.ACTION_SESSION_END;
29 import static com.android.internal.jank.InteractionJankMonitor.EXECUTOR_TASK_TIMEOUT;
30 
31 import android.annotation.IntDef;
32 import android.annotation.NonNull;
33 import android.annotation.Nullable;
34 import android.annotation.UiThread;
35 import android.graphics.HardwareRendererObserver;
36 import android.os.Handler;
37 import android.os.Trace;
38 import android.text.TextUtils;
39 import android.util.Log;
40 import android.util.SparseArray;
41 import android.view.Choreographer;
42 import android.view.FrameMetrics;
43 import android.view.SurfaceControl;
44 import android.view.SurfaceControl.JankData.JankType;
45 import android.view.ThreadedRenderer;
46 import android.view.ViewRootImpl;
47 
48 import com.android.internal.annotations.VisibleForTesting;
49 import com.android.internal.jank.InteractionJankMonitor.Configuration;
50 import com.android.internal.jank.InteractionJankMonitor.Session;
51 import com.android.internal.util.FrameworkStatsLog;
52 
53 import java.lang.annotation.Retention;
54 import java.lang.annotation.RetentionPolicy;
55 import java.util.concurrent.TimeUnit;
56 
57 /**
58  * A class that allows the app to get the frame metrics from HardwareRendererObserver.
59  * @hide
60  */
61 public class FrameTracker extends SurfaceControl.OnJankDataListener
62         implements HardwareRendererObserver.OnFrameMetricsAvailableListener {
63     private static final String TAG = "FrameTracker";
64     private static final boolean DEBUG = false;
65 
66     private static final long INVALID_ID = -1;
67     public static final int NANOS_IN_MILLISECOND = 1_000_000;
68 
69     private static final int MAX_LENGTH_EVENT_DESC = 20;
70 
71     static final int REASON_END_UNKNOWN = -1;
72     static final int REASON_END_NORMAL = 0;
73     static final int REASON_END_SURFACE_DESTROYED = 1;
74     static final int REASON_CANCEL_NORMAL = 16;
75     static final int REASON_CANCEL_NOT_BEGUN = 17;
76     static final int REASON_CANCEL_SAME_VSYNC = 18;
77     static final int REASON_CANCEL_TIMEOUT = 19;
78 
79     /** @hide */
80     @IntDef({
81             REASON_END_UNKNOWN,
82             REASON_END_NORMAL,
83             REASON_END_SURFACE_DESTROYED,
84             REASON_CANCEL_NORMAL,
85             REASON_CANCEL_NOT_BEGUN,
86             REASON_CANCEL_SAME_VSYNC,
87     })
88     @Retention(RetentionPolicy.SOURCE)
89     public @interface Reasons {
90     }
91 
92     @VisibleForTesting
93     public final InteractionJankMonitor mMonitor;
94     private final HardwareRendererObserver mObserver;
95     private final int mTraceThresholdMissedFrames;
96     private final int mTraceThresholdFrameTimeMillis;
97     private final ThreadedRendererWrapper mRendererWrapper;
98     private final FrameMetricsWrapper mMetricsWrapper;
99     private final SparseArray<JankInfo> mJankInfos = new SparseArray<>();
100     private final Session mSession;
101     private final ViewRootWrapper mViewRoot;
102     private final SurfaceControlWrapper mSurfaceControlWrapper;
103     private final ViewRootImpl.SurfaceChangedCallback mSurfaceChangedCallback;
104     private final Handler mHandler;
105     private final ChoreographerWrapper mChoreographer;
106     private final StatsLogWrapper mStatsLog;
107     private final boolean mDeferMonitoring;
108     private final FrameTrackerListener mListener;
109 
110     @VisibleForTesting
111     public final boolean mSurfaceOnly;
112 
113     private SurfaceControl mSurfaceControl;
114     private long mBeginVsyncId = INVALID_ID;
115     private long mEndVsyncId = INVALID_ID;
116     private boolean mMetricsFinalized;
117     private boolean mCancelled = false;
118     private boolean mTracingStarted = false;
119     private Runnable mWaitForFinishTimedOut;
120 
121     private static class JankInfo {
122         long frameVsyncId;
123         long totalDurationNanos;
124         boolean isFirstFrame;
125         boolean hwuiCallbackFired;
126         boolean surfaceControlCallbackFired;
127         @JankType int jankType;
128 
createFromHwuiCallback(long frameVsyncId, long totalDurationNanos, boolean isFirstFrame)129         static JankInfo createFromHwuiCallback(long frameVsyncId, long totalDurationNanos,
130                 boolean isFirstFrame) {
131             return new JankInfo(frameVsyncId, true, false, JANK_NONE, totalDurationNanos,
132                     isFirstFrame);
133         }
134 
createFromSurfaceControlCallback(long frameVsyncId, @JankType int jankType)135         static JankInfo createFromSurfaceControlCallback(long frameVsyncId,
136                 @JankType int jankType) {
137             return new JankInfo(frameVsyncId, false, true, jankType, 0, false /* isFirstFrame */);
138         }
139 
JankInfo(long frameVsyncId, boolean hwuiCallbackFired, boolean surfaceControlCallbackFired, @JankType int jankType, long totalDurationNanos, boolean isFirstFrame)140         private JankInfo(long frameVsyncId, boolean hwuiCallbackFired,
141                 boolean surfaceControlCallbackFired, @JankType int jankType,
142                 long totalDurationNanos, boolean isFirstFrame) {
143             this.frameVsyncId = frameVsyncId;
144             this.hwuiCallbackFired = hwuiCallbackFired;
145             this.surfaceControlCallbackFired = surfaceControlCallbackFired;
146             this.totalDurationNanos = totalDurationNanos;
147             this.jankType = jankType;
148             this.isFirstFrame = isFirstFrame;
149         }
150 
151         @Override
toString()152         public String toString() {
153             StringBuilder str = new StringBuilder();
154             switch (jankType) {
155                 case JANK_NONE:
156                     str.append("JANK_NONE");
157                     break;
158                 case JANK_APP_DEADLINE_MISSED:
159                     str.append("JANK_APP_DEADLINE_MISSED");
160                     break;
161                 case JANK_SURFACEFLINGER_DEADLINE_MISSED:
162                     str.append("JANK_SURFACEFLINGER_DEADLINE_MISSED");
163                     break;
164                 case JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED:
165                     str.append("JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED");
166                     break;
167                 case DISPLAY_HAL:
168                     str.append("DISPLAY_HAL");
169                     break;
170                 case PREDICTION_ERROR:
171                     str.append("PREDICTION_ERROR");
172                     break;
173                 case SURFACE_FLINGER_SCHEDULING:
174                     str.append("SURFACE_FLINGER_SCHEDULING");
175                     break;
176                 default:
177                     str.append("UNKNOWN: ").append(jankType);
178                     break;
179             }
180             str.append(", ").append(frameVsyncId);
181             str.append(", ").append(totalDurationNanos);
182             return str.toString();
183         }
184     }
185 
FrameTracker(@onNull InteractionJankMonitor monitor, @NonNull Session session, @NonNull Handler handler, @Nullable ThreadedRendererWrapper renderer, @Nullable ViewRootWrapper viewRootWrapper, @NonNull SurfaceControlWrapper surfaceControlWrapper, @NonNull ChoreographerWrapper choreographer, @Nullable FrameMetricsWrapper metrics, @NonNull StatsLogWrapper statsLog, int traceThresholdMissedFrames, int traceThresholdFrameTimeMillis, @Nullable FrameTrackerListener listener, @NonNull Configuration config)186     public FrameTracker(@NonNull InteractionJankMonitor monitor, @NonNull Session session,
187             @NonNull Handler handler, @Nullable ThreadedRendererWrapper renderer,
188             @Nullable ViewRootWrapper viewRootWrapper,
189             @NonNull SurfaceControlWrapper surfaceControlWrapper,
190             @NonNull ChoreographerWrapper choreographer,
191             @Nullable FrameMetricsWrapper metrics,
192             @NonNull StatsLogWrapper statsLog,
193             int traceThresholdMissedFrames, int traceThresholdFrameTimeMillis,
194             @Nullable FrameTrackerListener listener, @NonNull Configuration config) {
195         mMonitor = monitor;
196         mSurfaceOnly = config.isSurfaceOnly();
197         mSession = session;
198         mHandler = handler;
199         mChoreographer = choreographer;
200         mSurfaceControlWrapper = surfaceControlWrapper;
201         mStatsLog = statsLog;
202         mDeferMonitoring = config.shouldDeferMonitor();
203 
204         // HWUI instrumentation init.
205         mRendererWrapper = mSurfaceOnly ? null : renderer;
206         mMetricsWrapper = mSurfaceOnly ? null : metrics;
207         mViewRoot = mSurfaceOnly ? null : viewRootWrapper;
208         mObserver = mSurfaceOnly
209                 ? null
210                 : new HardwareRendererObserver(this, mMetricsWrapper.getTiming(),
211                         handler, /* waitForPresentTime= */ false);
212 
213         mTraceThresholdMissedFrames = traceThresholdMissedFrames;
214         mTraceThresholdFrameTimeMillis = traceThresholdFrameTimeMillis;
215         mListener = listener;
216 
217         if (mSurfaceOnly) {
218             mSurfaceControl = config.getSurfaceControl();
219             mSurfaceChangedCallback = null;
220         } else {
221             // HWUI instrumentation init.
222             // If the surface isn't valid yet, wait until it's created.
223             if (mViewRoot.getSurfaceControl().isValid()) {
224                 mSurfaceControl = mViewRoot.getSurfaceControl();
225             }
226 
227             mSurfaceChangedCallback = new ViewRootImpl.SurfaceChangedCallback() {
228                 @Override
229                 public void surfaceCreated(SurfaceControl.Transaction t) {
230                     getHandler().runWithScissors(() -> {
231                         if (mSurfaceControl == null) {
232                             mSurfaceControl = mViewRoot.getSurfaceControl();
233                             if (mBeginVsyncId != INVALID_ID) {
234                                 // Previous begin invocation is not successfully, begin it again.
235                                 begin();
236                             }
237                         }
238                     }, EXECUTOR_TASK_TIMEOUT);
239                 }
240 
241                 @Override
242                 public void surfaceReplaced(SurfaceControl.Transaction t) {
243                 }
244 
245                 @Override
246                 public void surfaceDestroyed() {
247 
248                     // Wait a while to give the system a chance for the remaining
249                     // frames to arrive, then force finish the session.
250                     getHandler().postDelayed(() -> {
251                         if (DEBUG) {
252                             Log.d(TAG, "surfaceDestroyed: " + mSession.getName()
253                                     + ", finalized=" + mMetricsFinalized
254                                     + ", info=" + mJankInfos.size()
255                                     + ", vsync=" + mBeginVsyncId);
256                         }
257                         if (!mMetricsFinalized) {
258                             end(REASON_END_SURFACE_DESTROYED);
259                             finish();
260                         }
261                     }, 50);
262                 }
263             };
264             // This callback has a reference to FrameTracker,
265             // remember to remove it to avoid leakage.
266             mViewRoot.addSurfaceChangedCallback(mSurfaceChangedCallback);
267         }
268     }
269 
270     @VisibleForTesting
getHandler()271     public Handler getHandler() {
272         return mHandler;
273     }
274 
275     /**
276      * Begin a trace session of the CUJ.
277      */
278     @UiThread
begin()279     public void begin() {
280         final long currentVsync = mChoreographer.getVsyncId();
281         // In normal case, we should begin at the next frame,
282         // the id of the next frame is not simply increased by 1,
283         // but we can exclude the current frame at least.
284         if (mBeginVsyncId == INVALID_ID) {
285             mBeginVsyncId = mDeferMonitoring ? currentVsync + 1 : currentVsync;
286         }
287         if (mSurfaceControl != null) {
288             if (DEBUG) {
289                 Log.d(TAG, "begin: " + mSession.getName() + ", begin=" + mBeginVsyncId
290                         + ", defer=" + mDeferMonitoring + ", current=" + currentVsync);
291             }
292             if (mDeferMonitoring && currentVsync < mBeginVsyncId) {
293                 markEvent("FT#deferMonitoring");
294                 // Normal case, we begin the instrument from the very beginning,
295                 // will exclude the first frame.
296                 postTraceStartMarker(this::beginInternal);
297             } else {
298                 // If we don't begin the instrument from the very beginning,
299                 // there is no need to skip the frame where the begin invocation happens.
300                 beginInternal();
301             }
302         } else {
303             if (DEBUG) {
304                 Log.d(TAG, "begin: defer beginning since the surface is not ready for CUJ="
305                         + mSession.getName());
306             }
307         }
308     }
309 
310     /**
311      * Start trace section at appropriate time.
312      */
313     @VisibleForTesting
postTraceStartMarker(Runnable action)314     public void postTraceStartMarker(Runnable action) {
315         mChoreographer.mChoreographer.postCallback(Choreographer.CALLBACK_INPUT, action, null);
316     }
317 
318     @UiThread
beginInternal()319     private void beginInternal() {
320         if (mCancelled || mEndVsyncId != INVALID_ID) {
321             return;
322         }
323         mTracingStarted = true;
324         markEvent("FT#begin");
325         Trace.beginAsyncSection(mSession.getName(), (int) mBeginVsyncId);
326         mSurfaceControlWrapper.addJankStatsListener(this, mSurfaceControl);
327         if (!mSurfaceOnly) {
328             mRendererWrapper.addObserver(mObserver);
329         }
330     }
331 
332     /**
333      * End the trace session of the CUJ.
334      */
335     @UiThread
end(@easons int reason)336     public boolean end(@Reasons int reason) {
337         if (mCancelled || mEndVsyncId != INVALID_ID) return false;
338         mEndVsyncId = mChoreographer.getVsyncId();
339         // Cancel the session if:
340         // 1. The session begins and ends at the same vsync id.
341         // 2. The session never begun.
342         if (mBeginVsyncId == INVALID_ID) {
343             return cancel(REASON_CANCEL_NOT_BEGUN);
344         } else if (mEndVsyncId <= mBeginVsyncId) {
345             return cancel(REASON_CANCEL_SAME_VSYNC);
346         } else {
347             if (DEBUG) {
348                 Log.d(TAG, "end: " + mSession.getName()
349                         + ", end=" + mEndVsyncId + ", reason=" + reason);
350             }
351             markEvent("FT#end#" + reason);
352             Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
353             mSession.setReason(reason);
354 
355             // We don't remove observer here,
356             // will remove it when all the frame metrics in this duration are called back.
357             // See onFrameMetricsAvailable for the logic of removing the observer.
358             // Waiting at most 10 seconds for all callbacks to finish.
359             mWaitForFinishTimedOut = () -> {
360                 Log.e(TAG, "force finish cuj because of time out:" + mSession.getName());
361                 finish();
362             };
363             getHandler().postDelayed(mWaitForFinishTimedOut, TimeUnit.SECONDS.toMillis(10));
364             notifyCujEvent(ACTION_SESSION_END);
365             return true;
366         }
367     }
368 
369     /**
370      * Cancel the trace session of the CUJ.
371      */
372     @UiThread
cancel(@easons int reason)373     public boolean cancel(@Reasons int reason) {
374         final boolean cancelFromEnd =
375                 reason == REASON_CANCEL_NOT_BEGUN || reason == REASON_CANCEL_SAME_VSYNC;
376         if (mCancelled || (mEndVsyncId != INVALID_ID && !cancelFromEnd)) return false;
377         mCancelled = true;
378         markEvent("FT#cancel#" + reason);
379         // We don't need to end the trace section if it has never begun.
380         if (mTracingStarted) {
381             Trace.endAsyncSection(mSession.getName(), (int) mBeginVsyncId);
382         }
383 
384         // Always remove the observers in cancel call to avoid leakage.
385         removeObservers();
386 
387         if (DEBUG) {
388             Log.d(TAG, "cancel: " + mSession.getName() + ", begin=" + mBeginVsyncId
389                     + ", end=" + mEndVsyncId + ", reason=" + reason);
390         }
391 
392         mSession.setReason(reason);
393         // Notify the listener the session has been cancelled.
394         // We don't notify the listeners if the session never begun.
395         notifyCujEvent(ACTION_SESSION_CANCEL);
396         return true;
397     }
398 
399     /**
400      * Mark the FrameTracker events in the trace.
401      *
402      * @param desc The description of the trace event,
403      *            shouldn't exceed {@link #MAX_LENGTH_EVENT_DESC}.
404      */
markEvent(@onNull String desc)405     private void markEvent(@NonNull String desc) {
406         if (desc.length() > MAX_LENGTH_EVENT_DESC) {
407             throw new IllegalArgumentException(TextUtils.formatSimple(
408                     "The length of the trace event description <%s> exceeds %d",
409                     desc, MAX_LENGTH_EVENT_DESC));
410         }
411         Trace.beginSection(TextUtils.formatSimple("%s#%s", mSession.getName(), desc));
412         Trace.endSection();
413     }
414 
notifyCujEvent(String action)415     private void notifyCujEvent(String action) {
416         if (mListener == null) return;
417         mListener.onCujEvents(mSession, action);
418     }
419 
420     @Override
onJankDataAvailable(SurfaceControl.JankData[] jankData)421     public void onJankDataAvailable(SurfaceControl.JankData[] jankData) {
422         postCallback(() -> {
423             if (mCancelled || mMetricsFinalized) {
424                 return;
425             }
426 
427             for (SurfaceControl.JankData jankStat : jankData) {
428                 if (!isInRange(jankStat.frameVsyncId)) {
429                     continue;
430                 }
431                 JankInfo info = findJankInfo(jankStat.frameVsyncId);
432                 if (info != null) {
433                     info.surfaceControlCallbackFired = true;
434                     info.jankType = jankStat.jankType;
435                 } else {
436                     mJankInfos.put((int) jankStat.frameVsyncId,
437                             JankInfo.createFromSurfaceControlCallback(
438                                     jankStat.frameVsyncId, jankStat.jankType));
439                 }
440             }
441             processJankInfos();
442         });
443     }
444 
445     /**
446      * For easier argument capture.
447      */
448     @VisibleForTesting
postCallback(Runnable callback)449     public void postCallback(Runnable callback) {
450         getHandler().post(callback);
451     }
452 
453     @Nullable
findJankInfo(long frameVsyncId)454     private JankInfo findJankInfo(long frameVsyncId) {
455         return mJankInfos.get((int) frameVsyncId);
456     }
457 
isInRange(long vsyncId)458     private boolean isInRange(long vsyncId) {
459         // It's possible that we may miss a callback for the frame with vsyncId == mEndVsyncId.
460         // Because of that, we collect all frames even if they happen after the end so we eventually
461         // have a frame after the end with both callbacks present.
462         return vsyncId >= mBeginVsyncId;
463     }
464 
465     @Override
onFrameMetricsAvailable(int dropCountSinceLastInvocation)466     public void onFrameMetricsAvailable(int dropCountSinceLastInvocation) {
467         postCallback(() -> {
468             if (mCancelled || mMetricsFinalized) {
469                 return;
470             }
471 
472             // Since this callback might come a little bit late after the end() call.
473             // We should keep tracking the begin / end timestamp that we can compare with
474             // vsync timestamp to check if the frame is in the duration of the CUJ.
475             long totalDurationNanos = mMetricsWrapper.getMetric(FrameMetrics.TOTAL_DURATION);
476             boolean isFirstFrame = mMetricsWrapper.getMetric(FrameMetrics.FIRST_DRAW_FRAME) == 1;
477             long frameVsyncId =
478                     mMetricsWrapper.getTiming()[FrameMetrics.Index.FRAME_TIMELINE_VSYNC_ID];
479 
480             if (!isInRange(frameVsyncId)) {
481                 return;
482             }
483             JankInfo info = findJankInfo(frameVsyncId);
484             if (info != null) {
485                 info.hwuiCallbackFired = true;
486                 info.totalDurationNanos = totalDurationNanos;
487                 info.isFirstFrame = isFirstFrame;
488             } else {
489                 mJankInfos.put((int) frameVsyncId, JankInfo.createFromHwuiCallback(
490                         frameVsyncId, totalDurationNanos, isFirstFrame));
491             }
492             processJankInfos();
493         });
494     }
495 
496     @UiThread
hasReceivedCallbacksAfterEnd()497     private boolean hasReceivedCallbacksAfterEnd() {
498         if (mEndVsyncId == INVALID_ID) {
499             return false;
500         }
501         JankInfo last = mJankInfos.size() == 0 ? null : mJankInfos.valueAt(mJankInfos.size() - 1);
502         if (last == null) {
503             return false;
504         }
505         if (last.frameVsyncId < mEndVsyncId) {
506             return false;
507         }
508         for (int i = mJankInfos.size() - 1; i >= 0; i--) {
509             JankInfo info = mJankInfos.valueAt(i);
510             if (info.frameVsyncId >= mEndVsyncId) {
511                 if (callbacksReceived(info)) {
512                     return true;
513                 }
514             }
515         }
516         return false;
517     }
518 
519     @UiThread
processJankInfos()520     private void processJankInfos() {
521         if (mMetricsFinalized) {
522             return;
523         }
524         if (!hasReceivedCallbacksAfterEnd()) {
525             return;
526         }
527         finish();
528     }
529 
callbacksReceived(JankInfo info)530     private boolean callbacksReceived(JankInfo info) {
531         return mSurfaceOnly
532                 ? info.surfaceControlCallbackFired
533                 : info.hwuiCallbackFired && info.surfaceControlCallbackFired;
534     }
535 
536     @UiThread
finish()537     private void finish() {
538         getHandler().removeCallbacks(mWaitForFinishTimedOut);
539         mWaitForFinishTimedOut = null;
540         if (mMetricsFinalized || mCancelled) return;
541         markEvent("FT#finish#" + mJankInfos.size());
542         mMetricsFinalized = true;
543 
544         // The tracing has been ended, remove the observer, see if need to trigger perfetto.
545         removeObservers();
546 
547         int totalFramesCount = 0;
548         long maxFrameTimeNanos = 0;
549         int missedFramesCount = 0;
550         int missedAppFramesCount = 0;
551         int missedSfFramesCount = 0;
552         int maxSuccessiveMissedFramesCount = 0;
553         int successiveMissedFramesCount = 0;
554 
555         for (int i = 0; i < mJankInfos.size(); i++) {
556             JankInfo info = mJankInfos.valueAt(i);
557             final boolean isFirstDrawn = !mSurfaceOnly && info.isFirstFrame;
558             if (isFirstDrawn) {
559                 continue;
560             }
561             if (info.frameVsyncId > mEndVsyncId) {
562                 break;
563             }
564             if (info.surfaceControlCallbackFired) {
565                 totalFramesCount++;
566                 boolean missedFrame = false;
567                 if ((info.jankType & JANK_APP_DEADLINE_MISSED) != 0) {
568                     Log.w(TAG, "Missed App frame:" + info + ", CUJ=" + mSession.getName());
569                     missedAppFramesCount++;
570                     missedFrame = true;
571                 }
572                 if ((info.jankType & DISPLAY_HAL) != 0
573                         || (info.jankType & JANK_SURFACEFLINGER_DEADLINE_MISSED) != 0
574                         || (info.jankType & JANK_SURFACEFLINGER_GPU_DEADLINE_MISSED) != 0
575                         || (info.jankType & SURFACE_FLINGER_SCHEDULING) != 0
576                         || (info.jankType & PREDICTION_ERROR) != 0) {
577                     Log.w(TAG, "Missed SF frame:" + info + ", CUJ=" + mSession.getName());
578                     missedSfFramesCount++;
579                     missedFrame = true;
580                 }
581                 if (missedFrame) {
582                     missedFramesCount++;
583                     successiveMissedFramesCount++;
584                 } else {
585                     maxSuccessiveMissedFramesCount = Math.max(
586                             maxSuccessiveMissedFramesCount, successiveMissedFramesCount);
587                     successiveMissedFramesCount = 0;
588                 }
589                 // TODO (b/174755489): Early latch currently gets fired way too often, so we have
590                 // to ignore it for now.
591                 if (!mSurfaceOnly && !info.hwuiCallbackFired) {
592                     Log.w(TAG, "Missing HWUI jank callback for vsyncId: " + info.frameVsyncId
593                             + ", CUJ=" + mSession.getName());
594                 }
595             }
596             if (!mSurfaceOnly && info.hwuiCallbackFired) {
597                 maxFrameTimeNanos = Math.max(info.totalDurationNanos, maxFrameTimeNanos);
598                 if (!info.surfaceControlCallbackFired) {
599                     Log.w(TAG, "Missing SF jank callback for vsyncId: " + info.frameVsyncId
600                             + ", CUJ=" + mSession.getName());
601                 }
602             }
603         }
604         maxSuccessiveMissedFramesCount = Math.max(
605                 maxSuccessiveMissedFramesCount, successiveMissedFramesCount);
606 
607         // Log the frame stats as counters to make them easily accessible in traces.
608         Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#missedFrames",
609                 missedFramesCount);
610         Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#missedAppFrames",
611                 missedAppFramesCount);
612         Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#missedSfFrames",
613                 missedSfFramesCount);
614         Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#totalFrames",
615                 totalFramesCount);
616         Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#maxFrameTimeMillis",
617                 (int) (maxFrameTimeNanos / NANOS_IN_MILLISECOND));
618         Trace.traceCounter(Trace.TRACE_TAG_APP, mSession.getName() + "#maxSuccessiveMissedFrames",
619                 maxSuccessiveMissedFramesCount);
620 
621         // Trigger perfetto if necessary.
622         if (shouldTriggerPerfetto(missedFramesCount, (int) maxFrameTimeNanos)) {
623             triggerPerfetto();
624         }
625         if (mSession.logToStatsd()) {
626             mStatsLog.write(
627                     FrameworkStatsLog.UI_INTERACTION_FRAME_INFO_REPORTED,
628                     mSession.getStatsdInteractionType(),
629                     totalFramesCount,
630                     missedFramesCount,
631                     maxFrameTimeNanos, /* will be 0 if mSurfaceOnly == true */
632                     missedSfFramesCount,
633                     missedAppFramesCount,
634                     maxSuccessiveMissedFramesCount);
635         }
636         if (DEBUG) {
637             Log.i(TAG, "finish: CUJ=" + mSession.getName()
638                     + " (" + mBeginVsyncId + "," + mEndVsyncId + ")"
639                     + " totalFrames=" + totalFramesCount
640                     + " missedAppFrames=" + missedAppFramesCount
641                     + " missedSfFrames=" + missedSfFramesCount
642                     + " missedFrames=" + missedFramesCount
643                     + " maxFrameTimeMillis=" + maxFrameTimeNanos / NANOS_IN_MILLISECOND
644                     + " maxSuccessiveMissedFramesCount=" + maxSuccessiveMissedFramesCount);
645         }
646     }
647 
shouldTriggerPerfetto(int missedFramesCount, int maxFrameTimeNanos)648     private boolean shouldTriggerPerfetto(int missedFramesCount, int maxFrameTimeNanos) {
649         boolean overMissedFramesThreshold = mTraceThresholdMissedFrames != -1
650                 && missedFramesCount >= mTraceThresholdMissedFrames;
651         boolean overFrameTimeThreshold = !mSurfaceOnly && mTraceThresholdFrameTimeMillis != -1
652                 && maxFrameTimeNanos >= mTraceThresholdFrameTimeMillis * NANOS_IN_MILLISECOND;
653         return overMissedFramesThreshold || overFrameTimeThreshold;
654     }
655 
656     /**
657      * Remove all the registered listeners, observers and callbacks.
658      */
659     @VisibleForTesting
660     @UiThread
removeObservers()661     public void removeObservers() {
662         mSurfaceControlWrapper.removeJankStatsListener(this);
663         if (!mSurfaceOnly) {
664             // HWUI part.
665             mRendererWrapper.removeObserver(mObserver);
666             if (mSurfaceChangedCallback != null) {
667                 mViewRoot.removeSurfaceChangedCallback(mSurfaceChangedCallback);
668             }
669         }
670     }
671 
672     /**
673      * Trigger the prefetto daemon.
674      */
triggerPerfetto()675     public void triggerPerfetto() {
676         mMonitor.trigger(mSession);
677     }
678 
679     /**
680      * A wrapper class that we can spy FrameMetrics (a final class) in unit tests.
681      */
682     public static class FrameMetricsWrapper {
683         private final FrameMetrics mFrameMetrics;
684 
FrameMetricsWrapper()685         public FrameMetricsWrapper() {
686             mFrameMetrics = new FrameMetrics();
687         }
688 
689         /**
690          * Wrapper method.
691          * @return timing data of the metrics
692          */
getTiming()693         public long[] getTiming() {
694             return mFrameMetrics.mTimingData;
695         }
696 
697         /**
698          * Wrapper method.
699          * @param index specific index of the timing data
700          * @return the timing data of the specified index
701          */
getMetric(int index)702         public long getMetric(int index) {
703             return mFrameMetrics.getMetric(index);
704         }
705     }
706 
707     /**
708      * A wrapper class that we can spy ThreadedRenderer (a final class) in unit tests.
709      */
710     public static class ThreadedRendererWrapper {
711         private final ThreadedRenderer mRenderer;
712 
ThreadedRendererWrapper(ThreadedRenderer renderer)713         public ThreadedRendererWrapper(ThreadedRenderer renderer) {
714             mRenderer = renderer;
715         }
716 
717         /**
718          * Wrapper method.
719          * @param observer observer
720          */
addObserver(HardwareRendererObserver observer)721         public void addObserver(HardwareRendererObserver observer) {
722             mRenderer.addObserver(observer);
723         }
724 
725         /**
726          * Wrapper method.
727          * @param observer observer
728          */
removeObserver(HardwareRendererObserver observer)729         public void removeObserver(HardwareRendererObserver observer) {
730             mRenderer.removeObserver(observer);
731         }
732     }
733 
734     public static class ViewRootWrapper {
735         private final ViewRootImpl mViewRoot;
736 
ViewRootWrapper(ViewRootImpl viewRoot)737         public ViewRootWrapper(ViewRootImpl viewRoot) {
738             mViewRoot = viewRoot;
739         }
740 
741         /**
742          * {@link ViewRootImpl#addSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback)}
743          * @param callback {@link ViewRootImpl.SurfaceChangedCallback}
744          */
addSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback callback)745         public void addSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback callback) {
746             mViewRoot.addSurfaceChangedCallback(callback);
747         }
748 
749         /**
750          * {@link ViewRootImpl#removeSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback)}
751          * @param callback {@link ViewRootImpl.SurfaceChangedCallback}
752          */
removeSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback callback)753         public void removeSurfaceChangedCallback(ViewRootImpl.SurfaceChangedCallback callback) {
754             mViewRoot.removeSurfaceChangedCallback(callback);
755         }
756 
getSurfaceControl()757         public SurfaceControl getSurfaceControl() {
758             return mViewRoot.getSurfaceControl();
759         }
760     }
761 
762     public static class SurfaceControlWrapper {
763 
addJankStatsListener(SurfaceControl.OnJankDataListener listener, SurfaceControl surfaceControl)764         public void addJankStatsListener(SurfaceControl.OnJankDataListener listener,
765                 SurfaceControl surfaceControl) {
766             SurfaceControl.addJankDataListener(listener, surfaceControl);
767         }
768 
removeJankStatsListener(SurfaceControl.OnJankDataListener listener)769         public void removeJankStatsListener(SurfaceControl.OnJankDataListener listener) {
770             SurfaceControl.removeJankDataListener(listener);
771         }
772     }
773 
774     public static class ChoreographerWrapper {
775 
776         private final Choreographer mChoreographer;
777 
ChoreographerWrapper(Choreographer choreographer)778         public ChoreographerWrapper(Choreographer choreographer) {
779             mChoreographer = choreographer;
780         }
781 
getVsyncId()782         public long getVsyncId() {
783             return mChoreographer.getVsyncId();
784         }
785     }
786 
787     public static class StatsLogWrapper {
write(int code, int arg1, long arg2, long arg3, long arg4, long arg5, long arg6, long arg7)788         public void write(int code,
789                 int arg1, long arg2, long arg3, long arg4, long arg5, long arg6, long arg7) {
790             FrameworkStatsLog.write(code, arg1, arg2, arg3, arg4, arg5, arg6, arg7);
791         }
792     }
793 
794     /**
795      * A listener that notifies cuj events.
796      */
797     public interface FrameTrackerListener {
798         /**
799          * Notify that the CUJ session was created.
800          *
801          * @param session the CUJ session
802          * @param action the specific action
803          */
onCujEvents(Session session, String action)804         void onCujEvents(Session session, String action);
805     }
806 }
807