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.

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: