| /* |
| * Copyright (c) 2014, Oracle and/or its affiliates. All rights reserved. |
| * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
| * |
| * This code is free software; you can redistribute it and/or modify it |
| * under the terms of the GNU General Public License version 2 only, as |
| * published by the Free Software Foundation. |
| * |
| * This code is distributed in the hope that it will be useful, but WITHOUT |
| * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
| * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
| * version 2 for more details (a copy is included in the LICENSE file that |
| * accompanied this code). |
| * |
| * You should have received a copy of the GNU General Public License version |
| * 2 along with this work; if not, write to the Free Software Foundation, |
| * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
| * |
| * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA |
| * or visit www.oracle.com if you need additional information or have any |
| * questions. |
| */ |
| |
| /* |
| * @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. |
| * |
| * @library /testlibrary |
| * @run main/othervm TestThreadDumpMonitorContention |
| */ |
| |
| import java.io.BufferedReader; |
| import java.io.InputStreamReader; |
| import java.lang.management.ManagementFactory; |
| import java.lang.management.RuntimeMXBean; |
| import java.util.ArrayList; |
| import java.util.List; |
| import java.util.regex.Matcher; |
| import java.util.regex.Pattern; |
| |
| import com.oracle.java.testlibrary.*; |
| |
| public class TestThreadDumpMonitorContention { |
| // jstack tends to be closely bound to the VM that we are running |
| // so use getTestJDKTool() instead of getCompileJDKTool() or even |
| // getJDKTool() which can fall back to "compile.jdk". |
| final static String JSTACK = JDKToolFinder.getTestJDKTool("jstack"); |
| final static String PID = getPid(); |
| |
| // 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_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 .*"); |
| |
| // looking for thread state lines with these patterns: |
| // java.lang.Thread.State: RUNNABLE |
| // java.lang.Thread.State: BLOCKED (on object monitor) |
| final static Pattern THREAD_STATE_PREFIX_PATTERN = Pattern.compile( |
| " *java\\.lang\\.Thread\\.State: .*"); |
| final static Pattern THREAD_STATE_BLOCKED_PATTERN = Pattern.compile( |
| " *java\\.lang\\.Thread\\.State: BLOCKED \\(on object monitor\\)"); |
| final static Pattern THREAD_STATE_RUNNABLE_PATTERN = Pattern.compile( |
| " *java\\.lang\\.Thread\\.State: RUNNABLE"); |
| |
| // looking for duplicates of this pattern: |
| // - locked <0x000000076ac59e20> (a TestThreadDumpMonitorContention$1) |
| final static Pattern LOCK_PATTERN = Pattern.compile( |
| ".* locked \\<.*\\(a TestThreadDumpMonitorContention.*"); |
| |
| // sanity checking header and thread state lines associated |
| // with this pattern: |
| // - waiting to lock <0x000000076ac59e20> (a TestThreadDumpMonitorContention$1) |
| 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 boolean have_header_line = false; |
| static boolean have_thread_state_line = false; |
| 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) { |
| int arg_i = 0; |
| if (args[arg_i].equals("-v")) { |
| verbose = true; |
| arg_i++; |
| } |
| |
| try { |
| n_samples = Integer.parseInt(args[arg_i]); |
| } catch (NumberFormatException nfe) { |
| System.err.println(nfe); |
| usage(); |
| } |
| } |
| |
| 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) { } |
| } |
| } |
| }; |
| Thread[] thread_list = new Thread[2]; |
| thread_list[0] = new Thread(runnable, "ContendingThread-1"); |
| thread_list[1] = new Thread(runnable, "ContendingThread-2"); |
| 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(); |
| |
| done = true; |
| |
| thread_list[0].join(); |
| thread_list[1].join(); |
| |
| if (error_cnt == 0) { |
| System.out.println("Test PASSED."); |
| } else { |
| System.out.println("Test FAILED."); |
| throw new AssertionError("error_cnt=" + error_cnt); |
| } |
| } |
| |
| // Reached a blank line which is the end of the |
| // stack trace without matching either LOCK_PATTERN |
| // or WAITING_PATTERN. Rare, but it's not an error. |
| // |
| // 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: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; |
| } |
| |
| return false; |
| } |
| |
| // Process the locked line here if we found one. |
| // |
| // 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: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: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 + "'"); |
| } |
| locked_match_list[locked_line_match_cnt] = new String(line); |
| locked_line_match_cnt++; |
| |
| matcher = HEADER_RUNNABLE_PATTERN.matcher(header_line); |
| if (matcher.matches()) { |
| sum_locked_hdr_runnable_cnt++; |
| } else { |
| // It's strange, but a locked line can also |
| // 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()) { |
| 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()) { |
| sum_locked_thr_state_blocked_cnt++; |
| } else { |
| System.err.println(); |
| System.err.println("ERROR: thread state line does not " + |
| "match runnable or waiting patterns."); |
| System.err.println("ERROR: " + "thread_state_line='" + |
| thread_state_line + "'"); |
| System.err.println("ERROR: locked_line='" + line + "'"); |
| error_cnt++; |
| } |
| } |
| |
| // Have everything we need from this thread stack |
| // that matches the LOCK_PATTERN. |
| have_header_line = false; |
| have_thread_state_line = false; |
| return true; |
| } |
| |
| return false; |
| } |
| |
| // Process the waiting line here if we found one. |
| // |
| // 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: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_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."); |
| System.err.println("ERROR: header_line='" + header_line + "'"); |
| System.err.println("ERROR: waiting_line='" + line + "'"); |
| error_cnt++; |
| } |
| |
| matcher = THREAD_STATE_BLOCKED_PATTERN.matcher(thread_state_line); |
| 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."); |
| System.err.println("ERROR: thread_state_line='" + |
| thread_state_line + "'"); |
| System.err.println("ERROR: waiting_line='" + line + "'"); |
| error_cnt++; |
| } |
| |
| // Have everything we need from this thread stack |
| // that matches the WAITING_PATTERN. |
| have_header_line = false; |
| have_thread_state_line = false; |
| return true; |
| } |
| |
| return false; |
| } |
| |
| static void doSamples() throws Exception { |
| for (int count = 0; count < n_samples; count++) { |
| 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); |
| |
| // We don't use the ProcessTools, OutputBuffer or |
| // OutputAnalyzer classes from the testlibrary because |
| // we have a complicated multi-line parse to perform |
| // on a narrow subset of the JSTACK output. |
| // |
| // - we only care about stack traces that match |
| // HEADER_PREFIX_PATTERN; only two should match |
| // - we care about at most three lines from each stack trace |
| // - if both stack traces match LOCKED_PATTERN, then that's |
| // 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{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_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 |
| // not match either LOCKED_PATTERN or WAITING_PATTERN |
| // because we might observe the thread outside of |
| // monitor operations; this is not considered a failure |
| // |
| // When we do observe LOCKED_PATTERN or WAITING_PATTERN, |
| // then we are checking the header and thread state patterns |
| // that occurred earlier in the current stack trace that |
| // matched HEADER_PREFIX_PATTERN. We don't use data from |
| // stack traces that don't match HEADER_PREFIX_PATTERN and |
| // we don't mix data between the two stack traces that do |
| // match HEADER_PREFIX_PATTERN. |
| // |
| Process process = new ProcessBuilder(JSTACK, PID) |
| .redirectErrorStream(true).start(); |
| |
| BufferedReader reader = new BufferedReader(new InputStreamReader( |
| process.getInputStream())); |
| String line; |
| while ((line = reader.readLine()) != null) { |
| Matcher matcher = null; |
| |
| // process the header line here |
| 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 + "'"); |
| } |
| header_line = new String(line); |
| have_header_line = true; |
| continue; |
| } |
| continue; // skip until have a header line |
| } |
| |
| // process the thread state line here |
| if (!have_thread_state_line) { |
| matcher = THREAD_STATE_PREFIX_PATTERN.matcher(line); |
| if (matcher.matches()) { |
| if (verbose) { |
| System.out.println("thread_state='" + line + "'"); |
| } |
| thread_state_line = new String(line); |
| have_thread_state_line = true; |
| continue; |
| } |
| continue; // skip until we have a thread state line |
| } |
| |
| // process the locked line here if we find one |
| if (checkLockedLine(line)) { |
| continue; |
| } |
| |
| // process the waiting line here if we find one |
| if (checkWaitingLine(line)) { |
| continue; |
| } |
| |
| // process the blank line here if we find one |
| if (checkBlankLine(line)) { |
| continue; |
| } |
| } |
| process.waitFor(); |
| |
| 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 |
| // that looks like this: 5436@mt-haku |
| // |
| // The testlibrary has tryFindJvmPid(), but that uses a separate |
| // process which is much more expensive for finding out your own PID. |
| // |
| static String getPid() { |
| RuntimeMXBean runtimebean = ManagementFactory.getRuntimeMXBean(); |
| String vmname = runtimebean.getName(); |
| int i = vmname.indexOf('@'); |
| if (i != -1) { |
| vmname = vmname.substring(0, i); |
| } |
| return vmname; |
| } |
| |
| static void usage() { |
| System.err.println("Usage: " + |
| "java TestThreadDumpMonitorContention [-v] [n_samples]"); |
| System.exit(1); |
| } |
| } |