8333358: java/io/IO/IO.java test fails intermittently

Reviewed-by: naoto

test/jdk/java/io/IO/IO.java

@@ -21,6 +21,7 @@
  * questions.
  */
 
+import java.lang.reflect.Method;
 import java.nio.file.Files;
 import java.nio.file.Path;
 import java.nio.file.Paths;
@@ -34,6 +35,10 @@ import org.junit.jupiter.api.BeforeAll;
 import org.junit.jupiter.api.Nested;
 import org.junit.jupiter.api.condition.EnabledOnOs;
 import org.junit.jupiter.api.condition.OS;
+import org.junit.jupiter.api.extension.AfterTestExecutionCallback;
+import org.junit.jupiter.api.extension.BeforeTestExecutionCallback;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.junit.jupiter.api.extension.ExtensionContext;
 import org.junit.jupiter.params.ParameterizedTest;
 import org.junit.jupiter.params.provider.Arguments;
 import org.junit.jupiter.params.provider.MethodSource;
@@ -48,6 +53,7 @@ import static org.junit.jupiter.api.Assertions.*;
  * @library /test/lib
  * @run junit IO
  */
+@ExtendWith(IO.TimingExtension.class)
 public class IO {
 
     @Nested
@@ -62,6 +68,11 @@ public class IO {
             if (!Files.exists(expect) || !Files.isExecutable(expect)) {
                 Assumptions.abort("'" + expect + "' not found");
             }
+            try {
+                var outputAnalyzer = ProcessTools.executeProcess(
+                        expect.toAbsolutePath().toString(), "-version");
+                outputAnalyzer.reportDiagnosticSummary();
+            } catch (Exception _) { }
         }
 
         /*
@@ -174,4 +185,41 @@ public class IO {
         assertEquals(1, output.getExitValue());
         output.shouldContain("Exception in thread \"main\" java.io.IOError");
     }
+
+
+    // adapted from https://junit.org/junit5/docs/current/user-guide/#extensions-lifecycle-callbacks-timing-extension
+    // remove after CODETOOLS-7903752 propagates to jtreg that this test is routinely run by
+
+    public static class TimingExtension implements BeforeTestExecutionCallback,
+            AfterTestExecutionCallback {
+
+        private static final System.Logger logger = System.getLogger(
+                TimingExtension.class.getName());
+
+        private static final String START_TIME = "start time";
+
+        @Override
+        public void beforeTestExecution(ExtensionContext context) {
+            getStore(context).put(START_TIME, time());
+        }
+
+        @Override
+        public void afterTestExecution(ExtensionContext context) {
+            Method testMethod = context.getRequiredTestMethod();
+            long startTime = getStore(context).remove(START_TIME, long.class);
+            long duration = time() - startTime;
+
+            logger.log(System.Logger.Level.INFO, () ->
+                    String.format("Method [%s] took %s ms.", testMethod.getName(), duration));
+        }
+
+        private ExtensionContext.Store getStore(ExtensionContext context) {
+            return context.getStore(ExtensionContext.Namespace.create(getClass(),
+                    context.getRequiredTestMethod()));
+        }
+
+        private long time() {
+            return System.nanoTime() / 1_000_000;
+        }
+    }
 }

test/jdk/java/io/IO/input.exp

@@ -23,6 +23,7 @@
 
 set prompt [lindex $argv $argc-1]
 set stty_init "rows 24 cols 80"
+set timeout -1
 
 spawn {*}$argv
 expect {
@@ -30,7 +31,8 @@ expect {
         send "hello\r"
     }
     timeout {
-        puts "timeout"; exit 1
+        puts "timeout"
+        exit 1
     }
 }
 expect eof

test/jdk/java/io/IO/output.exp

@@ -21,12 +21,23 @@
 # questions.
 #
 
-################################################################################
-# This script does not expect/verify anything and is only used to simulate tty #
-################################################################################
+# This script doesn't verify any output strings, it's only used to simulate tty
 
-# Use `noecho` below, otherwise, expect will output the expanded "spawn ..."
+set stty_init "rows 24 cols 80"
+set timeout -1
+
+# Use `-noecho` below, otherwise, expect will output the expanded "spawn ..."
 # command, which will interfere with asserting output from the java test
+# counterpart
 
 spawn -noecho {*}$argv
-expect eof
+
+expect {
+    eof {
+        exit 0
+    }
+    timeout {
+        puts "timeout"
+        exit 1
+    }
+}