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