fail on timeout displays stack of stuck thread (Issue #727)

Author: Adam Beneschan

src/main/java/org/junit/internal/runners/ExceptionWithThread.java

@@ -0,0 +1,69 @@
+package org.junit.internal.runners;
+
+import java.text.MessageFormat;
+
+/**
+ * An Exception that also carries information about some other relevant thread than
+ * the one whose stack trace is stored in the exception.
+ */
+public class ExceptionWithThread extends Exception {
+	
+	private Thread fThread;
+	private StackTraceElement[] fStack;
+	private String fDescription;
+	
+	/**
+	 * Constructs a new exception with the detail message and relevant thread.
+	 * @param message The detail message (as for an {@link Exception}).
+	 * @param thread The relevant thread.
+	 */
+	public ExceptionWithThread (String message, Thread thread) {
+		this (message, thread, null);
+	}
+
+	/**
+	 * Constructs a new exception with the detail message, relevant thread, and
+	 * a description explaining why the thread is relevant.
+	 * @param message The detail message (as for an {@link Exception}).
+	 * @param thread The relevant thread.
+	 * @param description A format string (used by {@link MessageFormat#format(Object)})
+	 * that describes why the thread is relevant.  {@code {0}} in the format string is
+	 * replaced by the thread name.
+	 */
+	public ExceptionWithThread (String message, Thread thread, String description) {
+		super(message);
+		fThread = thread;
+		try {
+			fStack = thread.getStackTrace();
+		} catch (SecurityException e) {
+			fStack = new StackTraceElement[0];
+		}
+		fDescription = (description == null) ? null :
+			MessageFormat.format(description, thread.getName());
+	
+	}
+
+	/**
+	 * Returns the relevant thread for the exception.
+	 * @return The relevant thread.
+	 */
+	public Thread getThread () { return fThread; }
+	
+	/**
+	 * Returns the stack trace of the relevant thread.
+	 * @return The stack trace of the relevant thread, at the point when the
+	 * {@link ExceptionWithThread} was constructed; may have length 0 if the 
+	 * stack trace could not be determined (e.g. the thread terminated before the
+	 * exception was created).
+	 */
+	public StackTraceElement[] getThreadStackTrace() { return fStack; }
+	
+	/**
+	 * Returns a description of why the thread is relevant.
+	 * @return A description of why the thread is relevant, or {@code null} if the
+	 * exception was created without a description.  If a description was provided,
+	 * the sequence {@code {0}} in the description is replaced by the name of the thread.
+	 */
+	public String getDescription() { return fDescription; }
+
+}

src/main/java/org/junit/internal/runners/statements/FailOnTimeout.java

@@ -1,17 +1,21 @@
 package org.junit.internal.runners.statements;
 
+import java.lang.management.ManagementFactory;
+import java.lang.management.ThreadMXBean;
 import java.util.concurrent.Callable;
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.FutureTask;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.TimeoutException;
 
+import org.junit.internal.runners.ExceptionWithThread;
 import org.junit.runners.model.Statement;
 
 public class FailOnTimeout extends Statement {
     private final Statement fOriginalStatement;
     private final TimeUnit fTimeUnit;
     private final long fTimeout;
+	private ThreadGroup fThreadGroup = null;
 
     public FailOnTimeout(Statement originalStatement, long millis) {
         this(originalStatement, millis, TimeUnit.MILLISECONDS);
@@ -26,7 +30,8 @@ public FailOnTimeout(Statement originalStatement, long timeout, TimeUnit unit) {
     @Override
     public void evaluate() throws Throwable {
         FutureTask<Throwable> task = new FutureTask<Throwable>(new CallableStatement());
-        Thread thread = new Thread(task, "Time-limited test");
+		fThreadGroup = new ThreadGroup ("FailOnTimeoutGroup");
+        Thread thread = new Thread(fThreadGroup, task, "Time-limited test");
         thread.setDaemon(true);
         thread.start();
         Throwable throwable = getResult(task, thread);
@@ -55,17 +60,82 @@ private Throwable getResult(FutureTask<Throwable> task, Thread thread) {
 
     private Exception createTimeoutException(Thread thread) {
         StackTraceElement[] stackTrace = thread.getStackTrace();
-        Exception exception = new Exception(String.format(
-                "test timed out after %d %s", fTimeout, fTimeUnit.name().toLowerCase()));
+        final Thread stuckThread = getStuckThread (thread);
+        String message = String.format(
+                "test timed out after %d %s", fTimeout, fTimeUnit.name().toLowerCase());
+        Exception exception = (stuckThread == null) 
+        	? new Exception(message) 
+            : new ExceptionWithThread (message, stuckThread,
+            		"Appears to be stuck in thread {0}");
         if (stackTrace != null) {
             exception.setStackTrace(stackTrace);
             thread.interrupt();
         }
         return exception;
     }
 
-    private class CallableStatement implements Callable<Throwable> {
+    /**
+     * Determines whether the test appears to be stuck in some thread other than
+     * the "main thread" (the one created to run the test).
+     * @param mainThread The main thread created by {@code evaluate()}
+     * @return The thread which appears to be causing the problem, if different from
+     * {@code mainThread}, or {@code null} if the main thread appears to be the
+     * problem or if the thread cannot be determined.  The return value is never equal 
+     * to {@code mainThread}.
+     */
+    private Thread getStuckThread (Thread mainThread) {
+    	if (fThreadGroup == null) return null;
+    	final int count = fThreadGroup.activeCount(); // this is just an estimate
+    	int enumSize = Math.max (count * 2, 100);
+    	int enumCount;
+    	Thread[] threads;
+		ThreadMXBean mxBean = ManagementFactory.getThreadMXBean();
+		int loopCount = 0;
+    	while (true) {
+    		threads = new Thread[enumSize];
+    		enumCount = fThreadGroup.enumerate (threads);
+    		// if there are too many threads to fit into the array, enumerate's result
+    		// is >= the array's length; therefore we can't trust that it returned all
+    		// the threads.  Try again.
+    		if (enumCount < enumSize) break;
+    		enumSize += 100;
+    		if (++loopCount >= 5) return null;
+    		// threads are proliferating too fast for us.  Bail before we get into 
+    		// trouble.
+    	} 
+    	
+    	// Now that we have all the threads in the test's thread group: Assume that
+    	// any thread we're "stuck" in is RUNNABLE.  Look for all RUNNABLE threads. 
+    	// If just one, we return that (unless it equals threadMain).  If there's more
+    	// than one, pick the one that's using the most CPU time, if this feature is
+    	// supported.
+    	Thread firstRunnable = null;
+    	Thread mostCpu = null;
+    	long maxCpuTime = 0;
+    	int runnableCount = 0;
+    	for (int i = 0; i < enumCount; i++) {
+    		if (threads[i].getState() == Thread.State.RUNNABLE) {
+    			runnableCount++;
+    			if (firstRunnable == null) firstRunnable = threads[i];
+    			if (mxBean.isThreadCpuTimeSupported()) {
+    				try {
+    					long cpuTime = mxBean.getThreadCpuTime(threads[i].getId());
+    					if (mostCpu == null || cpuTime > maxCpuTime) {
+    						mostCpu = threads[i];
+    						maxCpuTime = cpuTime;
+    					}
+    				} catch (UnsupportedOperationException e) {
+    				}
+    			}
+    		}   			
+    	}
+    	Thread stuckThread =
+    			(runnableCount == 1) ? firstRunnable :
+    				((mostCpu != null) ? mostCpu : firstRunnable);
+    	return (stuckThread == mainThread) ? null : stuckThread;
+    }
 
+	private class CallableStatement implements Callable<Throwable> {
         public Throwable call() throws Exception {
             try {
                 fOriginalStatement.evaluate();

src/main/java/org/junit/runner/notification/Failure.java

@@ -4,6 +4,7 @@
 import java.io.Serializable;
 import java.io.StringWriter;
 
+import org.junit.internal.runners.ExceptionWithThread;
 import org.junit.runner.Description;
 
 /**
@@ -68,7 +69,20 @@ public String toString() {
     public String getTrace() {
         StringWriter stringWriter = new StringWriter();
         PrintWriter writer = new PrintWriter(stringWriter);
-        getException().printStackTrace(writer);
+        Throwable exc = getException();
+        exc.printStackTrace(writer);
+        if (exc instanceof ExceptionWithThread) {
+        	ExceptionWithThread ewt = (ExceptionWithThread) exc;
+        	if (ewt.getDescription() == null)  {
+        	    writer.println("Stack for thread " + ewt.getThread().getName() + ":");
+        	} else {
+        		writer.println(ewt.getDescription() + ":");
+        	}
+        	StackTraceElement[] threadTrace = ewt.getThreadStackTrace();
+        	for (StackTraceElement traceElement : threadTrace) {
+        		writer.println("\tat " + traceElement);
+        	}
+        }
         StringBuffer buffer = stringWriter.getBuffer();
         return buffer.toString();
     }