Timeout exception uses wrong stack trace

[peterdemaeyer]

When a test with @Test(timeout = <timeout>) times out, it throws an exception which is supposed to have the stack trace of the method call which is actually stuck. This is not always the case however. More specifically: when the stuck method call is interruptible, the stack trace of the exception is totally wrong. This can be very misleading.

The root cause of the problem is in FailOnTimeout: the stack trace is grabbed from the stuck thread after it has been interrupted, which is a bug. The stack trace should be recorded before the thread is interrupted, and the recorded stack trace should later be injected in the timeout exception.

Unit test reproducing the issue:

    @Test
    public void stackTraceContainsRealCauseOfTimeout() throws Throwable {
        StuckStatement stuck= new StuckStatement();
        FailOnTimeout stuckTimeout= new FailOnTimeout(stuck, TIMEOUT);
        try {
            stuckTimeout.evaluate();
            // We must not get here, we expect a timeout exception
            fail("Expected timeout exception");
        } catch (Exception timeoutException) {
            StackTraceElement[] stackTrace= timeoutException.getStackTrace();
            boolean stackTraceContainsTheRealCauseOfTheTimeout= false;
            boolean stackTraceContainsNotTheRealCauseOfTheTimeout= false;
            for (StackTraceElement element : stackTrace) {
                String methodName= element.getMethodName();
                if ("theRealCauseOfTheTimeout".equals(methodName)) {
                    stackTraceContainsTheRealCauseOfTheTimeout= true;
                }
                if ("notTheRealCauseOfTheTimeout".equals(methodName)) {
                    stackTraceContainsNotTheRealCauseOfTheTimeout= true;
                }
            }
            assertTrue(
                    "Stack trace does not contain the real cause of the timeout",
                    stackTraceContainsTheRealCauseOfTheTimeout);
            assertFalse(
                    "Stack trace contains another than the real cause of the timeout, which can be very misleading",
                    stackTraceContainsNotTheRealCauseOfTheTimeout);
        }
    }

    private static final class StuckStatement extends Statement {

        @Override
        public void evaluate() throws Throwable {
            try {
                // Must show up in stack trace
                theRealCauseOfTheTimeout();
            } catch (InterruptedException e) {
            } finally {
                // Must _not_ show up in stack trace
                notTheRealCauseOfTheTimeout();
            }
        }

        private void theRealCauseOfTheTimeout() throws InterruptedException {
            sleep(MAX_VALUE);
        }

        private void notTheRealCauseOfTheTimeout() {
            for (long now= currentTimeMillis(), eta= now + 1000L; now < eta; now= currentTimeMillis()) {
                // Doesn't matter, just pretend to be busy
                atan(now);
            }
        }
    }

[peterdemaeyer]

I've submitted a fix for this (pull request #385)

[marcphilipp]

Fixed by #385.