commit dc00c3aef3561f97ac0ffda60aee1254c6d5fb74
author Hans Boehm <hboehm@google.com> Mon Jul 26 18:16:30 2021 -0700
committer Hans Boehm <hboehm@google.com> Tue Jul 27 20:27:48 2021 +0000
tree b676f79954a3347de1447308962e35717d1b1e41
parent ce9b902a161b86eb2d5ef9fe4442305e25828d0a

Retry more carefully

When we notice that notifications ran too quickly, start over from
the beginning. Just retrying the notiofications was ineffective,
presumably because we already triggered a GC. but it somehow
completed before we looked for blocking behavior.

Test: Treehugger, some manual testing with code changes.
Bug: 190148586
Change-Id: Ic4689165c5f37535b6ba0e05f03584cdc1d04c40

test/2040-huge-native-alloc/src/Main.java

diff --git a/test/2040-huge-native-alloc/src/Main.java b/test/2040-huge-native-alloc/src/Main.java
index 3c090c7..59e1266 100644
--- a/test/2040-huge-native-alloc/src/Main.java
+++ b/test/2040-huge-native-alloc/src/Main.java
@@ -24,6 +24,7 @@
   int allocated = 0;
   int deallocated = 0;
   static Object lock = new Object();
+  final static int MAX_TRIES = 4;
   WeakReference<BufferHolder>[] references = new WeakReference[HOW_MANY_HUGE];
 
   class BufferHolder {
@@ -55,9 +56,9 @@
   public static void main(String[] args) {
     System.loadLibrary(args[0]);
     System.out.println("Main Started");
-    while (true) {
+    for (int i = 1; i <= MAX_TRIES; ++i) {
       Runtime.getRuntime().gc();
-      if (new Main().tryToRun()) {
+      if (new Main().tryToRun(i == MAX_TRIES)) {
         break;
       }
       // Clean up and try again.
@@ -67,7 +68,8 @@
     System.out.println("Main Finished");
   }
 
-  boolean tryToRun() {
+  // Returns false on a failure that should be retried.
+  boolean tryToRun(boolean lastChance) {
     final int startingGcNum = getGcNum();
     timeNotifications();  // warm up.
     final long referenceTime1 = timeNotifications();
@@ -95,12 +97,13 @@
       System.out.println("Notifications ran too slowly; excessive blocking? msec = "
           + (actualTime / 1_000_000));
     } else if (actualTime < minBlockingTime) {
-      // Try again before reporting.
-      actualTime = timeNotifications();
-      if (actualTime < minBlockingTime) {
-        System.out.println("Notifications ran too quickly; no blocking GC? msec = "
-            + (actualTime / 1_000_000) + " reference(msec) = " + (referenceTime / 1_000_000));
+      if (!lastChance) {
+        // We sometimes see this, maybe because a GC is triggered by other means?
+        // Try again before reporting.
+        return false;
       }
+      System.out.println("Notifications ran too quickly; no blocking GC? msec = "
+          + (actualTime / 1_000_000) + " reference(msec) = " + (referenceTime / 1_000_000));
     }
 
     // Let finalizers run.