Author: ceki Date: Fri Jun 26 22:22:15 2009 New Revision: 2302 Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/Accessor.java - copied, changed from r2292, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/DeadlockTest.java - copied, changed from r2292, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/Worker.java - copied, changed from r2292, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/RunnableWithCounterAndDone.java - copied, changed from r2296, /logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java - copied, changed from r2296, /logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java Removed: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java Log: - added test case for lbclassic 139 - minor refactoring of the code (mostly renaming and moving to different package) Copied: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/Accessor.java (from r2292, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java) ============================================================================== --- /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Accessor.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/Accessor.java Fri Jun 26 22:22:15 2009 @@ -1,23 +1,29 @@ -package ch.qos.logback.classic.issue.lbclassic133; +package ch.qos.logback.classic.issue.lbclassic135.lbclassic139; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -public class Accessor { - private static Logger s_logger = LoggerFactory.getLogger(Accessor.class); +import ch.qos.logback.core.contention.RunnableWithCounterAndDone; - public void access(Worker worker) { - /** - * at some point, for any reason, this method decides to log the status of - * the worker object. - */ - s_logger.debug("Current worker status is: {}.", worker); - /** - * the following line would not cause the deadlock, because the thread never - * tries to acquire a lock on worker while already having a lock on the - * logger. - */ - //s_logger.debug("Current worker status (not deadlocking) is: {}.", worker - // .toString()); +/** + * + * @author Olivier Cailloux + * + */ +public class Accessor extends RunnableWithCounterAndDone { + private Logger logger = LoggerFactory.getLogger(Accessor.class); + + final Worker worker; + + Accessor(Worker worker) { + this.worker = worker; + } + + public void run() { + System.out.println("enter Accessor.run"); + while (!isDone()) { + logger.info("Current worker status is: {}.", worker); + } + System.out.println("leaving Accessor.run"); } } Copied: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/DeadlockTest.java (from r2292, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java) ============================================================================== --- /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/DeadlockTest.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/DeadlockTest.java Fri Jun 26 22:22:15 2009 @@ -1,40 +1,26 @@ -package ch.qos.logback.classic.issue.lbclassic133; +package ch.qos.logback.classic.issue.lbclassic135.lbclassic139; -import static org.junit.Assert.assertFalse; - -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; +import org.junit.Test; public class DeadlockTest { - private static Logger s_logger = LoggerFactory.getLogger(DeadlockTest.class); - - public static void main(String[] args) throws Exception { - s_logger.debug("Starting test."); - - final Worker worker = new Worker(); - final Thread workerThread = new Thread(new Runnable() { - public void run() { - while (true) { - worker.work(); - } - } - }); - workerThread.setName("WorkerThread"); - - final Thread accessorThread = new Thread(new Runnable() { - public void run() { - Accessor a = new Accessor(); - while (true) { - a.access(worker); - } - } - }); - accessorThread.setName("AccessorThread"); + @Test(timeout=2000) + public void test() throws Exception { + Worker worker = new Worker(); + Accessor accessor = new Accessor(worker); + + Thread workerThread = new Thread(worker, "WorkerThread"); + Thread accessorThread = new Thread(accessor, "AccessorThread"); + workerThread.start(); accessorThread.start(); - workerThread.join(50 * 1000); - assertFalse("Worker thread seems locked.", workerThread.isAlive()); + Thread.sleep(1500); + + worker.setDone(true); + accessor.setDone(true); + + workerThread.join(); + accessorThread.join(); } } Copied: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/Worker.java (from r2292, /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java) ============================================================================== --- /logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic133/Worker.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic135/lbclassic139/Worker.java Fri Jun 26 22:22:15 2009 @@ -1,40 +1,39 @@ -package ch.qos.logback.classic.issue.lbclassic133; +package ch.qos.logback.classic.issue.lbclassic135.lbclassic139; import org.slf4j.Logger; import org.slf4j.LoggerFactory; -public class Worker { - private static Logger s_logger = LoggerFactory.getLogger(Worker.class); +import ch.qos.logback.core.contention.RunnableWithCounterAndDone; - private final Object m_lock = new Object(); - - public void work() { - // Locks the object to do some work changing internal status. - synchronized (m_lock) { - // Does some work... - try { - Thread.sleep(1 * 1000); - } catch (InterruptedException exc) { - // +/** + * + * @author Olivier Cailloux + * + */ +public class Worker extends RunnableWithCounterAndDone { + private Logger logger = LoggerFactory.getLogger(Worker.class); + + private final Object lock = new Object(); + + public void run() { + System.out.println("enter Worker.run"); + while (!isDone()) { + synchronized (lock) { + try { + Thread.sleep(500); + } catch (InterruptedException exc) { + } + logger.info("lock the logger"); } - // Then calls logger, while still holding the lock. - s_logger.debug("Did some work, result is: {}."/* ,... */); } + System.out.println("leaving done"); } - public String getStatus() { - // Locks the object to make sure the status snapshot is coherent. (Will - // deadlock.) - synchronized (m_lock) { - // Packs some status information, e.g. in a StringBuffer. + @Override + public String toString() { + synchronized (lock) { final StringBuffer buf = new StringBuffer("STATUS"); - // Returns the string. return buf.toString(); } } - - @Override - public String toString() { - return getStatus(); - } } \ No newline at end of file Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/DateFormattingThreadedThroughputCalculator.java Fri Jun 26 22:22:15 2009 @@ -1,7 +1,7 @@ package ch.qos.logback.classic.issue.lbclassic36; import ch.qos.logback.classic.issue.lbclassic36.SelectiveDateFormattingRunnable.FormattingModel; -import ch.qos.logback.core.issue.ThreadedThroughputCalculator; +import ch.qos.logback.core.contention.ThreadedThroughputCalculator; /** * Measure the threaded throughtput of date formatting operations Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java ============================================================================== --- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java (original) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/lbclassic36/SelectiveDateFormattingRunnable.java Fri Jun 26 22:22:15 2009 @@ -4,7 +4,7 @@ import org.joda.time.format.DateTimeFormat; import org.joda.time.format.DateTimeFormatter; -import ch.qos.logback.core.issue.RunnableForThrougputComputation; +import ch.qos.logback.core.contention.RunnableWithCounterAndDone; /** * A runnable which behaves differently depending on the desired locking model. @@ -13,7 +13,7 @@ * @author Ceki Gulcu */ public class SelectiveDateFormattingRunnable extends - RunnableForThrougputComputation { + RunnableWithCounterAndDone { public static final String ISO8601_PATTERN = "yyyy-MM-dd HH:mm:ss,SSS"; Copied: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/RunnableWithCounterAndDone.java (from r2296, /logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java) ============================================================================== --- /logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/RunnableForThrougputComputation.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/RunnableWithCounterAndDone.java Fri Jun 26 22:22:15 2009 @@ -1,4 +1,4 @@ -package ch.qos.logback.core.issue; +package ch.qos.logback.core.contention; /** * A runnable with 'done' and 'counter' fields. @@ -6,7 +6,7 @@ * @author ceki * */ -abstract public class RunnableForThrougputComputation implements Runnable { +abstract public class RunnableWithCounterAndDone implements Runnable { protected boolean done = false; protected long counter = 0; Copied: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java (from r2296, /logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java) ============================================================================== --- /logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/ThreadedThroughputCalculator.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/contention/ThreadedThroughputCalculator.java Fri Jun 26 22:22:15 2009 @@ -1,4 +1,5 @@ -package ch.qos.logback.core.issue; +package ch.qos.logback.core.contention; + /** * @@ -11,7 +12,7 @@ */ public class ThreadedThroughputCalculator { - RunnableForThrougputComputation[] runnableArray; + RunnableWithCounterAndDone[] runnableArray; Thread[] threadArray; final long overallDurationInMillis; @@ -33,7 +34,7 @@ + System.getProperty("os.version")); } - public void execute(RunnableForThrougputComputation[] runnableArray) + public void execute(RunnableWithCounterAndDone[] runnableArray) throws InterruptedException { this.runnableArray = runnableArray; Thread[] threadArray = new Thread[runnableArray.length]; @@ -47,7 +48,7 @@ // let the threads run for a while Thread.sleep(overallDurationInMillis); - for (RunnableForThrougputComputation r : runnableArray) { + for (RunnableWithCounterAndDone r : runnableArray) { r.setDone(true); } for (Thread t : threadArray) { @@ -60,7 +61,7 @@ public void printThroughput(String msg, boolean detailed) throws InterruptedException { long sum = 0; - for (RunnableForThrougputComputation r : runnableArray) { + for (RunnableWithCounterAndDone r : runnableArray) { if(detailed) { System.out.println(r +" count="+r.getCounter()); } Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LockThroughput.java Fri Jun 26 22:22:15 2009 @@ -1,5 +1,6 @@ package ch.qos.logback.core.issue; +import ch.qos.logback.core.contention.ThreadedThroughputCalculator; import ch.qos.logback.core.issue.SelectiveLockRunnable.LockingModel; /** Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/NoLockThroughput.java Fri Jun 26 22:22:15 2009 @@ -1,5 +1,6 @@ package ch.qos.logback.core.issue; +import ch.qos.logback.core.contention.ThreadedThroughputCalculator; import ch.qos.logback.core.issue.SelectiveLockRunnable.LockingModel; /** Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/SelectiveLockRunnable.java Fri Jun 26 22:22:15 2009 @@ -3,13 +3,15 @@ import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReentrantLock; +import ch.qos.logback.core.contention.RunnableWithCounterAndDone; + /** * A runnable which behaves differently depending on the desired locking model. * * @author Joern Huxhorn * @author Ceki Gulcu */ -public class SelectiveLockRunnable extends RunnableForThrougputComputation { +public class SelectiveLockRunnable extends RunnableWithCounterAndDone { enum LockingModel { NOLOCK, SYNC, FAIR, UNFAIR;