1.1 --- a/test/runtime/Thread/TestThreadDumpMonitorContention.java Fri Jun 13 08:40:35 2014 +0000
1.2 +++ b/test/runtime/Thread/TestThreadDumpMonitorContention.java Thu Jun 12 15:57:16 2014 -0700
1.3 @@ -24,6 +24,7 @@
1.4 /*
1.5 * @test
1.6 * @bug 8036823
1.7 + * @bug 8046287
1.8 * @summary Creates two threads contending for the same lock and checks
1.9 * whether jstack reports "locked" by more than one thread.
1.10 *
1.11 @@ -52,10 +53,13 @@
1.12 // looking for header lines with these patterns:
1.13 // "ContendingThread-1" #19 prio=5 os_prio=64 tid=0x000000000079c000 nid=0x23 runnable [0xffff80ffb8b87000]
1.14 // "ContendingThread-2" #21 prio=5 os_prio=64 tid=0x0000000000780000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000]
1.15 + // "ContendingThread-2" #24 prio=5 os_prio=64 tid=0x0000000000ec8800 nid=0x31 waiting on condition [0xfffffd7bbfffe000]
1.16 final static Pattern HEADER_PREFIX_PATTERN = Pattern.compile(
1.17 "^\"ContendingThread-.*");
1.18 - final static Pattern HEADER_WAITING_PATTERN = Pattern.compile(
1.19 + final static Pattern HEADER_WAITING_PATTERN1 = Pattern.compile(
1.20 "^\"ContendingThread-.* waiting for monitor entry .*");
1.21 + final static Pattern HEADER_WAITING_PATTERN2 = Pattern.compile(
1.22 + "^\"ContendingThread-.* waiting on condition .*");
1.23 final static Pattern HEADER_RUNNABLE_PATTERN = Pattern.compile(
1.24 "^\"ContendingThread-.* runnable .*");
1.25
1.26 @@ -80,17 +84,34 @@
1.27 final static Pattern WAITING_PATTERN = Pattern.compile(
1.28 ".* waiting to lock \\<.*\\(a TestThreadDumpMonitorContention.*");
1.29
1.30 + final static Object barrier = new Object();
1.31 volatile static boolean done = false;
1.32
1.33 + static int barrier_cnt = 0;
1.34 + static int blank_line_match_cnt = 0;
1.35 static int error_cnt = 0;
1.36 - static String header_line = null;
1.37 static boolean have_header_line = false;
1.38 static boolean have_thread_state_line = false;
1.39 - static int match_cnt = 0;
1.40 - static String[] match_list = new String[2];
1.41 + static String header_line = null;
1.42 + static int header_prefix_match_cnt = 0;
1.43 + static int locked_line_match_cnt = 0;
1.44 + static String[] locked_match_list = new String[2];
1.45 static int n_samples = 15;
1.46 + static int sum_both_running_cnt = 0;
1.47 + static int sum_both_waiting_cnt = 0;
1.48 + static int sum_contended_cnt = 0;
1.49 + static int sum_locked_hdr_runnable_cnt = 0;
1.50 + static int sum_locked_hdr_waiting1_cnt = 0;
1.51 + static int sum_locked_hdr_waiting2_cnt = 0;
1.52 + static int sum_locked_thr_state_blocked_cnt = 0;
1.53 + static int sum_locked_thr_state_runnable_cnt = 0;
1.54 + static int sum_one_waiting_cnt = 0;
1.55 + static int sum_uncontended_cnt = 0;
1.56 + static int sum_waiting_hdr_waiting1_cnt = 0;
1.57 + static int sum_waiting_thr_state_blocked_cnt = 0;
1.58 static String thread_state_line = null;
1.59 static boolean verbose = false;
1.60 + static int waiting_line_match_cnt = 0;
1.61
1.62 public static void main(String[] args) throws Exception {
1.63 if (args.length != 0) {
1.64 @@ -110,6 +131,11 @@
1.65
1.66 Runnable runnable = new Runnable() {
1.67 public void run() {
1.68 + synchronized (barrier) {
1.69 + // let the main thread know we're running
1.70 + barrier_cnt++;
1.71 + barrier.notify();
1.72 + }
1.73 while (!done) {
1.74 synchronized (this) { }
1.75 }
1.76 @@ -118,8 +144,16 @@
1.77 Thread[] thread_list = new Thread[2];
1.78 thread_list[0] = new Thread(runnable, "ContendingThread-1");
1.79 thread_list[1] = new Thread(runnable, "ContendingThread-2");
1.80 - thread_list[0].start();
1.81 - thread_list[1].start();
1.82 + synchronized (barrier) {
1.83 + thread_list[0].start();
1.84 + thread_list[1].start();
1.85 +
1.86 + // Wait until the contending threads are running so that
1.87 + // we don't sample any thread init states.
1.88 + while (barrier_cnt < 2) {
1.89 + barrier.wait();
1.90 + }
1.91 + }
1.92
1.93 doSamples();
1.94
1.95 @@ -143,11 +177,12 @@
1.96 // Example:
1.97 // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000]
1.98 // java.lang.Thread.State: RUNNABLE
1.99 - // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
1.100 + // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
1.101 // at java.lang.Thread.run(Thread.java:745)
1.102 //
1.103 static boolean checkBlankLine(String line) {
1.104 if (line.length() == 0) {
1.105 + blank_line_match_cnt++;
1.106 have_header_line = false;
1.107 have_thread_state_line = false;
1.108 return true;
1.109 @@ -161,49 +196,73 @@
1.110 // Example 1:
1.111 // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000]
1.112 // java.lang.Thread.State: RUNNABLE
1.113 - // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
1.114 + // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
1.115 // - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
1.116 // at java.lang.Thread.run(Thread.java:745)
1.117 //
1.118 // Example 2:
1.119 // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000]
1.120 // java.lang.Thread.State: BLOCKED (on object monitor)
1.121 - // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
1.122 + // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
1.123 // - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
1.124 // at java.lang.Thread.run(Thread.java:745)
1.125 //
1.126 + // Example 3:
1.127 + // "ContendingThread-2" #24 prio=5 os_prio=64 tid=0x0000000000ec8800 nid=0x31 waiting on condition [0xfffffd7bbfffe000]
1.128 + // java.lang.Thread.State: RUNNABLE
1.129 + // JavaThread state: _thread_blocked
1.130 + // Thread: 0x0000000000ec8800 [0x31] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
1.131 + // JavaThread state: _thread_blocked
1.132 + // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
1.133 + // - locked <0xfffffd7e6d03eb28> (a TestThreadDumpMonitorContention$1)
1.134 + // at java.lang.Thread.run(Thread.java:745)
1.135 + //
1.136 static boolean checkLockedLine(String line) {
1.137 Matcher matcher = LOCK_PATTERN.matcher(line);
1.138 if (matcher.matches()) {
1.139 if (verbose) {
1.140 System.out.println("locked_line='" + line + "'");
1.141 }
1.142 - match_list[match_cnt] = new String(line);
1.143 - match_cnt++;
1.144 + locked_match_list[locked_line_match_cnt] = new String(line);
1.145 + locked_line_match_cnt++;
1.146
1.147 matcher = HEADER_RUNNABLE_PATTERN.matcher(header_line);
1.148 - if (!matcher.matches()) {
1.149 + if (matcher.matches()) {
1.150 + sum_locked_hdr_runnable_cnt++;
1.151 + } else {
1.152 // It's strange, but a locked line can also
1.153 - // match the HEADER_WAITING_PATTERN.
1.154 - matcher = HEADER_WAITING_PATTERN.matcher(header_line);
1.155 - if (!matcher.matches()) {
1.156 - System.err.println();
1.157 - System.err.println("ERROR: header line does " +
1.158 - "not match runnable or waiting patterns.");
1.159 - System.err.println("ERROR: header_line='" +
1.160 - header_line + "'");
1.161 - System.err.println("ERROR: locked_line='" + line + "'");
1.162 - error_cnt++;
1.163 + // match the HEADER_WAITING_PATTERN{1,2}.
1.164 + matcher = HEADER_WAITING_PATTERN1.matcher(header_line);
1.165 + if (matcher.matches()) {
1.166 + sum_locked_hdr_waiting1_cnt++;
1.167 + } else {
1.168 + matcher = HEADER_WAITING_PATTERN2.matcher(header_line);
1.169 + if (matcher.matches()) {
1.170 + sum_locked_hdr_waiting2_cnt++;
1.171 + } else {
1.172 + System.err.println();
1.173 + System.err.println("ERROR: header line does " +
1.174 + "not match runnable or waiting patterns.");
1.175 + System.err.println("ERROR: header_line='" +
1.176 + header_line + "'");
1.177 + System.err.println("ERROR: locked_line='" + line +
1.178 + "'");
1.179 + error_cnt++;
1.180 + }
1.181 }
1.182 }
1.183
1.184 matcher = THREAD_STATE_RUNNABLE_PATTERN.matcher(thread_state_line);
1.185 - if (!matcher.matches()) {
1.186 + if (matcher.matches()) {
1.187 + sum_locked_thr_state_runnable_cnt++;
1.188 + } else {
1.189 // It's strange, but a locked line can also
1.190 // match the THREAD_STATE_BLOCKED_PATTERN.
1.191 matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(
1.192 thread_state_line);
1.193 - if (!matcher.matches()) {
1.194 + if (matcher.matches()) {
1.195 + sum_locked_thr_state_blocked_cnt++;
1.196 + } else {
1.197 System.err.println();
1.198 System.err.println("ERROR: thread state line does not " +
1.199 "match runnable or waiting patterns.");
1.200 @@ -229,19 +288,22 @@
1.201 // Example:
1.202 // "ContendingThread-2" #22 prio=5 os_prio=64 tid=0x00000000007b9800 nid=0x30 waiting for monitor entry [0xfffffd7fc1010000]
1.203 // java.lang.Thread.State: BLOCKED (on object monitor)
1.204 - // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:67)
1.205 + // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140)
1.206 // - waiting to lock <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1)
1.207 // at java.lang.Thread.run(Thread.java:745)
1.208 //
1.209 static boolean checkWaitingLine(String line) {
1.210 Matcher matcher = WAITING_PATTERN.matcher(line);
1.211 if (matcher.matches()) {
1.212 + waiting_line_match_cnt++;
1.213 if (verbose) {
1.214 System.out.println("waiting_line='" + line + "'");
1.215 }
1.216
1.217 - matcher = HEADER_WAITING_PATTERN.matcher(header_line);
1.218 - if (!matcher.matches()) {
1.219 + matcher = HEADER_WAITING_PATTERN1.matcher(header_line);
1.220 + if (matcher.matches()) {
1.221 + sum_waiting_hdr_waiting1_cnt++;
1.222 + } else {
1.223 System.err.println();
1.224 System.err.println("ERROR: header line does " +
1.225 "not match a waiting pattern.");
1.226 @@ -251,7 +313,9 @@
1.227 }
1.228
1.229 matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(thread_state_line);
1.230 - if (!matcher.matches()) {
1.231 + if (matcher.matches()) {
1.232 + sum_waiting_thr_state_blocked_cnt++;
1.233 + } else {
1.234 System.err.println();
1.235 System.err.println("ERROR: thread state line " +
1.236 "does not match a waiting pattern.");
1.237 @@ -273,7 +337,10 @@
1.238
1.239 static void doSamples() throws Exception {
1.240 for (int count = 0; count < n_samples; count++) {
1.241 - match_cnt = 0;
1.242 + blank_line_match_cnt = 0;
1.243 + header_prefix_match_cnt = 0;
1.244 + locked_line_match_cnt = 0;
1.245 + waiting_line_match_cnt = 0;
1.246 // verbose mode or an error has a lot of output so add more space
1.247 if (verbose || error_cnt > 0) System.out.println();
1.248 System.out.println("Sample #" + count);
1.249 @@ -290,12 +357,12 @@
1.250 // a failure and we report it
1.251 // - for a stack trace that matches LOCKED_PATTERN, we verify:
1.252 // - the header line matches HEADER_RUNNABLE_PATTERN
1.253 - // or HEADER_WAITING_PATTERN
1.254 + // or HEADER_WAITING_PATTERN{1,2}
1.255 // - the thread state line matches THREAD_STATE_BLOCKED_PATTERN
1.256 // or THREAD_STATE_RUNNABLE_PATTERN
1.257 // - we report any mismatches as failures
1.258 // - for a stack trace that matches WAITING_PATTERN, we verify:
1.259 - // - the header line matches HEADER_WAITING_PATTERN
1.260 + // - the header line matches HEADER_WAITING_PATTERN1
1.261 // - the thread state line matches THREAD_STATE_BLOCKED_PATTERN
1.262 // - we report any mismatches as failures
1.263 // - the stack traces that match HEADER_PREFIX_PATTERN may
1.264 @@ -324,6 +391,7 @@
1.265 if (!have_header_line) {
1.266 matcher = HEADER_PREFIX_PATTERN.matcher(line);
1.267 if (matcher.matches()) {
1.268 + header_prefix_match_cnt++;
1.269 if (verbose) {
1.270 System.out.println();
1.271 System.out.println("header='" + line + "'");
1.272 @@ -366,19 +434,80 @@
1.273 }
1.274 process.waitFor();
1.275
1.276 - if (match_cnt == 2) {
1.277 - if (match_list[0].equals(match_list[1])) {
1.278 - System.err.println();
1.279 - System.err.println("ERROR: matching lock lines:");
1.280 - System.err.println("ERROR: line[0]'" + match_list[0] + "'");
1.281 - System.err.println("ERROR: line[1]'" + match_list[1] + "'");
1.282 - error_cnt++;
1.283 - }
1.284 - }
1.285 + if (header_prefix_match_cnt != 2) {
1.286 + System.err.println();
1.287 + System.err.println("ERROR: should match exactly two headers.");
1.288 + System.err.println("ERROR: header_prefix_match_cnt=" +
1.289 + header_prefix_match_cnt);
1.290 + error_cnt++;
1.291 + }
1.292 +
1.293 + if (locked_line_match_cnt == 2) {
1.294 + if (locked_match_list[0].equals(locked_match_list[1])) {
1.295 + System.err.println();
1.296 + System.err.println("ERROR: matching lock lines:");
1.297 + System.err.println("ERROR: line[0]'" +
1.298 + locked_match_list[0] + "'");
1.299 + System.err.println("ERROR: line[1]'" +
1.300 + locked_match_list[1] + "'");
1.301 + error_cnt++;
1.302 + }
1.303 + }
1.304 +
1.305 + if (locked_line_match_cnt == 1) {
1.306 + // one thread has the lock
1.307 + if (waiting_line_match_cnt == 1) {
1.308 + // and the other contended for it
1.309 + sum_contended_cnt++;
1.310 + } else {
1.311 + // and the other is just running
1.312 + sum_uncontended_cnt++;
1.313 + }
1.314 + } else if (waiting_line_match_cnt == 1) {
1.315 + // one thread is waiting
1.316 + sum_one_waiting_cnt++;
1.317 + } else if (waiting_line_match_cnt == 2) {
1.318 + // both threads are waiting
1.319 + sum_both_waiting_cnt++;
1.320 + } else {
1.321 + // both threads are running
1.322 + sum_both_running_cnt++;
1.323 + }
1.324
1.325 // slight delay between jstack launches
1.326 Thread.sleep(500);
1.327 }
1.328 +
1.329 + if (error_cnt != 0) {
1.330 + // skip summary info since there were errors
1.331 + return;
1.332 + }
1.333 +
1.334 + System.out.println("INFO: Summary for all samples:");
1.335 + System.out.println("INFO: both_running_cnt=" + sum_both_running_cnt);
1.336 + System.out.println("INFO: both_waiting_cnt=" + sum_both_waiting_cnt);
1.337 + System.out.println("INFO: contended_cnt=" + sum_contended_cnt);
1.338 + System.out.println("INFO: one_waiting_cnt=" + sum_one_waiting_cnt);
1.339 + System.out.println("INFO: uncontended_cnt=" + sum_uncontended_cnt);
1.340 + System.out.println("INFO: locked_hdr_runnable_cnt=" +
1.341 + sum_locked_hdr_runnable_cnt);
1.342 + System.out.println("INFO: locked_hdr_waiting1_cnt=" +
1.343 + sum_locked_hdr_waiting1_cnt);
1.344 + System.out.println("INFO: locked_hdr_waiting2_cnt=" +
1.345 + sum_locked_hdr_waiting2_cnt);
1.346 + System.out.println("INFO: locked_thr_state_blocked_cnt=" +
1.347 + sum_locked_thr_state_blocked_cnt);
1.348 + System.out.println("INFO: locked_thr_state_runnable_cnt=" +
1.349 + sum_locked_thr_state_runnable_cnt);
1.350 + System.out.println("INFO: waiting_hdr_waiting1_cnt=" +
1.351 + sum_waiting_hdr_waiting1_cnt);
1.352 + System.out.println("INFO: waiting_thr_state_blocked_cnt=" +
1.353 + sum_waiting_thr_state_blocked_cnt);
1.354 +
1.355 + if (sum_contended_cnt == 0) {
1.356 + System.err.println("WARNING: the primary scenario for 8036823" +
1.357 + " has not been exercised by this test run.");
1.358 + }
1.359 }
1.360
1.361 // This helper relies on RuntimeMXBean.getName() returning a string
