# HG changeset patch # User Doug Simon # Date 1384821548 -3600 # Node ID 6ae55c10796f3b0aa637fdbc2059a746410a05b6 # Parent 430a95455271752218b5cd7acc2ff9f7c3884a5f# Parent d70077ca358a0cb80b094e85439a366b4f4899b8 Merge. diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.debug/src/com/oracle/graal/debug/Debug.java --- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/Debug.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/Debug.java Tue Nov 19 01:39:08 2013 +0100 @@ -353,8 +353,20 @@ return null; } + /** + * Creates a {@linkplain DebugMetric metric} that is enabled iff debugging is + * {@linkplain #isEnabled() enabled} or the system property whose name is formed by adding to + * {@value #ENABLE_METRIC_PROPERTY_NAME_PREFIX} to {@code name} is + * {@linkplain Boolean#getBoolean(String) true}. If the latter condition is true, then the + * returned metric is {@linkplain DebugMetric#isConditional() unconditional} otherwise it is + * conditional. + *

+ * A disabled metric has virtually no overhead. + */ public static DebugMetric metric(String name) { - if (ENABLED) { + if (Boolean.getBoolean(ENABLE_METRIC_PROPERTY_NAME_PREFIX + name)) { + return new MetricImpl(name, false); + } else if (ENABLED) { return new MetricImpl(name, true); } else { return VOID_METRIC; @@ -438,10 +450,36 @@ public boolean isConditional() { return false; } + + public long getCurrentValue() { + return 0L; + } }; + /** + * @see #timer(String) + */ + public static final String ENABLE_TIMER_PROPERTY_NAME_PREFIX = "graal.debug.timer."; + + /** + * @see #metric(String) + */ + public static final String ENABLE_METRIC_PROPERTY_NAME_PREFIX = "graal.debug.metric."; + + /** + * Creates a {@linkplain DebugTimer timer} that is enabled iff debugging is + * {@linkplain #isEnabled() enabled} or the system property whose name is formed by adding to + * {@value #ENABLE_TIMER_PROPERTY_NAME_PREFIX} to {@code name} is + * {@linkplain Boolean#getBoolean(String) true}. If the latter condition is true, then the + * returned timer is {@linkplain DebugMetric#isConditional() unconditional} otherwise it is + * conditional. + *

+ * A disabled timer has virtually no overhead. + */ public static DebugTimer timer(String name) { - if (ENABLED) { + if (Boolean.getBoolean(ENABLE_TIMER_PROPERTY_NAME_PREFIX + name)) { + return new TimerImpl(name, false); + } else if (ENABLED) { return new TimerImpl(name, true); } else { return VOID_TIMER; @@ -461,5 +499,13 @@ public boolean isConditional() { return false; } + + public long getCurrentValue() { + return 0L; + } + + public TimeUnit getTimeUnit() { + return null; + } }; } diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugMetric.java --- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugMetric.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugMetric.java Tue Nov 19 01:39:08 2013 +0100 @@ -50,4 +50,9 @@ * enabled}. */ boolean isConditional(); + + /** + * Gets the current value of this metric. + */ + long getCurrentValue(); } diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java --- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java Tue Nov 19 01:39:08 2013 +0100 @@ -22,6 +22,8 @@ */ package com.oracle.graal.debug; +import java.util.concurrent.*; + import com.oracle.graal.debug.internal.*; /** @@ -56,4 +58,14 @@ * enabled}. */ boolean isConditional(); + + /** + * Gets the current value of this timer. + */ + long getCurrentValue(); + + /** + * Gets the time unit of this timer. + */ + TimeUnit getTimeUnit(); } diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/DebugValue.java --- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/DebugValue.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/DebugValue.java Tue Nov 19 01:39:08 2013 +0100 @@ -38,7 +38,7 @@ this.conditional = conditional; } - protected long getCurrentValue() { + public long getCurrentValue() { ensureInitialized(); return DebugScope.getInstance().getCurrentValue(index); } diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java --- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java Tue Nov 19 01:39:08 2013 +0100 @@ -23,6 +23,7 @@ package com.oracle.graal.debug.internal; import java.lang.management.*; +import java.util.concurrent.*; import com.oracle.graal.debug.*; @@ -87,6 +88,10 @@ return valueToString(value); } + public TimeUnit getTimeUnit() { + return TimeUnit.NANOSECONDS; + } + private abstract class AbstractTimer implements TimerCloseable { private final AbstractTimer parent; diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/CompilationTask.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/CompilationTask.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/CompilationTask.java Tue Nov 19 01:39:08 2013 +0100 @@ -25,6 +25,7 @@ import static com.oracle.graal.api.code.CodeUtil.*; import static com.oracle.graal.nodes.StructuredGraph.*; import static com.oracle.graal.phases.GraalOptions.*; +import static com.oracle.graal.phases.common.InliningUtil.*; import java.lang.reflect.*; import java.util.concurrent.*; @@ -33,15 +34,15 @@ import com.oracle.graal.api.code.*; import com.oracle.graal.api.code.CallingConvention.Type; import com.oracle.graal.api.meta.*; +import com.oracle.graal.compiler.CompilerThreadFactory.CompilerThread; import com.oracle.graal.compiler.*; -import com.oracle.graal.compiler.CompilerThreadFactory.CompilerThread; import com.oracle.graal.debug.*; import com.oracle.graal.debug.internal.*; +import com.oracle.graal.hotspot.bridge.*; import com.oracle.graal.hotspot.meta.*; import com.oracle.graal.nodes.*; import com.oracle.graal.nodes.spi.*; import com.oracle.graal.phases.*; -import com.oracle.graal.phases.common.*; import com.oracle.graal.phases.tiers.*; public final class CompilationTask implements Runnable { @@ -119,6 +120,11 @@ * no code must be outside this try/finally because it could happen otherwise that * clearQueuedForCompilation() is not executed */ + + HotSpotVMConfig config = backend.getRuntime().getConfig(); + long previousInlinedBytecodes = InlinedBytecodes.getCurrentValue(); + long previousCompilationTime = CompilationTime.getCurrentValue(); + HotSpotInstalledCode installedCode = null; try (TimerCloseable a = CompilationTime.start()) { if (!tryToChangeStatus(CompilationStatus.Queued, CompilationStatus.Running) || method.hasCompiledCode()) { return; @@ -155,7 +161,7 @@ // Compiling method substitution - must clone the graph graph = graph.copy(); } - InliningUtil.InlinedBytecodes.add(method.getCodeSize()); + InlinedBytecodes.add(method.getCodeSize()); CallingConvention cc = getCallingConvention(providers.getCodeCache(), Type.JavaCallee, graph.method(), false); Suites suites = providers.getSuites().getDefaultSuites(); return GraalCompiler.compileGraph(graph, cc, method, providers, backend, backend.getTarget(), graphCache, plan, optimisticOpts, method.getSpeculationLog(), suites, @@ -173,7 +179,7 @@ } try (TimerCloseable b = CodeInstallationTime.start()) { - installMethod(result); + installedCode = installMethod(result); } stats.finish(method); } catch (BailoutException bailout) { @@ -194,6 +200,14 @@ System.exit(-1); } } finally { + if (config.ciTime && installedCode != null) { + long processedBytes = InlinedBytecodes.getCurrentValue() - previousInlinedBytecodes; + long time = CompilationTime.getCurrentValue() - previousCompilationTime; + TimeUnit timeUnit = CompilationTime.getTimeUnit(); + VMToCompiler vm2c = backend.getRuntime().getVMToCompiler(); + vm2c.notifyCompilationDone(id, method, entryBCI != INVOCATION_ENTRY_BCI, (int) processedBytes, time, timeUnit, installedCode); + } + assert method.isQueuedForCompilation(); method.clearQueuedForCompilation(); } @@ -214,12 +228,12 @@ MetaUtil.format("%H::%n(%p)", method), isOSR ? "@ " + entryBCI + " " : "", method.getCodeSize())); } - private void installMethod(final CompilationResult compResult) { + private HotSpotInstalledCode installMethod(final CompilationResult compResult) { final HotSpotCodeCacheProvider codeCache = backend.getProviders().getCodeCache(); - Debug.scope("CodeInstall", new Object[]{new DebugDumpScope(String.valueOf(id), true), codeCache, method}, new Runnable() { + return Debug.scope("CodeInstall", new Object[]{new DebugDumpScope(String.valueOf(id), true), codeCache, method}, new Callable() { @Override - public void run() { + public HotSpotInstalledCode call() { HotSpotInstalledCode installedCode = codeCache.installMethod(method, entryBCI, compResult); if (Debug.isDumpEnabled()) { Debug.dump(new Object[]{compResult, installedCode}, "After code installation"); @@ -227,6 +241,7 @@ if (Debug.isLogEnabled()) { Debug.log("%s", backend.getProviders().getDisassembler().disassemble(installedCode)); } + return installedCode; } }); diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/HotSpotOptions.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/HotSpotOptions.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/HotSpotOptions.java Tue Nov 19 01:39:08 2013 +0100 @@ -27,13 +27,17 @@ import static java.nio.file.Files.*; import java.io.*; +import java.lang.reflect.*; import java.nio.charset.*; import java.nio.file.*; import java.util.*; import com.oracle.graal.debug.*; +import com.oracle.graal.graph.*; import com.oracle.graal.hotspot.logging.*; +import com.oracle.graal.java.*; import com.oracle.graal.options.*; +import com.oracle.graal.phases.common.*; /** * Called from {@code graalCompiler.cpp} to parse any Graal specific options. Such options are @@ -184,13 +188,47 @@ } /** + * Sets the relevant system property such that a {@link DebugTimer} or {@link DebugMetric} + * associated with a field in a class will be unconditionally enabled when it is created. + *

+ * This method verifies that the named field exists and is of an expected type. However, it does + * not verify that the timer or metric created has the same name of the field. + * + * @param c the class in which the field is declared + * @param name the name of the field + */ + private static void unconditionallyEnableTimerOrMetric(Class c, String name) { + try { + Field field = c.getDeclaredField(name); + String propertyName; + if (DebugTimer.class.isAssignableFrom(field.getType())) { + propertyName = Debug.ENABLE_TIMER_PROPERTY_NAME_PREFIX + name; + } else { + assert DebugMetric.class.isAssignableFrom(field.getType()); + propertyName = Debug.ENABLE_METRIC_PROPERTY_NAME_PREFIX + name; + } + String previous = System.setProperty(propertyName, "true"); + if (previous != null) { + Logger.info("Overrode value \"" + previous + "\" of system property \"" + propertyName + "\" with \"true\""); + } + } catch (Exception e) { + throw new GraalInternalError(e); + } + } + + /** * Called from VM code once all Graal command line options have been processed by * {@link #setOption(String)}. * * @param ciTime the value of the CITime HotSpot VM option */ public static void finalizeOptions(boolean ciTime) { - if (areDebugScopePatternsEnabled() || ciTime) { + if (ciTime) { + unconditionallyEnableTimerOrMetric(GraphBuilderPhase.class, "BytecodesParsed"); + unconditionallyEnableTimerOrMetric(InliningUtil.class, "InlinedBytecodes"); + unconditionallyEnableTimerOrMetric(CompilationTask.class, "CompilationTime"); + } + if (areDebugScopePatternsEnabled()) { assert !Debug.Initialization.isDebugInitialized(); System.setProperty(Debug.Initialization.INITIALIZER_PROPERTY_NAME, "true"); } diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/HotSpotVMConfig.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/HotSpotVMConfig.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/HotSpotVMConfig.java Tue Nov 19 01:39:08 2013 +0100 @@ -648,6 +648,7 @@ @HotSpotVMFlag(name = "CodeEntryAlignment") @Stable public int codeEntryAlignment; @HotSpotVMFlag(name = "VerifyOops") @Stable public boolean verifyOops; @HotSpotVMFlag(name = "CITime") @Stable public boolean ciTime; + @HotSpotVMFlag(name = "CITimeEach", optional = true) @Stable public boolean ciTimeEach; @HotSpotVMFlag(name = "CompileThreshold") @Stable public long compileThreshold; @HotSpotVMFlag(name = "CompileTheWorld") @Stable public boolean compileTheWorld; @HotSpotVMFlag(name = "CompileTheWorldStartAt") @Stable public int compileTheWorldStartAt; @@ -737,6 +738,16 @@ @HotSpotVMConstant(name = "GRAAL_COUNTERS_SIZE", optional = true) @Stable public int graalCountersSize; + @HotSpotVMField(name = "CompilerStatistics::_standard", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsStandardOffset; + @HotSpotVMField(name = "CompilerStatistics::_osr", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsOsrOffset; + @HotSpotVMField(name = "CompilerStatistics::_nmethods_size", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsNmethodsSizeOffset; + @HotSpotVMField(name = "CompilerStatistics::_nmethods_code_size", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsNmethodsCodeSizeOffset; + @HotSpotVMField(name = "CompilerStatistics::Data::_bytes", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsDataBytesOffset; + @HotSpotVMField(name = "CompilerStatistics::Data::_time", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsDataTimeOffset; + @HotSpotVMField(name = "CompilerStatistics::Data::_count", get = HotSpotVMField.Type.OFFSET) @Stable public long compilerStatisticsDataCountOffset; + @HotSpotVMField(name = "elapsedTimer::_counter", get = HotSpotVMField.Type.OFFSET) @Stable public long elapsedTimerCounterOffset; + @Stable public long elapsedTimerFrequency; + /** * This field is used to pass exception objects into and out of the runtime system during * exception handling for compiled code. diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/MetricRateInPhase.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/MetricRateInPhase.java Mon Nov 18 22:12:13 2013 +0100 +++ /dev/null Thu Jan 01 00:00:00 1970 +0000 @@ -1,76 +0,0 @@ -/* - * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved. - * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. - * - * This code is free software; you can redistribute it and/or modify it - * under the terms of the GNU General Public License version 2 only, as - * published by the Free Software Foundation. - * - * This code is distributed in the hope that it will be useful, but WITHOUT - * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or - * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License - * version 2 for more details (a copy is included in the LICENSE file that - * accompanied this code). - * - * You should have received a copy of the GNU General Public License version - * 2 along with this work; if not, write to the Free Software Foundation, - * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. - * - * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA - * or visit www.oracle.com if you need additional information or have any - * questions. - */ -package com.oracle.graal.hotspot.bridge; - -import java.io.*; -import java.util.concurrent.*; - -import com.oracle.graal.debug.*; -import com.oracle.graal.debug.internal.*; - -/** - * The rate of accumulation for a metric within an execution phase. - */ -final class MetricRateInPhase { - - private final String phase; - private final MetricRateInPhase previous; - private final long time; - private final long value; - private final TimeUnit timeUnit; - - public static MetricRateInPhase snapshot(String phase, MetricRateInPhase previous, DebugMetric metric, DebugTimer timer, TimeUnit timeUnit) { - return new MetricRateInPhase(phase, previous, metric, timer, timeUnit); - } - - private MetricRateInPhase(String phase, MetricRateInPhase previous, DebugMetric metric, DebugTimer timer, TimeUnit timeUnit) { - this.phase = phase; - this.previous = previous; - this.time = VMToCompilerImpl.collectTotal((DebugValue) timer); - this.value = VMToCompilerImpl.collectTotal((DebugValue) metric); - this.timeUnit = timeUnit; - } - - public int rate() { - long t = time; - long v = value; - if (previous != null) { - t -= previous.time; - v -= previous.value; - } - - t = timeUnit.convert(t, TimeUnit.NANOSECONDS); - if (t == 0) { - t = 1; - } - return (int) (v / t); - } - - public void printAll(String label, PrintStream stream) { - MetricRateInPhase rs = this; - while (rs != null) { - stream.println(label + "@" + rs.phase + ": " + rs.rate()); - rs = rs.previous; - } - } -} diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompiler.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompiler.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompiler.java Tue Nov 19 01:39:08 2013 +0100 @@ -24,6 +24,7 @@ package com.oracle.graal.hotspot.bridge; import java.io.*; +import java.util.concurrent.*; import com.oracle.graal.api.meta.*; import com.oracle.graal.hotspot.debug.*; @@ -45,9 +46,23 @@ */ void compileMethod(HotSpotResolvedJavaMethod method, int entryBCI, boolean blocking) throws Throwable; + /** + * Notifies this object of statistics for a completed compilation. + * + * @param id the identifier of the compilation + * @param method the method compiled + * @param osr specifies if the compilation was for on-stack-replacement + * @param processedBytecodes the number of bytecodes processed during the compilation, including + * the bytecodes of all inlined methods + * @param time the amount time spent compiling {@code method} + * @param timeUnit the units of {@code time} + * @param installedCode the nmethod installed as a result of the compilation + */ + void notifyCompilationDone(int id, HotSpotResolvedJavaMethod method, boolean osr, int processedBytecodes, long time, TimeUnit timeUnit, HotSpotInstalledCode installedCode); + void shutdownCompiler() throws Throwable; - void startCompiler(boolean bootstrapEnabled) throws Throwable; + void startCompiler(boolean bootstrapEnabled, long statsAddress) throws Throwable; void bootstrap() throws Throwable; diff -r d70077ca358a -r 6ae55c10796f graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompilerImpl.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompilerImpl.java Mon Nov 18 22:12:13 2013 +0100 +++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompilerImpl.java Tue Nov 19 01:39:08 2013 +0100 @@ -25,10 +25,8 @@ import static com.oracle.graal.compiler.GraalDebugConfig.*; import static com.oracle.graal.graph.UnsafeAccess.*; -import static com.oracle.graal.hotspot.CompilationTask.*; import static com.oracle.graal.hotspot.HotSpotGraalRuntime.*; -import static com.oracle.graal.java.GraphBuilderPhase.*; -import static com.oracle.graal.phases.common.InliningUtil.*; +import static java.util.concurrent.TimeUnit.*; import java.io.*; import java.lang.reflect.*; @@ -102,6 +100,8 @@ private long compilerStartTime; + private long compilerStatistics; + public VMToCompilerImpl(HotSpotGraalRuntime runtime) { this.runtime = runtime; @@ -122,7 +122,7 @@ assert unsafe.getObject(mirror, offset) == type; } - public void startCompiler(boolean bootstrapEnabled) throws Throwable { + public void startCompiler(boolean bootstrapEnabled, long compilerStatisticsAddress) throws Throwable { FastNodeClassRegistry.initialize(); @@ -149,6 +149,8 @@ } } + compilerStatistics = compilerStatisticsAddress; + TTY.initialize(log); if (Log.getValue() == null && Meter.getValue() == null && Time.getValue() == null && Dump.getValue() == null) { @@ -157,12 +159,6 @@ } } - if (config.ciTime) { - BytecodesParsed.setConditional(false); - InlinedBytecodes.setConditional(false); - CompilationTime.setConditional(false); - } - if (Debug.isEnabled()) { DebugEnvironment.initialize(log); @@ -256,10 +252,6 @@ */ protected void phaseTransition(String phase) { CompilationStatistics.clear(phase); - if (runtime.getConfig().ciTime) { - parsedBytecodesPerSecond = MetricRateInPhase.snapshot(phase, parsedBytecodesPerSecond, BytecodesParsed, CompilationTime, TimeUnit.SECONDS); - inlinedBytecodesPerSecond = MetricRateInPhase.snapshot(phase, inlinedBytecodesPerSecond, InlinedBytecodes, CompilationTime, TimeUnit.SECONDS); - } } /** @@ -325,6 +317,7 @@ if (ResetDebugValuesAfterBootstrap.getValue()) { printDebugValues("bootstrap", true); + resetCompilerStatistics(); } phaseTransition("bootstrap"); @@ -343,9 +336,6 @@ System.exit(0); } - private MetricRateInPhase parsedBytecodesPerSecond; - private MetricRateInPhase inlinedBytecodesPerSecond; - private void enqueue(Method m) throws Throwable { JavaMethod javaMethod = runtime.getHostProviders().getMetaAccess().lookupJavaMethod(m); assert !Modifier.isAbstract(((HotSpotResolvedJavaMethod) javaMethod).getModifiers()) && !Modifier.isNative(((HotSpotResolvedJavaMethod) javaMethod).getModifiers()) : javaMethod; @@ -374,11 +364,6 @@ printDebugValues(ResetDebugValuesAfterBootstrap.getValue() ? "application" : null, false); phaseTransition("final"); - if (runtime.getConfig().ciTime) { - parsedBytecodesPerSecond.printAll("ParsedBytecodesPerSecond", System.out); - inlinedBytecodesPerSecond.printAll("InlinedBytecodesPerSecond", System.out); - } - SnippetCounter.printGroups(TTY.out().out()); BenchmarkCounters.shutdown(runtime.getCompilerToVM(), compilerStartTime); } @@ -600,6 +585,64 @@ } } + private TimeUnit elapsedTimerTimeUnit; + + private TimeUnit getElapsedTimerTimeUnit() { + if (elapsedTimerTimeUnit == null) { + long freq = runtime.getConfig().elapsedTimerFrequency; + for (TimeUnit tu : TimeUnit.values()) { + if (tu.toSeconds(freq) == 1) { + elapsedTimerTimeUnit = tu; + break; + } + } + assert elapsedTimerTimeUnit != null; + } + return elapsedTimerTimeUnit; + } + + public synchronized void notifyCompilationDone(int id, HotSpotResolvedJavaMethod method, boolean osr, int processedBytecodes, long time, TimeUnit timeUnit, HotSpotInstalledCode installedCode) { + HotSpotVMConfig config = runtime.getConfig(); + long dataAddress = compilerStatistics + (osr ? config.compilerStatisticsOsrOffset : config.compilerStatisticsStandardOffset); + + long timeAddress = dataAddress + config.compilerStatisticsDataTimeOffset + config.elapsedTimerCounterOffset; + long previousElapsedTime = unsafe.getLong(timeAddress); + long elapsedTime = getElapsedTimerTimeUnit().convert(time, timeUnit); + unsafe.putLong(timeAddress, previousElapsedTime + elapsedTime); + + long bytesAddress = dataAddress + config.compilerStatisticsDataBytesOffset; + int currentBytes = unsafe.getInt(bytesAddress); + unsafe.putInt(bytesAddress, currentBytes + processedBytecodes); + + long countAddress = dataAddress + config.compilerStatisticsDataCountOffset; + int currentCount = unsafe.getInt(countAddress); + unsafe.putInt(countAddress, currentCount + 1); + + long nmethodsSizeAddress = compilerStatistics + config.compilerStatisticsNmethodsSizeOffset; + int currentSize = unsafe.getInt(nmethodsSizeAddress); + unsafe.putInt(nmethodsSizeAddress, currentSize + installedCode.getSize()); + + long nmethodsCodeSizeAddress = compilerStatistics + config.compilerStatisticsNmethodsCodeSizeOffset; + int currentCodeSize = unsafe.getInt(nmethodsCodeSizeAddress); + unsafe.putInt(nmethodsCodeSizeAddress, currentCodeSize + (int) installedCode.getCodeSize()); + + if (config.ciTimeEach) { + TTY.println(String.format("%-6d {%s: %d ms, %d bytes}", id, osr ? "osr" : "standard", MILLISECONDS.convert(time, timeUnit), processedBytecodes)); + } + } + + private static void resetCompilerStatisticsData(HotSpotVMConfig config, long dataAddress) { + unsafe.putInt(dataAddress + config.compilerStatisticsDataBytesOffset, 0); + unsafe.putInt(dataAddress + config.compilerStatisticsDataCountOffset, 0); + unsafe.putLong(dataAddress + config.compilerStatisticsDataTimeOffset + config.elapsedTimerCounterOffset, 0L); + } + + private void resetCompilerStatistics() { + HotSpotVMConfig config = runtime.getConfig(); + resetCompilerStatisticsData(config, compilerStatistics + config.compilerStatisticsStandardOffset); + resetCompilerStatisticsData(config, compilerStatistics + config.compilerStatisticsOsrOffset); + } + @Override public JavaMethod createUnresolvedJavaMethod(String name, String signature, JavaType holder) { return new HotSpotMethodUnresolved(name, signature, holder); diff -r d70077ca358a -r 6ae55c10796f src/share/vm/classfile/vmSymbols.hpp --- a/src/share/vm/classfile/vmSymbols.hpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/classfile/vmSymbols.hpp Tue Nov 19 01:39:08 2013 +0100 @@ -574,6 +574,7 @@ template(char_array_void_signature, "([C)V") \ template(int_int_void_signature, "(II)V") \ template(long_long_void_signature, "(JJ)V") \ + template(boolean_long_void_signature, "(ZJ)V") \ template(void_classloader_signature, "()Ljava/lang/ClassLoader;") \ template(void_object_signature, "()Ljava/lang/Object;") \ template(void_class_signature, "()Ljava/lang/Class;") \ @@ -903,7 +904,7 @@ do_signature(copyMemory_signature, "(Ljava/lang/Object;JLjava/lang/Object;JJ)V") \ do_intrinsic(_park, sun_misc_Unsafe, park_name, park_signature, F_RN) \ do_name( park_name, "park") \ - do_signature(park_signature, "(ZJ)V") \ + do_alias(park_signature, boolean_long_void_signature) \ do_intrinsic(_unpark, sun_misc_Unsafe, unpark_name, unpark_signature, F_RN) \ do_name( unpark_name, "unpark") \ do_alias( unpark_signature, /*(LObject;)V*/ object_void_signature) \ diff -r d70077ca358a -r 6ae55c10796f src/share/vm/compiler/abstractCompiler.hpp --- a/src/share/vm/compiler/abstractCompiler.hpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/compiler/abstractCompiler.hpp Tue Nov 19 01:39:08 2013 +0100 @@ -30,13 +30,38 @@ typedef void (*initializer)(void); #ifdef GRAAL -class CompilerStatistics { +// Per-compiler statistics +class CompilerStatistics VALUE_OBJ_CLASS_SPEC { + friend class VMStructs; + + class Data VALUE_OBJ_CLASS_SPEC { + friend class VMStructs; + public: + elapsedTimer _time; // time spent compiling + int _bytes; // number of bytecodes compiled, including inlined bytecodes + int _count; // number of compilations + Data() : _bytes(0), _count(0) {} + void update(elapsedTimer time, int bytes) { + _time.add(time); + _bytes += bytes; + _count++; + } + }; + public: - elapsedTimer _t_osr_compilation; - elapsedTimer _t_standard_compilation; - int _sum_osr_bytes_compiled; - int _sum_standard_bytes_compiled; - CompilerStatistics() : _sum_osr_bytes_compiled(0), _sum_standard_bytes_compiled(0) {} + Data _standard; // stats for non-OSR compilations + Data _osr; // stats for OSR compilations + int _nmethods_size; // + int _nmethods_code_size; + int bytes_per_second() { + int bytes = _standard._bytes + _osr._bytes; + if (bytes == 0) { + return 0; + } + double seconds = _standard._time.seconds() + _osr._time.seconds(); + return seconds == 0.0 ? 0 : (int) (bytes / seconds); + } + CompilerStatistics() : _nmethods_size(0), _nmethods_code_size(0) {} }; #endif diff -r d70077ca358a -r 6ae55c10796f src/share/vm/compiler/compileBroker.cpp --- a/src/share/vm/compiler/compileBroker.cpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/compiler/compileBroker.cpp Tue Nov 19 01:39:08 2013 +0100 @@ -2125,21 +2125,19 @@ _peak_compilation_time = time.milliseconds() > _peak_compilation_time ? time.milliseconds() : _peak_compilation_time; if (CITime) { + int bytes_compiled = method->code_size() + task->num_inlined_bytecodes(); + GRAAL_ONLY(CompilerStatistics* stats = compiler(task->comp_level())->stats();) if (is_osr) { _t_osr_compilation.add(time); - _sum_osr_bytes_compiled += method->code_size() + task->num_inlined_bytecodes(); -#ifdef GRAAL - compiler(task->comp_level())->stats()->_t_osr_compilation.add(time); - compiler(task->comp_level())->stats()->_sum_osr_bytes_compiled += method->code_size() + task->num_inlined_bytecodes(); -#endif + _sum_osr_bytes_compiled += bytes_compiled; + GRAAL_ONLY(stats->_osr.update(time, bytes_compiled);) } else { _t_standard_compilation.add(time); _sum_standard_bytes_compiled += method->code_size() + task->num_inlined_bytecodes(); -#ifdef GRAAL - compiler(task->comp_level())->stats()->_t_standard_compilation.add(time); - compiler(task->comp_level())->stats()->_sum_standard_bytes_compiled += method->code_size() + task->num_inlined_bytecodes(); -#endif + GRAAL_ONLY(stats->_standard.update(time, bytes_compiled);) } + GRAAL_ONLY(stats->_nmethods_size += code->total_size();) + GRAAL_ONLY(stats->_nmethods_code_size += code->insts_size();) } if (UsePerfData) { @@ -2196,16 +2194,82 @@ } void CompileBroker::print_times() { +#ifdef GRAAL + elapsedTimer standard_compilation; + elapsedTimer total_compilation; + elapsedTimer osr_compilation; + + int standard_bytes_compiled = 0; + int osr_bytes_compiled = 0; + + int standard_compile_count = 0; + int osr_compile_count = 0; + int total_compile_count = 0; + + int nmethods_size = 0; + int nmethods_code_size = 0; + bool printedHeader = false; + + for (unsigned int i = 0; i < sizeof(_compilers) / sizeof(AbstractCompiler*); i++) { + AbstractCompiler* comp = _compilers[i]; + if (comp != NULL) { + if (!printedHeader) { + printedHeader = true; + tty->cr(); + tty->print_cr("Individual compiler times (for compiled methods only)"); + tty->print_cr("------------------------------------------------"); + tty->cr(); + } + CompilerStatistics* stats = comp->stats(); + + standard_compilation.add(stats->_standard._time); + osr_compilation.add(stats->_osr._time); + + standard_bytes_compiled += stats->_standard._bytes; + osr_bytes_compiled += stats->_osr._bytes; + + standard_compile_count += stats->_standard._count; + osr_compile_count += stats->_osr._count; + + nmethods_size += stats->_nmethods_size; + nmethods_code_size += stats->_nmethods_code_size; + + tty->print_cr(" %s { speed: %d bytes/s; standard: %6.3f s, %d bytes, %d methods; osr: %6.3f s, %d bytes, %d methods; nmethods_size: %d bytes; nmethods_code_size: %d bytes}", + comp->name(), stats->bytes_per_second(), + stats->_standard._time.seconds(), stats->_standard._bytes, stats->_standard._count, + stats->_osr._time.seconds(), stats->_osr._bytes, stats->_osr._count, + stats->_nmethods_size, stats->_nmethods_code_size); + } + } + total_compile_count = osr_compile_count + standard_compile_count; + total_compilation.add(osr_compilation); + total_compilation.add(standard_compilation); +#else + elapsedTimer standard_compilation = CompileBroker::_t_standard_compilation; + elapsedTimer osr_compilation = CompileBroker::_t_osr_compilation; + elapsedTimer total_compilation = CompileBroker::_t_total_compilation; + + int standard_bytes_compiled = CompileBroker::_sum_standard_bytes_compiled; + int osr_bytes_compiled = CompileBroker::_sum_osr_bytes_compiled; + + int standard_compile_count = CompileBroker::_total_standard_compile_count; + int osr_compile_count = CompileBroker::_total_osr_compile_count; + int total_compile_count = CompileBroker::_total_compile_count; + + int nmethods_size = CompileBroker::_sum_nmethod_code_size; + int nmethods_code_size = CompileBroker::_sum_nmethod_size; +#endif + tty->cr(); tty->print_cr("Accumulated compiler times (for compiled methods only)"); tty->print_cr("------------------------------------------------"); //0000000000111111111122222222223333333333444444444455555555556666666666 //0123456789012345678901234567890123456789012345678901234567890123456789 - tty->print_cr(" Total compilation time : %6.3f s", CompileBroker::_t_total_compilation.seconds()); + tty->print_cr(" Total compilation time : %6.3f s", total_compilation.seconds()); tty->print_cr(" Standard compilation : %6.3f s, Average : %2.3f", - CompileBroker::_t_standard_compilation.seconds(), - CompileBroker::_t_standard_compilation.seconds() / CompileBroker::_total_standard_compile_count); - tty->print_cr(" On stack replacement : %6.3f s, Average : %2.3f", CompileBroker::_t_osr_compilation.seconds(), CompileBroker::_t_osr_compilation.seconds() / CompileBroker::_total_osr_compile_count); + standard_compilation.seconds(), + standard_compilation.seconds() / standard_compile_count); + tty->print_cr(" On stack replacement : %6.3f s, Average : %2.3f", osr_compilation.seconds(), osr_compilation.seconds() / osr_compile_count); AbstractCompiler *comp = compiler(CompLevel_simple); if (comp != NULL) { @@ -2216,35 +2280,19 @@ comp->print_timers(); } tty->cr(); - tty->print_cr(" Total compiled methods : %6d methods", CompileBroker::_total_compile_count); - tty->print_cr(" Standard compilation : %6d methods", CompileBroker::_total_standard_compile_count); - tty->print_cr(" On stack replacement : %6d methods", CompileBroker::_total_osr_compile_count); - int tcb = CompileBroker::_sum_osr_bytes_compiled + CompileBroker::_sum_standard_bytes_compiled; + tty->print_cr(" Total compiled methods : %6d methods", total_compile_count); + tty->print_cr(" Standard compilation : %6d methods", standard_compile_count); + tty->print_cr(" On stack replacement : %6d methods", osr_compile_count); + int tcb = osr_bytes_compiled + standard_bytes_compiled; tty->print_cr(" Total compiled bytecodes : %6d bytes", tcb); - tty->print_cr(" Standard compilation : %6d bytes", CompileBroker::_sum_standard_bytes_compiled); - tty->print_cr(" On stack replacement : %6d bytes", CompileBroker::_sum_osr_bytes_compiled); - double tcs = CompileBroker::_t_total_compilation.seconds(); + tty->print_cr(" Standard compilation : %6d bytes", standard_bytes_compiled); + tty->print_cr(" On stack replacement : %6d bytes", osr_bytes_compiled); + double tcs = total_compilation.seconds(); int bps = tcs == 0.0 ? 0 : (int)(tcb / tcs); tty->print_cr(" Average compilation speed: %6d bytes/s", bps); -#ifdef GRAAL - for (unsigned int i = 0; i < sizeof(_compilers) / sizeof(AbstractCompiler*); i++) { - AbstractCompiler* comp = _compilers[i]; - if (comp != NULL) { - CompilerStatistics* stats = comp->stats(); - int bytecodes = stats->_sum_osr_bytes_compiled + stats->_sum_standard_bytes_compiled; - if (bytecodes != 0) { - double seconds = stats->_t_osr_compilation.seconds() + stats->_t_standard_compilation.seconds(); - int bps = seconds == 0.0 ? 0 : (int) (bytecodes / seconds); - tty->print_cr(" %7s compilation speed: %6d bytes/s {standard: %6.3f s, %6d bytes; osr: %6.3f s, %6d bytes}", - comp->name(), bps, stats->_t_standard_compilation.seconds(), stats->_sum_standard_bytes_compiled, - stats->_t_osr_compilation.seconds(), stats->_sum_osr_bytes_compiled); - } - } - } -#endif tty->cr(); - tty->print_cr(" nmethod code size : %6d bytes", CompileBroker::_sum_nmethod_code_size); - tty->print_cr(" nmethod total size : %6d bytes", CompileBroker::_sum_nmethod_size); + tty->print_cr(" nmethod code size : %6d bytes", nmethods_code_size); + tty->print_cr(" nmethod total size : %6d bytes", nmethods_size); } // Debugging output for failure diff -r d70077ca358a -r 6ae55c10796f src/share/vm/graal/graalCompiler.cpp --- a/src/share/vm/graal/graalCompiler.cpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/graal/graalCompiler.cpp Tue Nov 19 01:39:08 2013 +0100 @@ -99,7 +99,8 @@ if (UseCompiler) { bool bootstrap = GRAALVM_ONLY(BootstrapGraal) NOT_GRAALVM(false); - VMToCompiler::startCompiler(bootstrap); + jlong compilerStatisticsAddress = (jlong) ((address) (stats())); + VMToCompiler::startCompiler(bootstrap, compilerStatisticsAddress); _initialized = true; CompilationPolicy::completed_vm_startup(); if (bootstrap) { diff -r d70077ca358a -r 6ae55c10796f src/share/vm/graal/graalCompilerToVM.cpp --- a/src/share/vm/graal/graalCompilerToVM.cpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/graal/graalCompilerToVM.cpp Tue Nov 19 01:39:08 2013 +0100 @@ -732,6 +732,8 @@ set_int("instanceKlassVtableStartOffset", InstanceKlass::vtable_start_offset() * HeapWordSize); + set_long("elapsedTimerFrequency", os::elapsed_frequency()); + //------------------------------------------------------------------------------------------------ set_address("handleDeoptStub", SharedRuntime::deopt_blob()->unpack()); diff -r d70077ca358a -r 6ae55c10796f src/share/vm/graal/graalVMToCompiler.cpp --- a/src/share/vm/graal/graalVMToCompiler.cpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/graal/graalVMToCompiler.cpp Tue Nov 19 01:39:08 2013 +0100 @@ -146,13 +146,14 @@ } } -void VMToCompiler::startCompiler(jboolean bootstrap_enabled) { +void VMToCompiler::startCompiler(jboolean bootstrap_enabled, jlong compilerStatisticsAddress) { JavaThread* THREAD = JavaThread::current(); JavaValue result(T_VOID); JavaCallArguments args; args.push_oop(instance()); args.push_int(bootstrap_enabled); - JavaCalls::call_interface(&result, vmToCompilerKlass(), vmSymbols::startCompiler_name(), vmSymbols::bool_void_signature(), &args, THREAD); + args.push_long(compilerStatisticsAddress); + JavaCalls::call_interface(&result, vmToCompilerKlass(), vmSymbols::startCompiler_name(), vmSymbols::boolean_long_void_signature(), &args, THREAD); check_pending_exception("Error while calling startCompiler"); } diff -r d70077ca358a -r 6ae55c10796f src/share/vm/graal/graalVMToCompiler.hpp --- a/src/share/vm/graal/graalVMToCompiler.hpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/graal/graalVMToCompiler.hpp Tue Nov 19 01:39:08 2013 +0100 @@ -67,7 +67,7 @@ static void shutdownCompiler(); // public abstract void startCompiler(boolean bootstrapEnabled); - static void startCompiler(jboolean bootstrap_enabled); + static void startCompiler(jboolean bootstrap_enabled, jlong compilerStatisticsAddress); // public abstract void bootstrap(); static void bootstrap(); diff -r d70077ca358a -r 6ae55c10796f src/share/vm/runtime/vmStructs.cpp --- a/src/share/vm/runtime/vmStructs.cpp Mon Nov 18 22:12:13 2013 +0100 +++ b/src/share/vm/runtime/vmStructs.cpp Tue Nov 19 01:39:08 2013 +0100 @@ -1283,8 +1283,14 @@ nonstatic_field(FreeList, _size, size_t) \ nonstatic_field(FreeList, _count, ssize_t) \ nonstatic_field(FreeList, _count, ssize_t) \ - nonstatic_field(MetablockTreeDictionary, _total_size, size_t) - + nonstatic_field(MetablockTreeDictionary, _total_size, size_t) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics, _standard, CompilerStatistics::Data)) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics, _osr, CompilerStatistics::Data)) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics, _nmethods_size, int)) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics, _nmethods_code_size, int)) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics::Data, _bytes, int)) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics::Data, _count, int)) \ + GRAAL_ONLY(nonstatic_field(CompilerStatistics::Data, _time, elapsedTimer)) //-------------------------------------------------------------------------------- // VM_TYPES @@ -2143,6 +2149,8 @@ /* Miscellaneous types */ \ /***************/ \ \ + GRAAL_ONLY(declare_toplevel_type(CompilerStatistics)) \ + GRAAL_ONLY(declare_toplevel_type(CompilerStatistics::Data)) \ declare_toplevel_type(PtrQueue) \ \ /* freelist */ \