diff --git a/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/CheckGraalInvariants.java b/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/CheckGraalInvariants.java index 6651dc1df7f4..b83d69580e60 100644 --- a/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/CheckGraalInvariants.java +++ b/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/CheckGraalInvariants.java @@ -84,6 +84,7 @@ import jdk.graal.compiler.nodes.graphbuilderconf.GraphBuilderContext; import jdk.graal.compiler.nodes.graphbuilderconf.InvocationPlugins; import jdk.graal.compiler.nodes.java.LoadFieldNode; +import jdk.graal.compiler.nodes.java.MethodCallTargetNode; import jdk.graal.compiler.nodes.memory.MemoryKill; import jdk.graal.compiler.nodes.memory.MultiMemoryKill; import jdk.graal.compiler.nodes.memory.SingleMemoryKill; @@ -101,6 +102,7 @@ import jdk.graal.compiler.phases.tiers.HighTierContext; import jdk.graal.compiler.phases.util.Providers; import jdk.graal.compiler.runtime.RuntimeProvider; +import jdk.graal.compiler.serviceprovider.GraalServices; import jdk.graal.compiler.test.AddExports; import jdk.graal.compiler.test.SubprocessUtil; import jdk.internal.misc.Unsafe; @@ -195,8 +197,11 @@ public boolean shouldVerifyFoldableMethods() { return true; } - public boolean shouldVerifyCurrentTimeMillis() { - return true; + public void verifyCurrentTimeMillis(MetaAccessProvider meta, MethodCallTargetNode t, ResolvedJavaType declaringClass) { + final ResolvedJavaType services = meta.lookupJavaType(GraalServices.class); + if (!declaringClass.equals(services)) { + throw new VerificationError(t, "Should use System.nanoTime() for measuring elapsed time or GraalServices.milliTimeStamp() for the time since the epoch"); + } } /** @@ -366,9 +371,7 @@ public static void runTest(InvariantsTool tool) { verifiers.add(foldableMethodsVerifier); } - if (tool.shouldVerifyCurrentTimeMillis()) { - verifiers.add(new VerifyCurrentTimeMillisUsage()); - } + verifiers.add(new VerifyCurrentTimeMillisUsage(tool)); tool.updateVerifiers(verifiers); diff --git a/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/VerifyCurrentTimeMillisUsage.java b/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/VerifyCurrentTimeMillisUsage.java index 09284999bb1e..7b156b0ffa83 100644 --- a/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/VerifyCurrentTimeMillisUsage.java +++ b/compiler/src/jdk.graal.compiler.test/src/jdk/graal/compiler/core/test/VerifyCurrentTimeMillisUsage.java @@ -24,6 +24,7 @@ */ package jdk.graal.compiler.core.test; +import jdk.graal.compiler.core.test.CheckGraalInvariants.InvariantsTool; import jdk.graal.compiler.nodes.StructuredGraph; import jdk.graal.compiler.nodes.java.MethodCallTargetNode; import jdk.graal.compiler.nodes.spi.CoreProviders; @@ -40,6 +41,12 @@ public class VerifyCurrentTimeMillisUsage extends VerifyPhase { private static final String CURRENT_TIME_MILLIS_NAME = "currentTimeMillis"; + private final InvariantsTool tool; + + public VerifyCurrentTimeMillisUsage(InvariantsTool tool) { + this.tool = tool; + } + @Override protected void verify(StructuredGraph graph, CoreProviders context) { final ResolvedJavaType systemType = context.getMetaAccess().lookupJavaType(System.class); @@ -48,11 +55,8 @@ protected void verify(StructuredGraph graph, CoreProviders context) { if (callee.getDeclaringClass().equals(systemType)) { String calleeName = callee.getName(); if (calleeName.equals(CURRENT_TIME_MILLIS_NAME)) { - final ResolvedJavaType services = context.getMetaAccess().lookupJavaType(GraalServices.class); - if (graph.method().getDeclaringClass().equals(services)) { - return; - } - throw new VerificationError(t, "Should use System.nanoTime for measuring elapsed time or GraalServices.milliTimeStamp for the time since the epoch"); + final ResolvedJavaType declaringClass = graph.method().getDeclaringClass(); + tool.verifyCurrentTimeMillis(context.getMetaAccess(), t, declaringClass); } } } diff --git a/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/GCImpl.java b/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/GCImpl.java index 2957b52939f7..359a5f4db10b 100644 --- a/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/GCImpl.java +++ b/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/GCImpl.java @@ -127,7 +127,7 @@ public final class GCImpl implements GC { private final CollectionPolicy policy; private boolean completeCollection = false; private UnsignedWord collectionEpoch = WordFactory.zero(); - private long lastWholeHeapExaminedTimeMillis = -1; + private long lastWholeHeapExaminedNanos = -1; @Platforms(Platform.HOSTED_ONLY.class) GCImpl() { @@ -332,7 +332,7 @@ private boolean doCollectOnce(GCCause cause, long requestingNanoTime, boolean co doCollectCore(!complete); if (complete) { - lastWholeHeapExaminedTimeMillis = System.currentTimeMillis(); + lastWholeHeapExaminedNanos = System.nanoTime(); } accounting.afterCollectOnce(completeCollection); @@ -446,7 +446,7 @@ private void printHeapSizeChange(String text, UnsignedWord before, UnsignedWord } private Log printGCPrefixAndTime() { - long uptimeMs = Isolates.getCurrentUptimeMillis(); + long uptimeMs = Isolates.getUptimeMillis(); return Log.log().string("[").rational(uptimeMs, TimeUtils.millisPerSecond, 3).string("s").string("] GC(").unsigned(collectionEpoch).string(") "); } @@ -1145,14 +1145,14 @@ public UnsignedWord getCollectionEpoch() { } public long getMillisSinceLastWholeHeapExamined() { - long startMillis; - if (lastWholeHeapExaminedTimeMillis < 0) { + long start; + if (lastWholeHeapExaminedNanos < 0) { // no full GC has yet been run, use time since the first allocation - startMillis = Isolates.getCurrentStartTimeMillis(); + start = Isolates.getStartTimeNanos(); } else { - startMillis = lastWholeHeapExaminedTimeMillis; + start = lastWholeHeapExaminedNanos; } - return System.currentTimeMillis() - startMillis; + return TimeUtils.millisSinceNanos(start); } @Fold diff --git a/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/Timers.java b/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/Timers.java index 00d0d8649462..cfc9be73fd07 100644 --- a/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/Timers.java +++ b/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/Timers.java @@ -88,7 +88,7 @@ public long getOpenedTime() { if (!wasOpened) { /* If a timer was not opened, pretend it was opened at the start of the VM. */ assert openNanos == 0; - return Isolates.getCurrentStartNanoTime(); + return Isolates.getStartTimeNanos(); } return openNanos; } diff --git a/substratevm/src/com.oracle.svm.core.windows/src/com/oracle/svm/core/windows/WindowsPlatformThreads.java b/substratevm/src/com.oracle.svm.core.windows/src/com/oracle/svm/core/windows/WindowsPlatformThreads.java index 43ef7cb0b02c..fdeffec10ac7 100644 --- a/substratevm/src/com.oracle.svm.core.windows/src/com/oracle/svm/core/windows/WindowsPlatformThreads.java +++ b/substratevm/src/com.oracle.svm.core.windows/src/com/oracle/svm/core/windows/WindowsPlatformThreads.java @@ -216,7 +216,7 @@ protected void park(boolean isAbsolute, long time) { if (time == 0) { millis = SynchAPI.INFINITE() & 0xFFFFFFFFL; } else if (isAbsolute) { - millis = time - System.currentTimeMillis(); + millis = time - TimeUtils.currentTimeMillis(); if (millis <= 0) { /* Already elapsed. */ return; diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/Isolates.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/Isolates.java index f6494a5ac407..078760c71491 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/Isolates.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/Isolates.java @@ -38,6 +38,7 @@ import com.oracle.svm.core.c.CGlobalDataFactory; import com.oracle.svm.core.c.function.CEntryPointErrors; import com.oracle.svm.core.os.CommittedMemoryProvider; +import com.oracle.svm.core.util.TimeUtils; import com.oracle.svm.core.util.VMError; import jdk.graal.compiler.nodes.NamedLocationIdentity; @@ -74,8 +75,8 @@ public class Isolates { /* Only used if SpawnIsolates is disabled. */ private static final CGlobalData SINGLE_ISOLATE_ALREADY_CREATED = CGlobalDataFactory.createWord(); - private static long startTimeMillis; - private static long startNanoTime; + private static long startTimeNanos; + private static long initDoneTimeMillis; private static long isolateId = -1; /** @@ -107,29 +108,30 @@ public static void assignIsolateId(boolean isFirstIsolate) { } } - public static void assignCurrentStartTime() { - assert startTimeMillis == 0 : startTimeMillis; - assert startNanoTime == 0 : startNanoTime; - startTimeMillis = System.currentTimeMillis(); - startNanoTime = System.nanoTime(); + public static void assignStartTime() { + assert startTimeNanos == 0 : startTimeNanos; + assert initDoneTimeMillis == 0 : initDoneTimeMillis; + startTimeNanos = System.nanoTime(); + initDoneTimeMillis = TimeUtils.currentTimeMillis(); } - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static long getCurrentStartTimeMillis() { - assert startTimeMillis != 0; - return startTimeMillis; + /** Epoch-based timestamp. If possible, {@link #getStartTimeNanos()} should be used instead. */ + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) + public static long getInitDoneTimeMillis() { + assert initDoneTimeMillis != 0; + return initDoneTimeMillis; } - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static long getCurrentUptimeMillis() { - assert startTimeMillis != 0; - return System.currentTimeMillis() - startTimeMillis; + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) + public static long getUptimeMillis() { + assert startTimeNanos != 0; + return TimeUtils.millisSinceNanos(startTimeNanos); } - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static long getCurrentStartNanoTime() { - assert startNanoTime != 0; - return startNanoTime; + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) + public static long getStartTimeNanos() { + assert startTimeNanos != 0; + return startTimeNanos; } @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) @@ -169,7 +171,7 @@ public static int create(WordPointer isolatePointer, IsolateArguments arguments) return CEntryPointErrors.NO_ERROR; } - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) public static PointerBase getHeapBase(Isolate isolate) { return isolate; } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/SubstrateDiagnostics.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/SubstrateDiagnostics.java index ccd3b795dce6..fb76f59ebd03 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/SubstrateDiagnostics.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/SubstrateDiagnostics.java @@ -915,8 +915,8 @@ public void printDiagnostics(Log log, ErrorContext context, int maxDiagnosticLev log.string("Page size: ").unsigned(VirtualMemoryProvider.get().getGranularity()).newline(); if (!SubstrateOptions.AsyncSignalSafeDiagnostics.getValue()) { - log.string("VM uptime: ").rational(Isolates.getCurrentUptimeMillis(), TimeUtils.millisPerSecond, 3).string("s").newline(); - log.string("Current timestamp: ").unsigned(System.currentTimeMillis()).newline(); + log.string("VM uptime: ").rational(Isolates.getUptimeMillis(), TimeUtils.millisPerSecond, 3).string("s").newline(); + log.string("Current timestamp: ").unsigned(TimeUtils.currentTimeMillis()).newline(); } CodeInfo info = CodeInfoTable.getFirstImageCodeInfo(); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/code/RuntimeCodeInfoHistory.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/code/RuntimeCodeInfoHistory.java index 21d830b298c7..8236a4fca329 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/code/RuntimeCodeInfoHistory.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/code/RuntimeCodeInfoHistory.java @@ -24,7 +24,6 @@ */ package com.oracle.svm.core.code; -import jdk.graal.compiler.api.replacements.Fold; import org.graalvm.nativeimage.ImageSingletons; import org.graalvm.nativeimage.Platform; import org.graalvm.nativeimage.Platforms; @@ -44,6 +43,8 @@ import com.oracle.svm.core.thread.VMThreads; import com.oracle.svm.core.util.TimeUtils; +import jdk.graal.compiler.api.replacements.Fold; + public class RuntimeCodeInfoHistory { private static final RingBuffer.Consumer PRINT_WITH_JAVA_HEAP_DATA = RuntimeCodeInfoHistory::printEntryWithJavaHeapData; private static final RingBuffer.Consumer PRINT_WITHOUT_JAVA_HEAP_DATA = RuntimeCodeInfoHistory::printEntryWithoutJavaHeapData; @@ -120,7 +121,7 @@ private static void printEntry(Object context, CodeCacheLogEntry entry, boolean } private static class CodeCacheLogEntry { - private long timestamp; + private long uptimeMillis; private String kind; private String codeName; private CodeInfo codeInfo; @@ -142,7 +143,7 @@ public void setValues(String kind, CodeInfo codeInfo, int codeInfoState, String assert Heap.getHeap().isInImageHeap(kind); this.safepointId = Safepoint.Master.singleton().getSafepointId(); - this.timestamp = System.currentTimeMillis(); + this.uptimeMillis = Isolates.getUptimeMillis(); this.kind = kind; this.codeInfo = codeInfo; this.codeInfoState = codeInfoState; @@ -162,8 +163,7 @@ public void setValues(String kind, CodeInfo codeInfo, int codeInfoState, String public void print(Log log, boolean allowJavaHeapAccess) { if (kind != null) { - long uptime = timestamp - Isolates.getCurrentStartTimeMillis(); - log.rational(uptime, TimeUtils.millisPerSecond, 3).string("s - ").string(kind).spaces(1); + log.rational(uptimeMillis, TimeUtils.millisPerSecond, 3).string("s - ").string(kind).spaces(1); String name = allowJavaHeapAccess ? codeName : null; CodeInfoAccess.printCodeInfo(log, codeInfo, codeInfoState, name, codeStart, codeEnd, hasInstalledCode, installedCodeAddress, installedCodeEntryPoint); log.string(", safepointId: ").unsigned(safepointId).newline(); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/container/Container.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/container/Container.java index d027983e673b..515976578701 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/container/Container.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/container/Container.java @@ -39,6 +39,7 @@ import com.oracle.svm.core.c.CGlobalData; import com.oracle.svm.core.c.CGlobalDataFactory; import com.oracle.svm.core.feature.AutomaticallyRegisteredImageSingleton; +import com.oracle.svm.core.util.TimeUtils; import com.oracle.svm.core.util.VMError; import jdk.graal.compiler.api.replacements.Fold; @@ -124,7 +125,7 @@ public static void initialize() { public int getActiveProcessorCount() { VMError.guarantee(isContainerized()); - long currentMs = System.currentTimeMillis(); + long currentMs = TimeUtils.currentTimeMillis(); if (currentMs > activeProcessorCountTimeoutMs) { cachedActiveProcessorCount = ContainerLibrary.getActiveProcessorCount(); activeProcessorCountTimeoutMs = currentMs + CACHE_MS; @@ -142,7 +143,7 @@ public int getCachedActiveProcessorCount() { public UnsignedWord getPhysicalMemory() { VMError.guarantee(isContainerized()); - long currentMs = System.currentTimeMillis(); + long currentMs = TimeUtils.currentTimeMillis(); if (currentMs > physicalMemoryTimeoutMs) { cachedPhysicalMemorySize = ContainerLibrary.physicalMemory(); physicalMemoryTimeoutMs = currentMs + CACHE_MS; @@ -160,7 +161,7 @@ public UnsignedWord getCachedPhysicalMemory() { public long getMemoryLimitInBytes() { VMError.guarantee(isContainerized()); - long currentMs = System.currentTimeMillis(); + long currentMs = TimeUtils.currentTimeMillis(); if (currentMs > memoryLimitInBytesTimeoutMs) { cachedMemoryLimitInBytes = ContainerLibrary.getMemoryLimitInBytes(); memoryLimitInBytesTimeoutMs = currentMs + CACHE_MS; diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/dcmd/VMUptimeDmd.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/dcmd/VMUptimeDmd.java index db165d53e072..a5e8c9caf980 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/dcmd/VMUptimeDmd.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/dcmd/VMUptimeDmd.java @@ -44,7 +44,7 @@ public VMUptimeDmd() { @BasedOnJDKFile("https://github.com/openjdk/jdk/blob/jdk-24+18/src/hotspot/share/services/diagnosticCommand.cpp#L393-L400") public String execute(DCmdArguments args) throws Throwable { StringBuilderLog log = new StringBuilderLog(); - log.rational(Isolates.getCurrentUptimeMillis(), TimeUtils.millisPerSecond, 3).string(" s").newline(); + log.rational(Isolates.getUptimeMillis(), TimeUtils.millisPerSecond, 3).string(" s").newline(); return log.getResult(); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/deopt/Deoptimizer.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/deopt/Deoptimizer.java index 0ad7af87d4ee..2dbecf6ff31c 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/deopt/Deoptimizer.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/deopt/Deoptimizer.java @@ -1030,7 +1030,7 @@ protected static void writeValueInMaterializedObj(Object materializedObj, Unsign } private static void printDeoptimizedFrame(Log log, Pointer sp, DeoptimizedFrame deoptimizedFrame, FrameInfoQueryResult sourceFrameInfo, boolean printOnlyTopFrames) { - log.string("[Deoptimization of frame (").rational(Isolates.getCurrentUptimeMillis(), TimeUtils.millisPerSecond, 3).string("s)").newline(); + log.string("[Deoptimization of frame (").rational(Isolates.getUptimeMillis(), TimeUtils.millisPerSecond, 3).string("s)").newline(); SubstrateInstalledCode installedCode = deoptimizedFrame.getSourceInstalledCode(); if (installedCode != null) { diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/graal/snippets/CEntryPointSnippets.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/graal/snippets/CEntryPointSnippets.java index 4634e667cfe8..564d5a944f46 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/graal/snippets/CEntryPointSnippets.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/graal/snippets/CEntryPointSnippets.java @@ -405,7 +405,7 @@ private static int initializeIsolateInterruptibly1(CEntryPointCreateIsolateParam boolean firstIsolate = Unsafe.getUnsafe().compareAndSetInt(null, initStateAddr, FirstIsolateInitStates.UNINITIALIZED, FirstIsolateInitStates.IN_PROGRESS); Isolates.assignIsolateId(firstIsolate); - Isolates.assignCurrentStartTime(); + Isolates.assignStartTime(); if (!firstIsolate) { int state = Unsafe.getUnsafe().getInt(initStateAddr); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpSupportImpl.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpSupportImpl.java index 4e86832cd10a..173fae2fecab 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpSupportImpl.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpSupportImpl.java @@ -118,10 +118,10 @@ private void dumpHeapOnOutOfMemoryError0() { try { Log.log().string("Dumping heap to ").string(path).string(" ...").newline(); - long start = System.currentTimeMillis(); + long start = System.nanoTime(); if (dumpHeap(fd, false)) { long fileSize = getFileSupport().size(fd); - long elapsedMs = System.currentTimeMillis() - start; + long elapsedMs = TimeUtils.millisSinceNanos(start); long seconds = elapsedMs / TimeUtils.millisPerSecond; long ms = elapsedMs % TimeUtils.millisPerSecond; Log.log().string("Heap dump file created [").signed(fileSize).string(" bytes in ").signed(seconds).character('.').signed(ms).string(" secs]").newline(); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpWriter.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpWriter.java index f336414616ca..3e540f152d02 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpWriter.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumpWriter.java @@ -85,6 +85,7 @@ import com.oracle.svm.core.thread.VMOperation; import com.oracle.svm.core.thread.VMThreads; import com.oracle.svm.core.threadlocal.VMThreadLocalSupport; +import com.oracle.svm.core.util.TimeUtils; import com.oracle.svm.core.util.VMError; import jdk.graal.compiler.api.replacements.Fold; @@ -504,7 +505,7 @@ private void writeHeader() { writeUTF8("JAVA PROFILE 1.0.2"); writeByte((byte) 0); writeInt(wordSize()); - writeLong(System.currentTimeMillis()); + writeLong(TimeUtils.currentTimeMillis()); } private void startTopLevelRecord(HProfTopLevelRecord tag) { diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumping.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumping.java index 197f41adef61..1d2df93e0b46 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumping.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/heap/dump/HeapDumping.java @@ -28,12 +28,14 @@ import java.nio.file.Files; import java.nio.file.Paths; -import jdk.graal.compiler.api.replacements.Fold; import org.graalvm.nativeimage.ImageSingletons; import org.graalvm.nativeimage.ProcessProperties; import org.graalvm.nativeimage.impl.HeapDumpSupport; import com.oracle.svm.core.SubstrateOptions; +import com.oracle.svm.core.util.TimeUtils; + +import jdk.graal.compiler.api.replacements.Fold; public abstract class HeapDumping implements HeapDumpSupport { @Fold @@ -58,7 +60,7 @@ public static String getHeapDumpPath(String defaultFilename) { } public void dumpHeap(boolean gcBefore) throws IOException { - String suffix = Long.toString(System.currentTimeMillis()); + String suffix = Long.toString(TimeUtils.currentTimeMillis()); String defaultFilename = getDefaultHeapDumpFilename(suffix); dumpHeap(getHeapDumpPath(defaultFilename), gcBefore); } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/RandomAccessors.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/RandomAccessors.java index eac5b488756e..7eff41b63ec5 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/RandomAccessors.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/RandomAccessors.java @@ -27,6 +27,8 @@ import java.util.concurrent.atomic.AtomicLong; +import com.oracle.svm.core.util.TimeUtils; + /** * RandomAccessors initializes a seeder at run time, on first access. The mechanism is used by both * SplittableRandomAccessors and ThreadLocalRandomAccessors since they share the same seeder @@ -76,7 +78,7 @@ private synchronized AtomicLong initialize() { seed = (seed << 8) | (seedBytes[i] & 0xffL); } } else { - seed = mix64(System.currentTimeMillis()) ^ mix64(System.nanoTime()); + seed = mix64(TimeUtils.currentTimeMillis()) ^ mix64(System.nanoTime()); } result = new AtomicLong(seed); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/management/SubstrateRuntimeMXBean.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/management/SubstrateRuntimeMXBean.java index 15ab9437ee4b..15f9a376f6a1 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/management/SubstrateRuntimeMXBean.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/management/SubstrateRuntimeMXBean.java @@ -70,22 +70,16 @@ public ObjectName getObjectName() { return Util.newObjectName(ManagementFactory.RUNTIME_MXBEAN_NAME); } - @SuppressWarnings("deprecation") @Override public String getName() { - long id; - String hostName; - try { - id = ProcessProperties.getProcessID(); - } catch (Throwable t) { - id = Isolates.getCurrentStartTimeMillis(); - } + long pid = ProcessProperties.getProcessID(); + String hostName = "localhost"; try { hostName = InetAddress.getLocalHost().getHostName(); } catch (UnknownHostException e) { - hostName = "localhost"; + // ignore } - return id + "@" + hostName; + return pid + "@" + hostName; } /* All remaining methods are unsupported on Substrate VM. */ @@ -147,13 +141,13 @@ public String getBootClassPath() { @Override public long getUptime() { - return Isolates.getCurrentUptimeMillis(); + return Isolates.getUptimeMillis(); } @Override @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) public long getStartTime() { - return Isolates.getCurrentStartTimeMillis(); + return Isolates.getInitDoneTimeMillis(); } /** Copied from {@code sun.management.RuntimeImpl#getSystemProperties()}. */ diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/resources/NativeImageResourceFileSystem.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/resources/NativeImageResourceFileSystem.java index 18b49814b1ad..dbc447cd3983 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/resources/NativeImageResourceFileSystem.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/resources/NativeImageResourceFileSystem.java @@ -84,11 +84,12 @@ import java.util.concurrent.locks.ReentrantReadWriteLock; import java.util.regex.Pattern; -import com.oracle.svm.core.configure.ConditionalRuntimeValue; import org.graalvm.collections.MapCursor; import com.oracle.svm.core.MissingRegistrationUtils; +import com.oracle.svm.core.configure.ConditionalRuntimeValue; import com.oracle.svm.core.jdk.Resources; +import com.oracle.svm.core.util.TimeUtils; /** *

@@ -111,7 +112,7 @@ public class NativeImageResourceFileSystem extends FileSystem { private final Set outputStreams = Collections.synchronizedSet(new HashSet<>()); private final Set tmpPaths = Collections.synchronizedSet(new HashSet<>()); - private final long defaultTimestamp = System.currentTimeMillis(); + private final long defaultTimestamp = TimeUtils.currentTimeMillis(); private final NativeImageResourceFileSystemProvider provider; private final Path resourcePath; @@ -544,7 +545,7 @@ void copyFile(boolean deleteSource, byte[] src, byte[] dst, CopyOption[] options } } if (!hasCopyAttrs) { - target.lastModifiedTime = target.lastAccessTime = target.createTime = System.currentTimeMillis(); + target.lastModifiedTime = target.lastAccessTime = target.createTime = TimeUtils.currentTimeMillis(); } update(target); if (deleteSource) { @@ -737,7 +738,7 @@ private InputStream getInputStream(Entry e) throws IOException { private OutputStream getOutputStream(Entry e) { e.getBytes(false); if (e.lastModifiedTime == -1) { - e.lastModifiedTime = System.currentTimeMillis(); + e.lastModifiedTime = TimeUtils.currentTimeMillis(); } OutputStream os = new EntryOutputStream(e, new ByteArrayOutputStream((e.size > 0) ? e.size : DEFAULT_BUFFER_SIZE)); outputStreams.add(os); @@ -935,7 +936,7 @@ public FileLock tryLock(long position, long size, boolean shared) throws IOExcep protected void implCloseChannel() throws IOException { fch.close(); if (forWrite) { - target.lastModifiedTime = System.currentTimeMillis(); + target.lastModifiedTime = TimeUtils.currentTimeMillis(); target.size = (int) Files.size(target.file); update(target); @@ -1114,7 +1115,7 @@ class Entry extends IndexNode { } void initTimes() { - this.lastModifiedTime = this.lastAccessTime = this.createTime = System.currentTimeMillis(); + this.lastModifiedTime = this.lastAccessTime = this.createTime = TimeUtils.currentTimeMillis(); } void initData() { @@ -1183,7 +1184,7 @@ class EntryOutputChannel extends ByteArrayChannel { super(e.size > 0 ? e.size : DEFAULT_BUFFER_SIZE, false); this.e = e; if (e.lastModifiedTime == -1) { - e.lastModifiedTime = System.currentTimeMillis(); + e.lastModifiedTime = TimeUtils.currentTimeMillis(); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jvmstat/SystemCounters.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jvmstat/SystemCounters.java index 45d3805b9e6f..1600ef439029 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jvmstat/SystemCounters.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jvmstat/SystemCounters.java @@ -32,6 +32,7 @@ import org.graalvm.nativeimage.Platform; import org.graalvm.nativeimage.Platforms; +import com.oracle.svm.core.Isolates; import com.oracle.svm.core.JavaMainWrapper; import com.oracle.svm.core.Uninterruptible; import com.oracle.svm.core.attach.AttachApiSupport; @@ -147,7 +148,7 @@ public void allocate() { daemonThreads.allocate(); processCPUTimeCounter.allocate(); - initDoneTime.allocate(System.currentTimeMillis()); + initDoneTime.allocate(Isolates.getInitDoneTimeMillis()); } private static String getSystemProperty(String s) { diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/VMOperationControl.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/VMOperationControl.java index 410f5ae151a5..976ae88778e3 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/VMOperationControl.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/VMOperationControl.java @@ -894,7 +894,7 @@ private static class VMOpHistory { public void add(VMOpStatus status, VMOperation operation, IsolateThread queueingThread, IsolateThread executingThread, int nestingLevel) { assert Heap.getHeap().isInImageHeap(status); VMOpStatusChange entry = history.next(); - entry.timestamp = System.currentTimeMillis(); + entry.uptimeMillis = Isolates.getUptimeMillis(); entry.status = status; entry.name = operation.getName(); entry.causesSafepoint = operation.getCausesSafepoint(); @@ -936,7 +936,7 @@ private enum VMOpStatus { * data structures). */ private static class VMOpStatusChange { - long timestamp; + long uptimeMillis; VMOpStatus status; String name; boolean causesSafepoint; @@ -952,8 +952,7 @@ private static class VMOpStatusChange { void print(Log log, boolean allowJavaHeapAccess) { VMOpStatus localStatus = status; if (localStatus != null) { - long uptime = timestamp - Isolates.getCurrentStartTimeMillis(); - log.rational(uptime, TimeUtils.millisPerSecond, 3).string("s - ").spaces(nestingLevel * 2).string(localStatus.name()); + log.rational(uptimeMillis, TimeUtils.millisPerSecond, 3).string("s - ").spaces(nestingLevel * 2).string(localStatus.name()); if (allowJavaHeapAccess) { log.string(" ").string(name); } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/util/TimeUtils.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/util/TimeUtils.java index ac53e26359d7..bbd1100154ba 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/util/TimeUtils.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/util/TimeUtils.java @@ -24,6 +24,8 @@ */ package com.oracle.svm.core.util; +import static com.oracle.svm.core.Uninterruptible.CALLED_FROM_UNINTERRUPTIBLE_CODE; + import org.graalvm.word.UnsignedWord; import org.graalvm.word.WordFactory; @@ -69,8 +71,19 @@ public static long microsToNanos(long micros) { } /** Nanoseconds since a previous {@link System#nanoTime()} call. */ + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) public static long nanoSecondsSince(long startNanos) { - return (System.nanoTime() - startNanos); + return System.nanoTime() - startNanos; + } + + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) + public static long millisSinceNanos(long startNanos) { + return millisSinceNanos(System.nanoTime(), startNanos); + } + + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) + public static long millisSinceNanos(long nowNanos, long startNanos) { + return roundNanosToMillis(nowNanos - startNanos); } /** @@ -105,6 +118,7 @@ public static long divideNanosToMillis(long nanos) { } /** Round the number of nanoseconds to milliseconds. */ + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) public static long roundNanosToMillis(long nanos) { return roundedDivide(nanos, nanosPerMilli); } @@ -120,6 +134,7 @@ public static long roundNanosToSeconds(long nanos) { } /* Divide, rounding to the nearest long. */ + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) public static long roundedDivide(long numerator, long denominator) { final long halfStep = denominator / 2L; final long addition = addOrMaxValue(numerator, halfStep); @@ -201,4 +216,13 @@ public static boolean maybeFatallyTooLong(long startNanos, long failureNanos, St } return false; } + + /** + * For measuring elapsed time, {@link System#nanoTime()} should be used because + * {@link System#currentTimeMillis()} is affected by adjustment of the system time. + */ + @Uninterruptible(reason = CALLED_FROM_UNINTERRUPTIBLE_CODE, mayBeInlined = true) + public static long currentTimeMillis() { + return System.currentTimeMillis(); + } } diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/ProgressReporter.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/ProgressReporter.java index 20d039e67298..a313f80ec77e 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/ProgressReporter.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/ProgressReporter.java @@ -81,6 +81,7 @@ import com.oracle.svm.core.option.OptionUtils; import com.oracle.svm.core.option.RuntimeOptionKey; import com.oracle.svm.core.option.SubstrateOptionsParser; +import com.oracle.svm.core.util.TimeUtils; import com.oracle.svm.core.util.UserError; import com.oracle.svm.core.util.VMError; import com.oracle.svm.hosted.ProgressReporterFeature.UserRecommendation; @@ -112,7 +113,7 @@ public class ProgressReporter implements FeatureSingleton, UnsavedSingleton { private static final String LINE_SEPARATOR; private static final int MAX_NUM_BREAKDOWN = 10; public static final String DOCS_BASE_URL = "https://github.com/oracle/graal/blob/master/docs/reference-manual/native-image/BuildOutput.md"; - private static final double EXCESSIVE_GC_MIN_THRESHOLD_MILLIS = 15_000; + private static final double EXCESSIVE_GC_MIN_THRESHOLD_MILLIS = TimeUtils.secondsToMillis(15); private static final double EXCESSIVE_GC_RATIO = 0.5; private final NativeImageSystemIOWrappers builderIO; @@ -125,7 +126,7 @@ public class ProgressReporter implements FeatureSingleton, UnsavedSingleton { private final LinkStrategy linkStrategy; private final ScheduledExecutorService executor = Executors.newSingleThreadScheduledExecutor(); - private long lastGCCheckTimeMillis = System.currentTimeMillis(); + private long lastGCCheckTimeNanos = System.nanoTime(); private GCStats lastGCStats = GCStats.getCurrent(); private long numRuntimeCompiledMethods = -1; private int numJNIClasses = -1; @@ -826,7 +827,7 @@ private static Path reportImageBuildStatistics() { } private void printResourceStatistics() { - double totalProcessTimeSeconds = Utils.millisToSeconds(System.currentTimeMillis() - ManagementFactory.getRuntimeMXBean().getStartTime()); + double totalProcessTimeSeconds = Utils.millisToSeconds(ManagementFactory.getRuntimeMXBean().getUptime()); GCStats gcStats = GCStats.getCurrent(); double gcSeconds = Utils.millisToSeconds(gcStats.totalTimeMillis); recordJsonMetric(ResourceUsageKey.GC_COUNT, gcStats.totalCount); @@ -850,9 +851,9 @@ private void printResourceStatistics() { } private void checkForExcessiveGarbageCollection() { - long current = System.currentTimeMillis(); - long timeDeltaMillis = current - lastGCCheckTimeMillis; - lastGCCheckTimeMillis = current; + long nowNanos = System.nanoTime(); + long timeDeltaMillis = TimeUtils.millisSinceNanos(nowNanos, lastGCCheckTimeNanos); + lastGCCheckTimeNanos = nowNanos; GCStats currentGCStats = GCStats.getCurrent(); long gcTimeDeltaMillis = currentGCStats.totalTimeMillis - lastGCStats.totalTimeMillis; double ratio = gcTimeDeltaMillis / (double) timeDeltaMillis; @@ -963,9 +964,9 @@ private static GCStats getCurrent() { return new GCStats(totalCount, totalTime); } - GCStats(long totalCount, long totalTime) { + GCStats(long totalCount, long totalTimeMillis) { this.totalCount = totalCount; - this.totalTimeMillis = totalTime; + this.totalTimeMillis = totalTimeMillis; } } diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/TemporaryBuildDirectoryProviderImpl.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/TemporaryBuildDirectoryProviderImpl.java index 923d31a92723..4c038dbf8aa7 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/TemporaryBuildDirectoryProviderImpl.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/TemporaryBuildDirectoryProviderImpl.java @@ -33,6 +33,7 @@ import java.util.Optional; import com.oracle.svm.core.c.libc.TemporaryBuildDirectoryProvider; +import com.oracle.svm.core.util.TimeUtils; import com.oracle.svm.core.util.VMError; public class TemporaryBuildDirectoryProviderImpl implements TemporaryBuildDirectoryProvider, AutoCloseable { @@ -49,7 +50,7 @@ public synchronized Path getTemporaryBuildDirectory() { tempDirectory = Files.createTempDirectory("SVM-"); deleteTempDirectory = true; } else { - tempDirectory = tempName.get().resolve("SVM-" + System.currentTimeMillis()); + tempDirectory = tempName.get().resolve("SVM-" + TimeUtils.currentTimeMillis()); assert !Files.exists(tempDirectory); Files.createDirectories(tempDirectory); }