Add SafePoint times to UpdateGraphProcessor cycle times logging.

IO/src/main/java/io/deephaven/io/log/LogEntry.java

@@ -93,54 +93,90 @@ default LogEntry appendDouble(Double f) {
     /**
      * Append a double to the given number of decimal places, rounding up.
      *
-     * @param f a double value to append to the logEntry
+     * @param doubleValue a double value to append to the logEntry
      * @param decimalPlaces a positive integer between 0 and 9
      * @return the resulting {@code LogEntry}
      */
-    default LogEntry appendPositiveDouble(double f, int decimalPlaces) {
+    default LogEntry appendDoubleToDecimalPlaces(final double doubleValue, final int decimalPlaces) {
+        return appendDoubleDecimalPlacesImpl(this, doubleValue, decimalPlaces, true);
+    }
+
+    /**
+     * Append a double with decimal places up to the given number.
+     *
+     * @param doubleValue a double value to append to the logEntry
+     * @param decimalPlaces a positive integer between 0 and 9
+     * @return the resulting {@code LogEntry}
+     */
+    default LogEntry appendDoubleToMaxDecimalPlaces(final double doubleValue, final int decimalPlaces) {
+        return appendDoubleDecimalPlacesImpl(this, doubleValue, decimalPlaces, false);
+    }
+
+    private static LogEntry appendDoubleDecimalPlacesImpl(
+            LogEntry entry, final double doubleValue, final int decimalPlaces, final boolean exact) {
         final int decimalPlacesAsPowerOf10 = MathUtil.pow10(decimalPlaces);
-        final long lf = (long) (0.5 + f * decimalPlacesAsPowerOf10);
-        final long integral = lf / decimalPlacesAsPowerOf10;
-        LogEntry r = append(integral);
-        if (decimalPlaces == 0) {
-            return r;
+        final boolean negative = doubleValue < 0.0;
+        final long longWeightedValue;
+        if (negative) {
+            longWeightedValue = -(long) (-0.5 + doubleValue * decimalPlacesAsPowerOf10);
+        } else {
+            longWeightedValue = (long) (0.5 + doubleValue * decimalPlacesAsPowerOf10);
+        }
+        final long integral = longWeightedValue / decimalPlacesAsPowerOf10;
+        if (negative) {
+            entry = entry.append(-integral);
+        } else {
+            entry = entry.append(integral);
         }
-        final int fractional = (int) (lf % decimalPlacesAsPowerOf10);
-        r = r.append(".");
+        if (decimalPlaces == 0) {
+            return entry;
+        }
+        int fractional = (int) (longWeightedValue % decimalPlacesAsPowerOf10);
+        int actualDecimalPlaces = decimalPlaces;
+        if (!exact) {
+            while (fractional > 0 && (fractional % 10 == 0)) {
+                fractional /= 10;
+                --actualDecimalPlaces;
+            }
+            if (fractional == 0) {
+                return entry;
+            }
+        }
+        entry = entry.append(".");
         final int base10FractionalDigits = MathUtil.base10digits(fractional);
-        final int leadingZeroes = decimalPlaces - base10FractionalDigits;
+        final int leadingZeroes = actualDecimalPlaces - base10FractionalDigits;
         switch (leadingZeroes) {
             case 9:
-                r = r.append("000000000");
+                entry = entry.append("000000000");
             case 8:
-                r = r.append("00000000");
+                entry = entry.append("00000000");
                 break;
             case 7:
-                r = r.append("0000000");
+                entry = entry.append("0000000");
                 break;
             case 6:
-                r = r.append("000000");
+                entry = entry.append("000000");
                 break;
             case 5:
-                r = r.append("00000");
+                entry = entry.append("00000");
                 break;
             case 4:
-                r = r.append("0000");
+                entry = entry.append("0000");
                 break;
             case 3:
-                r = r.append("000");
+                entry = entry.append("000");
                 break;
             case 2:
-                r = r.append("00");
+                entry = entry.append("00");
                 break;
             case 1:
-                r = r.append("0");
+                entry = entry.append("0");
                 break;
         }
         if (fractional == 0) {
-            return r;
+            return entry;
         }
-        return r.append(fractional);
+        return entry.append(fractional);
     }
 
     LogEntry nf();

IO/src/test/java/io/deephaven/io/log/impl/TestLogOutput.java

@@ -62,22 +62,25 @@ public void testBoolean() {
         assertEquals("false", results[1]);
     }
 
-    public void testPositiveDouble() {
-        logger.info().appendPositiveDouble(1.2345, 3).end();
-        logger.info().appendPositiveDouble(0.112255, 2).end();
-        logger.info().appendPositiveDouble(11111111.112255, 3).end();
-        logger.info().appendPositiveDouble(11111111.112255, 4).end();
-        logger.info().appendPositiveDouble(1111.4, 0).end();
-        logger.info().appendPositiveDouble(1111.5, 0).end();
-        logger.info().appendPositiveDouble(111.1234567894, 9).end();
-        logger.info().appendPositiveDouble(111.1234567895, 9).end();
-        logger.info().appendPositiveDouble(111.123456789, 9).end();
-        logger.info().appendPositiveDouble(111.12, 4).end();
-        logger.info().appendPositiveDouble(111.14, 2).end();
-        logger.info().appendPositiveDouble(111.15, 2).end();
-        logger.info().appendPositiveDouble(111.15, 0).end();
-        logger.info().appendPositiveDouble(0, 0).end();
-        logger.info().appendPositiveDouble(0, 3).end();
+    public void testPositiveDoubleToDecimalPlaces() {
+        logger.info().appendDoubleToDecimalPlaces(1.2345, 3).end();
+        logger.info().appendDoubleToDecimalPlaces(0.112255, 2).end();
+        logger.info().appendDoubleToDecimalPlaces(11111111.112255, 3).end();
+        logger.info().appendDoubleToDecimalPlaces(11111111.112255, 4).end();
+        logger.info().appendDoubleToDecimalPlaces(1111.4, 0).end();
+        logger.info().appendDoubleToDecimalPlaces(1111.5, 0).end();
+        logger.info().appendDoubleToDecimalPlaces(111.1234567894, 9).end();
+        logger.info().appendDoubleToDecimalPlaces(111.1234567895, 9).end();
+        logger.info().appendDoubleToMaxDecimalPlaces(111.1234567895, 9).end();
+        logger.info().appendDoubleToDecimalPlaces(111.123456789, 9).end();
+        logger.info().appendDoubleToMaxDecimalPlaces(111.123456789, 9).end();
+        logger.info().appendDoubleToDecimalPlaces(111.12, 4).end();
+        logger.info().appendDoubleToMaxDecimalPlaces(111.12, 4).end();
+        logger.info().appendDoubleToDecimalPlaces(111.14, 2).end();
+        logger.info().appendDoubleToDecimalPlaces(111.15, 2).end();
+        logger.info().appendDoubleToDecimalPlaces(111.15, 0).end();
+        logger.info().appendDoubleToDecimalPlaces(0, 0).end();
+        logger.info().appendDoubleToDecimalPlaces(0, 3).end();
         String[] results = logger.takeAll();
         int c = 0;
         assertEquals("1.235", results[c++]);
@@ -88,12 +91,24 @@ public void testPositiveDouble() {
         assertEquals("1112", results[c++]);
         assertEquals("111.123456789", results[c++]);
         assertEquals("111.123456790", results[c++]);
+        assertEquals("111.12345679", results[c++]);
+        assertEquals("111.123456789", results[c++]);
         assertEquals("111.123456789", results[c++]);
         assertEquals("111.1200", results[c++]);
+        assertEquals("111.12", results[c++]);
         assertEquals("111.14", results[c++]);
         assertEquals("111.15", results[c++]);
         assertEquals("111", results[c++]);
         assertEquals("0", results[c++]);
         assertEquals("0.000", results[c++]);
     }
+
+    public void testNegativeDoubleToDecimalPlaces() {
+        logger.info().appendDoubleToDecimalPlaces(-1.235, 2).end();
+        logger.info().appendDoubleToDecimalPlaces(-1.234, 2).end();
+        String[] results = logger.takeAll();
+        int c = 0;
+        assertEquals("-1.24", results[c++]);
+        assertEquals("-1.23", results[c++]);
+    }
 }

Util/src/main/java/io/deephaven/util/JvmIntrospectionContext.java

@@ -0,0 +1,69 @@
+package io.deephaven.util;
+
+import io.deephaven.util.hotspot.HotSpot;
+
+/**
+ * Utility class to facilitate obtaining data for safepoint pauses count and time between two points in code. A
+ * safepoint pause is a "stop the world, pause all threads" event in the HotSpot JVM. Note full Garbage Collection
+ * pauses are a dominant cause of safepoint pauses, but there are other triggers like: <il>
+ * <li>Deoptimization</li>
+ * <li>Biased lock revocation</li>
+ * <li>Thread dump</li>
+ * <li>Heap inspection< /li>
+ * <li>Class redefinition</li> </il> And others; you can see a full list <a href=
+ * "http://hg.openjdk.java.net/jdk8u/jdk8u/hotspot/file/fc3cd1db10e2/src/share/vm/runtime/vm_operations.hpp#l39"> here
+ * </a>.
+ *
+ */
+
+@SuppressWarnings("restriction")
+public class JvmIntrospectionContext {
+    private static final HotSpot hotspot = HotSpot.instance.orElse(null);
+    private long lastStartPausesCount = -1;
+    private long lastStartPausesTimeMillis = -1;
+    private long lastEndPausesCount;
+    private long lastEndPausesTimeMillis;
+
+    public static boolean hasSafePointData() {
+        return hotspot != null;
+    }
+
+    public JvmIntrospectionContext() {}
+
+    public void startSample() {
+        if (hotspot == null) {
+            return;
+        }
+        lastStartPausesCount = hotspot.getSafepointCount();
+        lastStartPausesTimeMillis = hotspot.getTotalSafepointTimeMillis();
+    }
+
+    /**
+     * Sample garbage collection count and times at the point of call.
+     */
+    public void endSample() {
+        if (hotspot == null) {
+            return;
+        }
+        lastEndPausesCount = hotspot.getSafepointCount();
+        lastEndPausesTimeMillis = hotspot.getTotalSafepointTimeMillis();
+    }
+
+    /**
+     * Number of collections between the last two calls to {@code sample()}
+     * 
+     * @return Number of collections
+     */
+    public long deltaSafePointPausesCount() {
+        return lastEndPausesCount - lastStartPausesCount;
+    }
+
+    /**
+     * Time in milliseconds in collections between the last two calls to {@code sample()}
+     * 
+     * @return Time in milliseconds
+     */
+    public long deltaSafePointPausesTimeMillis() {
+        return lastEndPausesTimeMillis - lastStartPausesTimeMillis;
+    }
+}

Util/src/main/java/io/deephaven/util/hotspot/HotSpot.java

@@ -0,0 +1,25 @@
+package io.deephaven.util.hotspot;
+
+import java.util.Iterator;
+import java.util.Optional;
+import java.util.ServiceLoader;
+
+public interface HotSpot {
+    Optional<HotSpot> instance = loadImpl();
+
+    private static Optional<HotSpot> loadImpl() {
+        final Iterator<HotSpot> it = ServiceLoader.load(HotSpot.class).iterator();
+        if (!it.hasNext()) {
+            return Optional.empty();
+        }
+        final HotSpot impl = it.next();
+        if (it.hasNext()) {
+            throw new IllegalStateException("Found multiple implementations for " + HotSpot.class.getSimpleName());
+        }
+        return Optional.of(impl);
+    }
+
+    long getSafepointCount();
+
+    long getTotalSafepointTimeMillis();
+}

buildSrc/src/main/groovy/io/deephaven/project/ProjectType.groovy

@@ -14,6 +14,7 @@ enum ProjectType {
     JAVA_EXTERNAL(true, 'io.deephaven.project.java-external'),
     JAVA_LOCAL(false, 'io.deephaven.project.java-local'),
     JAVA_PUBLIC(true, 'io.deephaven.project.java-public'),
+    JAVA_OPTIONAL_IMPL(true, 'io.deephaven.project.java-public'),
     BOM_PUBLIC(true, 'io.deephaven.project.bom-public'),
     ROOT(false, 'io.deephaven.project.root');
 

buildSrc/src/main/groovy/io/deephaven/project/util/CombinedJavadoc.groovy

@@ -14,6 +14,7 @@ class CombinedJavadoc {
         }
         switch (type) {
             case ProjectType.BOM_PUBLIC:
+            case ProjectType.JAVA_OPTIONAL_IMPL:
                 return false
             case ProjectType.JAVA_EXTERNAL:
             case ProjectType.JAVA_PUBLIC:

combined-javadoc/build.gradle

@@ -63,4 +63,4 @@ def allJavadoc = tasks.register 'allJavadoc', Javadoc, {
 
 artifacts {
     combinedJavadoc allJavadoc
-}
+}

engine/updategraph/build.gradle

@@ -11,6 +11,7 @@ dependencies {
     implementation project(':engine-chunk')
 
     compileOnly 'com.google.code.findbugs:jsr305:3.0.2'
+    runtimeOnly project(':hotspot')
 
     testImplementation 'junit:junit:4.13.2'