AspectJ + Spring for method click records

[tweetmeme source=”anismiles” only_single=false http://www.URL.com%5D

In one of the projects we recently did, we had a Spring and Jersey based JSON/XML REST API server. Clients would connect to this API server and access various resources. Now, for one of the reporting scenario, we needed to log who accessed which API method and when. This appeared to be very simple initially. I decided to intercept every http call, and log that.

However, when I dug deep, I found that one method might call another method internally, depending upon the situation. For example, say User-A is trying to login from Device-1, and he is already logged on to some other device, say Device-2. So, LoginResource would make a call to LogoutResouce to invalidate User-A’s session with Device-2. We couldn’t track this just by intercepting http calls. We needed to adopt some other strategy. Initially, I thought of logging each API method with brute force… but that was too inelegant to actually code. Then I looked at AspectJ, and I was enlightened.

First, Added AspectJ dependencies to pom.

...
	<dependencies>
		<!-- aspectj -->
		<dependency>
			<groupId>org.aspectj</groupId>
			<artifactId>aspectjtools</artifactId>
			<version>1.6.8</version>
		</dependency>
		<dependency>
			<groupId>org.aspectj</groupId>
			<artifactId>aspectjrt</artifactId>
			<version>1.6.8</version>
		</dependency>
		...
	<dependencies>
...

And updated spring config file.

<beans ... xsi:schemaLocation="... http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop.xsd ..."
 xmlns:aop="http://www.springframework.org/schema/aop" ... >
...
<aop:aspectj-autoproxy proxy-target-class="true" />
...

Then created a Java Method Annotation class.

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

@Retention(RetentionPolicy.RUNTIME)
@Target({ ElementType.METHOD })
public @interface RecordClick {
	String action();  // Name of the action
	String comment() default ""; // Comment, if any?
}

Every method we want to track, I just need to annotate it with @RecordClick. Like this:

// API to signup
@RecordClick(action = "signup", comment = "User initiated signup")
public User explicitSignup(String firstName, String lastName, String email, String phone, String password, Role role) throws ValidationException {
}

// API to signup
@RecordClick(action = "signup", comment = "System initiated signup")
public User implicitSignup(String email, String phone) throws ValidationException {
}

// API to signin
@RecordClick(action = "signin", comment = "User initiated signin")
public Session explicitSignin(String username, String password) {
}

Okay, so now I have everything in place. I just need to create an Aspect to advice pertinent methods. So, I will create an Aspect class. This will intercept all public methods that are annotated with @RecordClick annotation, and create a click record for this call.

@Aspect
@Component
public class RecordClickMethodInterceptor {

	private static final Logger log = LoggerFactory.getLogger(RecordClickMethodInterceptor.class);

	// This will create and save an individual click
	@Autowired
	private ClickResource clickResource;

	/**
	 * Intercepts all public methods annotated with @RecordClick
	 *
	 * @param pjp
	 * @param recordClick
	 * @return
	 * @throws Throwable
	 */
	@Around("execution(public * *(..)) && @annotation(recordClick)")
	public Object doClickRecord(ProceedingJoinPoint pjp, RecordClick recordClick) throws Throwable {
		log.info("Intercepted method={} with action={}", pjp.getSignature().getName(), recordClick.action());

		List<String> paramNames = new ArrayList<String>();
		try {
			MethodSignature signature = (MethodSignature) pjp.getSignature();
			// Fetch method argument names.
			// Note: to enable this, you must compile the code in debug mode.
			paramNames = Arrays.asList(signature.getParameterNames());
		} catch (Exception e) {
			log.error("Can't record clicks. You must compile the code with debug=true");
			// Proceed with method call
			return pjp.proceed();
		}

		log.info("paramNames={}", paramNames);

		String user = "anonymous";
		Map<String, Object> methodArguments = new HashMap<String, Object>();

		int index = 0;
		// Iterate through method arguments
		for (Object arg : pjp.getArgs()) {
			// name of this argument
			String name = paramNames.get(index++);
			log.info("{} ==> {}", name, arg);

			// if arg is null, skip
			if (null == arg) {
				continue;
			}

			// Fetch user from argument '@Context SecurityContext'
			if (arg instanceof SecurityContext) {
				Principal principal = ((SecurityContext) arg).getUserPrincipal();
				if (null != principal) {
					log.info("Found user={}", principal.getName());
					user = principal.getName();
				}
			}
			// Fetch user from argument 'Principal principal;
			else if (arg instanceof Principal) {
				Principal principal = (Principal) arg;
				log.info("Found user={}", principal.getName());
				user = principal.getName();
			}
			// save to methodArguments
			else {
				methodArguments.put(name, arg.toString());
			}
		}

		// execute the method
		Object returned = pjp.proceed();

		// Process the returned value

		// Record this click
		String action = recordClick.action();
		String comment = recordClick.comment();
		clickResource.createClick(user, action, methodArguments, comment);
		return returned;
	}
}

I also need to compile the code in debug mode, unless I do this, I will not be able to fetch method argument names which I desperately need in order to make any sense of these records. So, I needed to update maven-compiler-plugin to enable debug mode.

<plugin>
	<artifactId>maven-compiler-plugin</artifactId>
	<configuration>
		<source>${java-version}</source>
		<target>${java-version}</target>
		<!-- compile with debug so as to get param names in aspects -->
		<debug>true</debug>
		<debuglevel>lines,vars,source</debuglevel>
	</configuration>
</plugin>

That’s it! have fun. 🙂