Cómo monitorizar el tiempo de ejecución con Spring AOP

Anteriormente ya vimos cómo usar Spring AOP para implementar un servicio transversal de logging para nuestros proyectos. En esta ocasión vamos a desarrollar un aspecto que monitorice el tiempo de ejecución de los métodos de nuestro código.

Previos

Los pasos previos son casi los mismos del ejemplo del logging, es decir:

• Copiar a la carpeta lib del proyecto al menos los módulos spring-aop.jar, spring-beans.jar, spring-context.jar y spring-core.jar de Spring, localizados en la carpeta dist/modules de tu instalación de Spring framework.
• Copiar a la carpeta lib del proyecto las dependencias aopalliance.jar, aspectjweaver.jar, cglib-nodep-xxx.jar. Éste último puede que no sea necesario si estás usando Hibernate. Las encontrarás todas en la carpeta lib de tu instalación de Spring framework con dependencias.

Implementación

Esta vez haremos que nuestro aspecto, lo llamaremos TimeAopMonitor, implemente el interface org.aopalliance.intercept.MethodInterceptor para definir el método invoke que nos permita tener un control más directo del momento de la ejecución del método target que queremos monitorizar. De este modo podremos calcular el tiempo que ha tardado en ejecutarse. El código es muy sencillo:

public class TimeAopMonitor implements MethodInterceptor {

  public Object invoke(MethodInvocation methodInvocation) throws Throwable { 
    long start = System.currentTimeMillis(); 
    Object result = methodInvocation.proceed(); 
    long total = System.currentTimeMillis() - start;

    System.out.println(methodInvocation.getMethod()
      .getDeclaringClass().getName() + "."
      + methodInvocation.getMethod().getName()
      + " = " + total + "ms.");

    return result;
  }
}

Por supuesto, si usas un logger en vez del System.out.println, mejor.

Ojo porque el System.currentTimeMillis() no es todo lo preciso que podría ser deseable en Windows. Lleva asociado un error de +-10 milisegundos. Si usas Java 5 o superior y necesitas mayor precisión puedes usar System.nanoTime() que cálcula el tiempo en nanosegundos. También es más costoso claro.

Configuración

El último paso es configurar. Hay que definir el monitor como un bean de Spring y declarar mediante Aop los puntos de ejecución donde queramos que aplique.

Para facilitar la configuración haremos uso del schema aop de Spring y por hacerlo un poco diferente del anterior post usaremos el tipo de pointcut bean, exclusivo de Spring Aop, para indicar, pej, que vamos a monitorizar los beans cuyo id termine en Dao.

Un ejemplo del fichero de configuración Spring sería el siguiente:

<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns:aop="http://www.springframework.org/schema/aop"
xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.5.xsd
http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-2.5.xsd">

  <aop:config>
    <aop:advisor pointcut="bean(*Dao)" advice-ref="timeAopMonitor" />
  </aop:config>

  <bean id="timeAopMonitor" class="example.util.TimeAopMonitor" />
  [...]
</beans>

Conclusión

Esto es todo. Una solución elegante y rápida de implementar para monitorizar el tiempo de ejecución de tu código Java. Otras características serían:

• Sencillo. ¿no?
• Limpio. No es necesario modificar el código fuente a monitorizar.
• De quita-y-pon. Activar y desactivar la monitorización es tan rápido como escribir o borrar unas líneas de XML, reiniciar y listo. Ideal para monitorizar sólo en la fase de test.
  
• Totalmente configurable. La configuración permite seleccionar en detalle qué clases y métodos monitorizar.