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