May 15, 2011

Simple Java profiler

This is a small collection of Java classes to provide a simple profiling functionality: include it into your application to register the time consumption of your function calls. It may come in handy where a particularly slow module has been spotted and there is no need for a more complex profiling system

Besides of a time line of the application execution, it creates an histogram to present where your application spends more resources and what the most called functions are.

Take a look to the launcher example for usage:

import Profiler.Profiler;

public class launcher {

	/**
	 * @param args
	 */
	public static void main(String[] args) {
		Profiler pf = new Profiler();
		
		pf.start();
		
		pf.sleep(219);
		
		pf.checkPoint("one");
		pf.sleep(123);		
		pf.endCheckPoint();
		
		pf.checkPoint("two");
		pf.sleep(245);
		pf.endCheckPoint();
		
		pf.checkPoint("one");
		pf.sleep(13);		
		pf.endCheckPoint();
		
		pf.checkPoint("two");
		pf.sleep(25);
		pf.endCheckPoint();
		
		pf.checkPoint("one");
		pf.endCheckPoint();
		pf.checkPoint("one");
		pf.endCheckPoint();
		pf.checkPoint("one");
		pf.endCheckPoint();
		pf.checkPoint("one");
		pf.endCheckPoint();
		pf.checkPoint("two");
		pf.endCheckPoint();
		pf.checkPoint("two");
		pf.endCheckPoint();
		pf.checkPoint("two");
		pf.endCheckPoint();
		
		pf.sleep(194);
		
		pf.end();
		
		System.out.println(pf.toString());		

	}
}

The code above will produce:

The whole process took          821.556 milliseconds

1171994752050889 >> one took    122.580 milliseconds
1171994874654460 >> two took    245.045 milliseconds
1171995119708510 >> one took     13.648 milliseconds
1171995133362201 >> two took     25.382 milliseconds
1171995158749506 >> one took      0.005 milliseconds
1171995158757886 >> one took      0.003 milliseconds
1171995158764312 >> one took      0.004 milliseconds
1171995158771017 >> one took      0.003 milliseconds
1171995158777442 >> two took      0.003 milliseconds
1171995158783867 >> two took      0.003 milliseconds
1171995158790013 >> two took      0.064 milliseconds

Profiler information
CheckPoint     Frequency         Time      % Time
one                    6      136.244      16.58%
two                    5      270.498      32.93%

Download the code here. Please feel free to use it, adapt it and don’t forget to send me back your changes!