< prev index next >

test/runtime/ErrorHandling/TimeoutInErrorHandlingTest.java

Print this page
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 /*
   2  * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  */
  23 
  24 import java.io.BufferedReader;
  25 import java.io.File;
  26 import java.io.FileInputStream;
  27 import java.io.InputStreamReader;
  28 import java.util.regex.Pattern;
  29 
  30 import jdk.test.lib.process.OutputAnalyzer;
  31 import jdk.test.lib.Platform;
  32 import jdk.test.lib.process.ProcessTools;
  33 
  34 /*
  35  * @test
  36  * @bug 8166944
  37  * @summary Hanging Error Reporting steps may lead to torn error logs
  38  * @modules java.base/jdk.internal.misc
  39  * @library /test/lib
  40  * @requires vm.debug == true
  41  * @author Thomas Stuefe (SAP)
  42  */
  43 
  44 public class TimeoutInErrorHandlingTest {
  45 
  46 
  47     public static void main(String[] args) throws Exception {
  48 
  49         /* Start the VM and let it crash. Specify TestUnresponsiveErrorHandler which will
  50          * let three subsequent error reporting steps hang. The Timeout handling triggered
  51          * by the WatcherThread should kick in and interrupt those steps.



  52          *
  53          * Timeout in Error Reporting is controlled by ErrorLogTimeout, which defines after
  54          * how many seconds error reporting is stopped altogether and the VM is aborted.
  55          * Each error reporting step is granted up to half of this time before it is canceled
  56          * and the next step is started (the logic being, typically error steps are
  57          * instantaneous, if they hang, its typically an error which only should affect one
  58          * or two steps).
  59          * So, by causing three subsequent steps to hang, we expect the error log to contain
  60          * at least one, possibly two step-timeout messages, and then the global ErrorLogTimeout
  61          * should have been reached and the VM should have been aborted by the WatcherThread,
  62          * which should write "timer expired, abort..." to stderr. */
  63 
  64         // Not debug, not windows (yet)
  65         if (!Platform.isDebugBuild() || Platform.isWindows()) {
  66             return;
  67         }
  68 
  69         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
  70             "-XX:+UnlockDiagnosticVMOptions",
  71             "-Xmx100M",
  72             "-XX:ErrorHandlerTest=14",
  73             "-XX:+TestUnresponsiveErrorHandler",
  74             "-XX:ErrorLogTimeout=10", // 10 seconds
  75             "-XX:-CreateCoredumpOnCrash",
  76             "-version");
  77 
  78         OutputAnalyzer output_detail = new OutputAnalyzer(pb.start());
  79 
  80         // we should have crashed with a SIGSEGV
  81         output_detail.shouldMatch("# A fatal error has been detected by the Java Runtime Environment:.*");
  82         output_detail.shouldMatch("# +(?:SIGSEGV|EXCEPTION_ACCESS_VIOLATION).*");
  83 
  84         // VM should have been aborted by WatcherThread
  85         output_detail.shouldMatch(".*timer expired, abort.*");
  86 
  87         // extract hs-err file
  88         String hs_err_file = output_detail.firstMatch("# *(\\S*hs_err_pid\\d+\\.log)", 1);
  89         if (hs_err_file == null) {
  90             throw new RuntimeException("Did not find hs-err file in output.\n");
  91         }
  92 
  93         File f = new File(hs_err_file);
  94         if (!f.exists()) {
  95             throw new RuntimeException("hs-err file missing at "
  96                 + f.getAbsolutePath() + ".\n");
  97         }
  98 
  99         System.out.println("Found hs_err file. Scanning...");
 100 
 101         FileInputStream fis = new FileInputStream(f);
 102         BufferedReader br = new BufferedReader(new InputStreamReader(fis));
 103         String line = null;
 104 


 105         Pattern [] pattern = new Pattern[] {

 106             Pattern.compile(".*timeout occurred during error reporting in step.*")
 107         };
 108         int currentPattern = 0;
 109 
 110         String lastLine = null;
 111         while ((line = br.readLine()) != null) {
 112             if (currentPattern < pattern.length) {
 113               if (pattern[currentPattern].matcher(line).matches()) {
 114                 System.out.println("Found: " + line + ".");
 115                 currentPattern ++;
 116               }
 117             }
 118             lastLine = line;
 119         }
 120         br.close();
 121 
 122         if (currentPattern < pattern.length) {
 123             throw new RuntimeException("hs-err file incomplete (first missing pattern: " +  currentPattern + ")");
 124         }
 125 
   1 /*
   2  * Copyright (c) 2017 Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  */
  23 
  24 import java.io.BufferedReader;
  25 import java.io.File;
  26 import java.io.FileInputStream;
  27 import java.io.InputStreamReader;
  28 import java.util.regex.Pattern;
  29 
  30 import jdk.test.lib.process.OutputAnalyzer;
  31 import jdk.test.lib.Platform;
  32 import jdk.test.lib.process.ProcessTools;
  33 
  34 /*
  35  * @test
  36  * @bug 8166944
  37  * @summary Hanging Error Reporting steps may lead to torn error logs
  38  * @modules java.base/jdk.internal.misc
  39  * @library /test/lib
  40  * @requires (vm.debug == true) & (os.family != "windows")
  41  * @author Thomas Stuefe (SAP)
  42  */
  43 
  44 public class TimeoutInErrorHandlingTest {
  45 
  46 
  47     public static void main(String[] args) throws Exception {
  48 
  49         /* Start the VM and let it crash. Specify TestUnresponsiveErrorHandler which will
  50          * let five subsequent error reporting steps hang. The Timeout handling triggered
  51          * by the WatcherThread should kick in and interrupt those steps. In theory, the
  52          * text "timeout occurred during error reporting in step .." (the little timeouts)
  53          * should occur in the error log up to four times, followed by the final big timeout
  54          * "------ Timeout during error reporting after xx s. ------"
  55          *
  56          * Note that there are a number of uncertainties which make writing a 100% foolproof
  57          * test challenging. The time the error reporting thread takes to react to the
  58          * timeout triggers is unknown. So it is difficult to predict how many little timeouts
  59          * will be visible before the big timeout kicks in. Also, once the big timeout hits,
  60          * error reporting thread and Watcherthread will race. The former writes his last
  61          * message to the error logs and flushes, the latter waits 200ms and then exits the
  62          * process without further synchronization with the error reporting thread.
  63          *
  64          * Because of all this and the desire to write a bullet proof test which does
  65          * not fail sporadically, we will not test for the final timeout message nor for all
  66          * of the optimally expected little timeout messages. We just test for two of the
  67          * little timeout messages to see that repeated timeout handling is basically working.
  68          */


  69 
  70         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
  71             "-XX:+UnlockDiagnosticVMOptions",
  72             "-Xmx100M",
  73             "-XX:ErrorHandlerTest=14",
  74             "-XX:+TestUnresponsiveErrorHandler",
  75             "-XX:ErrorLogTimeout=16", // 16 seconds big timeout = 4 seconds per little timeout
  76             "-XX:-CreateCoredumpOnCrash",
  77             "-version");
  78 
  79         OutputAnalyzer output_detail = new OutputAnalyzer(pb.start());
  80 
  81         // we should have crashed with a SIGSEGV
  82         output_detail.shouldMatch("# A fatal error has been detected by the Java Runtime Environment:.*");
  83         output_detail.shouldMatch("# +(?:SIGSEGV|EXCEPTION_ACCESS_VIOLATION).*");
  84 
  85         // VM should have been aborted by WatcherThread
  86         output_detail.shouldMatch(".*timer expired, abort.*");
  87 
  88         // extract hs-err file
  89         String hs_err_file = output_detail.firstMatch("# *(\\S*hs_err_pid\\d+\\.log)", 1);
  90         if (hs_err_file == null) {
  91             throw new RuntimeException("Did not find hs-err file in output.\n");
  92         }
  93 
  94         File f = new File(hs_err_file);
  95         if (!f.exists()) {
  96             throw new RuntimeException("hs-err file missing at "
  97                 + f.getAbsolutePath() + ".\n");
  98         }
  99 
 100         System.out.println("Found hs_err file. Scanning...");
 101 
 102         FileInputStream fis = new FileInputStream(f);
 103         BufferedReader br = new BufferedReader(new InputStreamReader(fis));
 104         String line = null;
 105 
 106 
 107 
 108         Pattern [] pattern = new Pattern[] {
 109             Pattern.compile(".*timeout occurred during error reporting in step.*"),
 110             Pattern.compile(".*timeout occurred during error reporting in step.*")
 111         };
 112         int currentPattern = 0;
 113 
 114         String lastLine = null;
 115         while ((line = br.readLine()) != null) {
 116             if (currentPattern < pattern.length) {
 117               if (pattern[currentPattern].matcher(line).matches()) {
 118                 System.out.println("Found: " + line + ".");
 119                 currentPattern ++;
 120               }
 121             }
 122             lastLine = line;
 123         }
 124         br.close();
 125 
 126         if (currentPattern < pattern.length) {
 127             throw new RuntimeException("hs-err file incomplete (first missing pattern: " +  currentPattern + ")");
 128         }
 129 
< prev index next >