En ocasiones las aplicaciones que desarrollamos deben realizar pruebas de rendimiento para determinar cómo responden y detectar los posibles errores que podemos llegar a tener en un entorno estresado. Muy común entre estas pruebas de rendimiento es que se nos pida el estudio de los tiempos de acceso a base de datos y el tiempo que nuestros métodos requieren para devolver los datos que se les pide para lo que solemos vernos obligados a introducir código en todos nuestros métodos.
Generar un log con el tiempo que un método tarda en ejecutarse es muy simple. Tan sólo necesitamos un par de líneas de código:
public List<User> getAllUsers() throws DaoException { Date d = new Date(); List<User> users= null; try { // code log.debug("method time: " + (new Date().getTime() - d.getTime()) + " ms"); return users; } catch (Exception e) { log.error("Error al insertar un organismo - " + e.toString()); throw new DaoException(e, "error getting users..."); } }
Sin embargo, ¿qué sucede si tenemos un centenar de métodos para el acceso a base de datos? ¿Debemos ir uno a uno introduciendo esas líneas de código? Fácil pero laborioso.
Para simplificarnos la vida y evitar el copy/paste utilizaremos AOP en colaboración con Spring. Con AOP podremos logar los tiempos de todos de cada uno de nuestros métodos sin necesidad de ir método a método copiando y pegando las líneas de código anteriores.
Lo primero que necesitamos es importar las librerías necesarias para ello (nos centraremos sólo en las librerías AOP dejando a un lado el resto de librerías, tales como las librerías de Spring)
<!-- AOP --> <dependency> <groupId>cglib</groupId> <artifactId>cglib-nodep</artifactId> <version>2.2.2</version> </dependency> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjrt</artifactId> <version>1.6.12</version> </dependency> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjweaver</artifactId> <version>1.6.12</version> </dependency>
Seguidamente, creaemos nuestros aspecto y un "advice" de tipo "around" que será el que calcule el tiempo de ejecución de nuestros métodos:
package es.whatabout.service.db.aop; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.springframework.stereotype.Component; import org.springframework.util.StopWatch; @Aspect @Component public class Performance { private final Log log = LogFactory.getLog(Performance.class); /** * http://tomasjurman.blogspot.com.es/2010/01/spring-aop-with-annotation.html * * @param joinPoint * @return object * @throws Throwable */ @Around("execution(* es.whatabout.dao.*.* (..))") public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable { StopWatch clock = new StopWatch("performance_dao"); try { clock.start(); log.debug("Comenzando metodo: " + joinPoint.getSignature().getName()); return joinPoint.proceed(); } finally { clock.stop(); log.debug("Consumo: " + clock.prettyPrint()); } } }
No olvidemos declarar nuestra clase como un Aspecto y un Componente. Destacar también, en en la declaración del punto de corte hemos indicado que queremos que el advice se ejecute para todas las clases y métodos (*.*) del paquete es.whatabout.dao sean cuales sean cuales sean su parámetros ( (...) ) o retorno (*)
Por último, sólo queda configurar Spring correctamente de la siguiente forma:
<sws:annotation-driven /> <aop:aspectj-autoproxy proxy-target-class="true" /> <!-- enable component scanning (beware that this does not enable mapper scanning!) --> <context:component-scan base-package="es.whatabout.*" /> <!-- enable autowire --> <context:annotation-config />
Limpio y rápido. Si además, mañana queremos eliminar por completo cualquier log sobre tiempos, sólo debemos cambiar la configuración.
