Index: dart/compiler/java/com/google/dart/compiler/metrics/Tracer.java |
diff --git a/dart/compiler/java/com/google/dart/compiler/metrics/Tracer.java b/dart/compiler/java/com/google/dart/compiler/metrics/Tracer.java |
deleted file mode 100644 |
index 9103026b0b7e0711206c9c54035473d0bd1c69de..0000000000000000000000000000000000000000 |
--- a/dart/compiler/java/com/google/dart/compiler/metrics/Tracer.java |
+++ /dev/null |
@@ -1,959 +0,0 @@ |
-// Copyright (c) 2011, the Dart project authors. Please see the AUTHORS file |
-// for details. All rights reserved. Use of this source code is governed by a |
-// BSD-style license that can be found in the LICENSE file. |
- |
-package com.google.dart.compiler.metrics; |
- |
-import org.json.JSONException; |
-import org.json.JSONObject; |
-import org.json.JSONArray; |
- |
-import java.io.BufferedWriter; |
-import java.io.FileWriter; |
-import java.io.IOException; |
-import java.io.Writer; |
-import java.lang.management.GarbageCollectorMXBean; |
-import java.lang.management.ManagementFactory; |
-import java.lang.management.OperatingSystemMXBean; |
-import java.lang.management.ThreadMXBean; |
-import java.lang.reflect.Method; |
-import java.util.ArrayList; |
-import java.util.Arrays; |
-import java.util.List; |
-import java.util.Map; |
-import java.util.Stack; |
-import java.util.concurrent.BlockingQueue; |
-import java.util.concurrent.ConcurrentHashMap; |
-import java.util.concurrent.CountDownLatch; |
-import java.util.concurrent.LinkedBlockingQueue; |
-import java.util.concurrent.TimeUnit; |
- |
-/** |
- * Logs performance metrics for internal development purposes. The output is |
- * formatted so it can be opened directly in the SpeedTracer Chrome extension. |
- * This class formats events using SpeedTracer's custom event feature. The html |
- * file output can be viewed by using Chrome to open the file on a Chrome |
- * browser that has the SpeedTracer extension installed. |
- * |
- * <p> |
- * Enable logging by setting the system property {@code dart.speedtracerlog} to |
- * the output file path. |
- * </p> |
- * |
- * NB: This class has been copied almost verbatim from the gwt source tree |
- */ |
-public final class Tracer { |
- |
- // Log file name (logging is enabled if this is non-null) |
- private static final String logFile = System.getProperty("dart.speedtracerlog"); |
- |
- // Allow a system property to override the default output format |
- private static final String defaultFormatString = System.getProperty("dart.speedtracerformat"); |
- |
- // Use cumulative multi-threaded process cpu time instead of wall time |
- private static final boolean logProcessCpuTime = |
- getBooleanProperty("dart.speedtracer.logProcessCpuTime"); |
- |
- // Use per thread cpu time instead of wall time. If logProcessCpuTime is set, |
- // then this can remain false - we only need one or the other. |
- private static final boolean logThreadCpuTime = |
- getBooleanProperty("dart.speedtracer.logThreadCpuTime"); |
- |
- // Turn on logging summarizing gc time during an event |
- private static final boolean logGcTime = getBooleanProperty("dart.speedtracer.logGcTime"); |
- |
- // Turn on logging estimating overhead used for speedtracer logging. |
- private static final boolean logOverheadTime = |
- getBooleanProperty("dart.speedtracer.logOverheadTime"); |
- |
- static { |
- // verify configuration |
- if (logProcessCpuTime && logThreadCpuTime) { |
- throw new RuntimeException("System properties are misconfigured: " |
- + "Specify one or the other of 'dart.speedtracer.logProcessCpuTime' " |
- + "or 'dart.speedtracer.logThreadCpuTime', not both."); |
- } |
- } |
- |
- /** |
- * Represents a node in a tree of SpeedTracer events. |
- */ |
- public class TraceEvent { |
- protected final EventType type; |
- List<TraceEvent> children; |
- List<String> data; |
- |
- long elapsedDurationNanos; |
- long elapsedStartTimeNanos; |
- |
- long processCpuDurationNanos; |
- long processCpuStartTimeNanos; |
- |
- long threadCpuDurationNanos; |
- long threadCpuStartTimeNanos; |
- |
- TraceEvent() { |
- if (enabled) { |
- threadCpuTimeKeeper.resetTimeBase(); |
- recordStartTime(); |
- this.data = new ArrayList<String>(); |
- this.children = new ArrayList<TraceEvent>(); |
- } else { |
- this.processCpuStartTimeNanos = 0L; |
- this.threadCpuStartTimeNanos = 0L; |
- this.elapsedStartTimeNanos = 0L; |
- this.data = null; |
- this.children = null; |
- } |
- this.type = null; |
- } |
- |
- TraceEvent(TraceEvent parent, EventType type, String... data) { |
- |
- if (parent != null) { |
- parent.children.add(this); |
- } |
- this.type = type; |
- assert (data.length % 2 == 0); |
- recordStartTime(); |
- this.data = new ArrayList<String>(); |
- this.data.addAll(Arrays.asList(data)); |
- this.children = new ArrayList<TraceEvent>(); |
- } |
- |
- /** |
- * @param data key/value pairs to add to JSON object. |
- */ |
- public void addData(String... data) { |
- if (data != null) { |
- assert (data.length % 2 == 0); |
- this.data.addAll(Arrays.asList(data)); |
- } |
- } |
- |
- /** |
- * Signals the end of the current event. |
- */ |
- public void end(String... data) { |
- endImpl(this, data); |
- } |
- |
- /** |
- * Returns the event duration, in nanoseconds, for the log file. Depending |
- * on system properties, this will measured in elapsed time, process CPU |
- * time, or thread CPU time. |
- */ |
- public long getDurationNanos() { |
- return logProcessCpuTime ? processCpuDurationNanos : (logThreadCpuTime |
- ? threadCpuDurationNanos : elapsedDurationNanos); |
- } |
- |
- public long getElapsedDurationNanos() { |
- return this.elapsedDurationNanos; |
- } |
- |
- public long getElapsedStartTimeNanos() { |
- return this.elapsedStartTimeNanos; |
- } |
- |
- /** |
- * Returns the event start time, normalized in nanoseconds, for the log |
- * file. Depending on system properties, this will be normalized based on |
- * elapsed time, process CPU time, or thread CPU time. |
- */ |
- public long getStartTimeNanos() { |
- return logProcessCpuTime ? processCpuStartTimeNanos : (logThreadCpuTime |
- ? threadCpuStartTimeNanos : elapsedStartTimeNanos); |
- } |
- |
- public EventType getType() { |
- return type; |
- } |
- |
- @Override |
- public String toString() { |
- return type.getName(); |
- } |
- |
- /** |
- * Extends the durations of the current event by the durations of the |
- * specified event. |
- */ |
- void extendDuration(TraceEvent refEvent) { |
- elapsedDurationNanos += refEvent.elapsedDurationNanos; |
- processCpuDurationNanos += refEvent.processCpuDurationNanos; |
- threadCpuDurationNanos += refEvent.threadCpuDurationNanos; |
- } |
- |
- /** |
- * Sets the start time of this event to start immediately after the |
- * specified event ends. |
- */ |
- void setStartsAfter(TraceEvent refEvent) { |
- elapsedStartTimeNanos = refEvent.elapsedStartTimeNanos + refEvent.elapsedDurationNanos; |
- processCpuStartTimeNanos = |
- refEvent.processCpuStartTimeNanos + refEvent.processCpuDurationNanos; |
- threadCpuStartTimeNanos = refEvent.threadCpuStartTimeNanos + refEvent.threadCpuDurationNanos; |
- } |
- |
- JSONObject toJson() throws JSONException { |
- JSONObject json = new JSONObject(); |
- json.put("type", -2); |
- json.put("typeName", type.getName()); |
- json.put("color", type.getColor()); |
- double startMs = convertToMilliseconds(getStartTimeNanos()); |
- json.put("time", startMs); |
- double durationMs = convertToMilliseconds(getDurationNanos()); |
- json.put("duration", durationMs); |
- |
- JSONObject jsonData = new JSONObject(); |
- for (int i = 0; i < data.size(); i += 2) { |
- jsonData.put(data.get(i), data.get(i + 1)); |
- } |
- json.put("data", jsonData); |
- |
- JSONArray jsonChildren = new JSONArray(); |
- for (TraceEvent child : children) { |
- jsonChildren.put(child.toJson()); |
- } |
- json.put("children", jsonChildren); |
- |
- return json; |
- } |
- |
- /** |
- * Records the duration of this event based on the current time and the |
- * event's recorded start time. |
- */ |
- void updateDuration() { |
- long elapsedEndTimeNanos = elapsedTimeKeeper.normalizedTimeNanos(); |
- assert (elapsedEndTimeNanos >= elapsedStartTimeNanos); |
- elapsedDurationNanos = elapsedEndTimeNanos - elapsedStartTimeNanos; |
- |
- // don't bother making expensive time keeping method calls unless |
- // necessary |
- if (logProcessCpuTime) { |
- long processCpuEndTimeNanos = processCpuTimeKeeper.normalizedTimeNanos(); |
- assert (processCpuEndTimeNanos >= processCpuStartTimeNanos); |
- processCpuDurationNanos = processCpuEndTimeNanos - processCpuStartTimeNanos; |
- } else if (logThreadCpuTime) { |
- long threadCpuEndTimeNanos = threadCpuTimeKeeper.normalizedTimeNanos(); |
- assert (threadCpuEndTimeNanos >= threadCpuStartTimeNanos); |
- threadCpuDurationNanos = threadCpuEndTimeNanos - threadCpuStartTimeNanos; |
- } |
- } |
- |
- /** |
- * Marks the start time for this event. Three different time measurements |
- * are used: |
- * <ol> |
- * <li>Elapsed (wall-clock) time</li> |
- * <li>Process CPU time</li> |
- * <li>Thread CPU time</li> |
- * </ol> |
- */ |
- private void recordStartTime() { |
- elapsedStartTimeNanos = elapsedTimeKeeper.normalizedTimeNanos(); |
- |
- // don't bother making expensive time keeping method calls unless |
- // necessary |
- if (logProcessCpuTime) { |
- processCpuStartTimeNanos = processCpuTimeKeeper.normalizedTimeNanos(); |
- } else if (logThreadCpuTime) { |
- threadCpuStartTimeNanos = threadCpuTimeKeeper.normalizedTimeNanos(); |
- } |
- } |
- } |
- |
- /** |
- * Enumerated types for logging events implement this interface. |
- */ |
- public interface EventType { |
- String getColor(); |
- |
- String getName(); |
- } |
- |
- static enum Format { |
- /** |
- * Standard SpeedTracer log that includes JSON wrapped in HTML that will |
- * launch a SpeedTracer monitor session. |
- */ |
- HTML, |
- |
- /** |
- * Only the JSON data without any HTML wrappers. |
- */ |
- RAW |
- } |
- |
- /** |
- * A dummy implementation to do nothing if logging has not been turned on. |
- */ |
- private class DummyEvent extends TraceEvent { |
- @Override |
- public void addData(String... data) { |
- // do nothing |
- } |
- |
- @Override |
- public void end(String... data) { |
- // do nothing |
- } |
- |
- @Override |
- public String toString() { |
- return "Dummy"; |
- } |
- } |
- |
- /** |
- * Provides functionality specific to garbage collection events. |
- */ |
- private class GcEvent extends TraceEvent { |
- private TraceEvent refEvent; |
- |
- /** |
- * Constructs an event that represents garbage collection metrics. |
- * |
- * @param refEvent the event during which the garbage collections took place |
- * @param gcType the garbage collector type |
- * @param collectionCount the total number of collections for this garbage |
- * collector type |
- * @param durationNanos the total elapsed time spent in garbage collection |
- * during the span of {@code refEvent} |
- */ |
- GcEvent(TraceEvent refEvent, String gcType, long collectionCount, long durationNanos) { |
- super(null, SpeedTracerEventType.GC, "Collector Type", gcType, "Cumulative Collection Count", |
- Long.toString(collectionCount)); |
- |
- this.refEvent = refEvent; |
- // GarbageCollectorMXBean can only provide elapsed time, so that's all we |
- // record |
- this.elapsedDurationNanos = durationNanos; |
- } |
- |
- /** |
- * Returns elapsed duration since that is the only duration we can measure |
- * for garbage collection events. |
- */ |
- @Override |
- public long getDurationNanos() { |
- return getElapsedDurationNanos(); |
- } |
- |
- /** |
- * Returns a start time so that this event ends with its {@code refEvent}. |
- */ |
- @Override |
- public long getElapsedStartTimeNanos() { |
- return refEvent.getElapsedStartTimeNanos() + refEvent.getElapsedDurationNanos() |
- - getElapsedDurationNanos(); |
- } |
- |
- /** |
- * Returns a start time so that this event ends with its {@code refEvent}. |
- */ |
- @Override |
- public long getStartTimeNanos() { |
- return refEvent.getStartTimeNanos() + refEvent.getDurationNanos() - getDurationNanos(); |
- } |
- } |
- |
- /** |
- * Time keeper which uses wall time. |
- */ |
- private class ElapsedNormalizedTimeKeeper { |
- |
- private final long zeroTimeMillis; |
- |
- public ElapsedNormalizedTimeKeeper() { |
- zeroTimeMillis = System.currentTimeMillis(); |
- } |
- |
- public long normalizedTimeNanos() { |
- return (System.currentTimeMillis() - zeroTimeMillis) * 1000000L; |
- } |
- |
- public long zeroTimeMillis() { |
- return zeroTimeMillis; |
- } |
- } |
- |
- /** |
- * Time keeper which uses process cpu time. This can be greater than wall |
- * time, since it is cumulative over the multiple threads of a process. |
- */ |
- private class ProcessNormalizedTimeKeeper { |
- private final OperatingSystemMXBean osMXBean; |
- private final Method getProcessCpuTimeMethod; |
- private final long zeroTimeNanos; |
- private final long zeroTimeMillis; |
- |
- public ProcessNormalizedTimeKeeper() { |
- try { |
- osMXBean = ManagementFactory.getOperatingSystemMXBean(); |
- /* |
- * Find this method by reflection, since it's part of the Sun |
- * implementation for OperatingSystemMXBean, and we can't always assume |
- * that com.sun.management.OperatingSystemMXBean will be available. |
- */ |
- getProcessCpuTimeMethod = osMXBean.getClass().getMethod("getProcessCpuTime"); |
- getProcessCpuTimeMethod.setAccessible(true); |
- zeroTimeNanos = (Long) getProcessCpuTimeMethod.invoke(osMXBean); |
- zeroTimeMillis = (long) convertToMilliseconds(zeroTimeNanos); |
- } catch (Exception ex) { |
- throw new RuntimeException(ex); |
- } |
- } |
- |
- public long normalizedTimeNanos() { |
- try { |
- return (Long) getProcessCpuTimeMethod.invoke(osMXBean) - zeroTimeNanos; |
- } catch (Exception ex) { |
- throw new RuntimeException(ex); |
- } |
- } |
- |
- public long zeroTimeMillis() { |
- return zeroTimeMillis; |
- } |
- } |
- |
- /** |
- * Time keeper which uses per thread cpu time. It is assumed that individual |
- * events logged will be single threaded, and that top-level events will call |
- * {@link #resetTimeBase()} prior to logging time. The resettable time base is |
- * needed since each individual thread starts its timing at 0, regardless of |
- * when the thread is created. So we reset the time base at the beginning of |
- * an event, so that we can generate a chronologically representative output, |
- * although the relation to wall time is actually compressed within a logged |
- * event (thread cpu time does not include wait time, etc.). |
- */ |
- private class ThreadNormalizedTimeKeeper { |
- |
- private final ThreadMXBean threadMXBean; |
- private final ThreadLocal<Long> resettableTimeBase = new ThreadLocal<Long>(); |
- private final long zeroTimeNanos; |
- private final long zeroTimeMillis; |
- |
- public ThreadNormalizedTimeKeeper() { |
- threadMXBean = ManagementFactory.getThreadMXBean(); |
- if (!threadMXBean.isCurrentThreadCpuTimeSupported()) { |
- throw new RuntimeException("Current thread cpu time not supported"); |
- } |
- zeroTimeNanos = System.nanoTime(); |
- zeroTimeMillis = (long) convertToMilliseconds(zeroTimeNanos); |
- } |
- |
- public long normalizedTimeNanos() { |
- return threadMXBean.getCurrentThreadCpuTime() + resettableTimeBase.get(); |
- } |
- |
- public void resetTimeBase() { |
- /* |
- * Since all threads start individually at time 0L, we use this to offset |
- * each event's time so we can generate chronological output. |
- */ |
- resettableTimeBase.set(System.nanoTime() - zeroTimeNanos |
- - threadMXBean.getCurrentThreadCpuTime()); |
- } |
- |
- public long zeroTimeMillis() { |
- return zeroTimeMillis; |
- } |
- } |
- |
- /** |
- * Initializes the singleton on demand. |
- */ |
- private static class LazySpeedTracerLoggerHolder { |
- public static Tracer singleton = new Tracer(); |
- } |
- |
- /** |
- * Thread that converts log requests to JSON in the background. |
- */ |
- private class LogWriterThread extends Thread { |
- private static final int FLUSH_TIMER_MSECS = 10000; |
- private final String fileName; |
- private final BlockingQueue<TraceEvent> threadEventQueue; |
- private final Writer writer; |
- |
- public LogWriterThread(Writer writer, String fileName, final BlockingQueue<TraceEvent> eventQueue) { |
- super(); |
- this.writer = writer; |
- this.fileName = fileName; |
- this.threadEventQueue = eventQueue; |
- } |
- |
- @Override |
- public void run() { |
- long nextFlush = System.currentTimeMillis() + FLUSH_TIMER_MSECS; |
- try { |
- while (true) { |
- TraceEvent event = |
- threadEventQueue.poll(nextFlush - System.currentTimeMillis(), TimeUnit.MILLISECONDS); |
- if (event == null) { |
- // ignore. |
- } else if (event == shutDownSentinel) { |
- break; |
- } else if (event == flushSentinel) { |
- writer.flush(); |
- flushLatch.countDown(); |
- } else { |
- JSONObject json = event.toJson(); |
- json.write(writer); |
- writer.write('\n'); |
- } |
- if (System.currentTimeMillis() >= nextFlush) { |
- writer.flush(); |
- nextFlush = System.currentTimeMillis() + FLUSH_TIMER_MSECS; |
- } |
- } |
- // All queued events have been written. |
- if (outputFormat.equals(Format.HTML)) { |
- writer.write("</div></body></html>\n"); |
- } |
- writer.close(); |
- } catch (InterruptedException ignored) { |
- } catch (IOException e) { |
- System.err.println("Unable to write to dart.speedtracerlog '" |
- + (fileName == null ? "" : fileName) + "'"); |
- e.printStackTrace(); |
- } catch (JSONException e) { |
- // TODO(jat): Auto-generated catch block |
- e.printStackTrace(); |
- } finally { |
- shutDownLatch.countDown(); |
- } |
- } |
- } |
- |
- /** |
- * Records a LOG_MESSAGE type of SpeedTracer event. |
- */ |
- private class MarkTimelineEvent extends TraceEvent { |
- public MarkTimelineEvent(TraceEvent parent) { |
- super(); |
- if (parent != null) { |
- parent.children.add(this); |
- } |
- } |
- |
- @Override |
- JSONObject toJson() throws JSONException { |
- JSONObject json = new JSONObject(); |
- json.put("type", 11); |
- double startMs = convertToMilliseconds(getStartTimeNanos()); |
- json.put("time", startMs); |
- json.put("duration", 0.0); |
- JSONObject jsonData = new JSONObject(); |
- for (int i = 0; i < data.size(); i += 2) { |
- jsonData.put(data.get(i), data.get(i + 1)); |
- } |
- json.put("data", jsonData); |
- return json; |
- } |
- } |
- |
- /** |
- * Annotate the current event on the top of the stack with more information. |
- * The method expects key, value pairs, so there must be an even number of |
- * parameters. |
- * |
- * @param data JSON property, value pair to add to current event. |
- */ |
- public static void addData(String... data) { |
- Tracer.get().addDataImpl(data); |
- } |
- |
- /** |
- * Create a new global instance. Force the zero time to be recorded and the |
- * log to be opened if the default logging is turned on with the <code> |
- * -Ddart.speedtracerlog</code> VM property. |
- * |
- * This method is only intended to be called once. |
- */ |
- public static void init() { |
- get(); |
- } |
- |
- /** |
- * Returns true if the trace output file is configured. This is intended to be |
- * the quickest possible check, statically determined. |
- */ |
- public static boolean canTrace() { |
- return logFile != null; |
- } |
- |
- /** |
- * Adds a LOG_MESSAGE SpeedTracer event to the log. This represents a single |
- * point in time and has a special representation in the SpeedTracer UI. |
- */ |
- public static void markTimeline(String message) { |
- Tracer.get().markTimelineImpl(message); |
- } |
- |
- /** |
- * Signals that a new event has started. You must end each event for each |
- * corresponding call to {@code start}. You may nest timing calls. |
- * |
- * @param type the type of event |
- * @param data a set of key-value pairs (each key is followed by its value) |
- * that contain additional information about the event |
- * @return an Event object to be ended by the caller |
- */ |
- public static TraceEvent start(EventType type, String... data) { |
- return Tracer.get().startImpl(type, data); |
- } |
- |
- private static double convertToMilliseconds(long nanos) { |
- return nanos / 1000000.0d; |
- } |
- |
- /** |
- * Convenience method for ending event, which might possibly be null. |
- */ |
- public static void end(TraceEvent event, String... data) { |
- if (event != null) { |
- event.end(data); |
- } |
- } |
- |
- /** |
- * For accessing the logger as a singleton, you can retrieve the global |
- * instance. It is prudent, but not necessary to first initialize the |
- * singleton with a call to {@link #init()} to set the base time. |
- * |
- * @return the current global {@link Tracer} instance. |
- */ |
- private static Tracer get() { |
- return LazySpeedTracerLoggerHolder.singleton; |
- } |
- |
- private static boolean getBooleanProperty(String propName) { |
- try { |
- return System.getProperty(propName) != null; |
- } catch (RuntimeException ruEx) { |
- return false; |
- } |
- } |
- |
- private final boolean enabled; |
- |
- private final DummyEvent dummyEvent = new DummyEvent(); |
- |
- private BlockingQueue<TraceEvent> eventsToWrite; |
- |
- private final boolean fileLoggingEnabled; |
- |
- private CountDownLatch flushLatch; |
- |
- private TraceEvent flushSentinel; |
- |
- private Format outputFormat; |
- |
- private ThreadLocal<Stack<TraceEvent>> pendingEvents; |
- |
- private CountDownLatch shutDownLatch; |
- |
- private TraceEvent shutDownSentinel; |
- |
- private List<GarbageCollectorMXBean> gcMXBeans; |
- |
- private Map<String, Long> lastGcTimes; |
- |
- private final ElapsedNormalizedTimeKeeper elapsedTimeKeeper; |
- |
- private final ProcessNormalizedTimeKeeper processCpuTimeKeeper; |
- |
- private final ThreadNormalizedTimeKeeper threadCpuTimeKeeper; |
- |
- /** |
- * Constructor intended for unit testing. |
- * |
- * @param writer alternative {@link Writer} to send speed tracer output. |
- */ |
- Tracer(Writer writer, Format format) { |
- enabled = true; |
- fileLoggingEnabled = true; |
- outputFormat = format; |
- eventsToWrite = openLogWriter(writer, ""); |
- pendingEvents = initPendingEvents(); |
- elapsedTimeKeeper = new ElapsedNormalizedTimeKeeper(); |
- processCpuTimeKeeper = new ProcessNormalizedTimeKeeper(); |
- threadCpuTimeKeeper = new ThreadNormalizedTimeKeeper(); |
- shutDownSentinel = new DummyEvent(); |
- flushSentinel = new DummyEvent(); |
- shutDownLatch = new CountDownLatch(1); |
- } |
- |
- private Tracer() { |
- fileLoggingEnabled = logFile != null; |
- enabled = fileLoggingEnabled; |
- |
- if (enabled) { |
- elapsedTimeKeeper = new ElapsedNormalizedTimeKeeper(); |
- processCpuTimeKeeper = new ProcessNormalizedTimeKeeper(); |
- threadCpuTimeKeeper = new ThreadNormalizedTimeKeeper(); |
- |
- if (fileLoggingEnabled) { |
- // Allow a system property to override the default output format |
- Format format = Format.HTML; |
- if (defaultFormatString != null) { |
- for (Format value : Format.values()) { |
- if (value.name().toLowerCase().equals(defaultFormatString.toLowerCase())) { |
- format = value; |
- break; |
- } |
- } |
- } |
- outputFormat = format; |
- eventsToWrite = openDefaultLogWriter(); |
- |
- shutDownSentinel = new TraceEvent(); |
- flushSentinel = new TraceEvent(); |
- shutDownLatch = new CountDownLatch(1); |
- } |
- |
- if (logGcTime) { |
- gcMXBeans = ManagementFactory.getGarbageCollectorMXBeans(); |
- lastGcTimes = new ConcurrentHashMap<String, Long>(); |
- } |
- |
- pendingEvents = initPendingEvents(); |
- } else { |
- elapsedTimeKeeper = null; |
- processCpuTimeKeeper = null; |
- threadCpuTimeKeeper = null; |
- } |
- } |
- |
- public void addDataImpl(String... data) { |
- Stack<TraceEvent> threadPendingEvents = pendingEvents.get(); |
- if (threadPendingEvents.isEmpty()) { |
- throw new IllegalStateException("Tried to add data to an event that never started!"); |
- } |
- |
- TraceEvent currentEvent = threadPendingEvents.peek(); |
- currentEvent.addData(data); |
- } |
- |
- public void markTimelineImpl(String message) { |
- Stack<TraceEvent> threadPendingEvents = pendingEvents.get(); |
- TraceEvent parent = null; |
- if (!threadPendingEvents.isEmpty()) { |
- parent = threadPendingEvents.peek(); |
- } |
- TraceEvent newEvent = new MarkTimelineEvent(parent); |
- threadPendingEvents.push(newEvent); |
- newEvent.end("message", message); |
- } |
- |
- void addGcEvents(TraceEvent refEvent) { |
- // we're not sending GC events to the dartboard, so we only record them |
- // to file |
- if (!fileLoggingEnabled) { |
- return; |
- } |
- |
- for (GarbageCollectorMXBean gcMXBean : gcMXBeans) { |
- String gcName = gcMXBean.getName(); |
- Long lastGcTime = lastGcTimes.get(gcName); |
- long currGcTime = gcMXBean.getCollectionTime(); |
- if (lastGcTime == null) { |
- lastGcTime = 0L; |
- } |
- if (currGcTime > lastGcTime) { |
- // create a new event |
- long gcDurationNanos = (currGcTime - lastGcTime) * 1000000L; |
- TraceEvent gcEvent = |
- new GcEvent(refEvent, gcName, gcMXBean.getCollectionCount(), gcDurationNanos); |
- |
- eventsToWrite.add(gcEvent); |
- lastGcTimes.put(gcName, currGcTime); |
- } |
- } |
- } |
- |
- void addOverheadEvent(TraceEvent refEvent) { |
- TraceEvent overheadEvent = new TraceEvent(refEvent, SpeedTracerEventType.OVERHEAD); |
- // measure the time between the end of refEvent and now |
- overheadEvent.setStartsAfter(refEvent); |
- overheadEvent.updateDuration(); |
- |
- refEvent.extendDuration(overheadEvent); |
- } |
- |
- void endImpl(TraceEvent event, String... data) { |
- if (!enabled) { |
- return; |
- } |
- |
- if (data.length % 2 == 1) { |
- throw new IllegalArgumentException("Unmatched data argument"); |
- } |
- |
- Stack<TraceEvent> threadPendingEvents = pendingEvents.get(); |
- if (threadPendingEvents.isEmpty()) { |
- throw new IllegalStateException("Tried to end an event that never started!"); |
- } |
- TraceEvent currentEvent = threadPendingEvents.pop(); |
- currentEvent.updateDuration(); |
- |
- while (currentEvent != event && !threadPendingEvents.isEmpty()) { |
- // Missed a closing end for one or more frames! Try to sync back up. |
- currentEvent.addData("Missed", |
- "This event was closed without an explicit call to Event.end()"); |
- currentEvent = threadPendingEvents.pop(); |
- currentEvent.updateDuration(); |
- } |
- |
- if (threadPendingEvents.isEmpty() && currentEvent != event) { |
- currentEvent.addData("Missed", "Fell off the end of the threadPending events"); |
- } |
- |
- if (logGcTime) { |
- addGcEvents(currentEvent); |
- } |
- |
- currentEvent.addData(data); |
- |
- if (logOverheadTime) { |
- addOverheadEvent(currentEvent); |
- } |
- |
- if (threadPendingEvents.isEmpty()) { |
- if (fileLoggingEnabled) { |
- eventsToWrite.add(currentEvent); |
- } |
- } |
- } |
- |
- /** |
- * Notifies the background thread to finish processing all data in the queue. |
- * Blocks the current thread until the data is flushed in the Log Writer |
- * thread. |
- */ |
- void flush() { |
- if (!fileLoggingEnabled) { |
- return; |
- } |
- |
- try { |
- // Wait for the other thread to drain the queue. |
- flushLatch = new CountDownLatch(1); |
- eventsToWrite.add(flushSentinel); |
- flushLatch.await(); |
- } catch (InterruptedException e) { |
- // Ignored |
- } |
- } |
- |
- TraceEvent startImpl(EventType type, String... data) { |
- if (!enabled) { |
- return dummyEvent; |
- } |
- |
- if (data.length % 2 == 1) { |
- throw new IllegalArgumentException("Unmatched data argument"); |
- } |
- |
- Stack<TraceEvent> threadPendingEvents = pendingEvents.get(); |
- TraceEvent parent = null; |
- if (!threadPendingEvents.isEmpty()) { |
- parent = threadPendingEvents.peek(); |
- } else { |
- // reset the thread CPU time base for top-level events (so events can be |
- // properly sequenced chronologically) |
- threadCpuTimeKeeper.resetTimeBase(); |
- } |
- |
- TraceEvent newEvent = new TraceEvent(parent, type, data); |
- // Add a field to the top level event in order to track the base time |
- // so we can re-normalize the data |
- if (threadPendingEvents.size() == 0) { |
- long baseTime = |
- logProcessCpuTime ? processCpuTimeKeeper.zeroTimeMillis() : (logThreadCpuTime |
- ? threadCpuTimeKeeper.zeroTimeMillis() : elapsedTimeKeeper.zeroTimeMillis()); |
- newEvent.addData("baseTime", "" + baseTime); |
- } |
- threadPendingEvents.push(newEvent); |
- return newEvent; |
- } |
- |
- private ThreadLocal<Stack<TraceEvent>> initPendingEvents() { |
- return new ThreadLocal<Stack<TraceEvent>>() { |
- @Override |
- protected Stack<TraceEvent> initialValue() { |
- return new Stack<TraceEvent>(); |
- } |
- }; |
- } |
- |
- private BlockingQueue<TraceEvent> openDefaultLogWriter() { |
- Writer writer = null; |
- if (enabled) { |
- try { |
- writer = new BufferedWriter(new FileWriter(logFile)); |
- return openLogWriter(writer, logFile); |
- } catch (IOException e) { |
- System.err.println("Unable to open dart.speedtracerlog '" + logFile + "'"); |
- e.printStackTrace(); |
- } |
- } |
- return null; |
- } |
- |
- private BlockingQueue<TraceEvent> openLogWriter(final Writer writer, final String fileName) { |
- try { |
- if (outputFormat.equals(Format.HTML)) { |
- writer.write("<HTML isdump=\"true\"><body>" |
- + "<style>body {font-family:Helvetica; margin-left:15px;}</style>" |
- + "<h2>Performance dump from GWT</h2>" |
- + "<div>This file contains data that can be viewed with the " |
- + "<a href=\"http://code.google.com/speedtracer\">SpeedTracer</a> " |
- + "extension under the <a href=\"http://chrome.google.com/\">" |
- + "Chrome</a> browser.</div><p><span id=\"info\">" |
- + "(You must install the SpeedTracer extension to open this file)</span></p>" |
- + "<div style=\"display: none\" id=\"traceData\" version=\"0.17\">\n"); |
- } |
- } catch (IOException e) { |
- System.err.println("Unable to write to dart.speedtracerlog '" |
- + (fileName == null ? "" : fileName) + "'"); |
- e.printStackTrace(); |
- return null; |
- } |
- |
- final BlockingQueue<TraceEvent> eventQueue = new LinkedBlockingQueue<TraceEvent>(); |
- |
- Runtime.getRuntime().addShutdownHook(new Thread() { |
- @Override |
- public void run() { |
- try { |
- // Wait for the other thread to drain the queue. |
- eventQueue.add(shutDownSentinel); |
- shutDownLatch.await(); |
- } catch (InterruptedException e) { |
- // Ignored |
- } |
- } |
- }); |
- |
- // Background thread to write SpeedTracer events to log |
- Thread logWriterWorker = new LogWriterThread(writer, fileName, eventQueue); |
- |
- // Lower than normal priority. |
- logWriterWorker.setPriority((Thread.MIN_PRIORITY + Thread.NORM_PRIORITY) / 2); |
- |
- /* |
- * This thread must be daemon, otherwise shutdown hooks would never begin to |
- * run, and an app wouldn't finish. |
- */ |
- logWriterWorker.setDaemon(true); |
- logWriterWorker.setName("SpeedTracerLogger writer"); |
- logWriterWorker.start(); |
- return eventQueue; |
- } |
-} |