Basic bench-marking in Java

No, not that basic, don't worry

Benchmarking is useful when dealing with applications where performance is vital.  There are a million ways to bench mark your methods; profilers, tools, libraries, etc.  But honestly, sometimes it's too much of a hassle if all you want is a rough estimate of how much time a method or loop or anything else is taking.

So what I did was just a simple class which simply logs the start time, and end time, and prints it out if necessary; nothing outlandish.

The idea is to call a static method start just before entering the code to be tested, and then calling stop or stopAndPrint() when you want to, well, stop profiling.  The Timer class basically holds an array of "start times" and each time start is called, the pointer moves up, and down when stop is called.

PS: The complete code for this post is available in the downloads section, under Code, name Timer.java.  As this is the first time, I think you should know that the files are hosted Google docs, so just go there and hit download at the top right of the screen :)

Let's start then:

package com.jf.utils;


public class Timer
{
    private static final int MAX_TIMERS = 50;
    private static long[] startTimes = new long[MAX_TIMERS];
    private static long stopTime;
    private static long time;
    private static int pointer = -1;

So here we got :

• MAX_TIMERS which is a constant defining the maximum number of nested timers.  This limits the number of  consecutive starts we can have without stops;
• startTime is an array of long which shall keep track of all the starting times;
• stopTime is the time of the latest stop;
• time is the time between the last start and stop;
• pointer points to the current timer in the array, or the current consecutive timer.

public static void start()
{
    pointer ++;
    if (pointer > MAX_TIMERS)
    {
        System.err.println("The maximum timer count limit has been reached." +
        " Close some timers first before attemptin to open a new one.");
        return;
    }
    startTimes[pointer] = System.currentTimeMillis();
}

So this will start "profiling".  First, it will move the pointer up, so that it will put us in the next free location.  Next it will check if we reached the limit.  If we are at the limit, we will get a simple message, since we do not want a heavy class and will not be throwing any exceptions.  Finally it will record the starting time.  As you can see this is not at all an accurate way to test performance.  There are some milliseconds "wasted" just to increase the pointer and check if we are at the limit.

public static void stop()
{
    stopTime = System.currentTimeMillis();
    time = stopTime - startTimes[pointer];
    pointer--;
}

stop will, quite obviously, stop the timer.  What is does is rather simple.  We immediately record the current time, so as to avoid wasting time doing other tasks.  That is why we have a variable storing only the latest stop.  Then it will calculate the total time since the last start, pointed to by the current value of pointer.  The last operation is to move the pointer to the previous timer.  So as you can see we can only nest timers and every call to stop will simply stop the last timer that we started.

public static void stopAndPrint()
{
    stop();
    System.out.print("Timer in ");
    System.out.print(Thread.currentThread().getStackTrace()[2]);
    System.out.println(" clocked approx. " + getTimeFromMs(time));
}

A rather simple and convenient method is this one.  Here we will stop the timer and print out the values.  Note that calling this method might produce less accurate results, as time is wasted again while calling the method stop.  We can sacrifice code cleanliness here by placing the same code in stop here, so that a true stop operation is performed here without having to call another method.

public static String getTimeFromMs(long ms)
{
    if (ms < 1000)
        return ms + "ms";
    else if (ms >= 1000 && ms < 60000)
        return (ms/1000) + "s " + getTimeFromMs(ms - ((ms/1000)*1000));
    else if (ms >=60000 && ms < 3600000)
        return (ms/60000) + "m " + getTimeFromMs(ms - ((ms/60000)*60000));
    else
        return (ms/3600000) + "h " + getTimeFromMs(ms - ((ms/3600000)*3600000));
}

This is purely a convenience method which will cleanly print out a time passed to it in milliseconds and print it out in milliseconds, seconds, minutes and hours.  It recurses over it self until it gets to hours and cleanly groups minutes, seconds and millisecods.

So there you go.  A simple and ultra-basic way to test your code performance.  The thing is that this does not require any libraries (not even imports), or special IDEs or tools.  Just place this somewhere in your project and call start() and stop() or stopAndPrint() when ever you need to quickly get a rough idea.

The following code will give you an idea:

public static void main(String[] args)
{
    //Start profiling the whole main class
    Timer.start();
    int x = 10;
    int y = 5;
    //Start profiling the mul(x,y) method
    Timer.start();
    mul(x, y);
    //Stop profiling the mul(x,y) method and print result
    Timer.stopAndPrint();

    //Stop profiling the whole main class and print this one too
    Timer.stopAndPrint();
}

public static void mul(int x, int y)
{
    System.out.println(x * y);
}

Happy coding :D !