Buscar este blog

miércoles, 8 de agosto de 2012

Timer4Method: controla la duración de tus métodos

  Actualmente estoy en una temporada de vacaciones más larga de lo normal, y pensé que era una buena oportunidad para probar y aprender algunas cosas que desde hacía tiempo tenía en la lista de tareas pendientes, y decidí empezar por AOP y uso de Github. Pero la pregunta era, ¿que hacer?
    Como la idea era aprender, y no volverme loca con lo que hacía, decidí hacer un ejemplo que he visto que es bastante típico con AOP: controlar el tiempo de duración de un método; pero intentando darle un poquito más de valor haciendo, por una parte, que fuera sencillo de configurar, y dando además la posibilidad de que, ante una tardanza excesiva, envíe un email que avise de que algún método está tardando excesivamente.
    Sí, se que no estoy inventando la rueda, pero al final ha salido una pequeña librería que, al menos, puede ser útil a alguien, pues siempre, en toda aplicación, tenemos algunos procesos críticos que es interesante controlar y, aunque es sencillo hacerlo, más sencillo aún es poner simplemente una anotación al método y decirle cuales son los tiempos de duración que nos parecen excesivos para un warning, un error o el envío del correo.
    Y ahora, una pequeña explicación de la librería :) Por una parte, tenemos la anotación que se tendrá que poner en los métodos con los posibles atributos que se le podrán pasar:

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface Timer4Method {
 /** Time elapsed necessary to write warning log */
 public long maxTimeWarning() default 0;
 /** Time elapsed necessary to write error log */
 public long maxTimeError() default 0;
 /** Time elapsed necessary to send email */
 public long maxTimeMail() default 0;
}

Por otra parte, he puesto una clase que será la que controle la configuración de la librería (nivel de log, tiempo globales de duración de los métodos para enviar warnings, errores,... y configuración para el envío de correos). En principio esta información sólo se podrá pasar a través de un properties "timer4method.properties", pero por si acaso en un futuro incluyera otras formas, he incluido una factoría que elegirá la clase que recoge esta información dependiendo del tipo de configuración elegida. También hay otras clases de apoyo, como la de envío de correo, pero estas clase no creo que merezca la pena mostrarlas... pero si alguien está interesado, en el proyecto Github puede ver el código. Por último está la clase que implementa el aspecto (que, ante mi desconocimiento inicial, fue la que más problemas me dio para que se ejecutase correctamente y poder coger los atributos de la anotación). Lo más importante en esta clase es anotarla con @Aspect y especificar la anotación @Around en el método que se va a ejecutar "alrededor" del método (hay varias anotaciones que se pueden usar en los aspectos, dependiendo de si se quiere que el método se ejecute antes, alrededor, etc, pero para este caso, obviamente, la correcta es @Arround). El código principal de esta clase es:

@Aspect
public class Timer4MethodAspect {
@Around(value="@annotation(timer4Method)", argNames="timer4Method")
public Object profile(final ProceedingJoinPoint pjp, final Timer4Method timer4Method) throws Throwable {
initTime4MethodAttrs(timer4Method);
final long start = System.currentTimeMillis();
final Object output = pjp.proceed();
final long elapsedTime = System.currentTimeMillis() - start;
writeLog(elapsedTime, pjp.toLongString());
return output; 
}
Y ahora el último paso: ¿que hacer si quiero usarlo en mi proyecto? Muy sencillo:

- Añadir en el pom.xml :
        <repositories>      
            <repository>
                <id>luciamg-public-releases</id>
                <url>https://raw.github.com/luciamg/luciamg/master/releases</url>
            </repository>
        </repositories>
        <dependencies>
                <!-- Timer4Method -->
                <dependency>
                        <groupId>timer4method</groupId>
                        <artifactId>timer4method</artifactId>
                        <version>0.2</version>
                </dependency>        
                .......
        </dependencies>
        
- Activar los aspectos y definir el bean del aspecto Timer4Method en el context.xml:
                
        <!-- Activa @AspectJ support -->
        <aop:aspectj-autoproxy/>
        <bean id="encryptor" class="org.jasypt.encryption.pbe.StandardPBEStringEncryptor">
                <property name="algorithm" value="PBEWithMD5AndDES" />
                <property name="password" value="PfKOeRYPinqn7kb" />
        </bean>
        <bean id="timer4Method" class="org.timer4method.aspects.Timer4MethodAspect"/>
                <bean id="propertyConfigurer" class="org.jasypt.spring.properties.EncryptablePropertyPlaceholderConfigurer">
                <constructor-arg ref="encryptor" />
                <property name="ignoreUnresolvablePlaceholders" value="false" />
        </bean>
        
- Añadir el archivo timer4method.properties al classpath (en el código hay un ejemplo de este archivo). Las propiedades disponibles son:
        * timer4method.log.level : Nivel de log. Puede ser NONE, DEBUG, WARN or ERROR
        * timer4method.time.warning : Tiempo global necesario para mostrar un warning
        * timer4method.time.error : Tiempo global necesario para mostrar un error
        * timer4method.time.main : Tiempo global necesario para enviar un email
        * timer4method.appender.email.*** : Configuración del envío de emails
        
-  Añadir al método que se quiera controlar la anotación @Timer4Method con los atributos que se quiera: maxTimeWarning (tiempo necesario para mostrar un warning para ese método), maxTimeError (tiempo necesario para mostrar un error para ese método) y/o maxTimeMail (tiempo necesario para enviar un mail para ese método).

Tras hacer esto, si los métodos anotados exceden los tiempos puestos en la configuración o en la anotación de cada método se mostrará por consola el log correspondiente y, si se excede el tiempo para envio de email y la configuración de email es correcta, se recibirá un correo con la información del método que ha excedido el tiempo de ejecución indicado.