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