test/runtime/ErrorHandling/TimeoutInErrorHandlingTest.java

rev 12487 : 8166944: Hanging Error Reporting steps may lead to torn error logs.
Reviewed-by: cjplummer, dholmes
Summary: Interupt error reporting if reporting steps hang to enable subsequent reporting steps to run.
rev 12488 : [mq]: 8166944-Hanging-Error-Reporting-2

@@ -1,7 +1,7 @@
 /*
- * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2017 Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
  * under the terms of the GNU General Public License version 2 only, as
  * published by the Free Software Foundation.

@@ -35,45 +35,46 @@
  * @test
  * @bug 8166944
  * @summary Hanging Error Reporting steps may lead to torn error logs
  * @modules java.base/jdk.internal.misc
  * @library /test/lib
- * @requires vm.debug == true
+ * @requires (vm.debug == true) & (os.family != "windows")
  * @author Thomas Stuefe (SAP)
  */
 
 public class TimeoutInErrorHandlingTest {
 
 
     public static void main(String[] args) throws Exception {
 
         /* Start the VM and let it crash. Specify TestUnresponsiveErrorHandler which will
-         * let three subsequent error reporting steps hang. The Timeout handling triggered
-         * by the WatcherThread should kick in and interrupt those steps.
+         * let five subsequent error reporting steps hang. The Timeout handling triggered
+         * by the WatcherThread should kick in and interrupt those steps. In theory, the
+         * text "timeout occurred during error reporting in step .." (the little timeouts)
+         * should occur in the error log up to four times, followed by the final big timeout
+         * "------ Timeout during error reporting after xx s. ------"
          *
-         * Timeout in Error Reporting is controlled by ErrorLogTimeout, which defines after
-         * how many seconds error reporting is stopped altogether and the VM is aborted.
-         * Each error reporting step is granted up to half of this time before it is canceled
-         * and the next step is started (the logic being, typically error steps are
-         * instantaneous, if they hang, its typically an error which only should affect one
-         * or two steps).
-         * So, by causing three subsequent steps to hang, we expect the error log to contain
-         * at least one, possibly two step-timeout messages, and then the global ErrorLogTimeout
-         * should have been reached and the VM should have been aborted by the WatcherThread,
-         * which should write "timer expired, abort..." to stderr. */
-
-        // Not debug, not windows (yet)
-        if (!Platform.isDebugBuild() || Platform.isWindows()) {
-            return;
-        }
+         * Note that there are a number of uncertainties which make writing a 100% foolproof
+         * test challenging. The time the error reporting thread takes to react to the
+         * timeout triggers is unknown. So it is difficult to predict how many little timeouts
+         * will be visible before the big timeout kicks in. Also, once the big timeout hits,
+         * error reporting thread and Watcherthread will race. The former writes his last
+         * message to the error logs and flushes, the latter waits 200ms and then exits the
+         * process without further synchronization with the error reporting thread.
+         *
+         * Because of all this and the desire to write a bullet proof test which does
+         * not fail sporadically, we will not test for the final timeout message nor for all
+         * of the optimally expected little timeout messages. We just test for two of the
+         * little timeout messages to see that repeated timeout handling is basically working.
+         */
 
         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
             "-XX:+UnlockDiagnosticVMOptions",
             "-Xmx100M",
             "-XX:ErrorHandlerTest=14",
             "-XX:+TestUnresponsiveErrorHandler",
-            "-XX:ErrorLogTimeout=10", // 10 seconds
+            "-XX:ErrorLogTimeout=16", // 16 seconds big timeout = 4 seconds per little timeout
             "-XX:-CreateCoredumpOnCrash",
             "-version");
 
         OutputAnalyzer output_detail = new OutputAnalyzer(pb.start());
 

@@ -100,11 +101,14 @@
 
         FileInputStream fis = new FileInputStream(f);
         BufferedReader br = new BufferedReader(new InputStreamReader(fis));
         String line = null;
 
+
+
         Pattern [] pattern = new Pattern[] {
+            Pattern.compile(".*timeout occurred during error reporting in step.*"),
             Pattern.compile(".*timeout occurred during error reporting in step.*")
         };
         int currentPattern = 0;
 
         String lastLine = null;