// Copyright 2014 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. package org.chromium.base; import android.os.Debug; import android.os.Debug.MemoryInfo; import android.util.Log; import org.json.JSONArray; import org.json.JSONException; import org.json.JSONObject; import java.io.File; import java.io.FileNotFoundException; import java.io.FileOutputStream; import java.io.PrintStream; import java.util.LinkedList; import java.util.List; /** * PerfTraceEvent can be used like TraceEvent, but is intended for * performance measurement. By limiting the types of tracing we hope * to minimize impact on measurement. * * All PerfTraceEvent events funnel into TraceEvent. When not doing * performance measurements, they act the same. However, * PerfTraceEvents can be enabled even when TraceEvent is not. * * Unlike TraceEvent, PerfTraceEvent data is sent to the system log, * not to a trace file. * * Performance events need to have very specific names so we find * the right ones. For example, we specify the name exactly in * the @TracePerf annotation. Thus, unlike TraceEvent, we do not * support an implicit trace name based on the callstack. */ public class PerfTraceEvent { private static final int MAX_NAME_LENGTH = 40; private static final String MEMORY_TRACE_NAME_SUFFIX = "_BZR_PSS"; private static File sOutputFile = null; /** The event types understood by the perf trace scripts. */ private enum EventType { START("S"), FINISH("F"), INSTANT("I"); // The string understood by the trace scripts. private final String mTypeStr; EventType(String typeStr) { mTypeStr = typeStr; } @Override public String toString() { return mTypeStr; } } private static boolean sEnabled = false; private static boolean sTrackTiming = true; private static boolean sTrackMemory = false; // A list of performance trace event strings. // Events are stored as a JSON dict much like TraceEvent. // E.g. timestamp is in microseconds. private static JSONArray sPerfTraceStrings; // A filter for performance tracing. Only events that match a // string in the list are saved. Presence of a filter does not // necessarily mean perf tracing is enabled. private static List<String> sFilter; // Nanosecond start time of performance tracing. private static long sBeginNanoTime; /** * Specifies what event names will be tracked. * * @param strings Event names we will record. */ public static synchronized void setFilter(List<String> strings) { sFilter = new LinkedList<String>(strings); } /** * Enable or disable perf tracing. * Disabling of perf tracing will dump trace data to the system log. */ public static synchronized void setEnabled(boolean enabled) { if (sEnabled == enabled) { return; } if (enabled) { sBeginNanoTime = System.nanoTime(); sPerfTraceStrings = new JSONArray(); } else { dumpPerf(); sPerfTraceStrings = null; sFilter = null; } sEnabled = enabled; } /** * Enables memory tracking for all timing perf events tracked. * * <p> * Only works when called in combination with {@link #setEnabled(boolean)}. * * <p> * By enabling this feature, an additional perf event containing the memory usage will be * logged whenever {@link #instant(String)}, {@link #begin(String)}, or {@link #end(String)} * is called. * * @param enabled Whether to enable memory tracking for all perf events. */ public static synchronized void setMemoryTrackingEnabled(boolean enabled) { sTrackMemory = enabled; } /** * Enables timing tracking for all perf events tracked. * * <p> * Only works when called in combination with {@link #setEnabled(boolean)}. * * <p> * If this feature is enabled, whenever {@link #instant(String)}, {@link #begin(String)}, * or {@link #end(String)} is called the time since start of tracking will be logged. * * @param enabled Whether to enable timing tracking for all perf events. */ public static synchronized void setTimingTrackingEnabled(boolean enabled) { sTrackTiming = enabled; } /** * @return True if tracing is enabled, false otherwise. * It is safe to call trace methods without checking if PerfTraceEvent * is enabled. */ public static synchronized boolean enabled() { return sEnabled; } /** * Record an "instant" perf trace event. E.g. "screen update happened". */ public static synchronized void instant(String name) { // Instant doesn't really need/take an event id, but this should be okay. final long eventId = name.hashCode(); TraceEvent.instant(name); if (sEnabled && matchesFilter(name)) { savePerfString(name, eventId, EventType.INSTANT, false); } } /** * Record an "begin" perf trace event. * Begin trace events should have a matching end event. */ public static synchronized void begin(String name) { final long eventId = name.hashCode(); TraceEvent.startAsync(name, eventId); if (sEnabled && matchesFilter(name)) { // Done before calculating the starting perf data to ensure calculating the memory usage // does not influence the timing data. if (sTrackMemory) { savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.START, true); } if (sTrackTiming) { savePerfString(name, eventId, EventType.START, false); } } } /** * Record an "end" perf trace event, to match a begin event. The * time delta between begin and end is usually interesting to * graph code. */ public static synchronized void end(String name) { final long eventId = name.hashCode(); TraceEvent.finishAsync(name, eventId); if (sEnabled && matchesFilter(name)) { if (sTrackTiming) { savePerfString(name, eventId, EventType.FINISH, false); } // Done after calculating the ending perf data to ensure calculating the memory usage // does not influence the timing data. if (sTrackMemory) { savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.FINISH, true); } } } /** * Record an "begin" memory trace event. * Begin trace events should have a matching end event. */ public static synchronized void begin(String name, MemoryInfo memoryInfo) { final long eventId = name.hashCode(); TraceEvent.startAsync(name, eventId); if (sEnabled && matchesFilter(name)) { // Done before calculating the starting perf data to ensure calculating the memory usage // does not influence the timing data. long timestampUs = (System.nanoTime() - sBeginNanoTime) / 1000; savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.START, timestampUs, memoryInfo); if (sTrackTiming) { savePerfString(name, eventId, EventType.START, false); } } } /** * Record an "end" memory trace event, to match a begin event. The * memory usage delta between begin and end is usually interesting to * graph code. */ public static synchronized void end(String name, MemoryInfo memoryInfo) { final long eventId = name.hashCode(); TraceEvent.finishAsync(name, eventId); if (sEnabled && matchesFilter(name)) { if (sTrackTiming) { savePerfString(name, eventId, EventType.FINISH, false); } // Done after calculating the instant perf data to ensure calculating the memory usage // does not influence the timing data. long timestampUs = (System.nanoTime() - sBeginNanoTime) / 1000; savePerfString(makeMemoryTraceNameFromTimingName(name), eventId, EventType.FINISH, timestampUs, memoryInfo); } } /** * Determine if we are interested in this trace event. * @return True if the name matches the allowed filter; else false. */ private static boolean matchesFilter(String name) { return sFilter != null ? sFilter.contains(name) : false; } /** * Save a perf trace event as a JSON dict. The format mirrors a TraceEvent dict. * * @param name The trace data * @param id The id of the event * @param type the type of trace event (I, S, F) * @param includeMemory Whether to include current browser process memory usage in the trace. */ private static void savePerfString(String name, long id, EventType type, boolean includeMemory) { long timestampUs = (System.nanoTime() - sBeginNanoTime) / 1000; MemoryInfo memInfo = null; if (includeMemory) { memInfo = new MemoryInfo(); Debug.getMemoryInfo(memInfo); } savePerfString(name, id, type, timestampUs, memInfo); } /** * Save a perf trace event as a JSON dict. The format mirrors a TraceEvent dict. * * @param name The trace data * @param id The id of the event * @param type the type of trace event (I, S, F) * @param timestampUs The time stamp at which this event was recorded * @param memoryInfo Memory details to be included in this perf string, null if * no memory details are to be included. */ private static void savePerfString(String name, long id, EventType type, long timestampUs, MemoryInfo memoryInfo) { try { JSONObject traceObj = new JSONObject(); traceObj.put("cat", "Java"); traceObj.put("ts", timestampUs); traceObj.put("ph", type); traceObj.put("name", name); traceObj.put("id", id); if (memoryInfo != null) { int pss = memoryInfo.nativePss + memoryInfo.dalvikPss + memoryInfo.otherPss; traceObj.put("mem", pss); } sPerfTraceStrings.put(traceObj); } catch (JSONException e) { throw new RuntimeException(e); } } /** * Generating a trace name for tracking memory based on the timing name passed in. * * @param name The timing name to use as a base for the memory perf name. * @return The memory perf name to use. */ public static String makeMemoryTraceNameFromTimingName(String name) { return makeSafeTraceName(name, MEMORY_TRACE_NAME_SUFFIX); } /** * Builds a name to be used in the perf trace framework. The framework has length requirements * for names, so this ensures the generated name does not exceed the maximum (trimming the * base name if necessary). * * @param baseName The base name to use when generating the name. * @param suffix The required suffix to be appended to the name. * @return A name that is safe for the perf trace framework. */ public static String makeSafeTraceName(String baseName, String suffix) { int suffixLength = suffix.length(); if (baseName.length() + suffixLength > MAX_NAME_LENGTH) { baseName = baseName.substring(0, MAX_NAME_LENGTH - suffixLength); } return baseName + suffix; } /** * Sets a file to dump the results to. If {@code file} is {@code null}, it will be dumped * to STDOUT, otherwise the JSON performance data will be appended to {@code file}. This should * be called before the performance run starts. When {@link #setEnabled(boolean)} is called * with {@code false}, the perf data will be dumped. * * @param file Which file to append the performance data to. If {@code null}, the performance * data will be sent to STDOUT. */ public static synchronized void setOutputFile(File file) { sOutputFile = file; } /** * Dump all performance data we have saved up to the log. * Output as JSON for parsing convenience. */ private static void dumpPerf() { String json = sPerfTraceStrings.toString(); if (sOutputFile == null) { System.out.println(json); } else { try { PrintStream stream = new PrintStream(new FileOutputStream(sOutputFile, true)); try { stream.print(json); } finally { try { stream.close(); } catch (Exception ex) { Log.e("PerfTraceEvent", "Unable to close perf trace output file."); } } } catch (FileNotFoundException ex) { Log.e("PerfTraceEvent", "Unable to dump perf trace data to output file."); } } } }