1 // Copyright 2016 The Chromium Authors. All rights reserved. 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.annotation.SuppressLint; 8 import android.os.Build; 9 import android.os.Process; 10 import android.os.StrictMode; 11 import android.os.SystemClock; 12 13 import org.chromium.base.annotations.JNINamespace; 14 import org.chromium.base.annotations.MainDex; 15 16 import java.io.File; 17 import java.util.ArrayList; 18 import java.util.HashMap; 19 import java.util.List; 20 import java.util.Map; 21 22 /** Support for early tracing, before the native library is loaded. 23 * 24 * This is limited, as: 25 * - Arguments are not supported 26 * - Thread time is not reported 27 * - Two events with the same name cannot be in progress at the same time. 28 * 29 * Events recorded here are buffered in Java until the native library is available. Then it waits 30 * for the completion of pending events, and sends the events to the native side. 31 * 32 * Locking: This class is threadsafe. It is enabled when general tracing is, and then disabled when 33 * tracing is enabled from the native side. Event completions are still processed as long 34 * as some are pending, then early tracing is permanently disabled after dumping the 35 * events. This means that if any early event is still pending when tracing is disabled, 36 * all early events are dropped. 37 */ 38 @JNINamespace("base::android") 39 @MainDex 40 public class EarlyTraceEvent { 41 // Must be kept in sync with the native kAndroidTraceConfigFile. 42 private static final String TRACE_CONFIG_FILENAME = "/data/local/chrome-trace-config.json"; 43 44 /** Single trace event. */ 45 @VisibleForTesting 46 static final class Event { 47 final String mName; 48 final int mThreadId; 49 final long mBeginTimeNanos; 50 final long mBeginThreadTimeMillis; 51 long mEndTimeNanos; 52 long mEndThreadTimeMillis; 53 Event(String name)54 Event(String name) { 55 mName = name; 56 mThreadId = Process.myTid(); 57 mBeginTimeNanos = elapsedRealtimeNanos(); 58 mBeginThreadTimeMillis = SystemClock.currentThreadTimeMillis(); 59 } 60 end()61 void end() { 62 assert mEndTimeNanos == 0; 63 assert mEndThreadTimeMillis == 0; 64 mEndTimeNanos = elapsedRealtimeNanos(); 65 mEndThreadTimeMillis = SystemClock.currentThreadTimeMillis(); 66 } 67 68 @VisibleForTesting 69 @SuppressLint("NewApi") elapsedRealtimeNanos()70 static long elapsedRealtimeNanos() { 71 if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.JELLY_BEAN_MR1) { 72 return SystemClock.elapsedRealtimeNanos(); 73 } else { 74 return SystemClock.elapsedRealtime() * 1000000; 75 } 76 } 77 } 78 79 @VisibleForTesting 80 static final class AsyncEvent { 81 final boolean mIsStart; 82 final String mName; 83 final long mId; 84 final long mTimestampNanos; 85 AsyncEvent(String name, long id, boolean isStart)86 AsyncEvent(String name, long id, boolean isStart) { 87 mName = name; 88 mId = id; 89 mIsStart = isStart; 90 mTimestampNanos = Event.elapsedRealtimeNanos(); 91 } 92 } 93 94 // State transitions are: 95 // - enable(): DISABLED -> ENABLED 96 // - disable(): ENABLED -> FINISHING 97 // - Once there are no pending events: FINISHING -> FINISHED. 98 @VisibleForTesting static final int STATE_DISABLED = 0; 99 @VisibleForTesting static final int STATE_ENABLED = 1; 100 @VisibleForTesting static final int STATE_FINISHING = 2; 101 @VisibleForTesting static final int STATE_FINISHED = 3; 102 103 // Locks the fields below. 104 private static final Object sLock = new Object(); 105 106 @VisibleForTesting static volatile int sState = STATE_DISABLED; 107 // Not final as these object are not likely to be used at all. 108 @VisibleForTesting static List<Event> sCompletedEvents; 109 @VisibleForTesting 110 static Map<String, Event> sPendingEventByKey; 111 @VisibleForTesting static List<AsyncEvent> sAsyncEvents; 112 @VisibleForTesting static List<String> sPendingAsyncEvents; 113 114 /** @see TraceEvent#MaybeEnableEarlyTracing(). 115 */ maybeEnable()116 static void maybeEnable() { 117 ThreadUtils.assertOnUiThread(); 118 boolean shouldEnable = false; 119 // Checking for the trace config filename touches the disk. 120 StrictMode.ThreadPolicy oldPolicy = StrictMode.allowThreadDiskReads(); 121 try { 122 if (CommandLine.getInstance().hasSwitch("trace-startup")) { 123 shouldEnable = true; 124 } else { 125 try { 126 shouldEnable = (new File(TRACE_CONFIG_FILENAME)).exists(); 127 } catch (SecurityException e) { 128 // Access denied, not enabled. 129 } 130 } 131 } finally { 132 StrictMode.setThreadPolicy(oldPolicy); 133 } 134 if (shouldEnable) enable(); 135 } 136 137 @VisibleForTesting enable()138 static void enable() { 139 synchronized (sLock) { 140 if (sState != STATE_DISABLED) return; 141 sCompletedEvents = new ArrayList<Event>(); 142 sPendingEventByKey = new HashMap<String, Event>(); 143 sAsyncEvents = new ArrayList<AsyncEvent>(); 144 sPendingAsyncEvents = new ArrayList<String>(); 145 sState = STATE_ENABLED; 146 } 147 } 148 149 /** 150 * Disables Early tracing. 151 * 152 * Once this is called, no new event will be registered. However, end() calls are still recorded 153 * as long as there are pending events. Once there are none left, pass the events to the native 154 * side. 155 */ disable()156 static void disable() { 157 synchronized (sLock) { 158 if (!enabled()) return; 159 sState = STATE_FINISHING; 160 maybeFinishLocked(); 161 } 162 } 163 164 /** 165 * Returns whether early tracing is currently active. 166 * 167 * Active means that Early Tracing is either enabled or waiting to complete pending events. 168 */ isActive()169 static boolean isActive() { 170 int state = sState; 171 return (state == STATE_ENABLED || state == STATE_FINISHING); 172 } 173 enabled()174 static boolean enabled() { 175 return sState == STATE_ENABLED; 176 } 177 178 /** @see {@link TraceEvent#begin()}. */ begin(String name)179 public static void begin(String name) { 180 // begin() and end() are going to be called once per TraceEvent, this avoids entering a 181 // synchronized block at each and every call. 182 if (!enabled()) return; 183 Event event = new Event(name); 184 Event conflictingEvent; 185 synchronized (sLock) { 186 if (!enabled()) return; 187 conflictingEvent = sPendingEventByKey.put(makeEventKeyForCurrentThread(name), event); 188 } 189 if (conflictingEvent != null) { 190 throw new IllegalArgumentException( 191 "Multiple pending trace events can't have the same name"); 192 } 193 } 194 195 /** @see {@link TraceEvent#end()}. */ end(String name)196 public static void end(String name) { 197 if (!isActive()) return; 198 synchronized (sLock) { 199 if (!isActive()) return; 200 Event event = sPendingEventByKey.remove(makeEventKeyForCurrentThread(name)); 201 if (event == null) return; 202 event.end(); 203 sCompletedEvents.add(event); 204 if (sState == STATE_FINISHING) maybeFinishLocked(); 205 } 206 } 207 208 /** @see {@link TraceEvent#startAsync()}. */ startAsync(String name, long id)209 public static void startAsync(String name, long id) { 210 if (!enabled()) return; 211 AsyncEvent event = new AsyncEvent(name, id, true /*isStart*/); 212 synchronized (sLock) { 213 if (!enabled()) return; 214 sAsyncEvents.add(event); 215 sPendingAsyncEvents.add(name); 216 } 217 } 218 219 /** @see {@link TraceEvent#finishAsync()}. */ finishAsync(String name, long id)220 public static void finishAsync(String name, long id) { 221 if (!isActive()) return; 222 AsyncEvent event = new AsyncEvent(name, id, false /*isStart*/); 223 synchronized (sLock) { 224 if (!isActive()) return; 225 if (!sPendingAsyncEvents.remove(name)) return; 226 sAsyncEvents.add(event); 227 if (sState == STATE_FINISHING) maybeFinishLocked(); 228 } 229 } 230 231 @VisibleForTesting resetForTesting()232 static void resetForTesting() { 233 sState = EarlyTraceEvent.STATE_DISABLED; 234 sCompletedEvents = null; 235 sPendingEventByKey = null; 236 sAsyncEvents = null; 237 sPendingAsyncEvents = null; 238 } 239 maybeFinishLocked()240 private static void maybeFinishLocked() { 241 if (!sCompletedEvents.isEmpty()) { 242 dumpEvents(sCompletedEvents); 243 sCompletedEvents.clear(); 244 } 245 if (!sAsyncEvents.isEmpty()) { 246 dumpAsyncEvents(sAsyncEvents); 247 sAsyncEvents.clear(); 248 } 249 if (sPendingEventByKey.isEmpty() && sPendingAsyncEvents.isEmpty()) { 250 sState = STATE_FINISHED; 251 sPendingEventByKey = null; 252 sCompletedEvents = null; 253 sPendingAsyncEvents = null; 254 sAsyncEvents = null; 255 } 256 } 257 dumpEvents(List<Event> events)258 private static void dumpEvents(List<Event> events) { 259 long offsetNanos = getOffsetNanos(); 260 for (Event e : events) { 261 nativeRecordEarlyEvent(e.mName, e.mBeginTimeNanos + offsetNanos, 262 e.mEndTimeNanos + offsetNanos, e.mThreadId, 263 e.mEndThreadTimeMillis - e.mBeginThreadTimeMillis); 264 } 265 } dumpAsyncEvents(List<AsyncEvent> events)266 private static void dumpAsyncEvents(List<AsyncEvent> events) { 267 long offsetNanos = getOffsetNanos(); 268 for (AsyncEvent e : events) { 269 if (e.mIsStart) { 270 nativeRecordEarlyStartAsyncEvent(e.mName, e.mId, e.mTimestampNanos + offsetNanos); 271 } else { 272 nativeRecordEarlyFinishAsyncEvent(e.mName, e.mId, e.mTimestampNanos + offsetNanos); 273 } 274 } 275 } 276 getOffsetNanos()277 private static long getOffsetNanos() { 278 long nativeNowNanos = TimeUtils.nativeGetTimeTicksNowUs() * 1000; 279 long javaNowNanos = Event.elapsedRealtimeNanos(); 280 return nativeNowNanos - javaNowNanos; 281 } 282 283 /** 284 * Returns a key which consists of |name| and the ID of the current thread. 285 * The key is used with pending events making them thread-specific, thus avoiding 286 * an exception when similarly named events are started from multiple threads. 287 */ 288 @VisibleForTesting makeEventKeyForCurrentThread(String name)289 static String makeEventKeyForCurrentThread(String name) { 290 return name + "@" + Process.myTid(); 291 } 292 nativeRecordEarlyEvent(String name, long beginTimNanos, long endTimeNanos, int threadId, long threadDurationMillis)293 private static native void nativeRecordEarlyEvent(String name, long beginTimNanos, 294 long endTimeNanos, int threadId, long threadDurationMillis); nativeRecordEarlyStartAsyncEvent( String name, long id, long timestamp)295 private static native void nativeRecordEarlyStartAsyncEvent( 296 String name, long id, long timestamp); nativeRecordEarlyFinishAsyncEvent( String name, long id, long timestamp)297 private static native void nativeRecordEarlyFinishAsyncEvent( 298 String name, long id, long timestamp); 299 } 300