Relax 053-wait-some sucess criteria

Drop constraint on total extra delay. Shorten maximum wait time.

But then only only require success in 2 out of 3 runs.

Switch timing to use nanoTime() to get a monotonic clock. This might
have contributed to a few of the observed failures.

Bug: 175435088

Test: Prun-test --host 053-wait-some
Test: Retest with sleepy.wait(delay * 3/2); on line 66.
Test: Retest with timing set to true in code.
Change-Id: Ic8e392340ba1d70782f2a5303bfebf1d7251a86b
diff --git a/test/053-wait-some/src/Main.java b/test/053-wait-some/src/Main.java
index 0fd9e8d..2de90b7 100644
--- a/test/053-wait-some/src/Main.java
+++ b/test/053-wait-some/src/Main.java
@@ -22,6 +22,17 @@
     private final static long[] DELAYS = {
         200, 500, 1000, 2000, 3500, 8000
     };
+    // This test is inherently prone to failures through scheduling delays and spurious wakeups.
+    // We try it repeatedly, and check that failures are "rare enough".
+    // Currently we go for success on the first try or 2 out of 3.
+    private final static int NUM_TRIES = 3;
+    private final static int MAX_FAILURES = 1;
+    private final static int NANOS_PER_MILLI = 1_000_000;
+
+    // Allow a random scheduling delay of up to 400 msecs.  That value is empirically determined
+    // from failure logs, though we do get occasional violations.
+    // We seem to get very occasional very long delays on host, perhaps due to getting paged out.
+    private final static int MAX_SCHED_MILLIS = 400;
 
     public static void main(String[] args) {
         boolean timing = (args.length >= 1) && args[0].equals("--timing");
@@ -30,7 +41,6 @@
 
     public static void doit(boolean timing) {
         Object sleepy = new Object();
-        long start, end;
 
         synchronized (sleepy) {
             try {
@@ -42,53 +52,56 @@
                 ie.printStackTrace(System.out);
             }
 
-            long total_extra_delay = 0;
             for (long delay : DELAYS) {
                 System.out.println("Waiting for " + delay + "ms...");
+                long min = delay - 1;
+                long max = delay + MAX_SCHED_MILLIS;
 
-                start = System.currentTimeMillis();
-                try {
-                    sleepy.wait(delay);
-                } catch (InterruptedException ie) {
-                    ie.printStackTrace(System.out);
-                }
-                end = System.currentTimeMillis();
-
-                long elapsed = end - start;
+                int num_failures = 0;
+                long elapsed_to_report = 0;
                 boolean showTime = timing;
+                for (int i = 0; i < (timing ? 1 : NUM_TRIES); ++i) {
+                    final long start = System.nanoTime();
+                    try {
+                        sleepy.wait(delay);
+                    } catch (InterruptedException ie) {
+                        ie.printStackTrace(System.out);
+                    }
+                    final long end = System.nanoTime();
 
-                if (! timing) {
-                    // Allow a random scheduling delay of up to 600 msecs.
-                    // That value is empirically determined from failure logs.
-                    // We seem to get very occasional very long delays on host, perhaps due
-                    // to getting paged out.
-                    final long epsilon = 600;
-                    long min = delay - 1;
-                    long max = delay + epsilon;
-                    total_extra_delay += elapsed - delay;
+                    long elapsed = (end - start + NANOS_PER_MILLI / 2) / NANOS_PER_MILLI;
 
-                    if (elapsed < min) {
-                        // This can legitimately happen due to premature wake-ups.
-                        // This seems rare and unexpected enough in practice that we should
-                        // still report.
-                        System.out.println("  Elapsed time was too short");
-                        showTime = true;
-                    } else if (elapsed > max) {
-                        System.out.println("  Elapsed time was too long: "
-                            + "elapsed=" + elapsed + " max=" + max);
-                        showTime = true;
+                    if (timing) {
+                        elapsed_to_report = elapsed;
+                    } else {
+                        if (elapsed < min || elapsed > max) {
+                            ++ num_failures;
+                            elapsed_to_report = elapsed;
+                        } else if (i == 0) {
+                            // Save time if we immediately succeeded.
+                            break;
+                        }
                     }
                 }
-
+                if (num_failures > MAX_FAILURES) {
+                    System.out.println("Failed " + num_failures + " times out of "
+                            + NUM_TRIES + " tries.");
+                    showTime = true;
+                    if (elapsed_to_report < min) {
+                        // This can legitimately happen due to premature wake-ups.
+                        // This seems rare and unexpected enough in practice that we should
+                        // still report if it occurs repeatedly.
+                        System.out.println("  Elapsed time was too short");
+                    } else if (elapsed_to_report > max) {
+                        System.out.println("  Elapsed time was too long: "
+                             + "elapsed = " + elapsed_to_report + " max = " + max);
+                    }
+                }
                 if (showTime) {
                     System.out.println("  Wall clock elapsed "
-                            + elapsed + "ms");
+                            + elapsed_to_report + "ms");
                 }
             }
-            if (total_extra_delay > 1000) {
-                System.out.println("  Total unrequested delay of " + total_extra_delay
-                    + "msecs was too long");
-            }
         }
     }
 }