--- a/jdk/test/java/lang/Thread/ThreadStateController.java Tue Nov 04 15:09:01 2014 +0000
+++ b/jdk/test/java/lang/Thread/ThreadStateController.java Tue Nov 04 15:10:38 2014 +0000
@@ -1,5 +1,5 @@
/*
- * 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.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 @@
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 @@
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 @@
}
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 @@
}
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 @@
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 @@
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 @@
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 @@
}
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 @@
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();
+ }
}
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/jdk/test/lib/testlibrary/jdk/testlibrary/LockFreeLogManager.java Tue Nov 04 15:10:38 2014 +0000
@@ -0,0 +1,90 @@
+/*
+ * 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());
+ }
+}