Mercurial > hg > truffle

comparison test/runtime/Thread/TestThreadDumpMonitorContention.java @ 17965:4a1062dc52d1

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
8036823: Stack trace sometimes shows 'locked' instead of 'waiting to lock' Summary: Add a !owner check for 'waiting to lock' to catch current_pending_monitor corner cases. Reviewed-by: dholmes, sspitsyn, kmo, zgu Contributed-by: rednaxelafx@gmail.com, zhengyu.gu@oracle.com, daniel.daugherty@oracle.com
author dcubed
date Wed, 04 Jun 2014 06:25:53 -0700
parents
children 22146594cd5a
comparison
equal deleted inserted replaced
17964:660b3f6bf7d7 17965:4a1062dc52d1
1 /*
2 * Copyright (c) 2014, 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 /*
25 * @test
26 * @bug 8036823
27 * @summary Creates two threads contending for the same lock and checks
28 * whether jstack reports "locked" by more than one thread.
29 *
30 * @library /testlibrary
31 * @run main/othervm TestThreadDumpMonitorContention
32 */
33
34 import java.io.BufferedReader;
35 import java.io.InputStreamReader;
36 import java.lang.management.ManagementFactory;
37 import java.lang.management.RuntimeMXBean;
38 import java.util.ArrayList;
39 import java.util.List;
40 import java.util.regex.Matcher;
41 import java.util.regex.Pattern;
42
43 import com.oracle.java.testlibrary.*;
44
45 public class TestThreadDumpMonitorContention {
46 // jstack tends to be closely bound to the VM that we are running
47 // so use getTestJDKTool() instead of getCompileJDKTool() or even
48 // getJDKTool() which can fall back to "compile.jdk".
49 final static String JSTACK = JDKToolFinder.getTestJDKTool("jstack");
50 final static String PID = getPid();
51
52 // looking for header lines with these patterns:
53 // "ContendingThread-1" #19 prio=5 os_prio=64 tid=0x000000000079c000 nid=0x23 runnable [0xffff80ffb8b87000]
54 // "ContendingThread-2" #21 prio=5 os_prio=64 tid=0x0000000000780000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000]
55 final static Pattern HEADER_PREFIX_PATTERN = Pattern.compile(
56 "^\"ContendingThread-.*");
57 final static Pattern HEADER_WAITING_PATTERN = Pattern.compile(
58 "^\"ContendingThread-.* waiting for monitor entry .*");
59 final static Pattern HEADER_RUNNABLE_PATTERN = Pattern.compile(
60 "^\"ContendingThread-.* runnable .*");
61
62 // looking for thread state lines with these patterns:
63 // java.lang.Thread.State: RUNNABLE
64 // java.lang.Thread.State: BLOCKED (on object monitor)
65 final static Pattern THREAD_STATE_PREFIX_PATTERN = Pattern.compile(
66 " *java\\.lang\\.Thread\\.State: .*");
67 final static Pattern THREAD_STATE_BLOCKED_PATTERN = Pattern.compile(
68 " *java\\.lang\\.Thread\\.State: BLOCKED \\(on object monitor\\)");
69 final static Pattern THREAD_STATE_RUNNABLE_PATTERN = Pattern.compile(
70 " *java\\.lang\\.Thread\\.State: RUNNABLE");
71
72 // looking for duplicates of this pattern:
73 // - locked <0x000000076ac59e20> (a TestThreadDumpMonitorContention$1)
74 final static Pattern LOCK_PATTERN = Pattern.compile(
75 ".* locked \\<.*\\(a TestThreadDumpMonitorContention.*");
76
77 // sanity checking header and thread state lines associated
78 // with this pattern:
79 // - waiting to lock <0x000000076ac59e20> (a TestThreadDumpMonitorContention$1)
80 final static Pattern WAITING_PATTERN = Pattern.compile(
81 ".* waiting to lock \\<.*\\(a TestThreadDumpMonitorContention.*");
82
83 volatile static boolean done = false;
84
85 static int error_cnt = 0;
86 static String header_line = null;
87 static boolean have_header_line = false;
88 static boolean have_thread_state_line = false;
89 static int match_cnt = 0;
90 static String[] match_list = new String[2];
91 static int n_samples = 15;
92 static String thread_state_line = null;
93 static boolean verbose = false;
94
95 public static void main(String[] args) throws Exception {
96 if (args.length != 0) {
97 int arg_i = 0;
98 if (args[arg_i].equals("-v")) {
99 verbose = true;
100 arg_i++;
101 }
102
103 try {
104 n_samples = Integer.parseInt(args[arg_i]);
105 } catch (NumberFormatException nfe) {
106 System.err.println(nfe);
107 usage();
108 }
109 }
110
111 Runnable runnable = new Runnable() {
112 public void run() {
113 while (!done) {
114 synchronized (this) { }
115 }
116 }
117 };
118 Thread[] thread_list = new Thread[2];
119 thread_list[0] = new Thread(runnable, "ContendingThread-1");
120 thread_list[1] = new Thread(runnable, "ContendingThread-2");
121 thread_list[0].start();
122 thread_list[1].start();
123
124 doSamples();
125
126 done = true;
127
128 thread_list[0].join();
129 thread_list[1].join();
130
131 if (error_cnt == 0) {
132 System.out.println("Test PASSED.");
133 } else {
134 System.out.println("Test FAILED.");
135 throw new AssertionError("error_cnt=" + error_cnt);
136 }
137 }
138
139 // Reached a blank line which is the end of the
140 // stack trace without matching either LOCK_PATTERN
141 // or WAITING_PATTERN. Rare, but it's not an error.
142 //
143 // Example:
144 // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000]
145 // java.lang.Thread.State: RUNNABLE
146 // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
147 // at java.lang.Thread.run(Thread.java:745)
148 //
149 static boolean checkBlankLine(String line) {
150 if (line.length() == 0) {
151 have_header_line = false;
152 have_thread_state_line = false;
153 return true;
154 }
155
156 return false;
157 }
158
159 // Process the locked line here if we found one.
160 //
161 // Example 1:
162 // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000]
163 // java.lang.Thread.State: RUNNABLE
164 // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
165 // - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
166 // at java.lang.Thread.run(Thread.java:745)
167 //
168 // Example 2:
169 // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000]
170 // java.lang.Thread.State: BLOCKED (on object monitor)
171 // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
172 // - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
173 // at java.lang.Thread.run(Thread.java:745)
174 //
175 static boolean checkLockedLine(String line) {
176 Matcher matcher = LOCK_PATTERN.matcher(line);
177 if (matcher.matches()) {
178 if (verbose) {
179 System.out.println("locked_line='" + line + "'");
180 }
181 match_list[match_cnt] = new String(line);
182 match_cnt++;
183
184 matcher = HEADER_RUNNABLE_PATTERN.matcher(header_line);
185 if (!matcher.matches()) {
186 // It's strange, but a locked line can also
187 // match the HEADER_WAITING_PATTERN.
188 matcher = HEADER_WAITING_PATTERN.matcher(header_line);
189 if (!matcher.matches()) {
190 System.err.println();
191 System.err.println("ERROR: header line does " +
192 "not match runnable or waiting patterns.");
193 System.err.println("ERROR: header_line='" +
194 header_line + "'");
195 System.err.println("ERROR: locked_line='" + line + "'");
196 error_cnt++;
197 }
198 }
199
200 matcher = THREAD_STATE_RUNNABLE_PATTERN.matcher(thread_state_line);
201 if (!matcher.matches()) {
202 // It's strange, but a locked line can also
203 // match the THREAD_STATE_BLOCKED_PATTERN.
204 matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(
205 thread_state_line);
206 if (!matcher.matches()) {
207 System.err.println();
208 System.err.println("ERROR: thread state line does not " +
209 "match runnable or waiting patterns.");
210 System.err.println("ERROR: " + "thread_state_line='" +
211 thread_state_line + "'");
212 System.err.println("ERROR: locked_line='" + line + "'");
213 error_cnt++;
214 }
215 }
216
217 // Have everything we need from this thread stack
218 // that matches the LOCK_PATTERN.
219 have_header_line = false;
220 have_thread_state_line = false;
221 return true;
222 }
223
224 return false;
225 }
226
227 // Process the waiting line here if we found one.
228 //
229 // Example:
230 // "ContendingThread-2" #22 prio=5 os_prio=64 tid=0x00000000007b9800 nid=0x30 waiting for monitor entry [0xfffffd7fc1010000]
231 // java.lang.Thread.State: BLOCKED (on object monitor)
232 // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
233 // - waiting to lock <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
234 // at java.lang.Thread.run(Thread.java:745)
235 //
236 static boolean checkWaitingLine(String line) {
237 Matcher matcher = WAITING_PATTERN.matcher(line);
238 if (matcher.matches()) {
239 if (verbose) {
240 System.out.println("waiting_line='" + line + "'");
241 }
242
243 matcher = HEADER_WAITING_PATTERN.matcher(header_line);
244 if (!matcher.matches()) {
245 System.err.println();
246 System.err.println("ERROR: header line does " +
247 "not match a waiting pattern.");
248 System.err.println("ERROR: header_line='" + header_line + "'");
249 System.err.println("ERROR: waiting_line='" + line + "'");
250 error_cnt++;
251 }
252
253 matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(thread_state_line);
254 if (!matcher.matches()) {
255 System.err.println();
256 System.err.println("ERROR: thread state line " +
257 "does not match a waiting pattern.");
258 System.err.println("ERROR: thread_state_line='" +
259 thread_state_line + "'");
260 System.err.println("ERROR: waiting_line='" + line + "'");
261 error_cnt++;
262 }
263
264 // Have everything we need from this thread stack
265 // that matches the WAITING_PATTERN.
266 have_header_line = false;
267 have_thread_state_line = false;
268 return true;
269 }
270
271 return false;
272 }
273
274 static void doSamples() throws Exception {
275 for (int count = 0; count < n_samples; count++) {
276 match_cnt = 0;
277 // verbose mode or an error has a lot of output so add more space
278 if (verbose || error_cnt > 0) System.out.println();
279 System.out.println("Sample #" + count);
280
281 // We don't use the ProcessTools, OutputBuffer or
282 // OutputAnalyzer classes from the testlibrary because
283 // we have a complicated multi-line parse to perform
284 // on a narrow subset of the JSTACK output.
285 //
286 // - we only care about stack traces that match
287 // HEADER_PREFIX_PATTERN; only two should match
288 // - we care about at most three lines from each stack trace
289 // - if both stack traces match LOCKED_PATTERN, then that's
290 // a failure and we report it
291 // - for a stack trace that matches LOCKED_PATTERN, we verify:
292 // - the header line matches HEADER_RUNNABLE_PATTERN
293 // or HEADER_WAITING_PATTERN
294 // - the thread state line matches THREAD_STATE_BLOCKED_PATTERN
295 // or THREAD_STATE_RUNNABLE_PATTERN
296 // - we report any mismatches as failures
297 // - for a stack trace that matches WAITING_PATTERN, we verify:
298 // - the header line matches HEADER_WAITING_PATTERN
299 // - the thread state line matches THREAD_STATE_BLOCKED_PATTERN
300 // - we report any mismatches as failures
301 // - the stack traces that match HEADER_PREFIX_PATTERN may
302 // not match either LOCKED_PATTERN or WAITING_PATTERN
303 // because we might observe the thread outside of
304 // monitor operations; this is not considered a failure
305 //
306 // When we do observe LOCKED_PATTERN or WAITING_PATTERN,
307 // then we are checking the header and thread state patterns
308 // that occurred earlier in the current stack trace that
309 // matched HEADER_PREFIX_PATTERN. We don't use data from
310 // stack traces that don't match HEADER_PREFIX_PATTERN and
311 // we don't mix data between the two stack traces that do
312 // match HEADER_PREFIX_PATTERN.
313 //
314 Process process = new ProcessBuilder(JSTACK, PID)
315 .redirectErrorStream(true).start();
316
317 BufferedReader reader = new BufferedReader(new InputStreamReader(
318 process.getInputStream()));
319 String line;
320 while ((line = reader.readLine()) != null) {
321 Matcher matcher = null;
322
323 // process the header line here
324 if (!have_header_line) {
325 matcher = HEADER_PREFIX_PATTERN.matcher(line);
326 if (matcher.matches()) {
327 if (verbose) {
328 System.out.println();
329 System.out.println("header='" + line + "'");
330 }
331 header_line = new String(line);
332 have_header_line = true;
333 continue;
334 }
335 continue; // skip until have a header line
336 }
337
338 // process the thread state line here
339 if (!have_thread_state_line) {
340 matcher = THREAD_STATE_PREFIX_PATTERN.matcher(line);
341 if (matcher.matches()) {
342 if (verbose) {
343 System.out.println("thread_state='" + line + "'");
344 }
345 thread_state_line = new String(line);
346 have_thread_state_line = true;
347 continue;
348 }
349 continue; // skip until we have a thread state line
350 }
351
352 // process the locked line here if we find one
353 if (checkLockedLine(line)) {
354 continue;
355 }
356
357 // process the waiting line here if we find one
358 if (checkWaitingLine(line)) {
359 continue;
360 }
361
362 // process the blank line here if we find one
363 if (checkBlankLine(line)) {
364 continue;
365 }
366 }
367 process.waitFor();
368
369 if (match_cnt == 2) {
370 if (match_list[0].equals(match_list[1])) {
371 System.err.println();
372 System.err.println("ERROR: matching lock lines:");
373 System.err.println("ERROR: line[0]'" + match_list[0] + "'");
374 System.err.println("ERROR: line[1]'" + match_list[1] + "'");
375 error_cnt++;
376 }
377 }
378
379 // slight delay between jstack launches
380 Thread.sleep(500);
381 }
382 }
383
384 // This helper relies on RuntimeMXBean.getName() returning a string
385 // that looks like this: 5436@mt-haku
386 //
387 // The testlibrary has tryFindJvmPid(), but that uses a separate
388 // process which is much more expensive for finding out your own PID.
389 //
390 static String getPid() {
391 RuntimeMXBean runtimebean = ManagementFactory.getRuntimeMXBean();
392 String vmname = runtimebean.getName();
393 int i = vmname.indexOf('@');
394 if (i != -1) {
395 vmname = vmname.substring(0, i);
396 }
397 return vmname;
398 }
399
400 static void usage() {
401 System.err.println("Usage: " +
402 "java TestThreadDumpMonitorContention [-v] [n_samples]");
403 System.exit(1);
404 }
405 }