8046287: [TESTBUG] runtime/Thread/TestThreadDumpMonitorContention.java failed error_cnt=12
Summary: Added a new header waiting pattern to catch the case where the target thread waiting on a condition (like a VM op); several other test improvements
Reviewed-by: sspitsyn, dholmes
--- a/hotspot/test/runtime/Thread/TestThreadDumpMonitorContention.java Thu Jun 12 13:37:53 2014 -0400
+++ b/hotspot/test/runtime/Thread/TestThreadDumpMonitorContention.java Thu Jun 12 15:57:16 2014 -0700
@@ -24,6 +24,7 @@
/*
* @test
* @bug 8036823
+ * @bug 8046287
* @summary Creates two threads contending for the same lock and checks
* whether jstack reports "locked" by more than one thread.
*
@@ -52,10 +53,13 @@
// looking for header lines with these patterns:
// "ContendingThread-1" #19 prio=5 os_prio=64 tid=0x000000000079c000 nid=0x23 runnable [0xffff80ffb8b87000]
// "ContendingThread-2" #21 prio=5 os_prio=64 tid=0x0000000000780000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000]
+ // "ContendingThread-2" #24 prio=5 os_prio=64 tid=0x0000000000ec8800 nid=0x31 waiting on condition [0xfffffd7bbfffe000]
final static Pattern HEADER_PREFIX_PATTERN = Pattern.compile(
"^\"ContendingThread-.*");
- final static Pattern HEADER_WAITING_PATTERN = Pattern.compile(
+ final static Pattern HEADER_WAITING_PATTERN1 = Pattern.compile(
"^\"ContendingThread-.* waiting for monitor entry .*");
+ final static Pattern HEADER_WAITING_PATTERN2 = Pattern.compile(
+ "^\"ContendingThread-.* waiting on condition .*");
final static Pattern HEADER_RUNNABLE_PATTERN = Pattern.compile(
"^\"ContendingThread-.* runnable .*");
@@ -80,17 +84,34 @@
final static Pattern WAITING_PATTERN = Pattern.compile(
".* waiting to lock \\<.*\\(a TestThreadDumpMonitorContention.*");
+ final static Object barrier = new Object();
volatile static boolean done = false;
+ static int barrier_cnt = 0;
+ static int blank_line_match_cnt = 0;
static int error_cnt = 0;
- static String header_line = null;
static boolean have_header_line = false;
static boolean have_thread_state_line = false;
- static int match_cnt = 0;
- static String[] match_list = new String[2];
+ static String header_line = null;
+ static int header_prefix_match_cnt = 0;
+ static int locked_line_match_cnt = 0;
+ static String[] locked_match_list = new String[2];
static int n_samples = 15;
+ static int sum_both_running_cnt = 0;
+ static int sum_both_waiting_cnt = 0;
+ static int sum_contended_cnt = 0;
+ static int sum_locked_hdr_runnable_cnt = 0;
+ static int sum_locked_hdr_waiting1_cnt = 0;
+ static int sum_locked_hdr_waiting2_cnt = 0;
+ static int sum_locked_thr_state_blocked_cnt = 0;
+ static int sum_locked_thr_state_runnable_cnt = 0;
+ static int sum_one_waiting_cnt = 0;
+ static int sum_uncontended_cnt = 0;
+ static int sum_waiting_hdr_waiting1_cnt = 0;
+ static int sum_waiting_thr_state_blocked_cnt = 0;
static String thread_state_line = null;
static boolean verbose = false;
+ static int waiting_line_match_cnt = 0;
public static void main(String[] args) throws Exception {
if (args.length != 0) {
@@ -110,6 +131,11 @@
Runnable runnable = new Runnable() {
public void run() {
+ synchronized (barrier) {
+ // let the main thread know we're running
+ barrier_cnt++;
+ barrier.notify();
+ }
while (!done) {
synchronized (this) { }
}
@@ -118,8 +144,16 @@
Thread[] thread_list = new Thread[2];
thread_list[0] = new Thread(runnable, "ContendingThread-1");
thread_list[1] = new Thread(runnable, "ContendingThread-2");
- thread_list[0].start();
- thread_list[1].start();
+ synchronized (barrier) {
+ thread_list[0].start();
+ thread_list[1].start();
+
+ // Wait until the contending threads are running so that
+ // we don't sample any thread init states.
+ while (barrier_cnt < 2) {
+ barrier.wait();
+ }
+ }
doSamples();
@@ -143,11 +177,12 @@
// Example:
// "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000]
// java.lang.Thread.State: RUNNABLE
- // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
+ // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
// at java.lang.Thread.run(Thread.java:745)
//
static boolean checkBlankLine(String line) {
if (line.length() == 0) {
+ blank_line_match_cnt++;
have_header_line = false;
have_thread_state_line = false;
return true;
@@ -161,49 +196,73 @@
// Example 1:
// "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000]
// java.lang.Thread.State: RUNNABLE
- // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
+ // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
// - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
// at java.lang.Thread.run(Thread.java:745)
//
// Example 2:
// "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000]
// java.lang.Thread.State: BLOCKED (on object monitor)
- // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
+ // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
// - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
// at java.lang.Thread.run(Thread.java:745)
//
+ // Example 3:
+ // "ContendingThread-2" #24 prio=5 os_prio=64 tid=0x0000000000ec8800 nid=0x31 waiting on condition [0xfffffd7bbfffe000]
+ // java.lang.Thread.State: RUNNABLE
+ // JavaThread state: _thread_blocked
+ // Thread: 0x0000000000ec8800 [0x31] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
+ // JavaThread state: _thread_blocked
+ // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
+ // - locked <0xfffffd7e6d03eb28> (a TestThreadDumpMonitorContention$1)
+ // at java.lang.Thread.run(Thread.java:745)
+ //
static boolean checkLockedLine(String line) {
Matcher matcher = LOCK_PATTERN.matcher(line);
if (matcher.matches()) {
if (verbose) {
System.out.println("locked_line='" + line + "'");
}
- match_list[match_cnt] = new String(line);
- match_cnt++;
+ locked_match_list[locked_line_match_cnt] = new String(line);
+ locked_line_match_cnt++;
matcher = HEADER_RUNNABLE_PATTERN.matcher(header_line);
- if (!matcher.matches()) {
+ if (matcher.matches()) {
+ sum_locked_hdr_runnable_cnt++;
+ } else {
// It's strange, but a locked line can also
- // match the HEADER_WAITING_PATTERN.
- matcher = HEADER_WAITING_PATTERN.matcher(header_line);
- if (!matcher.matches()) {
- System.err.println();
- System.err.println("ERROR: header line does " +
- "not match runnable or waiting patterns.");
- System.err.println("ERROR: header_line='" +
- header_line + "'");
- System.err.println("ERROR: locked_line='" + line + "'");
- error_cnt++;
+ // match the HEADER_WAITING_PATTERN{1,2}.
+ matcher = HEADER_WAITING_PATTERN1.matcher(header_line);
+ if (matcher.matches()) {
+ sum_locked_hdr_waiting1_cnt++;
+ } else {
+ matcher = HEADER_WAITING_PATTERN2.matcher(header_line);
+ if (matcher.matches()) {
+ sum_locked_hdr_waiting2_cnt++;
+ } else {
+ System.err.println();
+ System.err.println("ERROR: header line does " +
+ "not match runnable or waiting patterns.");
+ System.err.println("ERROR: header_line='" +
+ header_line + "'");
+ System.err.println("ERROR: locked_line='" + line +
+ "'");
+ error_cnt++;
+ }
}
}
matcher = THREAD_STATE_RUNNABLE_PATTERN.matcher(thread_state_line);
- if (!matcher.matches()) {
+ if (matcher.matches()) {
+ sum_locked_thr_state_runnable_cnt++;
+ } else {
// It's strange, but a locked line can also
// match the THREAD_STATE_BLOCKED_PATTERN.
matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(
thread_state_line);
- if (!matcher.matches()) {
+ if (matcher.matches()) {
+ sum_locked_thr_state_blocked_cnt++;
+ } else {
System.err.println();
System.err.println("ERROR: thread state line does not " +
"match runnable or waiting patterns.");
@@ -229,19 +288,22 @@
// Example:
// "ContendingThread-2" #22 prio=5 os_prio=64 tid=0x00000000007b9800 nid=0x30 waiting for monitor entry [0xfffffd7fc1010000]
// java.lang.Thread.State: BLOCKED (on object monitor)
- // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
+ // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
// - waiting to lock <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
// at java.lang.Thread.run(Thread.java:745)
//
static boolean checkWaitingLine(String line) {
Matcher matcher = WAITING_PATTERN.matcher(line);
if (matcher.matches()) {
+ waiting_line_match_cnt++;
if (verbose) {
System.out.println("waiting_line='" + line + "'");
}
- matcher = HEADER_WAITING_PATTERN.matcher(header_line);
- if (!matcher.matches()) {
+ matcher = HEADER_WAITING_PATTERN1.matcher(header_line);
+ if (matcher.matches()) {
+ sum_waiting_hdr_waiting1_cnt++;
+ } else {
System.err.println();
System.err.println("ERROR: header line does " +
"not match a waiting pattern.");
@@ -251,7 +313,9 @@
}
matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(thread_state_line);
- if (!matcher.matches()) {
+ if (matcher.matches()) {
+ sum_waiting_thr_state_blocked_cnt++;
+ } else {
System.err.println();
System.err.println("ERROR: thread state line " +
"does not match a waiting pattern.");
@@ -273,7 +337,10 @@
static void doSamples() throws Exception {
for (int count = 0; count < n_samples; count++) {
- match_cnt = 0;
+ blank_line_match_cnt = 0;
+ header_prefix_match_cnt = 0;
+ locked_line_match_cnt = 0;
+ waiting_line_match_cnt = 0;
// verbose mode or an error has a lot of output so add more space
if (verbose || error_cnt > 0) System.out.println();
System.out.println("Sample #" + count);
@@ -290,12 +357,12 @@
// a failure and we report it
// - for a stack trace that matches LOCKED_PATTERN, we verify:
// - the header line matches HEADER_RUNNABLE_PATTERN
- // or HEADER_WAITING_PATTERN
+ // or HEADER_WAITING_PATTERN{1,2}
// - the thread state line matches THREAD_STATE_BLOCKED_PATTERN
// or THREAD_STATE_RUNNABLE_PATTERN
// - we report any mismatches as failures
// - for a stack trace that matches WAITING_PATTERN, we verify:
- // - the header line matches HEADER_WAITING_PATTERN
+ // - the header line matches HEADER_WAITING_PATTERN1
// - the thread state line matches THREAD_STATE_BLOCKED_PATTERN
// - we report any mismatches as failures
// - the stack traces that match HEADER_PREFIX_PATTERN may
@@ -324,6 +391,7 @@
if (!have_header_line) {
matcher = HEADER_PREFIX_PATTERN.matcher(line);
if (matcher.matches()) {
+ header_prefix_match_cnt++;
if (verbose) {
System.out.println();
System.out.println("header='" + line + "'");
@@ -366,19 +434,80 @@
}
process.waitFor();
- if (match_cnt == 2) {
- if (match_list[0].equals(match_list[1])) {
- System.err.println();
- System.err.println("ERROR: matching lock lines:");
- System.err.println("ERROR: line[0]'" + match_list[0] + "'");
- System.err.println("ERROR: line[1]'" + match_list[1] + "'");
- error_cnt++;
- }
- }
+ if (header_prefix_match_cnt != 2) {
+ System.err.println();
+ System.err.println("ERROR: should match exactly two headers.");
+ System.err.println("ERROR: header_prefix_match_cnt=" +
+ header_prefix_match_cnt);
+ error_cnt++;
+ }
+
+ if (locked_line_match_cnt == 2) {
+ if (locked_match_list[0].equals(locked_match_list[1])) {
+ System.err.println();
+ System.err.println("ERROR: matching lock lines:");
+ System.err.println("ERROR: line[0]'" +
+ locked_match_list[0] + "'");
+ System.err.println("ERROR: line[1]'" +
+ locked_match_list[1] + "'");
+ error_cnt++;
+ }
+ }
+
+ if (locked_line_match_cnt == 1) {
+ // one thread has the lock
+ if (waiting_line_match_cnt == 1) {
+ // and the other contended for it
+ sum_contended_cnt++;
+ } else {
+ // and the other is just running
+ sum_uncontended_cnt++;
+ }
+ } else if (waiting_line_match_cnt == 1) {
+ // one thread is waiting
+ sum_one_waiting_cnt++;
+ } else if (waiting_line_match_cnt == 2) {
+ // both threads are waiting
+ sum_both_waiting_cnt++;
+ } else {
+ // both threads are running
+ sum_both_running_cnt++;
+ }
// slight delay between jstack launches
Thread.sleep(500);
}
+
+ if (error_cnt != 0) {
+ // skip summary info since there were errors
+ return;
+ }
+
+ System.out.println("INFO: Summary for all samples:");
+ System.out.println("INFO: both_running_cnt=" + sum_both_running_cnt);
+ System.out.println("INFO: both_waiting_cnt=" + sum_both_waiting_cnt);
+ System.out.println("INFO: contended_cnt=" + sum_contended_cnt);
+ System.out.println("INFO: one_waiting_cnt=" + sum_one_waiting_cnt);
+ System.out.println("INFO: uncontended_cnt=" + sum_uncontended_cnt);
+ System.out.println("INFO: locked_hdr_runnable_cnt=" +
+ sum_locked_hdr_runnable_cnt);
+ System.out.println("INFO: locked_hdr_waiting1_cnt=" +
+ sum_locked_hdr_waiting1_cnt);
+ System.out.println("INFO: locked_hdr_waiting2_cnt=" +
+ sum_locked_hdr_waiting2_cnt);
+ System.out.println("INFO: locked_thr_state_blocked_cnt=" +
+ sum_locked_thr_state_blocked_cnt);
+ System.out.println("INFO: locked_thr_state_runnable_cnt=" +
+ sum_locked_thr_state_runnable_cnt);
+ System.out.println("INFO: waiting_hdr_waiting1_cnt=" +
+ sum_waiting_hdr_waiting1_cnt);
+ System.out.println("INFO: waiting_thr_state_blocked_cnt=" +
+ sum_waiting_thr_state_blocked_cnt);
+
+ if (sum_contended_cnt == 0) {
+ System.err.println("WARNING: the primary scenario for 8036823" +
+ " has not been exercised by this test run.");
+ }
}
// This helper relies on RuntimeMXBean.getName() returning a string