Our goal is to implement the mechanism to log every execution of selected methods. We also want to log all passed parameters and returned results. The same logging, without writing the aspect, is EasyLog and one @LogIt annotation.

Assumptions:

  • Should support any number of methods in the project
  • Methods may return any result (any type/class)
  • Methods may receive any set of parameters
  • Methods might be placed in any class in the project

This is just an example

  public SomeResult methodThatShouldBeLogged(.. set of parameters ..) {
      ...
  }

  public AnotherResult anotherMethodThatShouldBeLogged(.. another set of parameters ..) {
      ...
  }

What are we actually going to log? Log messages should include

  • all parameters passed to the method
  • returned result
  • execution time

Logging with AspectJ

Now we need to create an aspect Logger (or what ever you want to call it) with @Around advice.

  @Around("execution({.. pointcut for your methods ..})")

The problem is that we have to find a correct pointcut for each method that we want to log because all methods have different signatures and placed in different packages. After that we will need to create a separate advice for each method. Sometimes that’s not so easy.

Annotations for methods that should be logged

I’m going to show the trick that I use on all my projects.

First, we create the annotation @LogThat

  @Retention(RetentionPolicy.RUNTIME)
  @Target(ElementType.METHOD)
  public @interface LogThat {
  }

Log method with parameters and results. Logger aspect

Now we create our aspect Logger that contains only one @Around advice for all method that should be logged. In the code snippet I use Reporter.log(..) for actual logging messages because usually I use that in TestNG tests. You can use any other logger to log (Log4j, Logback, SLF4J…) on your project.

@Aspect
public class Logger {

    private Gson gson = new GsonBuilder().setPrettyPrinting().create();

    @Around("execution(* *(..)) && @annotation(io.lenar.examples.spring.log.LogThat)")
    public Object logMethods(ProceedingJoinPoint jp) throws Throwable {
        String methodName = jp.getSignature().getName();
        logMethodInvocationAndParameters(jp);

        long startTime = new Date().getTime();
        Object result = jp.proceed(jp.getArgs());
        long endTime = new Date().getTime();

        Reporter.log("\nExecution time: " + (endTime - startTime) + "ms", true);
        Reporter.log("<- " + methodName + " returns \n" + gson.toJson(result) + "\n", true);

        return result;
    }

    private void logMethodInvocationAndParameters(ProceedingJoinPoint jp) {
        String[] argNames = ((MethodSignature) jp.getSignature()).getParameterNames();
        Object[] values = jp.getArgs();
        Map<String, Object> params = new HashMap<>();
        if (argNames.length != 0) {
            for (int i = 0; i < argNames.length; i++) {
                params.put(argNames[i], values[i]);
            }
        }

        Reporter.log("-> method " + jp.getSignature().getName() + " invocation", true);
        if (!params.isEmpty()) Reporter.log(gson.toJson(params), true);
    }

}

Note: If this is a Spring project add @Component annotation to the Logger class.

The most interesting part here is logMethodInvocationAndParameters where we log passed parameters as a map in JSON format.

How to log method with parameters using annotation

Now we can annotate all methods that we want to log with @LogThat annotation. Logger will intercept all invocations of methods annotated with @LogThat and log

  @LogThat
  public SomeResult methodThatShouldBeLogged(.. set of parameters ..) {
      ...
  }

  @LogThat
  public AnotherResult anotherMethodThatShouldBeLogged(.. another set of parameters ..) {
      ...
  }

  public Result methodThatShouldntBeLogged(.. another set of parameters ..) {
      ...
  }

Aspect weaving

The last thing we need to setup is pom.xml to properly weave our aspects.

There are some differences between Spring and non-Spring projects so carefully read this - Aspect weaving in Spring and non-Spring projects

EasyLog (Site, Source code) is an open source library that allows you to log any method or all methods of a class with one annotations. Also it supports a lot of other useful features like masking fields to pevent sensitive data from logging and many others.

EasyLog uses a similar approach to the described in the post

You may also find these posts interesting: