In case you have ever worked with performance critical applications you may have stumbled across the excellent framework Perf4J. Perf4J allows developers to easily profile methods when they are called and expose the data in multiple formats. We use Perf4J in almost all of our web applications so we can keep track of performance.

Perf4J also includes a nice to use annotation, @Profiled, which is designed to use Aspects (AOP) to provide profiling to the pointcuts without having to manually start and stop timers. On their site there is no documentation on how to integrate with Guice so I took a look at if it would be possible to integrate Perf4J AOP with Guice AOP capabilities. Read on for how this can be done.

Guice have AOP capabilities through its MethodInterceptor. Declare a method intercepter that will trigger on the Perf4J annoation like below.

package com.cubeia.ws.guice;

import org.aopalliance.intercept.MethodInterceptor;
import org.aopalliance.intercept.MethodInvocation;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.perf4j.aop.AbstractJoinPoint;
import org.perf4j.aop.AgnosticTimingAspect;
import org.perf4j.aop.Profiled;
import org.perf4j.log4j.Log4JStopWatch;

public class ProfileInterceptor extends AgnosticTimingAspect implements MethodInterceptor {

	Logger log = Logger.getLogger(getClass());

	public Object invoke(final MethodInvocation invocation) throws Throwable {
		Profiled profiled = invocation.getStaticPart().getAnnotation(Profiled.class);

		Object runProfiledMethod = runProfiledMethod(
				new AbstractJoinPoint() {

					@Override
					public Object proceed() throws Throwable {
						return invocation.proceed();
					}

					@Override
					public Object[] getParameters() {
						return invocation.getArguments();
					}

					@Override
					public String getMethodName() {
						return invocation.getMethod().getName();
					}

					@Override
					public Object getExecutingObject() {
						return invocation.getThis();
					}
				},
				profiled,
				newStopWatch(profiled.logger() + "", profiled.level())
				);

		return runProfiledMethod;

	}

	protected Log4JStopWatch newStopWatch(String loggerName, String levelName) {
		Level level = Level.toLevel(levelName, Level.INFO);
		return new Log4JStopWatch(Logger.getLogger(loggerName), level, level);
	}

}

Then in your Guice module class declare this bindning:

bindInterceptor(Matchers.any(), Matchers.annotatedWith(Profiled.class), new ProfileInterceptor());

This will allow Guice to pick up the @Profiled annotation and the ProfileInterceptor will make a call to the Perf4J timer so that your methods will be profiled.

You might need to add the following dependencies to your project (Maven format):

<dependency>
    <groupId>org.perf4j</groupId>
    <artifactId>perf4j</artifactId>
    <version>0.9.16</version>
</dependency>

<dependency>
    <groupId>commons-jexl</groupId>
    <artifactId>commons-jexl</artifactId>
    <version>1.1</version>
</dependency>

Note that this will only work on classes that are created by Guice.

Bonus
As an additional point I also recommend breaking out Perf4J’s configuration from the Log4j configuration. The Perf4J configuration is very verbose and normally you want to have the log4j configuration outside the application so you can change it runtime while the Perf4J configuration is typically much more static and tied to explicit method names (i.e. tags).

To load an additional log4j configuration file with the perf4j configuration and merge it simply call a method once during startup like the one below.

public static void perf4JConfiguration() {
    // Load extra perf4j configuration which will be appended to any existing log4j config.
    URL resource = MyClass.class.getResource("/perf4j.xml");
    System.out.println("Append Perf4J configuration: "+resource);
    DOMConfigurator.configure(resource);
}