2

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?

2 Answers2

2

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
Matthew Farwell
  • 60,889
  • 18
  • 128
  • 171
  • +1 for the nice answer. JunitPerf sounds interesting - I added it to the list http://stackoverflow.com/questions/7146207/what-is-the-best-macro-benchmarking-tool-framework-to-measure-a-single-threaded. If you happen to know which aspects it can handle, could you be so kind and roughly fill it into the community wiki? – DaveFar Sep 16 '11 at 09:47
0

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.

DaveFar
  • 7,078
  • 4
  • 50
  • 90
  • Not doing micro-benchmarking just plain TDD checking that my methods do what I want and that I don't destroy them in refactoring. So there is no problem but it is very annoying getting 9sec runtime on a test that may finish in 10ms just due to strange report behavior. I consider runtime as what eclipse provides my with in the JUnit view for example test1(0,002 s) test2(0,001 s) test3(8,922 s) in reality test3 is (0,00x s) as the others. –  Sep 07 '11 at 17:48