Chronométrer le temps d’execution de ses méthodes Java avec une annotation faite maison

C’était une question qui revenait de temps à autre, et il existe peut-être un début de réponse ! Passer par une annotation est possible, grâce à java.lang.reflect.Proxy. Il suffirait de surcharger la méthode « invoke » et d’encapsuler à l’intérieur de cette dernière l’appel à la méthode d’origine.

Il nous faut donc :

• une interface pour notre annotation (appelée « Clocking » dans l’exemple qui suit),
• une interface pour notre objet à mesurer (appelée « Examples » dans notre exemple),
• un « InvocationHandler » qui va implémenter les méthodes de notre objet à mesurer (appelé « ExamplesInvocationHandler » dans notre exemple),
• un point d’entrée pour le code (devinez son nom ! :-)

Allons-y avec la partie simple, l’annotation :

package main;
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 Clocking {
    
}

Rien de sorcier là-dedans, elle cible les méthodes via l’annotation @Target et est prise en compte à l’exécution via l’annotation @Retention.

L’interface de notre objet « Examples », là encore, est très simple :

package main;

public interface Examples {
    @Clocking
    void thisIsAMethod();
    
    void thisIsAnotherMethod(String something);
    
    @Clocking
    void thisIsALongRunningMethod();
}

Et maintenant, voici le gestionnaire d’appels de notre objet, « ExamplesInvocationHandler » :

package main;

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.time.Duration;
import java.time.Instant;

public class ExamplesInvocationHandler implements InvocationHandler {
    // ******************************
    // Fields
    // ******************************
    private Examples examples = new ExamplesImpl();
    
    // ******************************
    // Public methods
    // ******************************
    @Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        // If the annotation is not present, just redirect the method call to its origin...
        if(!method.isAnnotationPresent(Clocking.class)) {
            return method.invoke(examples, args);
        }
        
        // ... otherwise log the execution time of it.
        Instant start = Instant.now();
        Object returnObj = method.invoke(examples, args);
        Instant end = Instant.now();
        
        // TODO: This is for demonstration purpose only and should use the application's logging system.
        System.out.println("Method " + method.getName() + " executed in " + Duration.between(end, start) + ".");
        
        return returnObj;
    }
    
    // ******************************
    // Inner classes
    // ******************************
    private static class ExamplesImpl implements Examples {
        @Override
        public void thisIsAMethod() {
            System.out.println("thisIsAMethod called!");
        }

        @Override
        public void thisIsAnotherMethod(String something) {
            System.out.println("thisIsAnotherMethod called!");
        }
        
        @Override
        public void thisIsALongRunningMethod() {
            try {
                Thread.sleep(5000);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            
            System.out.println("thisIsALongRunningMethod called!");
        }
    }
}

Il faut pour ce dernier qu’il implémente « InvocationHandler » afin de pouvoir surcharger la méthode « invoke ». Dans cette surcharge, nous allons utiliser la réflexion pour vérifier la présence de notre annotation « Clocking ». Si elle n’est pas présente, il suffit de retourner l’appel à la méthode initiale et dans le cas contraire, faire la même chose, mais en prenant soin d’encapsuler cet appel de nos outils de mesure. (Ici, l’objet « Instant » de Java 8 est utilisé, mais un system.nano ou currenttime fera l’affaire également pour les versions antérieures.)

Évidemment, il faut implémenter les méthodes de notre interface ; ceci est ici fait via la classe interne « ExamplesImpl ».

Et maintenant on teste tout ça avec notre dernier objet « Main » :

package main;
import java.lang.reflect.Proxy;

public class Main {
    public static void main(String[] args) {
        Examples examples = (Examples) Proxy.newProxyInstance(Examples.class.getClassLoader(), new Class[]{Examples.class}, new ExamplesInvocationHandler());
        
        examples.thisIsAMethod();
        examples.thisIsAnotherMethod("");
        examples.thisIsALongRunningMethod();
    }
}

La subtilité consiste à instancier « Examples » à l’aide de l’objet Proxy (cf. java.lang.reflect.Proxy) et ensuite, d’en appeler les méthodes. Si elles sont annotées, on aura une sortie console. Dans notre cas, nous devrions voir le résultat suivant :

thisIsAMethod called!
Method thisIsAMethod executed in PT0S.
thisIsAnotherMethod called!
thisIsALongRunningMethod called!
Method thisIsALongRunningMethod executed in PT-5.001S.

Maintenant, le défi serait de rendre tout ça facilement utilisable pour des objets déjà existants, d’explorer plus en avant cette idée pour trouver peut être une solution plus générique (à l’aide d’une « factory » ?)... Et d’en faire un prochain article !