diff options
-rw-r--r-- | src/core/lombok/core/AST.java | 6 | ||||
-rw-r--r-- | src/core/lombok/core/debug/HistogramTracker.java | 77 | ||||
-rw-r--r-- | src/core/lombok/eclipse/TransformEclipseAST.java | 11 |
3 files changed, 72 insertions, 22 deletions
diff --git a/src/core/lombok/core/AST.java b/src/core/lombok/core/AST.java index 7bddbada..e6efe058 100644 --- a/src/core/lombok/core/AST.java +++ b/src/core/lombok/core/AST.java @@ -61,7 +61,7 @@ public abstract class AST<A extends AST<A, L, N>, L extends LombokNode<A, L, N>, Map<N, N> identityDetector = new IdentityHashMap<N, N>(); private Map<N, L> nodeMap = new IdentityHashMap<N, L>(); private boolean changed = false; - private static final HistogramTracker histogramTracker = System.getProperty("lombok.timeConfig") == null ? null : new HistogramTracker("lombok.config"); + private static final HistogramTracker configTracker = System.getProperty("lombok.timeConfig") == null ? null : new HistogramTracker("lombok.config"); protected AST(String fileName, String packageDeclaration, ImportList imports) { this.fileName = fileName == null ? "(unknown).java" : fileName; @@ -421,11 +421,11 @@ public abstract class AST<A extends AST<A, L, N>, L extends LombokNode<A, L, N>, } public final <T> T readConfiguration(ConfigurationKey<T> key) { - long start = System.currentTimeMillis(); + long start = configTracker == null ? 0L : configTracker.start(); try { return LombokConfiguration.read(key, this); } finally { - if (histogramTracker != null) histogramTracker.report(start); + if (configTracker != null) configTracker.end(start); } } } diff --git a/src/core/lombok/core/debug/HistogramTracker.java b/src/core/lombok/core/debug/HistogramTracker.java index 3ae8a58b..5471540f 100644 --- a/src/core/lombok/core/debug/HistogramTracker.java +++ b/src/core/lombok/core/debug/HistogramTracker.java @@ -1,5 +1,6 @@ package lombok.core.debug; +import java.io.PrintStream; import java.util.Calendar; import java.util.GregorianCalendar; import java.util.concurrent.atomic.AtomicBoolean; @@ -12,41 +13,63 @@ import java.util.concurrent.atomic.AtomicStampedReference; * emitted until you call report(). */ public class HistogramTracker { - private static final int[] RANGES = {1, 2, 5, 9, 17, 33, 65, 129, 257}; - private static final long REPORT_TIME = 1000 * 60; + private static final long[] RANGES = { + 250001L, 500001L, 1000001L, 2000001L, 4000001L, 8000001L, 16000001L, 32000001L, + 64000001L, 128000001L, 256000001L, 512000001L, 1024000001L, 2048000001L, 10000000001L}; + private static final long REPORT_WINDOW = 1000 * 60; private final String category; - private final AtomicStampedReference<int[]> bars = new AtomicStampedReference<int[]>(new int[RANGES.length + 2], 0); + private final AtomicStampedReference<long[]> bars = new AtomicStampedReference<long[]>(new long[RANGES.length + 2], 0); private final AtomicBoolean addedSysHook = new AtomicBoolean(false); + private final PrintStream out; public HistogramTracker(String category) { this.category = category; + this.out = null; + printInit(); + } + + public HistogramTracker(String category, PrintStream out) { + this.category = category; + this.out = out; + printInit(); + } + + private void printInit() { if (category == null) { - ProblemReporter.info("Initialized histogram", null); + if (out == null) ProblemReporter.info("Initialized histogram", null); + else out.println("Initialized histogram"); } else { - ProblemReporter.info(String.format("Initialized histogram tracker for '%s'", category), null); + if (out == null) ProblemReporter.info(String.format("Initialized histogram tracker for '%s'", category), null); + else out.printf("Initialized histogram tracker for '%s'%n", category); } } - public void report(long start) { + public long start() { + return System.nanoTime(); + } + + public void end(long startToken) { if (!addedSysHook.getAndSet(true)) Runtime.getRuntime().addShutdownHook(new Thread("Histogram Printer") { @Override public void run() { int[] currentInterval = {0}; - int[] b = bars.get(currentInterval); + long[] b = bars.get(currentInterval); printReport(currentInterval[0], b); } }); - long end = System.currentTimeMillis(); - long delta = end - start; - int interval = (int) (end / REPORT_TIME); + long end = System.nanoTime(); + long now = System.currentTimeMillis(); + long delta = end - startToken; + if (delta < 0L) delta = 0L; + int interval = (int) (now / REPORT_WINDOW); int[] currentInterval = {0}; - int[] bars = this.bars.get(currentInterval); - int[] newBars; + long[] bars = this.bars.get(currentInterval); + long[] newBars; if (currentInterval[0] != interval) { printReport(currentInterval[0], bars); - newBars = new int[RANGES.length + 2]; + newBars = new long[RANGES.length + 2]; if (!this.bars.compareAndSet(bars, newBars, currentInterval[0], interval)) { newBars = this.bars.get(currentInterval); } @@ -65,12 +88,12 @@ public class HistogramTracker { newBars[RANGES.length]++; } - private void printReport(int interval, int[] bars) { + private void printReport(int interval, long[] bars) { StringBuilder sb = new StringBuilder(); if (category != null) sb.append(category).append(" "); sb.append("["); GregorianCalendar gc = new GregorianCalendar(); - gc.setTimeInMillis(interval * REPORT_TIME); + gc.setTimeInMillis(interval * REPORT_WINDOW); int hour = gc.get(Calendar.HOUR_OF_DAY); int minute = gc.get(Calendar.MINUTE); if (hour < 10) sb.append('0'); @@ -78,16 +101,32 @@ public class HistogramTracker { if (minute < 10) sb.append('0'); sb.append(minute).append("] {"); - int sum = bars[RANGES.length]; + long sum = bars[RANGES.length]; + int count = 0; + int lastZeroPos = sb.length(); for (int i = 0; i < RANGES.length; i++) { sum += bars[i]; - sb.append(bars[i]).append(" "); + sb.append(bars[i]); + if (bars[i] != 0) lastZeroPos = sb.length(); + sb.append(" "); + count++; + if (count == 3) sb.append("-- "); + if (count == 9) sb.append("-- "); } + if (sum == 0) return; + sb.setLength(lastZeroPos); - sb.append(bars[RANGES.length]).append("} total calls: ").append(sum).append(" total time: ").append(bars[RANGES.length + 1]); + double millis = bars[RANGES.length + 1] / 1000000.0; + + long over = bars[RANGES.length]; + if (over > 0L) { + sb.append(" -- ").append(bars[RANGES.length]); + } + sb.append("} total calls: ").append(sum).append(" total time (millis): ").append((int)(millis + 0.5)); - ProblemReporter.info(sb.toString(), null); + if (out == null) ProblemReporter.info(sb.toString(), null); + else out.println(sb.toString()); } } diff --git a/src/core/lombok/eclipse/TransformEclipseAST.java b/src/core/lombok/eclipse/TransformEclipseAST.java index 11caf5c2..e6528178 100644 --- a/src/core/lombok/eclipse/TransformEclipseAST.java +++ b/src/core/lombok/eclipse/TransformEclipseAST.java @@ -26,6 +26,7 @@ import static lombok.eclipse.handlers.EclipseHandlerUtil.*; import java.lang.reflect.Field; import lombok.core.debug.DebugSnapshotStore; +import lombok.core.debug.HistogramTracker; import lombok.patcher.Symbols; import org.eclipse.jdt.internal.compiler.ast.AbstractMethodDeclaration; @@ -57,6 +58,14 @@ public class TransformEclipseAST { private static final HandlerLibrary handlers; public static boolean disableLombok = false; + private static final HistogramTracker lombokTracker; + + static { + String v = System.getProperty("lombok.histogram"); + if (v == null) lombokTracker = null; + else if (v.toLowerCase().equals("sysout")) lombokTracker = new HistogramTracker("lombok.histogram", System.out); + else lombokTracker = new HistogramTracker("lombok.histogram"); + } static { Field f = null; @@ -136,8 +145,10 @@ public class TransformEclipseAST { try { DebugSnapshotStore.INSTANCE.snapshot(ast, "transform entry"); + long histoToken = lombokTracker == null ? 0L : lombokTracker.start(); EclipseAST existing = getAST(ast, false); new TransformEclipseAST(existing).go(); + if (lombokTracker != null) lombokTracker.end(histoToken); DebugSnapshotStore.INSTANCE.snapshot(ast, "transform exit"); } catch (Throwable t) { DebugSnapshotStore.INSTANCE.snapshot(ast, "transform error: %s", t.getClass().getSimpleName()); |