8263332: JFR: Dump recording from a recording stream

Reviewed-by: mgronlun

src/hotspot/share/jfr/recorder/repository/jfrChunk.cpp

@@ -37,13 +37,16 @@ static const u2 JFR_VERSION_MINOR = 1;
 // strictly monotone
 static jlong nanos_now() {
   static jlong last = 0;
-  // We use javaTimeMillis so this can be correlated with
-  // external timestamps.
-  const jlong now = os::javaTimeMillis() * JfrTimeConverter::NANOS_PER_MILLISEC;
+
+  jlong seconds;
+  jlong nanos;
+  // Use same clock source as Instant.now() to ensure
+  // that Recording::getStopTime() returns an Instant that
+  // is in sync.
+  os::javaTimeSystemUTC(seconds, nanos);
+  const jlong now = seconds * 1000000000 + nanos;
   if (now > last) {
     last = now;
-  } else {
-    ++last;
   }
   return last;
 }
@@ -124,7 +127,6 @@ int64_t JfrChunk::start_ticks() const {
 }
 
 int64_t JfrChunk::start_nanos() const {
-  assert(_start_nanos != 0, "invariant");
   return _start_nanos;
 }
 
@@ -144,14 +146,14 @@ void JfrChunk::update_start_ticks() {
 
 void JfrChunk::update_start_nanos() {
   const jlong now = nanos_now();
-  assert(now > _start_nanos, "invariant");
-  assert(now > _last_update_nanos, "invariant");
+  assert(now >= _start_nanos, "invariant");
+  assert(now >= _last_update_nanos, "invariant");
   _start_nanos = _last_update_nanos = now;
 }
 
 void JfrChunk::update_current_nanos() {
   const jlong now = nanos_now();
-  assert(now > _last_update_nanos, "invariant");
+  assert(now >= _last_update_nanos, "invariant");
   _last_update_nanos = now;
 }
 

src/hotspot/share/jfr/recorder/repository/jfrChunkWriter.cpp

@@ -254,7 +254,7 @@ int64_t JfrChunkWriter::last_checkpoint_offset() const {
 
 int64_t JfrChunkWriter::current_chunk_start_nanos() const {
   assert(_chunk != NULL, "invariant");
-  return this->is_valid() ? _chunk->start_nanos() : invalid_time;
+  return _chunk->start_nanos();
 }
 
 void JfrChunkWriter::set_last_checkpoint_offset(int64_t offset) {

src/jdk.jfr/share/classes/jdk/jfr/consumer/RecordingStream.java

@@ -26,20 +26,23 @@
 package jdk.jfr.consumer;
 
 import java.io.IOException;
+import java.nio.file.Path;
 import java.security.AccessControlContext;
 import java.security.AccessController;
 import java.time.Duration;
 import java.time.Instant;
 import java.util.Collections;
 import java.util.List;
 import java.util.Map;
+import java.util.Objects;
 import java.util.function.Consumer;
 
 import jdk.jfr.Configuration;
 import jdk.jfr.Event;
 import jdk.jfr.EventSettings;
 import jdk.jfr.EventType;
 import jdk.jfr.Recording;
+import jdk.jfr.RecordingState;
 import jdk.jfr.internal.PlatformRecording;
 import jdk.jfr.internal.PrivateAccess;
 import jdk.jfr.internal.SecuritySupport;
@@ -402,6 +405,41 @@ public void startAsync() {
         directoryStream.startAsync(startNanos);
     }
 
+    /**
+     * Writes recording data to a file.
+     * <p>
+     * The recording stream must be started, but not closed.
+     * <p>
+     * It's highly recommended that a max age or max size is set before
+     * starting the stream. Otherwise, the dump may not contain any events.
+     *
+     * @param destination the location where recording data is written, not
+     *        {@code null}
+     *
+     * @throws IOException if the recording data can't be copied to the specified
+     *         location, or if the stream is closed, or not started.
+     *
+     * @throws SecurityException if a security manager exists and the caller doesn't
+     *         have {@code FilePermission} to write to the destination path
+     *
+     * @see RecordingStream#setMaxAge(Duration)
+     * @see RecordingStream#setMaxSize(Duration)
+     */
+    public void dump(Path destination) throws IOException {
+        Objects.requireNonNull(destination);
+        Object recorder = PrivateAccess.getInstance().getPlatformRecorder();
+        synchronized (recorder) {
+            RecordingState state = recording.getState();
+            if (state == RecordingState.CLOSED) {
+                throw new IOException("Recording stream has been closed, no content to write");
+            }
+            if (state == RecordingState.NEW) {
+                throw new IOException("Recording stream has not been started, no content to write");
+            }
+            recording.dump(destination);
+        }
+    }
+
     @Override
     public void awaitTermination(Duration timeout) throws InterruptedException {
         directoryStream.awaitTermination(timeout);

src/jdk.jfr/share/classes/jdk/jfr/internal/MetadataRepository.java

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2016, 2020, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2016, 2021, 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
@@ -31,6 +31,7 @@
 import java.io.ByteArrayOutputStream;
 import java.io.DataOutputStream;
 import java.io.IOException;
+import java.time.Instant;
 import java.util.ArrayList;
 import java.util.Collections;
 import java.util.HashMap;
@@ -62,6 +63,7 @@ public final class MetadataRepository {
     private boolean staleMetadata = true;
     private boolean unregistered;
     private long lastUnloaded = -1;
+    private Instant outputChange;
 
     public MetadataRepository() {
         initializeJVMEventTypes();
@@ -263,11 +265,13 @@ synchronized void setStaleMetadata() {
     // Lock around setOutput ensures that other threads don't
     // emit events after setOutput and unregister the event class, before a call
     // to storeDescriptorInJVM
-    synchronized void setOutput(String filename) {
+    synchronized Instant setOutput(String filename) {
         if (staleMetadata) {
             storeDescriptorInJVM();
         }
+        awaitUniqueTimestamp();
         jvm.setOutput(filename);
+        long nanos = jvm.getChunkStartNanos();
         if (filename != null) {
             RepositoryFiles.notifyNewFile();
         }
@@ -278,6 +282,29 @@ synchronized void setOutput(String filename) {
             }
             unregistered = false;
         }
+        return Utils.epochNanosToInstant(nanos);
+    }
+
+    // Each chunk needs a unique start timestamp and
+    // if the clock resolution is low, two chunks may
+    // get the same timestamp.
+    private void awaitUniqueTimestamp() {
+        if (outputChange == null) {
+            outputChange = Instant.now();
+            return;
+        }
+        while (true) {
+            Instant time = Instant.now();
+            if (!time.equals(outputChange)) {
+                outputChange = time;
+                return;
+            }
+            try {
+                Thread.sleep(0, 100);
+            } catch (InterruptedException iex) {
+                // ignore
+            }
+        }
     }
 
     private void unregisterUnloaded() {

src/jdk.jfr/share/classes/jdk/jfr/internal/PlatformRecorder.java

@@ -222,14 +222,7 @@ synchronized void destroy() {
 
     synchronized long start(PlatformRecording recording) {
         // State can only be NEW or DELAYED because of previous checks
-        ZonedDateTime zdtNow = ZonedDateTime.now();
-        Instant now = zdtNow.toInstant();
-        recording.setStartTime(now);
-        recording.updateTimer();
-        Duration duration = recording.getDuration();
-        if (duration != null) {
-            recording.setStopTime(now.plus(duration));
-        }
+        Instant startTime = null;
         boolean toDisk = recording.isToDisk();
         boolean beginPhysical = true;
         long streamInterval = recording.getStreamIntervalMillis();
@@ -246,7 +239,7 @@ synchronized long start(PlatformRecording recording) {
         if (beginPhysical) {
             RepositoryChunk newChunk = null;
             if (toDisk) {
-                newChunk = repository.newChunk(zdtNow);
+                newChunk = repository.newChunk();
                 if (EventLog.shouldLog()) {
                     EventLog.start();
                 }
@@ -257,47 +250,59 @@ synchronized long start(PlatformRecording recording) {
             currentChunk = newChunk;
             jvm.beginRecording();
             startNanos = jvm.getChunkStartNanos();
+            startTime = Utils.epochNanosToInstant(startNanos);
+            if (currentChunk != null) {
+                currentChunk.setStartTime(startTime);
+            }
             recording.setState(RecordingState.RUNNING);
             updateSettings();
+            recording.setStartTime(startTime);
             writeMetaEvents();
         } else {
             RepositoryChunk newChunk = null;
             if (toDisk) {
-                newChunk = repository.newChunk(zdtNow);
+                newChunk = repository.newChunk();
                 if (EventLog.shouldLog()) {
                     EventLog.start();
                 }
                 RequestEngine.doChunkEnd();
-                MetadataRepository.getInstance().setOutput(newChunk.getFile().toString());
-                startNanos = jvm.getChunkStartNanos();
+                String p = newChunk.getFile().toString();
+                startTime = MetadataRepository.getInstance().setOutput(p);
+                newChunk.setStartTime(startTime);
             }
+            startNanos = jvm.getChunkStartNanos();
+            startTime = Utils.epochNanosToInstant(startNanos);
+            recording.setStartTime(startTime);
             recording.setState(RecordingState.RUNNING);
             updateSettings();
             writeMetaEvents();
             if (currentChunk != null) {
-                finishChunk(currentChunk, now, recording);
+                finishChunk(currentChunk, startTime, recording);
             }
             currentChunk = newChunk;
         }
         if (toDisk) {
             RequestEngine.setFlushInterval(streamInterval);
         }
         RequestEngine.doChunkBegin();
-
+        Duration duration = recording.getDuration();
+        if (duration != null) {
+            recording.setStopTime(startTime.plus(duration));
+        }
+        recording.updateTimer();
         return startNanos;
     }
 
     synchronized void stop(PlatformRecording recording) {
         RecordingState state = recording.getState();
+        Instant stopTime;
 
         if (Utils.isAfter(state, RecordingState.RUNNING)) {
             throw new IllegalStateException("Can't stop an already stopped recording.");
         }
         if (Utils.isBefore(state, RecordingState.RUNNING)) {
             throw new IllegalStateException("Recording must be started before it can be stopped.");
         }
-        ZonedDateTime zdtNow = ZonedDateTime.now();
-        Instant now = zdtNow.toInstant();
         boolean toDisk = false;
         boolean endPhysical = true;
         long streamInterval = Long.MAX_VALUE;
@@ -317,33 +322,37 @@ synchronized void stop(PlatformRecording recording) {
         if (endPhysical) {
             RequestEngine.doChunkEnd();
             if (recording.isToDisk()) {
-                if (currentChunk != null) {
-                    if (inShutdown) {
-                        jvm.markChunkFinal();
-                    }
-                    MetadataRepository.getInstance().setOutput(null);
-                    finishChunk(currentChunk, now, null);
-                    currentChunk = null;
+                if (inShutdown) {
+                    jvm.markChunkFinal();
                 }
+                stopTime = MetadataRepository.getInstance().setOutput(null);
+                finishChunk(currentChunk, stopTime, null);
+                currentChunk = null;
             } else {
                 // last memory
-                dumpMemoryToDestination(recording);
+                stopTime = dumpMemoryToDestination(recording);
             }
             jvm.endRecording();
+            recording.setStopTime(stopTime);
             disableEvents();
         } else {
             RepositoryChunk newChunk = null;
             RequestEngine.doChunkEnd();
             updateSettingsButIgnoreRecording(recording);
+
+            String path = null;
             if (toDisk) {
-                newChunk = repository.newChunk(zdtNow);
-                MetadataRepository.getInstance().setOutput(newChunk.getFile().toString());
-            } else {
-                MetadataRepository.getInstance().setOutput(null);
+                newChunk = repository.newChunk();
+                path = newChunk.getFile().toString();
+            }
+            stopTime = MetadataRepository.getInstance().setOutput(path);
+            if (toDisk) {
+                newChunk.setStartTime(stopTime);
             }
+            recording.setStopTime(stopTime);
             writeMetaEvents();
             if (currentChunk != null) {
-                finishChunk(currentChunk, now, null);
+                finishChunk(currentChunk, stopTime, null);
             }
             currentChunk = newChunk;
             RequestEngine.doChunkBegin();
@@ -360,12 +369,14 @@ synchronized void stop(PlatformRecording recording) {
         }
     }
 
-    private void dumpMemoryToDestination(PlatformRecording recording)  {
+    private Instant dumpMemoryToDestination(PlatformRecording recording)  {
         WriteableUserPath dest = recording.getDestination();
         if (dest != null) {
-            MetadataRepository.getInstance().setOutput(dest.getRealPathText());
+            Instant t = MetadataRepository.getInstance().setOutput(dest.getRealPathText());
             recording.clearDestination();
+            return t;
         }
+        return Instant.now();
     }
     private void disableEvents() {
         MetadataRepository.getInstance().disableEvents();
@@ -389,13 +400,14 @@ void updateSettingsButIgnoreRecording(PlatformRecording ignoreMe) {
 
 
     synchronized void rotateDisk() {
-        ZonedDateTime now = ZonedDateTime.now();
-        RepositoryChunk newChunk = repository.newChunk(now);
+        RepositoryChunk newChunk = repository.newChunk();
         RequestEngine.doChunkEnd();
-        MetadataRepository.getInstance().setOutput(newChunk.getFile().toString());
+        String path = newChunk.getFile().toString();
+        Instant timestamp = MetadataRepository.getInstance().setOutput(path);
+        newChunk.setStartTime(timestamp);
         writeMetaEvents();
         if (currentChunk != null) {
-            finishChunk(currentChunk, now.toInstant(), null);
+            finishChunk(currentChunk, timestamp, null);
         }
         currentChunk = newChunk;
         RequestEngine.doChunkBegin();

src/jdk.jfr/share/classes/jdk/jfr/internal/PlatformRecording.java

@@ -166,7 +166,6 @@ public boolean stop(String reason) {
             recorder.stop(this);
             String endText = reason == null ? "" : ". Reason \"" + reason + "\".";
             Logger.log(LogTag.JFR, LogLevel.INFO, "Stopped recording \"" + getName() + "\" (" + getId() + ")" + endText);
-            this.stopTime = Instant.now();
             newState = getState();
         }
         WriteableUserPath dest = getDestination();
@@ -317,10 +316,10 @@ public PlatformRecording newSnapshotClone(String reason, Boolean pathToGcRoots)
         }
         RecordingState state = getState();
         if (state == RecordingState.CLOSED) {
-            throw new IOException("Recording \"" + name + "\" (id=" + id + ") has been closed, no contents to write");
+            throw new IOException("Recording \"" + name + "\" (id=" + id + ") has been closed, no content to write");
         }
         if (state == RecordingState.DELAYED || state == RecordingState.NEW) {
-            throw new IOException("Recording \"" + name + "\" (id=" + id + ") has not started, no contents to write");
+            throw new IOException("Recording \"" + name + "\" (id=" + id + ") has not started, no content to write");
         }
         if (state == RecordingState.STOPPED) {
             PlatformRecording clone = recorder.newTemporaryRecording();