8058506: ThreadMXBeanStateTest throws exception

Reviewed-by: egahlin, dholmes

test/java/lang/Thread/ThreadStateController.java

 /*
- * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2013, 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
@@ -27,6 +27,8 @@ import java.util.concurrent.TimeoutException;
 import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.locks.LockSupport;
 
+import jdk.testlibrary.LockFreeLogManager;
+
 /**
  * ThreadStateController allows a thread to request this thread to transition
  * to a specific thread state.  The {@linkplain #transitionTo request} is
@@ -94,8 +96,12 @@ public class ThreadStateController extends Thread {
     private static final int S_TERMINATE = 8;
 
     // for debugging
-    private AtomicInteger iterations = new AtomicInteger();
-    private AtomicInteger interrupted = new AtomicInteger();
+    private final AtomicInteger iterations = new AtomicInteger();
+    private final AtomicInteger interrupted = new AtomicInteger();
+
+    private final LockFreeLogManager logManager = new LockFreeLogManager();
+
+    @Override
     public void run() {
         // this thread has started
         while (!done) {
@@ -119,13 +125,13 @@ public class ThreadStateController extends Thread {
                     break;
                 }
                 case S_BLOCKED: {
-                    System.out.format("%d: %s is going to block (interations %d)%n",
-                                      getId(), getName(), iterations.get());
+                    log("%d: %s is going to block (iterations %d)%n",
+                        getId(), getName(), iterations.get());
                     stateChange(nextState);
                     // going to block on lock
                     synchronized (lock) {
-                        System.out.format("%d:   %s acquired the lock (interations %d)%n",
-                                          getId(), getName(), iterations.get());
+                        log("%d:   %s acquired the lock (iterations %d)%n",
+                            getId(), getName(), iterations.get());
                         try {
                             // this thread has escaped the BLOCKED state
                             // release the lock and a short wait before continue
@@ -139,13 +145,13 @@ public class ThreadStateController extends Thread {
                 }
                 case S_WAITING: {
                     synchronized (lock) {
-                        System.out.format("%d: %s is going to waiting (interations %d interrupted %d)%n",
-                                          getId(), getName(), iterations.get(), interrupted.get());
+                        log("%d: %s is going to waiting (iterations %d interrupted %d)%n",
+                            getId(), getName(), iterations.get(), interrupted.get());
                         try {
                             stateChange(nextState);
                             lock.wait();
-                            System.out.format("%d:   %s wakes up from waiting (interations %d interrupted %d)%n",
-                                              getId(), getName(), iterations.get(), interrupted.get());
+                            log("%d:   %s wakes up from waiting (iterations %d interrupted %d)%n",
+                                getId(), getName(), iterations.get(), interrupted.get());
                         } catch (InterruptedException e) {
                             // ignore
                             interrupted.incrementAndGet();
@@ -155,13 +161,13 @@ public class ThreadStateController extends Thread {
                 }
                 case S_TIMED_WAITING: {
                     synchronized (lock) {
-                        System.out.format("%d: %s is going to timed waiting (interations %d interrupted %d)%n",
-                                          getId(), getName(), iterations.get(), interrupted.get());
+                        log("%d: %s is going to timed waiting (iterations %d interrupted %d)%n",
+                            getId(), getName(), iterations.get(), interrupted.get());
                         try {
                             stateChange(nextState);
                             lock.wait(10000);
-                            System.out.format("%d:   %s wakes up from timed waiting (interations %d interrupted %d)%n",
-                                              getId(), getName(), iterations.get(), interrupted.get());
+                            log("%d:   %s wakes up from timed waiting (iterations %d interrupted %d)%n",
+                                getId(), getName(), iterations.get(), interrupted.get());
                         } catch (InterruptedException e) {
                             // ignore
                             interrupted.incrementAndGet();
@@ -170,23 +176,23 @@ public class ThreadStateController extends Thread {
                     break;
                 }
                 case S_PARKED: {
-                    System.out.format("%d: %s is going to park (interations %d)%n",
-                                      getId(), getName(), iterations.get());
+                    log("%d: %s is going to park (iterations %d)%n",
+                        getId(), getName(), iterations.get());
                     stateChange(nextState);
                     LockSupport.park();
                     break;
                 }
                 case S_TIMED_PARKED: {
-                    System.out.format("%d: %s is going to timed park (interations %d)%n",
-                                      getId(), getName(), iterations.get());
+                    log("%d: %s is going to timed park (iterations %d)%n",
+                        getId(), getName(), iterations.get());
                     long deadline = System.currentTimeMillis() + 10000*1000;
                     stateChange(nextState);
                     LockSupport.parkUntil(deadline);
                     break;
                 }
                 case S_SLEEPING: {
-                    System.out.format("%d: %s is going to sleep (interations %d interrupted %d)%n",
-                                      getId(), getName(), iterations.get(), interrupted.get());
+                    log("%d: %s is going to sleep (iterations %d interrupted %d)%n",
+                        getId(), getName(), iterations.get(), interrupted.get());
                     try {
                         stateChange(nextState);
                         Thread.sleep(1000000);
@@ -219,8 +225,8 @@ public class ThreadStateController extends Thread {
         if (newState == nextState) {
             state = nextState;
             phaser.arrive();
-            System.out.format("%d:   state change: %s %s%n",
-                              getId(), toStateName(nextState), phaserToString(phaser));
+            log("%d:   state change: %s %s%n",
+                getId(), toStateName(nextState), phaserToString(phaser));
             return;
         }
 
@@ -270,12 +276,12 @@ public class ThreadStateController extends Thread {
 
     private void nextState(int s) throws InterruptedException {
         final long id = Thread.currentThread().getId();
-        System.out.format("%d: wait until the thread transitions to %s %s%n",
-                          id, toStateName(s), phaserToString(phaser));
+        log("%d: wait until the thread transitions to %s %s%n",
+            id, toStateName(s), phaserToString(phaser));
         this.newState = s;
         int phase = phaser.arrive();
-        System.out.format("%d:   awaiting party arrive %s %s%n",
-                           id, toStateName(s), phaserToString(phaser));
+        log("%d:   awaiting party arrive %s %s%n",
+            id, toStateName(s), phaserToString(phaser));
         for (;;) {
             // when this thread has changed its state before it waits or parks
             // on a lock, a potential race might happen if it misses the notify
@@ -301,20 +307,22 @@ public class ThreadStateController extends Thread {
             }
             try {
                 phaser.awaitAdvanceInterruptibly(phase, 100, TimeUnit.MILLISECONDS);
-                System.out.format("%d:   arrived at %s %s%n",
-                                  id, toStateName(s), phaserToString(phaser));
+                log("%d:   arrived at %s %s%n",
+                    id, toStateName(s), phaserToString(phaser));
                 return;
             } catch (TimeoutException ex) {
                 // this thread hasn't arrived at this phase
-                System.out.format("%d: Timeout: %s%n", id, phaser);
+                log("%d: Timeout: %s%n", id, phaser);
             }
         }
     }
+
     private String phaserToString(Phaser p) {
         return "[phase = " + p.getPhase() +
                " parties = " + p.getRegisteredParties() +
                " arrived = " + p.getArrivedParties() + "]";
     }
+
     private String toStateName(int state) {
         switch (state) {
             case S_RUNNABLE:
@@ -337,4 +345,20 @@ public class ThreadStateController extends Thread {
                 return "unknown " + state;
         }
     }
+
+    private void log(String msg, Object ... params) {
+        logManager.log(msg, params);
+    }
+
+    /**
+     * Waits for the controller to complete the test run and returns the
+     * generated log
+     * @return The controller log
+     * @throws InterruptedException
+     */
+    public String getLog() throws InterruptedException {
+        this.join();
+
+        return logManager.toString();
+    }
 }

