[logback-dev] benchmarking extension to junit?

Joern Huxhorn jhuxhorn at googlemail.com
Mon Aug 4 20:58:11 CEST 2008


Ceki Gulcu wrote:
> Hello all,
>
> Logback contains a small number of time-sensitive tests. The time needed to 
> execute these tests depend on the capabilities of the host CPU. For example, if 
> on my machine a test executes in 1 millisecond, I would expect it to
> finish in say 1*10 milliseconds on most machine -- allowing for 10 fold variation.
>
> Does anyone know of a junit extension which can help me normalize the
> coefficient, 10 in the previous example, so that it adapts to the
> speed of the host CPU? There is also the problem of the JIT
> compiler...
>
> Any recommendations on the subject?
>
>   
Well, I don't have a real solution to your problem...
The only performance-related JUnit framework I'm aware of is 
http://clarkware.com/software/JUnitPerf.html but I think it's outdated 
and I never used it.
It could be useful for load-testing, though.

If you are using JUnit 4.x I'd suggest something like the following:

import org.junit.Test;
import org.junit.BeforeClass;
import org.junit.Before;
import static junit.framework.Assert.assertEquals;
import static junit.framework.Assert.fail;

public class TimingTest
{

    private static long referenceTime;
   
    @BeforeClass
    public static void initReferenceTime()
    {
        long time=System.currentTimeMillis();
       
        // lets waste some time...
        StringBuffer msg=new StringBuffer();
        for(int i=0;i<10000;i++)
        {
            msg.append(i);
        }
        System.out.println(msg.toString());
        referenceTime=System.currentTimeMillis()-time;
        System.out.println("ReferenceTime: "+referenceTime+" millis");
    }
   
    @Test(timeout = 1000)
    public void works()
        throws Exception
    {
        long time=System.currentTimeMillis();
        Thread.sleep(referenceTime*5);
        time=System.currentTimeMillis()-time;
        long maxTime=referenceTime*10;
        if(time>maxTime)
        {
            fail("Test was not expected to take more than "+maxTime+" 
millis but took "+time+" millis!");
        }
    }

    @Test(timeout = 1000)
    public void fails()
        throws Exception
    {
        long time=System.currentTimeMillis();
        Thread.sleep(referenceTime*15);
        time=System.currentTimeMillis()-time;
        long maxTime=referenceTime*10;
        if(time>maxTime)
        {
            fail("Test was not expected to take more than "+maxTime+" 
millis but took "+time+" millis!");
        }
    }
}


The problem with this approach, however, is that referenceTime isn't 
very stable. It fluctuates between 15ms and 40ms on my development 
system. I guess this fluctuation could be reduced by using an even 
higher number in the initReferenceTime loop.
The time-wasting would have to be changed depending on the 
problem-domain of the real test, e.g. something like the above if String 
operations are performed in the actual code that is tested.

The timeout I've given in @Test is supposed to be a definitive upper 
level that should never be reached. This could be left out, though.

I have some doubts what the Hotspot-JIT will be doing if the above 
initReferenceTime is used the same way in more than one class. I have 
some hope that it does NOT realize that it's the same code but I'm not sure.

The code above isn't perfect, neither is it especially elegant, but it's 
probably good enough for your use case if initReferenceTime and the 
factors are tuned a bit...
I don't know.

Joern.


More information about the logback-dev mailing list