Mon, 28 Jul 2014 15:06:38 -0700
8051344: JVM crashed in Compile::start() during method parsing w/ UseRTMDeopt turned on
Summary: call rtm_deopt() only if there were no compilation bailouts before.
Reviewed-by: kvn
dcubed@6708 | 1 | /* |
dcubed@6708 | 2 | * Copyright (c) 2014, Oracle and/or its affiliates. All rights reserved. |
dcubed@6708 | 3 | * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
dcubed@6708 | 4 | * |
dcubed@6708 | 5 | * This code is free software; you can redistribute it and/or modify it |
dcubed@6708 | 6 | * under the terms of the GNU General Public License version 2 only, as |
dcubed@6708 | 7 | * published by the Free Software Foundation. |
dcubed@6708 | 8 | * |
dcubed@6708 | 9 | * This code is distributed in the hope that it will be useful, but WITHOUT |
dcubed@6708 | 10 | * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
dcubed@6708 | 11 | * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
dcubed@6708 | 12 | * version 2 for more details (a copy is included in the LICENSE file that |
dcubed@6708 | 13 | * accompanied this code). |
dcubed@6708 | 14 | * |
dcubed@6708 | 15 | * You should have received a copy of the GNU General Public License version |
dcubed@6708 | 16 | * 2 along with this work; if not, write to the Free Software Foundation, |
dcubed@6708 | 17 | * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
dcubed@6708 | 18 | * |
dcubed@6708 | 19 | * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA |
dcubed@6708 | 20 | * or visit www.oracle.com if you need additional information or have any |
dcubed@6708 | 21 | * questions. |
dcubed@6708 | 22 | */ |
dcubed@6708 | 23 | |
dcubed@6708 | 24 | /* |
dcubed@6708 | 25 | * @test |
dcubed@6708 | 26 | * @bug 8036823 |
dcubed@6727 | 27 | * @bug 8046287 |
dcubed@6708 | 28 | * @summary Creates two threads contending for the same lock and checks |
dcubed@6708 | 29 | * whether jstack reports "locked" by more than one thread. |
dcubed@6708 | 30 | * |
dcubed@6708 | 31 | * @library /testlibrary |
dcubed@6708 | 32 | * @run main/othervm TestThreadDumpMonitorContention |
dcubed@6708 | 33 | */ |
dcubed@6708 | 34 | |
dcubed@6708 | 35 | import java.io.BufferedReader; |
dcubed@6708 | 36 | import java.io.InputStreamReader; |
dcubed@6708 | 37 | import java.lang.management.ManagementFactory; |
dcubed@6708 | 38 | import java.lang.management.RuntimeMXBean; |
dcubed@6708 | 39 | import java.util.ArrayList; |
dcubed@6708 | 40 | import java.util.List; |
dcubed@6708 | 41 | import java.util.regex.Matcher; |
dcubed@6708 | 42 | import java.util.regex.Pattern; |
dcubed@6708 | 43 | |
dcubed@6708 | 44 | import com.oracle.java.testlibrary.*; |
dcubed@6708 | 45 | |
dcubed@6708 | 46 | public class TestThreadDumpMonitorContention { |
dcubed@6708 | 47 | // jstack tends to be closely bound to the VM that we are running |
dcubed@6708 | 48 | // so use getTestJDKTool() instead of getCompileJDKTool() or even |
dcubed@6708 | 49 | // getJDKTool() which can fall back to "compile.jdk". |
dcubed@6708 | 50 | final static String JSTACK = JDKToolFinder.getTestJDKTool("jstack"); |
dcubed@6708 | 51 | final static String PID = getPid(); |
dcubed@6708 | 52 | |
dcubed@6708 | 53 | // looking for header lines with these patterns: |
dcubed@6708 | 54 | // "ContendingThread-1" #19 prio=5 os_prio=64 tid=0x000000000079c000 nid=0x23 runnable [0xffff80ffb8b87000] |
dcubed@6708 | 55 | // "ContendingThread-2" #21 prio=5 os_prio=64 tid=0x0000000000780000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000] |
dcubed@6727 | 56 | // "ContendingThread-2" #24 prio=5 os_prio=64 tid=0x0000000000ec8800 nid=0x31 waiting on condition [0xfffffd7bbfffe000] |
dcubed@6708 | 57 | final static Pattern HEADER_PREFIX_PATTERN = Pattern.compile( |
dcubed@6708 | 58 | "^\"ContendingThread-.*"); |
dcubed@6727 | 59 | final static Pattern HEADER_WAITING_PATTERN1 = Pattern.compile( |
dcubed@6708 | 60 | "^\"ContendingThread-.* waiting for monitor entry .*"); |
dcubed@6727 | 61 | final static Pattern HEADER_WAITING_PATTERN2 = Pattern.compile( |
dcubed@6727 | 62 | "^\"ContendingThread-.* waiting on condition .*"); |
dcubed@6708 | 63 | final static Pattern HEADER_RUNNABLE_PATTERN = Pattern.compile( |
dcubed@6708 | 64 | "^\"ContendingThread-.* runnable .*"); |
dcubed@6708 | 65 | |
dcubed@6708 | 66 | // looking for thread state lines with these patterns: |
dcubed@6708 | 67 | // java.lang.Thread.State: RUNNABLE |
dcubed@6708 | 68 | // java.lang.Thread.State: BLOCKED (on object monitor) |
dcubed@6708 | 69 | final static Pattern THREAD_STATE_PREFIX_PATTERN = Pattern.compile( |
dcubed@6708 | 70 | " *java\\.lang\\.Thread\\.State: .*"); |
dcubed@6708 | 71 | final static Pattern THREAD_STATE_BLOCKED_PATTERN = Pattern.compile( |
dcubed@6708 | 72 | " *java\\.lang\\.Thread\\.State: BLOCKED \\(on object monitor\\)"); |
dcubed@6708 | 73 | final static Pattern THREAD_STATE_RUNNABLE_PATTERN = Pattern.compile( |
dcubed@6708 | 74 | " *java\\.lang\\.Thread\\.State: RUNNABLE"); |
dcubed@6708 | 75 | |
dcubed@6708 | 76 | // looking for duplicates of this pattern: |
dcubed@6708 | 77 | // - locked <0x000000076ac59e20> (a TestThreadDumpMonitorContention$1) |
dcubed@6708 | 78 | final static Pattern LOCK_PATTERN = Pattern.compile( |
dcubed@6708 | 79 | ".* locked \\<.*\\(a TestThreadDumpMonitorContention.*"); |
dcubed@6708 | 80 | |
dcubed@6708 | 81 | // sanity checking header and thread state lines associated |
dcubed@6708 | 82 | // with this pattern: |
dcubed@6708 | 83 | // - waiting to lock <0x000000076ac59e20> (a TestThreadDumpMonitorContention$1) |
dcubed@6708 | 84 | final static Pattern WAITING_PATTERN = Pattern.compile( |
dcubed@6708 | 85 | ".* waiting to lock \\<.*\\(a TestThreadDumpMonitorContention.*"); |
dcubed@6708 | 86 | |
dcubed@6727 | 87 | final static Object barrier = new Object(); |
dcubed@6708 | 88 | volatile static boolean done = false; |
dcubed@6708 | 89 | |
dcubed@6727 | 90 | static int barrier_cnt = 0; |
dcubed@6727 | 91 | static int blank_line_match_cnt = 0; |
dcubed@6708 | 92 | static int error_cnt = 0; |
dcubed@6708 | 93 | static boolean have_header_line = false; |
dcubed@6708 | 94 | static boolean have_thread_state_line = false; |
dcubed@6727 | 95 | static String header_line = null; |
dcubed@6727 | 96 | static int header_prefix_match_cnt = 0; |
dcubed@6727 | 97 | static int locked_line_match_cnt = 0; |
dcubed@6727 | 98 | static String[] locked_match_list = new String[2]; |
dcubed@6708 | 99 | static int n_samples = 15; |
dcubed@6727 | 100 | static int sum_both_running_cnt = 0; |
dcubed@6727 | 101 | static int sum_both_waiting_cnt = 0; |
dcubed@6727 | 102 | static int sum_contended_cnt = 0; |
dcubed@6727 | 103 | static int sum_locked_hdr_runnable_cnt = 0; |
dcubed@6727 | 104 | static int sum_locked_hdr_waiting1_cnt = 0; |
dcubed@6727 | 105 | static int sum_locked_hdr_waiting2_cnt = 0; |
dcubed@6727 | 106 | static int sum_locked_thr_state_blocked_cnt = 0; |
dcubed@6727 | 107 | static int sum_locked_thr_state_runnable_cnt = 0; |
dcubed@6727 | 108 | static int sum_one_waiting_cnt = 0; |
dcubed@6727 | 109 | static int sum_uncontended_cnt = 0; |
dcubed@6727 | 110 | static int sum_waiting_hdr_waiting1_cnt = 0; |
dcubed@6727 | 111 | static int sum_waiting_thr_state_blocked_cnt = 0; |
dcubed@6708 | 112 | static String thread_state_line = null; |
dcubed@6708 | 113 | static boolean verbose = false; |
dcubed@6727 | 114 | static int waiting_line_match_cnt = 0; |
dcubed@6708 | 115 | |
dcubed@6708 | 116 | public static void main(String[] args) throws Exception { |
dcubed@6708 | 117 | if (args.length != 0) { |
dcubed@6708 | 118 | int arg_i = 0; |
dcubed@6708 | 119 | if (args[arg_i].equals("-v")) { |
dcubed@6708 | 120 | verbose = true; |
dcubed@6708 | 121 | arg_i++; |
dcubed@6708 | 122 | } |
dcubed@6708 | 123 | |
dcubed@6708 | 124 | try { |
dcubed@6708 | 125 | n_samples = Integer.parseInt(args[arg_i]); |
dcubed@6708 | 126 | } catch (NumberFormatException nfe) { |
dcubed@6708 | 127 | System.err.println(nfe); |
dcubed@6708 | 128 | usage(); |
dcubed@6708 | 129 | } |
dcubed@6708 | 130 | } |
dcubed@6708 | 131 | |
dcubed@6708 | 132 | Runnable runnable = new Runnable() { |
dcubed@6708 | 133 | public void run() { |
dcubed@6727 | 134 | synchronized (barrier) { |
dcubed@6727 | 135 | // let the main thread know we're running |
dcubed@6727 | 136 | barrier_cnt++; |
dcubed@6727 | 137 | barrier.notify(); |
dcubed@6727 | 138 | } |
dcubed@6708 | 139 | while (!done) { |
dcubed@6708 | 140 | synchronized (this) { } |
dcubed@6708 | 141 | } |
dcubed@6708 | 142 | } |
dcubed@6708 | 143 | }; |
dcubed@6708 | 144 | Thread[] thread_list = new Thread[2]; |
dcubed@6708 | 145 | thread_list[0] = new Thread(runnable, "ContendingThread-1"); |
dcubed@6708 | 146 | thread_list[1] = new Thread(runnable, "ContendingThread-2"); |
dcubed@6727 | 147 | synchronized (barrier) { |
dcubed@6727 | 148 | thread_list[0].start(); |
dcubed@6727 | 149 | thread_list[1].start(); |
dcubed@6727 | 150 | |
dcubed@6727 | 151 | // Wait until the contending threads are running so that |
dcubed@6727 | 152 | // we don't sample any thread init states. |
dcubed@6727 | 153 | while (barrier_cnt < 2) { |
dcubed@6727 | 154 | barrier.wait(); |
dcubed@6727 | 155 | } |
dcubed@6727 | 156 | } |
dcubed@6708 | 157 | |
dcubed@6708 | 158 | doSamples(); |
dcubed@6708 | 159 | |
dcubed@6708 | 160 | done = true; |
dcubed@6708 | 161 | |
dcubed@6708 | 162 | thread_list[0].join(); |
dcubed@6708 | 163 | thread_list[1].join(); |
dcubed@6708 | 164 | |
dcubed@6708 | 165 | if (error_cnt == 0) { |
dcubed@6708 | 166 | System.out.println("Test PASSED."); |
dcubed@6708 | 167 | } else { |
dcubed@6708 | 168 | System.out.println("Test FAILED."); |
dcubed@6708 | 169 | throw new AssertionError("error_cnt=" + error_cnt); |
dcubed@6708 | 170 | } |
dcubed@6708 | 171 | } |
dcubed@6708 | 172 | |
dcubed@6708 | 173 | // Reached a blank line which is the end of the |
dcubed@6708 | 174 | // stack trace without matching either LOCK_PATTERN |
dcubed@6708 | 175 | // or WAITING_PATTERN. Rare, but it's not an error. |
dcubed@6708 | 176 | // |
dcubed@6708 | 177 | // Example: |
dcubed@6708 | 178 | // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000] |
dcubed@6708 | 179 | // java.lang.Thread.State: RUNNABLE |
dcubed@6727 | 180 | // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140) |
dcubed@6708 | 181 | // at java.lang.Thread.run(Thread.java:745) |
dcubed@6708 | 182 | // |
dcubed@6708 | 183 | static boolean checkBlankLine(String line) { |
dcubed@6708 | 184 | if (line.length() == 0) { |
dcubed@6727 | 185 | blank_line_match_cnt++; |
dcubed@6708 | 186 | have_header_line = false; |
dcubed@6708 | 187 | have_thread_state_line = false; |
dcubed@6708 | 188 | return true; |
dcubed@6708 | 189 | } |
dcubed@6708 | 190 | |
dcubed@6708 | 191 | return false; |
dcubed@6708 | 192 | } |
dcubed@6708 | 193 | |
dcubed@6708 | 194 | // Process the locked line here if we found one. |
dcubed@6708 | 195 | // |
dcubed@6708 | 196 | // Example 1: |
dcubed@6708 | 197 | // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f runnable [0xfffffd7fc1111000] |
dcubed@6708 | 198 | // java.lang.Thread.State: RUNNABLE |
dcubed@6727 | 199 | // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140) |
dcubed@6708 | 200 | // - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1) |
dcubed@6708 | 201 | // at java.lang.Thread.run(Thread.java:745) |
dcubed@6708 | 202 | // |
dcubed@6708 | 203 | // Example 2: |
dcubed@6708 | 204 | // "ContendingThread-1" #21 prio=5 os_prio=64 tid=0x00000000007b9000 nid=0x2f waiting for monitor entry [0xfffffd7fc1111000] |
dcubed@6708 | 205 | // java.lang.Thread.State: BLOCKED (on object monitor) |
dcubed@6727 | 206 | // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140) |
dcubed@6708 | 207 | // - locked <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1) |
dcubed@6708 | 208 | // at java.lang.Thread.run(Thread.java:745) |
dcubed@6708 | 209 | // |
dcubed@6727 | 210 | // Example 3: |
dcubed@6727 | 211 | // "ContendingThread-2" #24 prio=5 os_prio=64 tid=0x0000000000ec8800 nid=0x31 waiting on condition [0xfffffd7bbfffe000] |
dcubed@6727 | 212 | // java.lang.Thread.State: RUNNABLE |
dcubed@6727 | 213 | // JavaThread state: _thread_blocked |
dcubed@6727 | 214 | // Thread: 0x0000000000ec8800 [0x31] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 |
dcubed@6727 | 215 | // JavaThread state: _thread_blocked |
dcubed@6727 | 216 | // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140) |
dcubed@6727 | 217 | // - locked <0xfffffd7e6d03eb28> (a TestThreadDumpMonitorContention$1) |
dcubed@6727 | 218 | // at java.lang.Thread.run(Thread.java:745) |
dcubed@6727 | 219 | // |
dcubed@6708 | 220 | static boolean checkLockedLine(String line) { |
dcubed@6708 | 221 | Matcher matcher = LOCK_PATTERN.matcher(line); |
dcubed@6708 | 222 | if (matcher.matches()) { |
dcubed@6708 | 223 | if (verbose) { |
dcubed@6708 | 224 | System.out.println("locked_line='" + line + "'"); |
dcubed@6708 | 225 | } |
dcubed@6727 | 226 | locked_match_list[locked_line_match_cnt] = new String(line); |
dcubed@6727 | 227 | locked_line_match_cnt++; |
dcubed@6708 | 228 | |
dcubed@6708 | 229 | matcher = HEADER_RUNNABLE_PATTERN.matcher(header_line); |
dcubed@6727 | 230 | if (matcher.matches()) { |
dcubed@6727 | 231 | sum_locked_hdr_runnable_cnt++; |
dcubed@6727 | 232 | } else { |
dcubed@6708 | 233 | // It's strange, but a locked line can also |
dcubed@6727 | 234 | // match the HEADER_WAITING_PATTERN{1,2}. |
dcubed@6727 | 235 | matcher = HEADER_WAITING_PATTERN1.matcher(header_line); |
dcubed@6727 | 236 | if (matcher.matches()) { |
dcubed@6727 | 237 | sum_locked_hdr_waiting1_cnt++; |
dcubed@6727 | 238 | } else { |
dcubed@6727 | 239 | matcher = HEADER_WAITING_PATTERN2.matcher(header_line); |
dcubed@6727 | 240 | if (matcher.matches()) { |
dcubed@6727 | 241 | sum_locked_hdr_waiting2_cnt++; |
dcubed@6727 | 242 | } else { |
dcubed@6727 | 243 | System.err.println(); |
dcubed@6727 | 244 | System.err.println("ERROR: header line does " + |
dcubed@6727 | 245 | "not match runnable or waiting patterns."); |
dcubed@6727 | 246 | System.err.println("ERROR: header_line='" + |
dcubed@6727 | 247 | header_line + "'"); |
dcubed@6727 | 248 | System.err.println("ERROR: locked_line='" + line + |
dcubed@6727 | 249 | "'"); |
dcubed@6727 | 250 | error_cnt++; |
dcubed@6727 | 251 | } |
dcubed@6708 | 252 | } |
dcubed@6708 | 253 | } |
dcubed@6708 | 254 | |
dcubed@6708 | 255 | matcher = THREAD_STATE_RUNNABLE_PATTERN.matcher(thread_state_line); |
dcubed@6727 | 256 | if (matcher.matches()) { |
dcubed@6727 | 257 | sum_locked_thr_state_runnable_cnt++; |
dcubed@6727 | 258 | } else { |
dcubed@6708 | 259 | // It's strange, but a locked line can also |
dcubed@6708 | 260 | // match the THREAD_STATE_BLOCKED_PATTERN. |
dcubed@6708 | 261 | matcher = THREAD_STATE_BLOCKED_PATTERN.matcher( |
dcubed@6708 | 262 | thread_state_line); |
dcubed@6727 | 263 | if (matcher.matches()) { |
dcubed@6727 | 264 | sum_locked_thr_state_blocked_cnt++; |
dcubed@6727 | 265 | } else { |
dcubed@6708 | 266 | System.err.println(); |
dcubed@6708 | 267 | System.err.println("ERROR: thread state line does not " + |
dcubed@6708 | 268 | "match runnable or waiting patterns."); |
dcubed@6708 | 269 | System.err.println("ERROR: " + "thread_state_line='" + |
dcubed@6708 | 270 | thread_state_line + "'"); |
dcubed@6708 | 271 | System.err.println("ERROR: locked_line='" + line + "'"); |
dcubed@6708 | 272 | error_cnt++; |
dcubed@6708 | 273 | } |
dcubed@6708 | 274 | } |
dcubed@6708 | 275 | |
dcubed@6708 | 276 | // Have everything we need from this thread stack |
dcubed@6708 | 277 | // that matches the LOCK_PATTERN. |
dcubed@6708 | 278 | have_header_line = false; |
dcubed@6708 | 279 | have_thread_state_line = false; |
dcubed@6708 | 280 | return true; |
dcubed@6708 | 281 | } |
dcubed@6708 | 282 | |
dcubed@6708 | 283 | return false; |
dcubed@6708 | 284 | } |
dcubed@6708 | 285 | |
dcubed@6708 | 286 | // Process the waiting line here if we found one. |
dcubed@6708 | 287 | // |
dcubed@6708 | 288 | // Example: |
dcubed@6708 | 289 | // "ContendingThread-2" #22 prio=5 os_prio=64 tid=0x00000000007b9800 nid=0x30 waiting for monitor entry [0xfffffd7fc1010000] |
dcubed@6708 | 290 | // java.lang.Thread.State: BLOCKED (on object monitor) |
dcubed@6727 | 291 | // at TestThreadDumpMonitorContention$1.run(TestThreadDumpMonitorContention.java:140) |
dcubed@6708 | 292 | // - waiting to lock <0xfffffd7e6a2912f8> (a TestThreadDumpMonitorContention$1) |
dcubed@6708 | 293 | // at java.lang.Thread.run(Thread.java:745) |
dcubed@6708 | 294 | // |
dcubed@6708 | 295 | static boolean checkWaitingLine(String line) { |
dcubed@6708 | 296 | Matcher matcher = WAITING_PATTERN.matcher(line); |
dcubed@6708 | 297 | if (matcher.matches()) { |
dcubed@6727 | 298 | waiting_line_match_cnt++; |
dcubed@6708 | 299 | if (verbose) { |
dcubed@6708 | 300 | System.out.println("waiting_line='" + line + "'"); |
dcubed@6708 | 301 | } |
dcubed@6708 | 302 | |
dcubed@6727 | 303 | matcher = HEADER_WAITING_PATTERN1.matcher(header_line); |
dcubed@6727 | 304 | if (matcher.matches()) { |
dcubed@6727 | 305 | sum_waiting_hdr_waiting1_cnt++; |
dcubed@6727 | 306 | } else { |
dcubed@6708 | 307 | System.err.println(); |
dcubed@6708 | 308 | System.err.println("ERROR: header line does " + |
dcubed@6708 | 309 | "not match a waiting pattern."); |
dcubed@6708 | 310 | System.err.println("ERROR: header_line='" + header_line + "'"); |
dcubed@6708 | 311 | System.err.println("ERROR: waiting_line='" + line + "'"); |
dcubed@6708 | 312 | error_cnt++; |
dcubed@6708 | 313 | } |
dcubed@6708 | 314 | |
dcubed@6708 | 315 | matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(thread_state_line); |
dcubed@6727 | 316 | if (matcher.matches()) { |
dcubed@6727 | 317 | sum_waiting_thr_state_blocked_cnt++; |
dcubed@6727 | 318 | } else { |
dcubed@6708 | 319 | System.err.println(); |
dcubed@6708 | 320 | System.err.println("ERROR: thread state line " + |
dcubed@6708 | 321 | "does not match a waiting pattern."); |
dcubed@6708 | 322 | System.err.println("ERROR: thread_state_line='" + |
dcubed@6708 | 323 | thread_state_line + "'"); |
dcubed@6708 | 324 | System.err.println("ERROR: waiting_line='" + line + "'"); |
dcubed@6708 | 325 | error_cnt++; |
dcubed@6708 | 326 | } |
dcubed@6708 | 327 | |
dcubed@6708 | 328 | // Have everything we need from this thread stack |
dcubed@6708 | 329 | // that matches the WAITING_PATTERN. |
dcubed@6708 | 330 | have_header_line = false; |
dcubed@6708 | 331 | have_thread_state_line = false; |
dcubed@6708 | 332 | return true; |
dcubed@6708 | 333 | } |
dcubed@6708 | 334 | |
dcubed@6708 | 335 | return false; |
dcubed@6708 | 336 | } |
dcubed@6708 | 337 | |
dcubed@6708 | 338 | static void doSamples() throws Exception { |
dcubed@6708 | 339 | for (int count = 0; count < n_samples; count++) { |
dcubed@6727 | 340 | blank_line_match_cnt = 0; |
dcubed@6727 | 341 | header_prefix_match_cnt = 0; |
dcubed@6727 | 342 | locked_line_match_cnt = 0; |
dcubed@6727 | 343 | waiting_line_match_cnt = 0; |
dcubed@6708 | 344 | // verbose mode or an error has a lot of output so add more space |
dcubed@6708 | 345 | if (verbose || error_cnt > 0) System.out.println(); |
dcubed@6708 | 346 | System.out.println("Sample #" + count); |
dcubed@6708 | 347 | |
dcubed@6708 | 348 | // We don't use the ProcessTools, OutputBuffer or |
dcubed@6708 | 349 | // OutputAnalyzer classes from the testlibrary because |
dcubed@6708 | 350 | // we have a complicated multi-line parse to perform |
dcubed@6708 | 351 | // on a narrow subset of the JSTACK output. |
dcubed@6708 | 352 | // |
dcubed@6708 | 353 | // - we only care about stack traces that match |
dcubed@6708 | 354 | // HEADER_PREFIX_PATTERN; only two should match |
dcubed@6708 | 355 | // - we care about at most three lines from each stack trace |
dcubed@6708 | 356 | // - if both stack traces match LOCKED_PATTERN, then that's |
dcubed@6708 | 357 | // a failure and we report it |
dcubed@6708 | 358 | // - for a stack trace that matches LOCKED_PATTERN, we verify: |
dcubed@6708 | 359 | // - the header line matches HEADER_RUNNABLE_PATTERN |
dcubed@6727 | 360 | // or HEADER_WAITING_PATTERN{1,2} |
dcubed@6708 | 361 | // - the thread state line matches THREAD_STATE_BLOCKED_PATTERN |
dcubed@6708 | 362 | // or THREAD_STATE_RUNNABLE_PATTERN |
dcubed@6708 | 363 | // - we report any mismatches as failures |
dcubed@6708 | 364 | // - for a stack trace that matches WAITING_PATTERN, we verify: |
dcubed@6727 | 365 | // - the header line matches HEADER_WAITING_PATTERN1 |
dcubed@6708 | 366 | // - the thread state line matches THREAD_STATE_BLOCKED_PATTERN |
dcubed@6708 | 367 | // - we report any mismatches as failures |
dcubed@6708 | 368 | // - the stack traces that match HEADER_PREFIX_PATTERN may |
dcubed@6708 | 369 | // not match either LOCKED_PATTERN or WAITING_PATTERN |
dcubed@6708 | 370 | // because we might observe the thread outside of |
dcubed@6708 | 371 | // monitor operations; this is not considered a failure |
dcubed@6708 | 372 | // |
dcubed@6708 | 373 | // When we do observe LOCKED_PATTERN or WAITING_PATTERN, |
dcubed@6708 | 374 | // then we are checking the header and thread state patterns |
dcubed@6708 | 375 | // that occurred earlier in the current stack trace that |
dcubed@6708 | 376 | // matched HEADER_PREFIX_PATTERN. We don't use data from |
dcubed@6708 | 377 | // stack traces that don't match HEADER_PREFIX_PATTERN and |
dcubed@6708 | 378 | // we don't mix data between the two stack traces that do |
dcubed@6708 | 379 | // match HEADER_PREFIX_PATTERN. |
dcubed@6708 | 380 | // |
dcubed@6708 | 381 | Process process = new ProcessBuilder(JSTACK, PID) |
dcubed@6708 | 382 | .redirectErrorStream(true).start(); |
dcubed@6708 | 383 | |
dcubed@6708 | 384 | BufferedReader reader = new BufferedReader(new InputStreamReader( |
dcubed@6708 | 385 | process.getInputStream())); |
dcubed@6708 | 386 | String line; |
dcubed@6708 | 387 | while ((line = reader.readLine()) != null) { |
dcubed@6708 | 388 | Matcher matcher = null; |
dcubed@6708 | 389 | |
dcubed@6708 | 390 | // process the header line here |
dcubed@6708 | 391 | if (!have_header_line) { |
dcubed@6708 | 392 | matcher = HEADER_PREFIX_PATTERN.matcher(line); |
dcubed@6708 | 393 | if (matcher.matches()) { |
dcubed@6727 | 394 | header_prefix_match_cnt++; |
dcubed@6708 | 395 | if (verbose) { |
dcubed@6708 | 396 | System.out.println(); |
dcubed@6708 | 397 | System.out.println("header='" + line + "'"); |
dcubed@6708 | 398 | } |
dcubed@6708 | 399 | header_line = new String(line); |
dcubed@6708 | 400 | have_header_line = true; |
dcubed@6708 | 401 | continue; |
dcubed@6708 | 402 | } |
dcubed@6708 | 403 | continue; // skip until have a header line |
dcubed@6708 | 404 | } |
dcubed@6708 | 405 | |
dcubed@6708 | 406 | // process the thread state line here |
dcubed@6708 | 407 | if (!have_thread_state_line) { |
dcubed@6708 | 408 | matcher = THREAD_STATE_PREFIX_PATTERN.matcher(line); |
dcubed@6708 | 409 | if (matcher.matches()) { |
dcubed@6708 | 410 | if (verbose) { |
dcubed@6708 | 411 | System.out.println("thread_state='" + line + "'"); |
dcubed@6708 | 412 | } |
dcubed@6708 | 413 | thread_state_line = new String(line); |
dcubed@6708 | 414 | have_thread_state_line = true; |
dcubed@6708 | 415 | continue; |
dcubed@6708 | 416 | } |
dcubed@6708 | 417 | continue; // skip until we have a thread state line |
dcubed@6708 | 418 | } |
dcubed@6708 | 419 | |
dcubed@6708 | 420 | // process the locked line here if we find one |
dcubed@6708 | 421 | if (checkLockedLine(line)) { |
dcubed@6708 | 422 | continue; |
dcubed@6708 | 423 | } |
dcubed@6708 | 424 | |
dcubed@6708 | 425 | // process the waiting line here if we find one |
dcubed@6708 | 426 | if (checkWaitingLine(line)) { |
dcubed@6708 | 427 | continue; |
dcubed@6708 | 428 | } |
dcubed@6708 | 429 | |
dcubed@6708 | 430 | // process the blank line here if we find one |
dcubed@6708 | 431 | if (checkBlankLine(line)) { |
dcubed@6708 | 432 | continue; |
dcubed@6708 | 433 | } |
dcubed@6708 | 434 | } |
dcubed@6708 | 435 | process.waitFor(); |
dcubed@6708 | 436 | |
dcubed@6727 | 437 | if (header_prefix_match_cnt != 2) { |
dcubed@6727 | 438 | System.err.println(); |
dcubed@6727 | 439 | System.err.println("ERROR: should match exactly two headers."); |
dcubed@6727 | 440 | System.err.println("ERROR: header_prefix_match_cnt=" + |
dcubed@6727 | 441 | header_prefix_match_cnt); |
dcubed@6727 | 442 | error_cnt++; |
dcubed@6727 | 443 | } |
dcubed@6727 | 444 | |
dcubed@6727 | 445 | if (locked_line_match_cnt == 2) { |
dcubed@6727 | 446 | if (locked_match_list[0].equals(locked_match_list[1])) { |
dcubed@6727 | 447 | System.err.println(); |
dcubed@6727 | 448 | System.err.println("ERROR: matching lock lines:"); |
dcubed@6727 | 449 | System.err.println("ERROR: line[0]'" + |
dcubed@6727 | 450 | locked_match_list[0] + "'"); |
dcubed@6727 | 451 | System.err.println("ERROR: line[1]'" + |
dcubed@6727 | 452 | locked_match_list[1] + "'"); |
dcubed@6727 | 453 | error_cnt++; |
dcubed@6727 | 454 | } |
dcubed@6727 | 455 | } |
dcubed@6727 | 456 | |
dcubed@6727 | 457 | if (locked_line_match_cnt == 1) { |
dcubed@6727 | 458 | // one thread has the lock |
dcubed@6727 | 459 | if (waiting_line_match_cnt == 1) { |
dcubed@6727 | 460 | // and the other contended for it |
dcubed@6727 | 461 | sum_contended_cnt++; |
dcubed@6727 | 462 | } else { |
dcubed@6727 | 463 | // and the other is just running |
dcubed@6727 | 464 | sum_uncontended_cnt++; |
dcubed@6727 | 465 | } |
dcubed@6727 | 466 | } else if (waiting_line_match_cnt == 1) { |
dcubed@6727 | 467 | // one thread is waiting |
dcubed@6727 | 468 | sum_one_waiting_cnt++; |
dcubed@6727 | 469 | } else if (waiting_line_match_cnt == 2) { |
dcubed@6727 | 470 | // both threads are waiting |
dcubed@6727 | 471 | sum_both_waiting_cnt++; |
dcubed@6727 | 472 | } else { |
dcubed@6727 | 473 | // both threads are running |
dcubed@6727 | 474 | sum_both_running_cnt++; |
dcubed@6727 | 475 | } |
dcubed@6708 | 476 | |
dcubed@6708 | 477 | // slight delay between jstack launches |
dcubed@6708 | 478 | Thread.sleep(500); |
dcubed@6708 | 479 | } |
dcubed@6727 | 480 | |
dcubed@6727 | 481 | if (error_cnt != 0) { |
dcubed@6727 | 482 | // skip summary info since there were errors |
dcubed@6727 | 483 | return; |
dcubed@6727 | 484 | } |
dcubed@6727 | 485 | |
dcubed@6727 | 486 | System.out.println("INFO: Summary for all samples:"); |
dcubed@6727 | 487 | System.out.println("INFO: both_running_cnt=" + sum_both_running_cnt); |
dcubed@6727 | 488 | System.out.println("INFO: both_waiting_cnt=" + sum_both_waiting_cnt); |
dcubed@6727 | 489 | System.out.println("INFO: contended_cnt=" + sum_contended_cnt); |
dcubed@6727 | 490 | System.out.println("INFO: one_waiting_cnt=" + sum_one_waiting_cnt); |
dcubed@6727 | 491 | System.out.println("INFO: uncontended_cnt=" + sum_uncontended_cnt); |
dcubed@6727 | 492 | System.out.println("INFO: locked_hdr_runnable_cnt=" + |
dcubed@6727 | 493 | sum_locked_hdr_runnable_cnt); |
dcubed@6727 | 494 | System.out.println("INFO: locked_hdr_waiting1_cnt=" + |
dcubed@6727 | 495 | sum_locked_hdr_waiting1_cnt); |
dcubed@6727 | 496 | System.out.println("INFO: locked_hdr_waiting2_cnt=" + |
dcubed@6727 | 497 | sum_locked_hdr_waiting2_cnt); |
dcubed@6727 | 498 | System.out.println("INFO: locked_thr_state_blocked_cnt=" + |
dcubed@6727 | 499 | sum_locked_thr_state_blocked_cnt); |
dcubed@6727 | 500 | System.out.println("INFO: locked_thr_state_runnable_cnt=" + |
dcubed@6727 | 501 | sum_locked_thr_state_runnable_cnt); |
dcubed@6727 | 502 | System.out.println("INFO: waiting_hdr_waiting1_cnt=" + |
dcubed@6727 | 503 | sum_waiting_hdr_waiting1_cnt); |
dcubed@6727 | 504 | System.out.println("INFO: waiting_thr_state_blocked_cnt=" + |
dcubed@6727 | 505 | sum_waiting_thr_state_blocked_cnt); |
dcubed@6727 | 506 | |
dcubed@6727 | 507 | if (sum_contended_cnt == 0) { |
dcubed@6727 | 508 | System.err.println("WARNING: the primary scenario for 8036823" + |
dcubed@6727 | 509 | " has not been exercised by this test run."); |
dcubed@6727 | 510 | } |
dcubed@6708 | 511 | } |
dcubed@6708 | 512 | |
dcubed@6708 | 513 | // This helper relies on RuntimeMXBean.getName() returning a string |
dcubed@6708 | 514 | // that looks like this: 5436@mt-haku |
dcubed@6708 | 515 | // |
dcubed@6708 | 516 | // The testlibrary has tryFindJvmPid(), but that uses a separate |
dcubed@6708 | 517 | // process which is much more expensive for finding out your own PID. |
dcubed@6708 | 518 | // |
dcubed@6708 | 519 | static String getPid() { |
dcubed@6708 | 520 | RuntimeMXBean runtimebean = ManagementFactory.getRuntimeMXBean(); |
dcubed@6708 | 521 | String vmname = runtimebean.getName(); |
dcubed@6708 | 522 | int i = vmname.indexOf('@'); |
dcubed@6708 | 523 | if (i != -1) { |
dcubed@6708 | 524 | vmname = vmname.substring(0, i); |
dcubed@6708 | 525 | } |
dcubed@6708 | 526 | return vmname; |
dcubed@6708 | 527 | } |
dcubed@6708 | 528 | |
dcubed@6708 | 529 | static void usage() { |
dcubed@6708 | 530 | System.err.println("Usage: " + |
dcubed@6708 | 531 | "java TestThreadDumpMonitorContention [-v] [n_samples]"); |
dcubed@6708 | 532 | System.exit(1); |
dcubed@6708 | 533 | } |
dcubed@6708 | 534 | } |