test/java/lang/management/ThreadMXBean/ThreadMXBeanStateTest.java

 /*
- * Copyright (c) 2003, 2013, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2003, 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
@@ -31,6 +31,8 @@
  * @author  Mandy Chung
  *
  * @library ../../Thread
+ * @library /lib/testlibrary
+ * @build jdk.testlibrary.LockFreeLogManager
  * @build ThreadMXBeanStateTest ThreadStateController
  * @run main ThreadMXBeanStateTest
  */
@@ -44,15 +46,17 @@ public class ThreadMXBeanStateTest {
     private static final ThreadMXBean tm = ManagementFactory.getThreadMXBean();
 
     static class Lock {
-        private String name;
+        private final String name;
         Lock(String name) {
             this.name = name;
         }
+        @Override
         public String toString() {
             return name;
         }
     }
-    private static Lock globalLock = new Lock("my lock");
+
+    private static final Lock globalLock = new Lock("my lock");
 
     public static void main(String[] argv) throws Exception {
         // Force thread state initialization now before the test
@@ -109,7 +113,7 @@ public class ThreadMXBeanStateTest {
         thread.checkThreadState(TERMINATED);
 
         try {
-            thread.join();
+            System.out.println(thread.getLog());
         } catch (InterruptedException e) {
             e.printStackTrace();
             System.out.println("TEST FAILED: Unexpected exception.");

test/lib/testlibrary/jdk/testlibrary/LockFreeLogManager.java

+/*
+ * 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.
+ */
+
+package jdk.testlibrary;
+
+import java.util.Collection;
+import java.util.Formatter;
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentLinkedQueue;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.stream.Collectors;
+
+/**
+ * A log manager designed specifically to allow collecting ordered log messages
+ * in a multi-threaded environment without involving any kind of locking.
+ * <p>
+ * It is particularly useful in situations when one needs to assert various
+ * details about the tested thread state or the locks it hold while also wanting
+ * to produce diagnostic log messages.
+ * <p>
+ * The log manager does not provide any guarantees about the completness of the
+ * logs written from different threads - it is up to the caller to make sure
+ * {@code toString()} method is called only when all the activity has ceased
+ * and the per-thread logs contain all the necessary data.
+ *
+ * @author Jaroslav Bachorik
+ **/
+public class LockFreeLogManager {
+    private final AtomicInteger logCntr = new AtomicInteger(0);
+    private final Collection<Map<Integer, String>> allRecords = new ConcurrentLinkedQueue<>();
+    private final ThreadLocal<Map<Integer, String>> records = new ThreadLocal<Map<Integer, String>>() {
+        @Override
+        protected Map<Integer, String> initialValue() {
+            Map<Integer, String> m = new ConcurrentHashMap<>();
+            allRecords.add(m);
+            return m;
+        }
+
+    };
+
+    /**
+     * Log a message
+     * @param format Message format
+     * @param params Message parameters
+     */
+    public void log(String format, Object ... params) {
+        int id = logCntr.getAndIncrement();
+        try (Formatter formatter = new Formatter()) {
+            records.get().put(id, formatter.format(format, params).toString());
+        }
+    }
+
+    /**
+     * Will generate an aggregated log of chronologically ordered messages.
+     * <p>
+     * Make sure that you call this method only when all the related threads
+     * have finished; otherwise you might get incomplete data.
+     *
+     * @return An aggregated log of chronologically ordered messages
+     */
+    @Override
+    public String toString() {
+        return allRecords.stream()
+            .flatMap(m->m.entrySet().stream())
+            .sorted((l, r)->l.getKey().compareTo(r.getKey()))
+            .map(e->e.getValue())
+            .collect(Collectors.joining());
+    }
+}