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 ****
  /*
!  * Copyright (c) 2016, 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.
--- 1,7 ----
  /*
!  * 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,79 ****
   * @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
   * @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.
           *
!          * 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;
!         }
  
          ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
              "-XX:+UnlockDiagnosticVMOptions",
              "-Xmx100M",
              "-XX:ErrorHandlerTest=14",
              "-XX:+TestUnresponsiveErrorHandler",
!             "-XX:ErrorLogTimeout=10", // 10 seconds
              "-XX:-CreateCoredumpOnCrash",
              "-version");
  
          OutputAnalyzer output_detail = new OutputAnalyzer(pb.start());
  
--- 35,80 ----
   * @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) & (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 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. ------"
           *
!          * 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=16", // 16 seconds big timeout = 4 seconds per little timeout
              "-XX:-CreateCoredumpOnCrash",
              "-version");
  
          OutputAnalyzer output_detail = new OutputAnalyzer(pb.start());
  
*** 100,110 ****
--- 101,114 ----
  
          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;