1 // Copyright 2014 The Chromium Authors 2 // Use of this source code is governed by a BSD-style license that can be 3 // found in the LICENSE file. 4 5 package org.chromium.base; 6 7 import android.app.Activity; 8 import android.content.res.Resources.NotFoundException; 9 import android.os.Looper; 10 import android.os.MessageQueue; 11 import android.util.Log; 12 import android.util.Printer; 13 import android.view.View; 14 import android.view.ViewGroup; 15 16 import androidx.annotation.VisibleForTesting; 17 18 import org.jni_zero.CalledByNative; 19 import org.jni_zero.JNINamespace; 20 import org.jni_zero.NativeMethods; 21 22 import org.chromium.base.task.PostTask; 23 import org.chromium.base.task.TaskTraits; 24 25 import java.util.ArrayList; 26 27 /** 28 * Java mirror of Chrome trace event API. See base/trace_event/trace_event.h. 29 * 30 * To get scoped trace events, use the "try with resource" construct, for instance: 31 * <pre>{@code 32 * try (TraceEvent e = TraceEvent.scoped("MyTraceEvent")) { 33 * // code. 34 * } 35 * }</pre> 36 * 37 * The event name of the trace events must be a string literal or a |static final String| class 38 * member. Otherwise NoDynamicStringsInTraceEventCheck error will be thrown. 39 * 40 * It is OK to use tracing before the native library has loaded, in a slightly restricted fashion. 41 * @see EarlyTraceEvent for details. 42 */ 43 @JNINamespace("base::android") 44 public class TraceEvent implements AutoCloseable { 45 private static volatile boolean sEnabled; // True when tracing into Chrome's tracing service. 46 private static volatile boolean sUiThreadReady; 47 private static boolean sEventNameFilteringEnabled; 48 49 @VisibleForTesting(otherwise = VisibleForTesting.PRIVATE) 50 static class BasicLooperMonitor implements Printer { 51 @VisibleForTesting(otherwise = VisibleForTesting.PRIVATE) 52 static final String LOOPER_TASK_PREFIX = "Looper.dispatch: "; 53 54 @VisibleForTesting(otherwise = VisibleForTesting.PRIVATE) 55 static final String FILTERED_EVENT_NAME = LOOPER_TASK_PREFIX + "EVENT_NAME_FILTERED"; 56 57 private static final int SHORTEST_LOG_PREFIX_LENGTH = "<<<<< Finished to ".length(); 58 private String mCurrentTarget; 59 60 @Override println(final String line)61 public void println(final String line) { 62 if (line.startsWith(">")) { 63 beginHandling(line); 64 } else { 65 assert line.startsWith("<"); 66 endHandling(line); 67 } 68 } 69 beginHandling(final String line)70 void beginHandling(final String line) { 71 // May return an out-of-date value. this is not an issue as EarlyTraceEvent#begin() 72 // will filter the event in this case. 73 boolean earlyTracingActive = EarlyTraceEvent.enabled(); 74 if (sEnabled || earlyTracingActive) { 75 // Note that we don't need to log ATrace events here because the 76 // framework does that for us (M+). 77 mCurrentTarget = getTraceEventName(line); 78 if (sEnabled) { 79 TraceEventJni.get().beginToplevel(mCurrentTarget); 80 } else { 81 EarlyTraceEvent.begin(mCurrentTarget, /* isToplevel= */ true); 82 } 83 } 84 } 85 endHandling(final String line)86 void endHandling(final String line) { 87 boolean earlyTracingActive = EarlyTraceEvent.enabled(); 88 if ((sEnabled || earlyTracingActive) && mCurrentTarget != null) { 89 if (sEnabled) { 90 TraceEventJni.get().endToplevel(mCurrentTarget); 91 } else { 92 EarlyTraceEvent.end(mCurrentTarget, /* isToplevel= */ true); 93 } 94 } 95 mCurrentTarget = null; 96 } 97 98 @VisibleForTesting(otherwise = VisibleForTesting.PRIVATE) getTraceEventName(String line)99 static String getTraceEventName(String line) { 100 if (sEventNameFilteringEnabled) { 101 return FILTERED_EVENT_NAME; 102 } 103 return LOOPER_TASK_PREFIX + getTarget(line) + "(" + getTargetName(line) + ")"; 104 } 105 106 /** 107 * Android Looper formats |logLine| as 108 * 109 * ">>>>> Dispatching to (TARGET) {HASH_CODE} TARGET_NAME: WHAT" 110 * 111 * and 112 * 113 * "<<<<< Finished to (TARGET) {HASH_CODE} TARGET_NAME". 114 * 115 * This has been the case since at least 2009 (Donut). This function extracts the 116 * TARGET part of the message. 117 */ getTarget(String logLine)118 private static String getTarget(String logLine) { 119 int start = logLine.indexOf('(', SHORTEST_LOG_PREFIX_LENGTH); 120 int end = start == -1 ? -1 : logLine.indexOf(')', start); 121 return end != -1 ? logLine.substring(start + 1, end) : ""; 122 } 123 124 // Extracts the TARGET_NAME part of the log message (see above). getTargetName(String logLine)125 private static String getTargetName(String logLine) { 126 int start = logLine.indexOf('}', SHORTEST_LOG_PREFIX_LENGTH); 127 int end = start == -1 ? -1 : logLine.indexOf(':', start); 128 if (end == -1) { 129 end = logLine.length(); 130 } 131 return start != -1 ? logLine.substring(start + 2, end) : ""; 132 } 133 } 134 135 /** 136 * A class that records, traces and logs statistics about the UI thead's Looper. 137 * The output of this class can be used in a number of interesting ways: 138 * <p> 139 * <ol><li> 140 * When using chrometrace, there will be a near-continuous line of 141 * measurements showing both event dispatches as well as idles; 142 * </li><li> 143 * Logging messages are output for events that run too long on the 144 * event dispatcher, making it easy to identify problematic areas; 145 * </li><li> 146 * Statistics are output whenever there is an idle after a non-trivial 147 * amount of activity, allowing information to be gathered about task 148 * density and execution cadence on the Looper; 149 * </li></ol> 150 * <p> 151 * The class attaches itself as an idle handler to the main Looper, and 152 * monitors the execution of events and idle notifications. Task counters 153 * accumulate between idle notifications and get reset when a new idle 154 * notification is received. 155 */ 156 private static final class IdleTracingLooperMonitor extends BasicLooperMonitor 157 implements MessageQueue.IdleHandler { 158 // Tags for dumping to logcat or TraceEvent 159 private static final String TAG = "TraceEvt_LooperMonitor"; 160 private static final String IDLE_EVENT_NAME = "Looper.queueIdle"; 161 162 // Calculation constants 163 private static final long FRAME_DURATION_MILLIS = 1000L / 60L; // 60 FPS 164 // A reasonable threshold for defining a Looper event as "long running" 165 private static final long MIN_INTERESTING_DURATION_MILLIS = FRAME_DURATION_MILLIS; 166 // A reasonable threshold for a "burst" of tasks on the Looper 167 private static final long MIN_INTERESTING_BURST_DURATION_MILLIS = 168 MIN_INTERESTING_DURATION_MILLIS * 3; 169 170 // Stats tracking 171 private long mLastIdleStartedAt; 172 private long mLastWorkStartedAt; 173 private int mNumTasksSeen; 174 private int mNumIdlesSeen; 175 private int mNumTasksSinceLastIdle; 176 177 // State 178 private boolean mIdleMonitorAttached; 179 180 // Called from within the begin/end methods only. 181 // This method can only execute on the looper thread, because that is 182 // the only thread that is permitted to call Looper.myqueue(). syncIdleMonitoring()183 private final void syncIdleMonitoring() { 184 if (sEnabled && !mIdleMonitorAttached) { 185 // approximate start time for computational purposes 186 mLastIdleStartedAt = TimeUtils.elapsedRealtimeMillis(); 187 Looper.myQueue().addIdleHandler(this); 188 mIdleMonitorAttached = true; 189 Log.v(TAG, "attached idle handler"); 190 } else if (mIdleMonitorAttached && !sEnabled) { 191 Looper.myQueue().removeIdleHandler(this); 192 mIdleMonitorAttached = false; 193 Log.v(TAG, "detached idle handler"); 194 } 195 } 196 197 @Override beginHandling(final String line)198 final void beginHandling(final String line) { 199 // Close-out any prior 'idle' period before starting new task. 200 if (mNumTasksSinceLastIdle == 0) { 201 TraceEvent.end(IDLE_EVENT_NAME); 202 } 203 mLastWorkStartedAt = TimeUtils.elapsedRealtimeMillis(); 204 syncIdleMonitoring(); 205 super.beginHandling(line); 206 } 207 208 @Override endHandling(final String line)209 final void endHandling(final String line) { 210 final long elapsed = TimeUtils.elapsedRealtimeMillis() - mLastWorkStartedAt; 211 if (elapsed > MIN_INTERESTING_DURATION_MILLIS) { 212 traceAndLog(Log.WARN, "observed a task that took " + elapsed + "ms: " + line); 213 } 214 super.endHandling(line); 215 syncIdleMonitoring(); 216 mNumTasksSeen++; 217 mNumTasksSinceLastIdle++; 218 } 219 traceAndLog(int level, String message)220 private static void traceAndLog(int level, String message) { 221 TraceEvent.instant("TraceEvent.LooperMonitor:IdleStats", message); 222 Log.println(level, TAG, message); 223 } 224 225 @Override queueIdle()226 public final boolean queueIdle() { 227 final long now = TimeUtils.elapsedRealtimeMillis(); 228 if (mLastIdleStartedAt == 0) mLastIdleStartedAt = now; 229 final long elapsed = now - mLastIdleStartedAt; 230 mNumIdlesSeen++; 231 TraceEvent.begin(IDLE_EVENT_NAME, mNumTasksSinceLastIdle + " tasks since last idle."); 232 if (elapsed > MIN_INTERESTING_BURST_DURATION_MILLIS) { 233 // Dump stats 234 String statsString = 235 mNumTasksSeen 236 + " tasks and " 237 + mNumIdlesSeen 238 + " idles processed so far, " 239 + mNumTasksSinceLastIdle 240 + " tasks bursted and " 241 + elapsed 242 + "ms elapsed since last idle"; 243 traceAndLog(Log.DEBUG, statsString); 244 } 245 mLastIdleStartedAt = now; 246 mNumTasksSinceLastIdle = 0; 247 return true; // stay installed 248 } 249 } 250 251 // Holder for monitor avoids unnecessary construction on non-debug runs 252 private static final class LooperMonitorHolder { 253 private static final BasicLooperMonitor sInstance = 254 CommandLine.getInstance().hasSwitch(BaseSwitches.ENABLE_IDLE_TRACING) 255 ? new IdleTracingLooperMonitor() 256 : new BasicLooperMonitor(); 257 } 258 259 private final String mName; 260 261 /** Constructor used to support the "try with resource" construct. */ TraceEvent(String name, String arg)262 private TraceEvent(String name, String arg) { 263 mName = name; 264 begin(name, arg); 265 } 266 267 /** Constructor used to support the "try with resource" construct. */ TraceEvent(String name, int arg)268 private TraceEvent(String name, int arg) { 269 mName = name; 270 begin(name, arg); 271 } 272 273 @Override close()274 public void close() { 275 end(mName); 276 } 277 278 /** 279 * Factory used to support the "try with resource" construct. 280 * 281 * Note that if tracing is not enabled, this will not result in allocating an object. 282 * 283 * @param name Trace event name. 284 * @param arg The arguments of the event. 285 * @return a TraceEvent, or null if tracing is not enabled. 286 */ scoped(String name, String arg)287 public static TraceEvent scoped(String name, String arg) { 288 if (!(EarlyTraceEvent.enabled() || enabled())) return null; 289 return new TraceEvent(name, arg); 290 } 291 292 /** 293 * Factory used to support the "try with resource" construct. 294 * 295 * Note that if tracing is not enabled, this will not result in allocating an object. 296 * 297 * @param name Trace event name. 298 * @param arg An integer argument of the event. 299 * @return a TraceEvent, or null if tracing is not enabled. 300 */ scoped(String name, int arg)301 public static TraceEvent scoped(String name, int arg) { 302 if (!(EarlyTraceEvent.enabled() || enabled())) return null; 303 return new TraceEvent(name, arg); 304 } 305 306 /** Similar to {@link #scoped(String, String arg)}, but uses null for |arg|. */ scoped(String name)307 public static TraceEvent scoped(String name) { 308 return scoped(name, null); 309 } 310 311 /** Notification from native that tracing is enabled/disabled. */ 312 @CalledByNative setEnabled(boolean enabled)313 public static void setEnabled(boolean enabled) { 314 if (enabled) EarlyTraceEvent.disable(); 315 // Only disable logging if Chromium enabled it originally, so as to not disrupt logging done 316 // by other applications 317 if (sEnabled != enabled) { 318 sEnabled = enabled; 319 ThreadUtils.getUiThreadLooper() 320 .setMessageLogging(enabled ? LooperMonitorHolder.sInstance : null); 321 } 322 if (sUiThreadReady) { 323 ViewHierarchyDumper.updateEnabledState(); 324 } 325 } 326 327 @CalledByNative setEventNameFilteringEnabled(boolean enabled)328 public static void setEventNameFilteringEnabled(boolean enabled) { 329 sEventNameFilteringEnabled = enabled; 330 } 331 eventNameFilteringEnabled()332 public static boolean eventNameFilteringEnabled() { 333 return sEventNameFilteringEnabled; 334 } 335 336 /** 337 * May enable early tracing depending on the environment. 338 * 339 * @param readCommandLine If true, also check command line flags to see 340 * whether tracing should be turned on. 341 */ maybeEnableEarlyTracing(boolean readCommandLine)342 public static void maybeEnableEarlyTracing(boolean readCommandLine) { 343 // Enable early trace events based on command line flags. This is only 344 // done for Chrome since WebView tracing isn't controlled with command 345 // line flags. 346 if (readCommandLine) { 347 EarlyTraceEvent.maybeEnableInBrowserProcess(); 348 } 349 if (EarlyTraceEvent.enabled()) { 350 ThreadUtils.getUiThreadLooper().setMessageLogging(LooperMonitorHolder.sInstance); 351 } 352 } 353 onNativeTracingReady()354 public static void onNativeTracingReady() { 355 TraceEventJni.get().registerEnabledObserver(); 356 } 357 358 // Called by ThreadUtils. onUiThreadReady()359 static void onUiThreadReady() { 360 sUiThreadReady = true; 361 if (sEnabled) { 362 ViewHierarchyDumper.updateEnabledState(); 363 } 364 } 365 366 /** 367 * @return True if tracing is enabled, false otherwise. 368 * It is safe to call trace methods without checking if TraceEvent 369 * is enabled. 370 */ enabled()371 public static boolean enabled() { 372 return sEnabled; 373 } 374 375 /** 376 * Triggers the 'instant' native trace event with no arguments. 377 * @param name The name of the event. 378 */ instant(String name)379 public static void instant(String name) { 380 if (sEnabled) TraceEventJni.get().instant(name, null); 381 } 382 383 /** 384 * Triggers the 'instant' native trace event. 385 * @param name The name of the event. 386 * @param arg The arguments of the event. 387 */ instant(String name, String arg)388 public static void instant(String name, String arg) { 389 if (sEnabled) TraceEventJni.get().instant(name, arg); 390 } 391 392 /** 393 * Triggers a 'instant' native "AndroidIPC" event. 394 * @param name The name of the IPC. 395 * @param durMs The duration the IPC took in milliseconds. 396 */ instantAndroidIPC(String name, long durMs)397 public static void instantAndroidIPC(String name, long durMs) { 398 if (sEnabled) TraceEventJni.get().instantAndroidIPC(name, durMs); 399 } 400 401 /** 402 * Triggers a 'instant' native "AndroidToolbar" event. 403 * @param blockReason the enum TopToolbarBlockCapture (-1 if not blocked). 404 * @param allowReason the enum TopToolbarAllowCapture (-1 if not allowed). 405 * @param snapshotDiff the enum ToolbarSnapshotDifference (-1 if no diff). 406 */ instantAndroidToolbar(int blockReason, int allowReason, int snapshotDiff)407 public static void instantAndroidToolbar(int blockReason, int allowReason, int snapshotDiff) { 408 if (sEnabled) { 409 TraceEventJni.get().instantAndroidToolbar(blockReason, allowReason, snapshotDiff); 410 } 411 } 412 413 /** 414 * Records a 'WebView.Startup.CreationTime.TotalFactoryInitTime' event with the 415 * 'android_webview.timeline' category starting at `startTimeMs` with the duration of 416 * `durationMs`. 417 */ webViewStartupTotalFactoryInit(long startTimeMs, long durationMs)418 public static void webViewStartupTotalFactoryInit(long startTimeMs, long durationMs) { 419 if (sEnabled) { 420 TraceEventJni.get().webViewStartupTotalFactoryInit(startTimeMs, durationMs); 421 } 422 } 423 424 /** 425 * Records a 'WebView.Startup.CreationTime.Stage1.FactoryInit' event with the 426 * 'android_webview.timeline' category starting at `startTimeMs` with the duration of 427 * `durationMs`. 428 */ webViewStartupStage1(long startTimeMs, long durationMs)429 public static void webViewStartupStage1(long startTimeMs, long durationMs) { 430 if (sEnabled) { 431 TraceEventJni.get().webViewStartupStage1(startTimeMs, durationMs); 432 } 433 } 434 435 /** 436 * Records 'WebView.Startup.CreationTime.Stage2.ProviderInit.Warm' and 437 * 'WebView.Startup.CreationTime.Stage2.ProviderInit.Cold' events depending on the value of 438 * `isColdStartup` with the 'android_webview.timeline' category starting at `startTimeMs` with 439 * the duration of `durationMs`. 440 */ webViewStartupStage2( long startTimeMs, long durationMs, boolean isColdStartup)441 public static void webViewStartupStage2( 442 long startTimeMs, long durationMs, boolean isColdStartup) { 443 if (sEnabled) { 444 TraceEventJni.get().webViewStartupStage2(startTimeMs, durationMs, isColdStartup); 445 } 446 } 447 448 /** Records 'Startup.LaunchCause' event with the 'interactions' category. */ startupLaunchCause(long activityId, int launchCause)449 public static void startupLaunchCause(long activityId, int launchCause) { 450 if (!sEnabled) return; 451 TraceEventJni.get().startupLaunchCause(activityId, launchCause); 452 } 453 454 /** Records 'Startup.TimeToFirstVisibleContent2' event with the 'interactions' category. */ startupTimeToFirstVisibleContent2( long activityId, long startTimeMs, long durationMs)455 public static void startupTimeToFirstVisibleContent2( 456 long activityId, long startTimeMs, long durationMs) { 457 if (!sEnabled) return; 458 TraceEventJni.get().startupTimeToFirstVisibleContent2(activityId, startTimeMs, durationMs); 459 } 460 461 /** 462 * Snapshots the view hierarchy state on the main thread and then finishes emitting a trace 463 * event on the threadpool. 464 */ snapshotViewHierarchy()465 public static void snapshotViewHierarchy() { 466 if (sEnabled && TraceEventJni.get().viewHierarchyDumpEnabled()) { 467 // Emit separate begin and end so we can set the flow id at the end. 468 TraceEvent.begin("instantAndroidViewHierarchy"); 469 470 // If we have no views don't bother to emit any TraceEvents for efficiency. 471 ArrayList<ActivityInfo> views = snapshotViewHierarchyState(); 472 if (views.isEmpty()) { 473 TraceEvent.end("instantAndroidViewHierarchy"); 474 return; 475 } 476 477 // Use the correct snapshot object as a processed scoped flow id. This connects the 478 // mainthread work with the result emitted on the threadpool. We do this because 479 // resolving resource names can trigger exceptions (NotFoundException) which can be 480 // quite slow. 481 long flow = views.hashCode(); 482 483 PostTask.postTask( 484 TaskTraits.BEST_EFFORT, 485 () -> { 486 // Actually output the dump as a trace event on a thread pool. 487 TraceEventJni.get().initViewHierarchyDump(flow, views); 488 }); 489 TraceEvent.end("instantAndroidViewHierarchy", null, flow); 490 } 491 } 492 493 /** 494 * Triggers the 'start' native trace event with no arguments. 495 * @param name The name of the event. 496 * @param id The id of the asynchronous event. 497 */ startAsync(String name, long id)498 public static void startAsync(String name, long id) { 499 EarlyTraceEvent.startAsync(name, id); 500 if (sEnabled) { 501 TraceEventJni.get().startAsync(name, id); 502 } 503 } 504 505 /** 506 * Triggers the 'finish' native trace event with no arguments. 507 * @param name The name of the event. 508 * @param id The id of the asynchronous event. 509 */ finishAsync(String name, long id)510 public static void finishAsync(String name, long id) { 511 EarlyTraceEvent.finishAsync(name, id); 512 if (sEnabled) { 513 TraceEventJni.get().finishAsync(name, id); 514 } 515 } 516 517 /** 518 * Triggers the 'begin' native trace event with no arguments. 519 * @param name The name of the event. 520 */ begin(String name)521 public static void begin(String name) { 522 begin(name, null); 523 } 524 525 /** 526 * Triggers the 'begin' native trace event. 527 * @param name The name of the event. 528 * @param arg The arguments of the event. 529 */ begin(String name, String arg)530 public static void begin(String name, String arg) { 531 EarlyTraceEvent.begin(name, /* isToplevel= */ false); 532 if (sEnabled) { 533 TraceEventJni.get().begin(name, arg); 534 } 535 } 536 537 /** 538 * Triggers the 'begin' native trace event. 539 * @param name The name of the event. 540 * @param arg An integer argument of the event. 541 */ begin(String name, int arg)542 public static void begin(String name, int arg) { 543 EarlyTraceEvent.begin(name, /* isToplevel= */ false); 544 if (sEnabled) { 545 TraceEventJni.get().beginWithIntArg(name, arg); 546 } 547 } 548 549 /** 550 * Triggers the 'end' native trace event with no arguments. 551 * @param name The name of the event. 552 */ end(String name)553 public static void end(String name) { 554 end(name, null); 555 } 556 557 /** 558 * Triggers the 'end' native trace event. 559 * @param name The name of the event. 560 * @param arg The arguments of the event. 561 */ end(String name, String arg)562 public static void end(String name, String arg) { 563 end(name, arg, 0); 564 } 565 566 /** 567 * Triggers the 'end' native trace event. 568 * @param name The name of the event. 569 * @param arg The arguments of the event. 570 * @param flow The flow ID to associate with this event (0 is treated as invalid). 571 */ end(String name, String arg, long flow)572 public static void end(String name, String arg, long flow) { 573 EarlyTraceEvent.end(name, /* isToplevel= */ false); 574 if (sEnabled) { 575 TraceEventJni.get().end(name, arg, flow); 576 } 577 } 578 snapshotViewHierarchyState()579 public static ArrayList<ActivityInfo> snapshotViewHierarchyState() { 580 if (!ApplicationStatus.isInitialized()) { 581 return new ArrayList<ActivityInfo>(); 582 } 583 584 // In local testing we generally just have one activity. 585 ArrayList<ActivityInfo> views = new ArrayList<>(2); 586 for (Activity a : ApplicationStatus.getRunningActivities()) { 587 views.add(new ActivityInfo(a.getClass().getName())); 588 ViewHierarchyDumper.dumpView( 589 views.get(views.size() - 1), 590 /* parentId= */ 0, 591 a.getWindow().getDecorView().getRootView()); 592 } 593 return views; 594 } 595 596 @NativeMethods 597 interface Natives { registerEnabledObserver()598 void registerEnabledObserver(); 599 instant(String name, String arg)600 void instant(String name, String arg); 601 begin(String name, String arg)602 void begin(String name, String arg); 603 beginWithIntArg(String name, int arg)604 void beginWithIntArg(String name, int arg); 605 end(String name, String arg, long flow)606 void end(String name, String arg, long flow); 607 beginToplevel(String target)608 void beginToplevel(String target); 609 endToplevel(String target)610 void endToplevel(String target); 611 startAsync(String name, long id)612 void startAsync(String name, long id); 613 finishAsync(String name, long id)614 void finishAsync(String name, long id); 615 viewHierarchyDumpEnabled()616 boolean viewHierarchyDumpEnabled(); 617 initViewHierarchyDump(long id, Object list)618 void initViewHierarchyDump(long id, Object list); 619 startActivityDump(String name, long dumpProtoPtr)620 long startActivityDump(String name, long dumpProtoPtr); 621 addViewDump( int id, int parentId, boolean isShown, boolean isDirty, String className, String resourceName, long activityProtoPtr)622 void addViewDump( 623 int id, 624 int parentId, 625 boolean isShown, 626 boolean isDirty, 627 String className, 628 String resourceName, 629 long activityProtoPtr); 630 instantAndroidIPC(String name, long durMs)631 void instantAndroidIPC(String name, long durMs); 632 instantAndroidToolbar(int blockReason, int allowReason, int snapshotDiff)633 void instantAndroidToolbar(int blockReason, int allowReason, int snapshotDiff); 634 webViewStartupTotalFactoryInit(long startTimeMs, long durationMs)635 void webViewStartupTotalFactoryInit(long startTimeMs, long durationMs); 636 webViewStartupStage1(long startTimeMs, long durationMs)637 void webViewStartupStage1(long startTimeMs, long durationMs); 638 webViewStartupStage2(long startTimeMs, long durationMs, boolean isColdStartup)639 void webViewStartupStage2(long startTimeMs, long durationMs, boolean isColdStartup); 640 startupLaunchCause(long activityId, int launchCause)641 void startupLaunchCause(long activityId, int launchCause); 642 startupTimeToFirstVisibleContent2(long activityId, long startTimeMs, long durationMs)643 void startupTimeToFirstVisibleContent2(long activityId, long startTimeMs, long durationMs); 644 } 645 646 /** 647 * A method to be called by native code that uses the ViewHierarchyDumper class to emit a trace 648 * event with views of all running activities of the app. 649 */ 650 @CalledByNative dumpViewHierarchy(long dumpProtoPtr, Object list)651 public static void dumpViewHierarchy(long dumpProtoPtr, Object list) { 652 if (!ApplicationStatus.isInitialized()) { 653 return; 654 } 655 656 // Convert the Object back into the ArrayList of ActivityInfo, lifetime of this object is 657 // maintained by the Runnable that we are running in currently. 658 ArrayList<ActivityInfo> activities = (ArrayList<ActivityInfo>) list; 659 660 for (ActivityInfo activity : activities) { 661 long activityProtoPtr = 662 TraceEventJni.get().startActivityDump(activity.mActivityName, dumpProtoPtr); 663 for (ViewInfo view : activity.mViews) { 664 // We need to resolve the resource, take care as NotFoundException can be common and 665 // java exceptions aren't he fastest thing ever. 666 String resource; 667 try { 668 resource = 669 view.mRes != null 670 ? (view.mId == 0 || view.mId == -1 671 ? "__no_id__" 672 : view.mRes.getResourceName(view.mId)) 673 : "__no_resources__"; 674 } catch (NotFoundException e) { 675 resource = "__name_not_found__"; 676 } 677 TraceEventJni.get() 678 .addViewDump( 679 view.mId, 680 view.mParentId, 681 view.mIsShown, 682 view.mIsDirty, 683 view.mClassName, 684 resource, 685 activityProtoPtr); 686 } 687 } 688 } 689 690 /** 691 * This class contains the minimum information to represent a view that the {@link 692 * #ViewHierarchyDumper} needs, so that in {@link #snapshotViewHierarchy} we can output a trace 693 * event off the main thread. 694 */ 695 public static class ViewInfo { ViewInfo( int id, int parentId, boolean isShown, boolean isDirty, String className, android.content.res.Resources res)696 public ViewInfo( 697 int id, 698 int parentId, 699 boolean isShown, 700 boolean isDirty, 701 String className, 702 android.content.res.Resources res) { 703 mId = id; 704 mParentId = parentId; 705 mIsShown = isShown; 706 mIsDirty = isDirty; 707 mClassName = className; 708 mRes = res; 709 } 710 711 private int mId; 712 private int mParentId; 713 private boolean mIsShown; 714 private boolean mIsDirty; 715 private String mClassName; 716 // One can use mRes to resolve mId to a resource name. 717 private android.content.res.Resources mRes; 718 } 719 720 /** 721 * This class contains the minimum information to represent an Activity that the {@link 722 * #ViewHierarchyDumper} needs, so that in {@link #snapshotViewHierarchy} we can output a trace 723 * event off the main thread. 724 */ 725 public static class ActivityInfo { ActivityInfo(String activityName)726 public ActivityInfo(String activityName) { 727 mActivityName = activityName; 728 // Local testing found about 115ish views in the ChromeTabbedActivity. 729 mViews = new ArrayList<ViewInfo>(125); 730 } 731 732 public String mActivityName; 733 public ArrayList<ViewInfo> mViews; 734 } 735 736 /** 737 * A class that periodically dumps the view hierarchy of all running activities of the app to 738 * the trace. Enabled/disabled via the disabled-by-default-android_view_hierarchy trace 739 * category. 740 * 741 * The class registers itself as an idle handler, so that it can run when there are no other 742 * tasks in the queue (but not more often than once a second). When the queue is idle, 743 * it calls the initViewHierarchyDump() native function which in turn calls the 744 * TraceEvent.dumpViewHierarchy() with a pointer to the proto buffer to fill in. The 745 * TraceEvent.dumpViewHierarchy() traverses all activities and dumps view hierarchy for every 746 * activity. Altogether, the call sequence is as follows: 747 * ViewHierarchyDumper.queueIdle() 748 * -> JNI#initViewHierarchyDump() 749 * -> TraceEvent.dumpViewHierarchy() 750 * -> JNI#startActivityDump() 751 * -> ViewHierarchyDumper.dumpView() 752 * -> JNI#addViewDump() 753 */ 754 private static final class ViewHierarchyDumper implements MessageQueue.IdleHandler { 755 private static final String EVENT_NAME = "TraceEvent.ViewHierarchyDumper"; 756 private static final long MIN_VIEW_DUMP_INTERVAL_MILLIS = 1000L; 757 private static boolean sEnabled; 758 private static ViewHierarchyDumper sInstance; 759 private long mLastDumpTs; 760 761 @Override queueIdle()762 public final boolean queueIdle() { 763 final long now = TimeUtils.elapsedRealtimeMillis(); 764 if (mLastDumpTs == 0 || (now - mLastDumpTs) > MIN_VIEW_DUMP_INTERVAL_MILLIS) { 765 mLastDumpTs = now; 766 snapshotViewHierarchy(); 767 } 768 769 // Returning true to keep IdleHandler alive. 770 return true; 771 } 772 updateEnabledState()773 public static void updateEnabledState() { 774 PostTask.runOrPostTask( 775 TaskTraits.UI_DEFAULT, 776 () -> { 777 if (TraceEventJni.get().viewHierarchyDumpEnabled()) { 778 if (sInstance == null) { 779 sInstance = new ViewHierarchyDumper(); 780 } 781 enable(); 782 } else { 783 if (sInstance != null) { 784 disable(); 785 } 786 } 787 }); 788 } 789 dumpView(ActivityInfo collection, int parentId, View v)790 private static void dumpView(ActivityInfo collection, int parentId, View v) { 791 ThreadUtils.assertOnUiThread(); 792 int id = v.getId(); 793 collection.mViews.add( 794 new ViewInfo( 795 id, 796 parentId, 797 v.isShown(), 798 v.isDirty(), 799 v.getClass().getSimpleName(), 800 v.getResources())); 801 802 if (v instanceof ViewGroup) { 803 ViewGroup vg = (ViewGroup) v; 804 for (int i = 0; i < vg.getChildCount(); i++) { 805 dumpView(collection, id, vg.getChildAt(i)); 806 } 807 } 808 } 809 enable()810 private static void enable() { 811 ThreadUtils.assertOnUiThread(); 812 if (!sEnabled) { 813 Looper.myQueue().addIdleHandler(sInstance); 814 sEnabled = true; 815 } 816 } 817 disable()818 private static void disable() { 819 ThreadUtils.assertOnUiThread(); 820 if (sEnabled) { 821 Looper.myQueue().removeIdleHandler(sInstance); 822 sEnabled = false; 823 } 824 } 825 } 826 } 827