Timing Seam Injection

One of the main concepts in Seam is the Bijection of Components. Seam can inject components into eachother and can outject them for use in for instance XHTML pages. However, bijection takes time, how much time is mainly dependent on how much dependencies need to be loaded. However, normally you cannot easily measure the overhead time of bijection.

In order to facilitate bijection, Seam wraps components in an interceptor called the BijectionInterceptor. Luckily Seam provides an Interceptor chain, which we can use to wrap another interceptor around the BijectionInterceptor so that we can actually measure execution time, including the bijection overhead. Let's start with the interceptor:

import org.jboss.seam.Component;
import org.jboss.seam.annotations.intercept.AroundInvoke;
import org.jboss.seam.annotations.intercept.Interceptor;
import org.jboss.seam.core.BijectionInterceptor;
import org.jboss.seam.intercept.AbstractInterceptor;
import org.jboss.seam.intercept.InvocationContext;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
* Measuring tool for injection calls.
*/
@Interceptor(around = BijectionInterceptor.class, stateless = true)
public class TimingInterceptor extends AbstractInterceptor {
       private static final long serialVersionUID = 5274243063215400992L;
       private static final Logger log = LoggerFactory.getLogger(TimingInterceptor.class);

       /**
        * Measure the timing of injection calls.
        * @param ic The Invocation Context.
        * @return The return value of the invocation.
        * @throws Exception Throws any exception which occurs in the invocationContext.
        */
       @AroundInvoke
       public Object aroundInvoke(InvocationContext ic) throws Exception {
               String componentName = getComponent().getName();
               componentName += "." + ic.getMethod().getName();
               long milliStart = System.currentTimeMillis();
               Object o = null;
               try {
                       o = ic.proceed();
               } finally {
                       log.debug("Execution of {} took {} millis", componentName, System.currentTimeMillis() - milliStart);
               }
               return o;
       }

       /**
        * This interceptor is ALWAYS enabled.
        * @return true.
        */
       public boolean isInterceptorEnabled() {
               return true;
       }
}

This interceptor can effectively measure the time spent in the full call, including the bijection process. With the @Interceptor annotation we have specified that the TimerInterceptor should be wrapped around the BijectionInterceptor.

We must now instruct Seam to use our interceptor. Seam can discover that it needs to wrap an invocation to a method with our interceptor if an annotation is present which references the interceptor. So let's write such an annotation:

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

import org.jboss.seam.annotations.intercept.Interceptors;

/**
* Annotation that specifies whether calls to a certain Seam component are timed.
*/
@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Interceptors(TimingInterceptor.class)
public @interface Timed {
}

The @Timed annotation is annotated with @Interceptors, which specifies which interceptors it needs in the interceptor chain. By referencing the TimingInterceptor here, we instruct Seam to use that one when the component is annotated with @Timed. Once you do that, you will be able to see how many milliseconds are spent in the total execution of a method of that component.