# HG changeset patch # User vtewari # Date 1473327039 -19800 # Node ID d3928f9ab663445ff64c7f78842a4291d0e4bc0d # Parent d1d7b21e1abdeede87a102acbe3f82592fd97421 8152589: java/lang/management/ThreadMXBean/Locks.java fails intermittently, blocked on wrong object Reviewed-by: dholmes, dcubed diff -r d1d7b21e1abd -r d3928f9ab663 jdk/test/java/lang/management/ThreadMXBean/Locks.java --- a/jdk/test/java/lang/management/ThreadMXBean/Locks.java Wed Sep 07 16:17:20 2016 +0200 +++ b/jdk/test/java/lang/management/ThreadMXBean/Locks.java Thu Sep 08 15:00:39 2016 +0530 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2003, 2015, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2003, 2016, 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 @@ -26,27 +26,28 @@ * @bug 4530538 * @summary Basic unit test of ThreadInfo.getLockName() * and ThreadInfo.getLockOwnerName() + * @library /lib/testlibrary * @author Mandy Chung * @author Jaroslav Bachorik * - * @library /lib/testlibrary * @modules java.management * @build jdk.testlibrary.* * @run main/othervm Locks */ - import java.lang.management.*; +import java.util.Arrays; +import java.util.Optional; import java.util.concurrent.Phaser; +import java.util.function.Predicate; import jdk.testlibrary.LockFreeLogManager; public class Locks { - private static final Object objA = new Object(); - private static final Object objB = new Object(); - private static final Object objC = new Object(); - private static final ThreadMXBean tm = ManagementFactory.getThreadMXBean(); - private static final LockFreeLogManager logger = new LockFreeLogManager(); - private static boolean testFailed = false; + private static final Object OBJA = new Object(); + private static final Object OBJB = new Object(); + private static final EnhancedWaiter OBJC = new EnhancedWaiter(); + private static final ThreadMXBean TM = ManagementFactory.getThreadMXBean(); + private static final LockFreeLogManager LOGGER = new LockFreeLogManager(); private static String getLockName(Object lock) { if (lock == null) return null; @@ -56,67 +57,103 @@ } private static void assertNoLock(Thread t) { - long tid = t.getId(); - ThreadInfo info = tm.getThreadInfo(tid); - String result = info.getLockName(); + if (t == null) { + return; + } + Optional result = Arrays.asList( + TM.getThreadInfo(TM.getAllThreadIds(), true, true)). + stream(). + filter(tInfo -> (tInfo != null && tInfo.getLockOwnerName() != null) + ? tInfo.getLockOwnerName().equals(t.getName()) : false). + findAny(); + if (result.isPresent()) { + throw new RuntimeException("Thread " + t.getName() + " is not " + + "supposed to be hold any lock. Currently owning lock : " + + result.get().getLockName()); + } + } - if (result != null) { - throw new RuntimeException("Thread " + t.getName() + " is not supposed to hold any lock. " + - "Currently owning lock: " + result); + /* + * Handy debug function to check if error condition is because of test code or not. + */ + private static void printStackTrace(Thread thread) { + if (thread == null) { + return; + } + StackTraceElement[] stackTrace = thread.getStackTrace(); + log("Stack dump : Thread -> " + thread.getName()); + for (StackTraceElement stackTraceEl : stackTrace) { + log("\t" + stackTraceEl.toString()); } } - private static void checkBlockedObject(Thread t, Object lock, Thread owner, - Thread.State expectedState) { + private static void assertThreadState(Thread t, Thread.State expectedState) { long tid = t.getId(); - ThreadInfo info = tm.getThreadInfo(tid); - String result = info.getLockName(); - String expectedLock = (lock != null ? getLockName(lock) : null); - String expectedOwner = (owner != null ? owner.getName() : null); + if (expectedState == Thread.State.BLOCKED + && TM.getThreadInfo(tid).getThreadState() != Thread.State.BLOCKED) { + int retryCount = 0; + printStackTrace(t); + while (TM.getThreadInfo(tid).getThreadState() != Thread.State.BLOCKED) { + if (retryCount++ > 500) { + printStackTrace(t); + throw new RuntimeException("Thread " + t.getName() + " is at " + + TM.getThreadInfo(tid).getThreadState() + " state but is expected to " + + "be in Thread.State = " + expectedState); + } + goSleep(100); + } + } + if (!TM.getThreadInfo(tid).getThreadState().equals(expectedState)) { + printStackTrace(t); + throw new RuntimeException("Thread " + t.getName() + " is at " + + TM.getThreadInfo(tid).getThreadState() + " state but is expected to " + + "be in Thread.State = " + expectedState); + } + } - if (lock != null) { - if (expectedState == Thread.State.BLOCKED) { - int retryCount=0; - while(info.getThreadState() != Thread.State.BLOCKED) { - if (retryCount++ > 500) { - throw new RuntimeException("Thread " + t.getName() + - " is expected to block on " + expectedLock + - " but got " + result + - " Thread.State = " + info.getThreadState()); - } - goSleep(100); - info = tm.getThreadInfo(tid); - result = info.getLockName(); + /* + * Do slow check if thread is blocked on a lock. It is possible that last thread + * to come out of Phaser might still be in Phaser call stack (Unsafe.park) and + * hence might eventually acquire expected lock. + */ + private static void checkBlockedObject(Thread t, Object lock, Thread owner) { + long tid = t.getId(); + String result = TM.getThreadInfo(tid).getLockName(); + final String expectedLock = (lock != null ? getLockName(lock) : null); + Predicate p = (res) -> ((res != null && !res.equals(expectedLock)) + || (res == null && expectedLock != null)); + + if (p.test(result)) { + printStackTrace(t); + int retryCount = 0; + while (p.test(result)) { + if (retryCount++ > 500) { + printStackTrace(t); + throw new RuntimeException("Thread " + t.getName() + " is blocked on " + + expectedLock + " but got " + result); } - } - if (expectedState == Thread.State.WAITING && - info.getThreadState() != Thread.State.WAITING) { - throw new RuntimeException("Thread " + t.getName() + - " is expected to wait on " + expectedLock + - " but got " + result + - " Thread.State = " + info.getThreadState()); + goSleep(100); + result = TM.getThreadInfo(tid).getLockName(); } } - if ((result != null && !result.equals(expectedLock)) || - (result == null && expectedLock != null)) { - throw new RuntimeException("Thread " + t.getName() + " is blocked on " + - expectedLock + " but got " + result); - } - result = info.getLockOwnerName(); - if ((result != null && !result.equals(expectedOwner)) || - (result == null && expectedOwner != null)) { - throw new RuntimeException("Owner of " + lock + " should be " + - expectedOwner + " but got " + result); + result = TM.getThreadInfo(tid).getLockOwnerName(); + final String expectedOwner = (owner != null ? owner.getName() : null); + + p = (res) -> ((res != null && !res.equals(expectedOwner)) + || (res == null && expectedOwner != null)); + if (p.test(result)) { + printStackTrace(t); + throw new RuntimeException("Owner of " + lock + " should be " + + expectedOwner + " but got " + result); } } - private static void goSleep(long ms) { + private static void goSleep(long ms){ try { Thread.sleep(ms); - } catch (InterruptedException e) { - e.printStackTrace(); - testFailed = true; + } catch (InterruptedException ex) { + throw new RuntimeException(ex); } } @@ -128,14 +165,15 @@ super("LockAThread"); this.p = p; } + @Override public void run() { - synchronized(objA) { - // stop here for LockBThread to hold objB - log("LockAThread about to block on objB"); + synchronized(OBJA) { + // block here while LockBThread holds OBJB + log("LockAThread about to block on OBJB"); p.arriveAndAwaitAdvance(); // Phase 1 (blocking) - synchronized(objB) { + synchronized(OBJB) { dummyCounter++; - }; + } } p.arriveAndAwaitAdvance(); // Phase 2 (blocking) log("LockAThread about to exit"); @@ -150,14 +188,15 @@ super("LockBThread"); this.p = p; } + @Override public void run() { - synchronized(objB) { - log("LockBThread about to block on objC"); + synchronized(OBJB) { + log("LockBThread about to block on OBJC"); p.arriveAndAwaitAdvance(); // Phase 1 (blocking) - // Signal main thread about to block on objC - synchronized(objC) { + // Signal main thread about to block on OBJC + synchronized(OBJC) { dummyCounter++; - }; + } } p.arriveAndAwaitAdvance(); // Phase 2 (blocking) log("LockBThread about to exit"); @@ -166,9 +205,30 @@ } } + /* + * Must be invoked from within a synchronized context + */ + private static class EnhancedWaiter { + + boolean isNotified = false; + + public void doWait() throws InterruptedException { + while (!isNotified) { + wait(); + } + isNotified = false; + } + + public void doNotify() { + isNotified = true; + notify(); + } + } + private static WaitingThread waiter; private static final Object ready = new Object(); private static CheckerThread checker; + static class WaitingThread extends Thread { private final Phaser p; @@ -180,17 +240,16 @@ } @Override public void run() { - synchronized(objC) { - log("WaitingThread about to wait on objC"); + synchronized(OBJC) { + log("WaitingThread about to wait on OBJC"); try { - // Signal checker thread, about to wait on objC. + // Signal checker thread, about to wait on OBJC. waiting = false; p.arriveAndAwaitAdvance(); // Phase 1 (waiting) waiting = true; - objC.wait(); + OBJC.doWait(); } catch (InterruptedException e) { - e.printStackTrace(); - testFailed = true; + throw new RuntimeException(e); // Do not continue test } // block until CheckerThread finishes checking @@ -202,19 +261,18 @@ dummyCounter++; } } - synchronized(objC) { + synchronized(OBJC) { try { - // signal checker thread, about to wait on objC + // signal checker thread, about to wait on OBJC waiting = false; p.arriveAndAwaitAdvance(); // Phase 3 (waiting) waiting = true; - objC.wait(); + OBJC.doWait(); } catch (InterruptedException e) { - e.printStackTrace(); - testFailed = true; + throw new RuntimeException(e); } } - log("WaitingThread about to exit waiting on objC 2"); + log("WaitingThread about to exit waiting on OBJC 2"); } public void waitForWaiting() { @@ -241,85 +299,87 @@ super("CheckerThread"); } + @Override public void run() { - synchronized (ready) { - // wait until WaitingThread about to wait for objC + synchronized(ready) { + // wait until WaitingThread about to wait for OBJC waiter.waitForWaiting(); // Phase 1 (waiting) - checkBlockedObject(waiter, objC, null, Thread.State.WAITING); + assertThreadState(waiter, Thread.State.WAITING); + checkBlockedObject(waiter, OBJC, null); - synchronized (objC) { - objC.notify(); + synchronized(OBJC) { + OBJC.doNotify(); } - // wait for waiter thread to about to enter // synchronized object ready. waiter.waitForBlocked(); // Phase 2 (waiting) - checkBlockedObject(waiter, ready, this, Thread.State.BLOCKED); + assertThreadState(waiter, Thread.State.BLOCKED); + checkBlockedObject(waiter, ready, this); } // wait for signal from waiting thread that it is about - // wait for objC. + // wait for OBJC. waiter.waitForWaiting(); // Phase 3 (waiting) - synchronized(objC) { - checkBlockedObject(waiter, objC, Thread.currentThread(), Thread.State.WAITING); - objC.notify(); + synchronized(OBJC) { + assertThreadState(waiter, Thread.State.WAITING); + checkBlockedObject(waiter, OBJC, Thread.currentThread()); + OBJC.doNotify(); } - } } public static void main(String args[]) throws Exception { - Thread mainThread = Thread.currentThread(); + try { + Thread mainThread = Thread.currentThread(); - // Test uncontested case - LockAThread t1; - LockBThread t2; - - Phaser p = new Phaser(3); - synchronized(objC) { - // Make sure the main thread is not holding any lock - assertNoLock(mainThread); + // Test uncontested case + LockAThread t1; + LockBThread t2; - // Test deadlock case - // t1 holds lockA and attempts to lock B - // t2 holds lockB and attempts to lock C - - t1 = new LockAThread(p); - t1.start(); + Phaser p = new Phaser(3); + synchronized(OBJC) { + // Make sure the main thread is not holding any lock + assertNoLock(mainThread); - t2 = new LockBThread(p); - t2.start(); + // Test deadlock case + // t1 holds lockA and attempts to lock B + // t2 holds lockB and attempts to lock C + t1 = new LockAThread(p); + t1.start(); - p.arriveAndAwaitAdvance(); // Phase 1 (blocking) - checkBlockedObject(t2, objC, mainThread, Thread.State.BLOCKED); - checkBlockedObject(t1, objB, t2, Thread.State.BLOCKED); + t2 = new LockBThread(p); + t2.start(); - long[] expectedThreads = new long[3]; - expectedThreads[0] = t1.getId(); // blocked on lockB - expectedThreads[1] = t2.getId(); // owner of lockB blocking on lockC - expectedThreads[2] = mainThread.getId(); // owner of lockC - findThreadsBlockedOn(objB, expectedThreads); - } - p.arriveAndAwaitAdvance(); // Phase 2 (blocking) + p.arriveAndAwaitAdvance(); // Phase 1 (blocking) + assertThreadState(t2, Thread.State.BLOCKED); + checkBlockedObject(t2, OBJC, mainThread); + assertThreadState(t1, Thread.State.BLOCKED); + checkBlockedObject(t1, OBJB, t2); - p = new Phaser(2); - // Test Object.wait() case - waiter = new WaitingThread(p); - waiter.start(); + long[] expectedThreads = new long[3]; + expectedThreads[0] = t1.getId(); // blocked on lockB + expectedThreads[1] = t2.getId(); // owner of lockB blocking on lockC + expectedThreads[2] = mainThread.getId(); // owner of lockC + findThreadsBlockedOn(OBJB, expectedThreads); + } + p.arriveAndAwaitAdvance(); // Phase 2 (blocking) - checker = new CheckerThread(); - checker.start(); + p = new Phaser(2); + // Test Object.wait() case + waiter = new WaitingThread(p); + waiter.start(); + + checker = new CheckerThread(); + checker.start(); - try { - waiter.join(); - checker.join(); - } catch (InterruptedException e) { - e.printStackTrace(); - testFailed = true; - } - - if (testFailed) { - throw new RuntimeException("TEST FAILED."); + try { + waiter.join(); + checker.join(); + } catch (InterruptedException e) { + throw new RuntimeException(e); + } + } finally { // log all the messages to STDOUT + System.out.println(LOGGER.toString()); } System.out.println("Test passed."); } @@ -335,9 +395,9 @@ throw new RuntimeException("TEST FAILED: " + lock + " expected to have owner"); } - for (int j = 0; j < infos.length; j++) { - if (infos[j].getThreadId() == threadId) { - ownerInfo = infos[j]; + for (ThreadInfo info1 : infos) { + if (info1.getThreadId() == threadId) { + ownerInfo = info1; break; } } @@ -349,11 +409,11 @@ throws Exception { String lock = getLockName(o); // Check with ThreadInfo with no stack trace (i.e. no safepoint) - ThreadInfo[] infos = tm.getThreadInfo(tm.getAllThreadIds()); + ThreadInfo[] infos = TM.getThreadInfo(TM.getAllThreadIds()); doCheck(infos, lock, expectedThreads); // Check with ThreadInfo with stack trace - infos = tm.getThreadInfo(tm.getAllThreadIds(), 1); + infos = TM.getThreadInfo(TM.getAllThreadIds(), 1); doCheck(infos, lock, expectedThreads); } @@ -376,7 +436,7 @@ long[] threads = new long[10]; int count = 0; threads[count++] = ownerInfo.getThreadId(); - while (ownerInfo != null && ownerInfo.getThreadState() == Thread.State.BLOCKED) { + while (ownerInfo.getThreadState() == Thread.State.BLOCKED) { ownerInfo = findOwnerInfo(infos, lock); threads[count++] = ownerInfo.getThreadId(); log(" Owner = %s id = %d", @@ -407,6 +467,6 @@ } private static void log(String format, Object ... args) { - logger.log(format + "%n", args); + LOGGER.log(format + "%n", args); } }