1 /*
2  * Copyright (c) 2017, 2019, 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     public static final boolean verbose = System.getProperty("verbose") != null;
47     // 16 seconds for hs_err generation timeout = 4 seconds per step timeout
48     public static final int ERROR_LOG_TIMEOUT = 16;
49 
main(String[] args)50     public static void main(String[] args) throws Exception {
51 
52         int error_log_timeout = ERROR_LOG_TIMEOUT;
53         if ("SunOS".equals(System.getProperty("os.name"))) {
54             // Give Solaris machines 3X as much time:
55             error_log_timeout *= 3;
56         }
57 
58         /* Start the VM and let it crash. Specify TestUnresponsiveErrorHandler which will
59          * let five subsequent error reporting steps hang. The Timeout handling triggered
60          * by the WatcherThread should kick in and interrupt those steps. In theory, the
61          * text "timeout occurred during error reporting in step .." (the little timeouts)
62          * should occur in the error log up to four times, followed by the final big timeout
63          * "------ Timeout during error reporting after xx s. ------"
64          *
65          * Note that there are a number of uncertainties which make writing a 100% foolproof
66          * test challenging. The time the error reporting thread takes to react to the
67          * timeout triggers is unknown. So it is difficult to predict how many little timeouts
68          * will be visible before the big timeout kicks in. Also, once the big timeout hits,
69          * error reporting thread and Watcherthread will race. The former writes his last
70          * message to the error logs and flushes, the latter waits 200ms and then exits the
71          * process without further synchronization with the error reporting thread.
72          *
73          * Because of all this and the desire to write a bullet proof test which does
74          * not fail sporadically, we will not test for the final timeout message nor for all
75          * of the optimally expected little timeout messages. We just test for two of the
76          * little timeout messages to see that repeated timeout handling is basically working.
77          */
78 
79         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(
80             "-XX:+UnlockDiagnosticVMOptions",
81             "-Xmx100M",
82             "-XX:ErrorHandlerTest=14",
83             "-XX:+TestUnresponsiveErrorHandler",
84             "-XX:ErrorLogTimeout=" + error_log_timeout,
85             "-XX:-CreateCoredumpOnCrash",
86             "-version");
87 
88         OutputAnalyzer output_detail = new OutputAnalyzer(pb.start());
89 
90         if (verbose) {
91             System.err.println("<begin cmd output>");
92             System.err.println(output_detail.getOutput());
93             System.err.println("<end cmd output>");
94         }
95 
96         // we should have crashed with a SIGSEGV
97         output_detail.shouldMatch("# A fatal error has been detected by the Java Runtime Environment:.*");
98         output_detail.shouldMatch("# +(?:SIGSEGV|SIGBUS|EXCEPTION_ACCESS_VIOLATION).*");
99 
100         // VM should have been aborted by WatcherThread
101         output_detail.shouldMatch(".*timer expired, abort.*");
102 
103         // extract hs-err file
104         String hs_err_file = output_detail.firstMatch("# *(\\S*hs_err_pid\\d+\\.log)", 1);
105         if (hs_err_file == null) {
106             if (!verbose) {
107                 System.err.println("<begin cmd output>");
108                 System.err.println(output_detail.getOutput());
109                 System.err.println("<end cmd output>");
110             }
111             throw new RuntimeException("Did not find hs-err file in output.\n");
112         }
113 
114         File f = new File(hs_err_file);
115         if (!f.exists()) {
116             if (!verbose) {
117                 System.err.println("<begin cmd output>");
118                 System.err.println(output_detail.getOutput());
119                 System.err.println("<end cmd output>");
120             }
121             throw new RuntimeException("hs-err file missing at "
122                 + f.getAbsolutePath() + ".\n");
123         }
124 
125         System.out.println("Found hs_err file. Scanning...");
126 
127         FileInputStream fis = new FileInputStream(f);
128         BufferedReader br = new BufferedReader(new InputStreamReader(fis));
129         String line = null;
130 
131 
132         Pattern [] pattern = new Pattern[] {
133             Pattern.compile(".*timeout occurred during error reporting in step.*"),
134             Pattern.compile(".*timeout occurred during error reporting in step.*")
135         };
136         int currentPattern = 0;
137 
138         String lastLine = null;
139         StringBuilder saved_hs_err = new StringBuilder();
140         while ((line = br.readLine()) != null) {
141             saved_hs_err.append(line + System.lineSeparator());
142             if (currentPattern < pattern.length) {
143                 if (pattern[currentPattern].matcher(line).matches()) {
144                     System.out.println("Found: " + line + ".");
145                     currentPattern ++;
146                 }
147             }
148             lastLine = line;
149         }
150         br.close();
151 
152         if (verbose) {
153             System.err.println("<begin hs_err contents>");
154             System.err.print(saved_hs_err);
155             System.err.println("<end hs_err contents>");
156         }
157 
158         if (currentPattern < pattern.length) {
159             if (!verbose) {
160                 System.err.println("<begin hs_err contents>");
161                 System.err.print(saved_hs_err);
162                 System.err.println("<end hs_err contents>");
163             }
164             throw new RuntimeException("hs-err file incomplete (first missing pattern: " +  currentPattern + ")");
165         }
166 
167         System.out.println("OK.");
168 
169     }
170 
171 }
172