Tracking Performance in Java with Perf4J

Where are the Bottlenecks?

Performance is a critical aspect of any solution and pretty difficult to measure since we have to account for all the different load scenarios a system might meet in production. There are a good number of performance profiling tools which can help find bottlenecks in development, but what happens when the system is in the test or production environment and you need to check performance? We can't use the profiler in the production environment so we probably have to fall back on good old logging. Even in development and test environment performance logging may be quicker and simpler especially if you know what you are looking for. This is where we might use the Date class and the "getTime()" can solve this problem as shown below.

However this can become messy and difficult to track and re-use in many parts of your code. Therefore we are probably faced with creating a framework of classes to manage this function and to manage logging of the data. This is such a common test requirement in development I thought there must be a framework out there which already does this, but at the same time is simple to use. I was right, there is and it's called Perf4J.

Simple Performance Logging with Perf4J

Perf4J is a framework for performance logging  which comes packaged in a single JAR. It is simple to use and provides support for timing code sections and exporting the result to standard logging tools such as Log4J.
However it doesn't stop there. Perf4J supplies a number of features for helping you analyse the results of your performance logging. Support is provided for generating real-time performance information using an appender in Log4J. There is also support for generating graphs using the Google Chart API.
The advantage of using a standard framework like Perf4J is that we don't need to maintain the code and that it has a much larger user base than a "build your own" solution which means help is available from the community. Perf4J is licensed as open source under the "Apache License Version 2.0".

Logging Execution Times

The logging of execution times is based around using a StopWatch class which allows you to "start" and "stop" a timer for a section of code. The StopWatch can be setup to send this data to the log of of your choice. A nice feature here is that when you start the StopWatch you can give a "tag" which identifies the performance measurement and a "message" which can identify a particular section of the performance measurement. This is really useful if you are taking many measurements and want to organise these measurements so they are easily readable. This allows us to group our performance measurements together making the resulting log much easier to understand.

Below is an example of a simple JUnit test for logging two sections of code. In order for this example to work the "rta.test" logger has been configured in a log4j.xml file.

As can be seen from the code, the StopWatch is set up in the Log4JStopWatch  for compatibility with Log4J. We are then free to log times using our "tags" and "messages". The result of the above code is shown below.

Conclusion

Perf4J is a simple framework for performance logging. It allows you to easily take performance measurements and organise these measurements. If you want more advanced visualisation of the statistics there are features provided for this as well. Using this framework reduces the maintenance associated with "build your own" solution and a broader user base provides better support. In short a nice framework which makes you life a little easier when performance testing.