8361338: JFR: Min and max time in MethodTime event is confusing

Reviewed-by: mgronlun

Author: egahlin

src/jdk.jfr/share/classes/jdk/jfr/events/MethodTimingEvent.java

@@ -29,11 +29,13 @@
 import jdk.jfr.Name;
 import jdk.jfr.Timespan;
 import jdk.jfr.internal.RemoveFields;
+import jdk.jfr.Description;
 
 @Name("jdk.MethodTiming")
 @Label("Method Timing")
 @Category({ "Java Virtual Machine", "Method Tracing" })
 @RemoveFields({ "duration", "eventThread", "stackTrace" })
+@Description("Measures the approximate time it takes for a method to execute, including all delays, not just CPU processing time")
 public final class MethodTimingEvent extends AbstractJDKEvent {
 
     @Label("Method")
@@ -43,14 +45,17 @@ public final class MethodTimingEvent extends AbstractJDKEvent {
     public long invocations;
 
     @Label("Minimum Time")
+    @Description("The value may be missing (Long.MIN_VALUE) if the clock-resolution is too low to establish a minimum time")
     @Timespan(Timespan.TICKS)
     public long minimum;
 
     @Label("Average Time")
+    @Description("The value may be missing (Long.MIN_VALUE) if the clock-resolution is too low to establish an average time")
     @Timespan(Timespan.TICKS)
     public long average;
 
     @Label("Maximum Time")
+    @Description("The value may be missing (Long.MIN_VALUE) if the clock-resolution is too low to establish a maximum time")
     @Timespan(Timespan.TICKS)
     public long maximum;
 

src/jdk.jfr/share/classes/jdk/jfr/internal/query/view.ini

@@ -471,9 +471,9 @@ table = "COLUMN 'Alloc. Time', 'Application Method', 'Object Age', 'Heap Usage'
 
 [application.method-timing]
 label = "Method Timing"
-table = "COLUMN 'Timed Method', 'Invocations', 'Min. Time', 'Max. Time', 'Average Time'
+table = "COLUMN 'Timed Method', 'Invocations', 'Minimum Time', 'Average Time', 'Maximum Time'
          FORMAT none, none, ms-precision:6, ms-precision:6, ms-precision:6
-         SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(minimum), LAST_BATCH(maximum), LAST_BATCH(average)
+         SELECT LAST_BATCH(method) AS M, LAST_BATCH(invocations), LAST_BATCH(minimum), LAST_BATCH(average), LAST_BATCH(maximum)
          FROM jdk.MethodTiming GROUP BY method ORDER BY average"
 
 [application.method-calls]

src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedClass.java

@@ -33,6 +33,7 @@
  * Holds timed method for a class. Used when publishing method ids.
  */
 public final class TimedClass {
+    private static final long MISSING = Long.MIN_VALUE;
     private final ConcurrentHashMap<Long, TimedMethod> methods = new ConcurrentHashMap<>();
 
     public TimedMethod add(Method method) {
@@ -60,13 +61,23 @@ public void emit(long timestamp) {
                 long methodId = tm.method().methodId();
                 long invocations = tm.invocations().get();
                 long time = tm.time().get();
-                long average = invocations == 0 ? Long.MIN_VALUE : time / invocations;
                 long min = tm.minimum().get();
-                if (min == Long.MAX_VALUE) {
-                    min = Long.MIN_VALUE; // Signals that the value is missing
-                }
                 long max = tm.maximum().get();
-                MethodTimingEvent.commit(timestamp, methodId, invocations, min, average, max);
+                if (time == 0 || invocations == 0) {
+                    // If time is zero, it's a low resolution clock and more invocations are needed.
+                    MethodTimingEvent.commit(timestamp, methodId, invocations, MISSING, MISSING, MISSING);
+                } else {
+                    long average = (time + invocations / 2) / invocations;
+                    if (min == Long.MAX_VALUE) {
+                        min = average;
+                    }
+                    if (max == Long.MIN_VALUE) {
+                        max = average;
+                    }
+                    min = Math.min(min, average);
+                    max = Math.max(max, average);
+                    MethodTimingEvent.commit(timestamp, methodId, invocations, min, average, max);
+                }
                 tm.method().log("Emitted event");
             }
         }

src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/TimedMethod.java

@@ -39,6 +39,9 @@ record TimedMethod(AtomicLong invocations, AtomicLong time, AtomicLong minimum,
     }
 
     public void updateMinMax(long duration) {
+        if (duration == 0) {
+            return; // Ignore data due to low-resolution clock
+        }
         if (duration > maximum.getPlain()) {
             while (true) {
                 long max = maximum.get();