JUnit @AfterClass run time is added to a poor test

Question

I'm facing a slight JUnit inconvenience regarding the run time for each test to run.

I have an @AfterClass annotation and the last test that runs will get it's runtime added to it's.

So the report will incorrectly show a long run time for the poor test that happens to be run last.

Is there a way to exclude its run time from the last test?

Answer 1

This is an issue with Eclipse, not junit. If we use this as an example:

public class TimingTest {
    @Test public void test1() {
        System.out.println("test1");
        sleep(1000);
    }

    @Test public void test2() {
        System.out.println("test2");
        sleep(2000);
    }

    @After public void after() {
        System.out.println("after");
        sleep(3000);
    }

    @AfterClass public static void afterClass() {
        System.out.println("afterClass");
        sleep(5000);
    }

    private static void sleep(int i) {
        try {
            Thread.sleep(i);
        } catch (InterruptedException e) {
            throw new RuntimeException(e);
        }
    }
}

then we get for test1=4s, test2=10s (in Eclipse). However, the junit runner in Eclipse isn't using the information that junit is giving it. The RunListener interface defines methods testStarted, testFinished, testRunStarted, testRunFinished. If we look at when these methods are called, using:

public class RunJunitTestRunListener {
    private static class MyListener extends RunListener {
        private long runStart = 0L;
        private long testStart = 0L;

        @Override
        public void testRunStarted(Description description) throws Exception {
            System.out.println("runStarted");
            runStart = System.currentTimeMillis();
            super.testRunStarted(description);
        }

        @Override
        public void testRunFinished(Result result) throws Exception {
            System.out.println("runFinished " + (System.currentTimeMillis() - runStart) + "ms");
            super.testRunFinished(result);
        }

        @Override
        public void testStarted(Description description) throws Exception {
            System.out.println("testStarted");
            testStart = System.currentTimeMillis();
            super.testStarted(description);
        }

        @Override
        public void testFinished(Description description) throws Exception {
            System.out.println("testFinished " + (System.currentTimeMillis() - testStart) + "ms");
            super.testFinished(description);
        }
    }

    public static void main(String[] args) {
        JUnitCore core= new JUnitCore();
        core.addListener(new MyListener());
        core.run(TimingTest.class);
    }
}

we get the output:

testFinished 4004ms
testFinished 5002ms
runFinished 14012ms

which is what you would expect. Eclipse is adding the @afterClass onto the times. So, if you care about the timing of your methods, you need to either

1. Run the above code, create your own listener. There is no easy way to attach a listener to a particular test.
2. Use a benchmarking suite (junit-benchmark as DaveBall suggested or JunitPerf
3. Don't do anything slow in @AfterClass

Answer 2

How do you include/consider runtime in the last test?

If you are measuring performance, use a micro-benchmark. Check out junit-benchmark, I think it's one of the easiest micro-benchmarking libraries.