test/runtime/Thread/TestThreadDumpMonitorContention.java

Mon, 28 Jul 2014 15:06:38 -0700

author
fzhinkin
date
Mon, 28 Jul 2014 15:06:38 -0700
changeset 6997
dbb05f6d93c4
parent 6727
22146594cd5a
child 6876
710a3c8b516e
permissions
-rw-r--r--

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

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

mercurial