1// Copyright (c) 2012 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 5package org.chromium.content.common; 6 7import android.os.Debug; 8import android.os.Debug.MemoryInfo; 9import android.util.Log; 10 11import org.json.JSONArray; 12import org.json.JSONException; 13import org.json.JSONObject; 14 15import java.io.File; 16import java.io.FileNotFoundException; 17import java.io.FileOutputStream; 18import java.io.PrintStream; 19import java.util.LinkedList; 20import java.util.List; 21 22/** 23 * PerfTraceEvent can be used like TraceEvent, but is intended for 24 * performance measurement. By limiting the types of tracing we hope 25 * to minimize impact on measurement. 26 * 27 * All PerfTraceEvent events funnel into TraceEvent. When not doing 28 * performance measurements, they act the same. However, 29 * PerfTraceEvents can be enabled even when TraceEvent is not. 30 * 31 * Unlike TraceEvent, PerfTraceEvent data is sent to the system log, 32 * not to a trace file. 33 * 34 * Performance events need to have very specific names so we find 35 * the right ones. For example, we specify the name exactly in 36 * the @TracePerf annotation. Thus, unlike TraceEvent, we do not 37 * support an implicit trace name based on the callstack. 38 */ 39public class PerfTraceEvent { 40 private static final int MAX_NAME_LENGTH = 40; 41 private static final String MEMORY_TRACE_NAME_SUFFIX = "_BZR_PSS"; 42 private static File sOutputFile = null; 43 44 /** The event types understood by the perf trace scripts. */ 45 private enum EventType { 46 START("S"), 47 FINISH("F"), 48 INSTANT("I"); 49 50 // The string understood by the trace scripts. 51 private final String mTypeStr; 52 53 EventType(String typeStr) { 54 mTypeStr = typeStr; 55 } 56 57 @Override 58 public String toString() { 59 return mTypeStr; 60 } 61 } 62 63 private static boolean sEnabled = false; 64 private static boolean sTrackTiming = true; 65 private static boolean sTrackMemory = false; 66 67 // A list of performance trace event strings. 68 // Events are stored as a JSON dict much like TraceEvent. 69 // E.g. timestamp is in microseconds. 70 private static JSONArray sPerfTraceStrings; 71 72 // A filter for performance tracing. Only events that match a 73 // string in the list are saved. Presence of a filter does not 74 // necessarily mean perf tracing is enabled. 75 private static List<String> sFilter; 76 77 // Nanosecond start time of performance tracing. 78 private static long sBeginNanoTime; 79 80 /** 81 * Specifies what event names will be tracked. 82 * 83 * @param strings Event names we will record. 84 */ 85 public static synchronized void setFilter(List<String> strings) { 86 sFilter = new LinkedList<String>(strings); 87 } 88 89 /** 90 * Enable or disable perf tracing. 91 * Disabling of perf tracing will dump trace data to the system log. 92 */ 93 public static synchronized void setEnabled(boolean enabled) { 94 if (sEnabled == enabled) { 95 return; 96 } 97 if (enabled) { 98 sBeginNanoTime = System.nanoTime(); 99 sPerfTraceStrings = new JSONArray(); 100 } else { 101 dumpPerf(); 102 sPerfTraceStrings = null; 103 sFilter = null; 104 } 105 sEnabled = enabled; 106 } 107 108 /** 109 * Enables memory tracking for all timing perf events tracked. 110 * 111 * <p> 112 * Only works when called in combination with {@link #setEnabled(boolean)}. 113 * 114 * <p> 115 * By enabling this feature, an additional perf event containing the memory usage will be 116 * logged whenever {@link #instant(String)}, {@link #begin(String)}, or {@link #end(String)} 117 * is called. 118 * 119 * @param enabled Whether to enable memory tracking for all perf events. 120 */ 121 public static synchronized void setMemoryTrackingEnabled(boolean enabled) { 122 sTrackMemory = enabled; 123 } 124 125 /** 126 * Enables timing tracking for all perf events tracked. 127 * 128 * <p> 129 * Only works when called in combination with {@link #setEnabled(boolean)}. 130 * 131 * <p> 132 * If this feature is enabled, whenever {@link #instant(String)}, {@link #begin(String)}, 133 * or {@link #end(String)} is called the time since start of tracking will be logged. 134 * 135 * @param enabled Whether to enable timing tracking for all perf events. 136 */ 137 public static synchronized void setTimingTrackingEnabled(boolean enabled) { 138 sTrackTiming = enabled; 139 } 140 141 /** 142 * @return True if tracing is enabled, false otherwise. 143 * It is safe to call trace methods without checking if PerfTraceEvent 144 * is enabled. 145 */ 146 public static synchronized boolean enabled() { 147 return sEnabled; 148 } 149 150 /** 151 * Record an "instant" perf trace event. E.g. "screen update happened". 152 */ 153 public static synchronized void instant(String name) { 154 // Instant doesn't really need/take an event id, but this should be okay. 155 final long eventId = name.hashCode(); 156 TraceEvent.instant(name); 157 if (sEnabled && matchesFilter(name)) { 158 savePerfString(name, eventId, EventType.INSTANT, false); 159 } 160 } 161 162 163 /** 164 * Record an "begin" perf trace event. 165 * Begin trace events should have a matching end event. 166 */ 167 public static synchronized void begin(String name) { 168 final long eventId = name.hashCode(); 169 TraceEvent.startAsync(name, eventId); 170 if (sEnabled && matchesFilter(name)) { 171 // Done before calculating the starting perf data to ensure calculating the memory usage 172 // does not influence the timing data. 173 if (sTrackMemory) { 174 savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.START, 175 true); 176 } 177 if (sTrackTiming) { 178 savePerfString(name, eventId, EventType.START, false); 179 } 180 } 181 } 182 183 /** 184 * Record an "end" perf trace event, to match a begin event. The 185 * time delta between begin and end is usually interesting to 186 * graph code. 187 */ 188 public static synchronized void end(String name) { 189 final long eventId = name.hashCode(); 190 TraceEvent.finishAsync(name, eventId); 191 if (sEnabled && matchesFilter(name)) { 192 if (sTrackTiming) { 193 savePerfString(name, eventId, EventType.FINISH, false); 194 } 195 // Done after calculating the ending perf data to ensure calculating the memory usage 196 // does not influence the timing data. 197 if (sTrackMemory) { 198 savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.FINISH, 199 true); 200 } 201 } 202 } 203 204 /** 205 * Record an "begin" memory trace event. 206 * Begin trace events should have a matching end event. 207 */ 208 public static synchronized void begin(String name, MemoryInfo memoryInfo) { 209 final long eventId = name.hashCode(); 210 TraceEvent.startAsync(name, eventId); 211 if (sEnabled && matchesFilter(name)) { 212 // Done before calculating the starting perf data to ensure calculating the memory usage 213 // does not influence the timing data. 214 long timestampUs = (System.nanoTime() - sBeginNanoTime) / 1000; 215 savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.START, 216 timestampUs, memoryInfo); 217 if (sTrackTiming) { 218 savePerfString(name, eventId, EventType.START, false); 219 } 220 } 221 } 222 223 /** 224 * Record an "end" memory trace event, to match a begin event. The 225 * memory usage delta between begin and end is usually interesting to 226 * graph code. 227 */ 228 public static synchronized void end(String name, MemoryInfo memoryInfo) { 229 final long eventId = name.hashCode(); 230 TraceEvent.finishAsync(name, eventId); 231 if (sEnabled && matchesFilter(name)) { 232 if (sTrackTiming) { 233 savePerfString(name, eventId, EventType.FINISH, false); 234 } 235 // Done after calculating the instant perf data to ensure calculating the memory usage 236 // does not influence the timing data. 237 long timestampUs = (System.nanoTime() - sBeginNanoTime) / 1000; 238 savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.FINISH, 239 timestampUs, memoryInfo); 240 } 241 } 242 243 /** 244 * Determine if we are interested in this trace event. 245 * @return True if the name matches the allowed filter; else false. 246 */ 247 private static boolean matchesFilter(String name) { 248 return sFilter != null ? sFilter.contains(name) : false; 249 } 250 251 /** 252 * Save a perf trace event as a JSON dict. The format mirrors a TraceEvent dict. 253 * 254 * @param name The trace data 255 * @param id The id of the event 256 * @param type the type of trace event (I, S, F) 257 * @param includeMemory Whether to include current browser process memory usage in the trace. 258 */ 259 private static void savePerfString(String name, long id, EventType type, 260 boolean includeMemory) { 261 long timestampUs = (System.nanoTime() - sBeginNanoTime) / 1000; 262 MemoryInfo memInfo = null; 263 if (includeMemory) { 264 memInfo = new MemoryInfo(); 265 Debug.getMemoryInfo(memInfo); 266 } 267 savePerfString(name, id, type, timestampUs, memInfo); 268 } 269 270 /** 271 * Save a perf trace event as a JSON dict. The format mirrors a TraceEvent dict. 272 * 273 * @param name The trace data 274 * @param id The id of the event 275 * @param type the type of trace event (I, S, F) 276 * @param timestampUs The time stamp at which this event was recorded 277 * @param memoryInfo Memory details to be included in this perf string, null if 278 * no memory details are to be included. 279 */ 280 private static void savePerfString(String name, long id, EventType type, long timestampUs, 281 MemoryInfo memoryInfo) { 282 try { 283 JSONObject traceObj = new JSONObject(); 284 traceObj.put("cat", "Java"); 285 traceObj.put("ts", timestampUs); 286 traceObj.put("ph", type); 287 traceObj.put("name", name); 288 traceObj.put("id", id); 289 if (memoryInfo != null) { 290 int pss = memoryInfo.nativePss + memoryInfo.dalvikPss + memoryInfo.otherPss; 291 traceObj.put("mem", pss); 292 } 293 sPerfTraceStrings.put(traceObj); 294 } catch (JSONException e) { 295 throw new RuntimeException(e); 296 } 297 } 298 299 /** 300 * Generating a trace name for tracking memory based on the timing name passed in. 301 * 302 * @param name The timing name to use as a base for the memory perf name. 303 * @return The memory perf name to use. 304 */ 305 public static String makeMemoryTraceNameFromTimingName(String name) { 306 return makeSafeTraceName(name, MEMORY_TRACE_NAME_SUFFIX); 307 } 308 309 /** 310 * Builds a name to be used in the perf trace framework. The framework has length requirements 311 * for names, so this ensures the generated name does not exceed the maximum (trimming the 312 * base name if necessary). 313 * 314 * @param baseName The base name to use when generating the name. 315 * @param suffix The required suffix to be appended to the name. 316 * @return A name that is safe for the perf trace framework. 317 */ 318 public static String makeSafeTraceName(String baseName, String suffix) { 319 int suffixLength = suffix.length(); 320 321 if (baseName.length() + suffixLength > MAX_NAME_LENGTH) { 322 baseName = baseName.substring(0, MAX_NAME_LENGTH - suffixLength); 323 } 324 return baseName + suffix; 325 } 326 327 /** 328 * Sets a file to dump the results to. If {@code file} is {@code null}, it will be dumped 329 * to STDOUT, otherwise the JSON performance data will be appended to {@code file}. This should 330 * be called before the performance run starts. When {@link #setEnabled(boolean)} is called 331 * with {@code false}, the perf data will be dumped. 332 * 333 * @param file Which file to append the performance data to. If {@code null}, the performance 334 * data will be sent to STDOUT. 335 */ 336 public static synchronized void setOutputFile(File file) { 337 sOutputFile = file; 338 } 339 340 /** 341 * Dump all performance data we have saved up to the log. 342 * Output as JSON for parsing convenience. 343 */ 344 private static void dumpPerf() { 345 String json = sPerfTraceStrings.toString(); 346 347 if (sOutputFile == null) { 348 System.out.println(json); 349 } else { 350 try { 351 PrintStream stream = new PrintStream(new FileOutputStream(sOutputFile, true)); 352 try { 353 stream.print(json); 354 } finally { 355 try { 356 stream.close(); 357 } catch (Exception ex) { 358 Log.e("PerfTraceEvent", "Unable to close perf trace output file."); 359 } 360 } 361 } catch (FileNotFoundException ex) { 362 Log.e("PerfTraceEvent", "Unable to dump perf trace data to output file."); 363 } 364 } 365 } 366} 367