2

Hi I am using following code to print logs using aop in my webflux app,I have trouble writing unit/integration tests ?can we verify log interactions here?Any help would be appreciated

@Retention(RetentionPolicy.RUNTIME) 
@Target(ElementType.METHOD) 
public @interface Loggable {} 
@Aspect
@Slf4j
public class LoggerAspect {

  @Around("@annotation(Loggable)")
  public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable {

    long start = System.currentTimeMillis();
    var result = joinPoint.proceed();
    if (result instanceof Mono) {
      var monoResult = (Mono) result;
      AtomicReference<String> traceId = new AtomicReference<>("");

      return monoResult
        .doOnSuccess(o -> {
          var response = "";
          if (Objects.nonNull(o)) {
            response = o.toString();
          }
          log.info("Enter: {}.{}() with argument[s] = {}",
            joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(),
            joinPoint.getArgs());
          log.info("Exit: {}.{}() had arguments = {}, with result = {}, Execution time = {} ms",
            joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(),
            joinPoint.getArgs()[0],
            response, (System.currentTimeMillis() - start));
        });
    }
  }
}

Test Failing. Somehow when i debug pointer is not going inside doOnNext Method.And I am not sure how I can assert log interaction in above Logging aspect.In Junit5 I know I can use mockito for each method and return something ,but how i can rerturn in spock.

class LogAspectTest extends Specification {
  private static final String MOCK_METHOD_LOG_VALUE = "mockMethodLogValue"
  private Logger log = Mock()
  private ProceedingJoinPoint mockJoinPoint = Mock()
  private static Mono<String> methodReturn = Mono.just(["Data", "Data"])
  private LogAspect logAspect = new LogAspect(log)

  @Unroll
  def 'logAround verify log interaction'() {
    given:
    mockJoinPoint.proceed() == Mono.just("Hello")
    final Method method = TestClass.class.getMethod("mockMethod")

    when:
    logAspect.logAround(mockJoinPoint)

    then:
    interaction { mockJoinPointAndMethodSignatureInteractions(method, methodReturnToUse) }

    where:
    resultType | methodReturnToUse
    'Mono'     | methodReturn
  }

  private void mockJoinPointAndMethodSignatureInteractions(Method method, Publisher result) {
    1 * mockJoinPoint.proceed() >> result
    1 * log.info() >> ""

  }

  private static class TestClass {
    @Loggable
    Mono<String> mockMethod() { return Mono.just("data") }

  }
}

Is it recommended to write Integration Test for @Loggable annotation since it just logging not sure how can write Integration Test which assert the log statements

kriegaex
  • 63,017
  • 15
  • 111
  • 202
Rocky4Ever
  • 828
  • 3
  • 12
  • 35
  • Could you please show the test you have so far and explain what problems you have with it? – kriegaex Oct 02 '20 at 00:33
  • Added my test to the question. – Rocky4Ever Oct 02 '20 at 01:04
  • The code under test is still missing and the name `LoggerAspect` is not the same as `LogAspect` used in the test. Also a `return result;` statement is missing at the end of the aspect's advice method. You also have to return something if the result is not a `Mono`. I think it is always a good idea to actually compile and run the code before posting it here because the people who volunteer to help you don't want to figure out how to fix your code structurally at first before they can reproduce the actual problem. – kriegaex Oct 02 '20 at 02:22
  • Furthermore, there are no imports and package names, but I assume your `@Slf4j` annotation is from Lombok. What Lombok creates is something like `private static final Logger log = LoggerFactory.getLogger(LogAspect.class);`, hence you cannot assign anything to that member because it is both final and private. Also, there is no constructor `LogAspect(Logger logger)` like you fake-use it in your test. So this does not even compile. – kriegaex Oct 02 '20 at 02:26
  • I just found [this article](https://medium.com/@azizulhaq.ananto/how-to-handle-logs-and-tracing-in-spring-webflux-and-microservices-a0b45adc4610) by chance. Maybe you should have mentioned it as a source instead of just copying the code, pretending it is your own. – kriegaex Oct 02 '20 at 07:52

1 Answers1

3

Like I said in my comment, you cannot easily mock a private static final field without using add-on tools like PowerMock or similar. I think that whenever you need something like that, you should rather refactor your code for better testability. Here is an idea which is far from perfect, but I want to give you an idea about how you could unit-test your aspect. As for an integration test, you can also do that, but ask yourself what you want to test: really the aspect or that Spring AOP pointcut matching works correctly?

Anyway, let us assume that your classes under test are:

package de.scrum_master.stackoverflow.q64164101;

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 Loggable {}
package de.scrum_master.stackoverflow.q64164101;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import reactor.core.publisher.Mono;

import java.util.Objects;
import java.util.function.Consumer;

@Aspect
public class LogAspect {
  private static final Logger log = LoggerFactory.getLogger(LogAspect.class.getName());

  @Around("@annotation(Loggable)")
  public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable {
    long start = System.currentTimeMillis();
    Object result = joinPoint.proceed();
    if (result instanceof Mono)
      return ((Mono) result).doOnSuccess(getConsumer(joinPoint, start));
    return result;
  }

  public Consumer getConsumer(ProceedingJoinPoint joinPoint, long start) {
    return o -> {
      String response = "";
      if (Objects.nonNull(o))
        response = o.toString();
      log.info("Enter: {}.{}() with argument[s] = {}",
        joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(),
        joinPoint.getArgs());
      log.info("Exit: {}.{}() had arguments = {}, with result = {}, Execution time = {} ms",
        joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName(),
        joinPoint.getArgs()[0],
        response, (System.currentTimeMillis() - start));
    };
  }
}

See how I factored out the lambda into a helper method? It has two effects:

  • It makes the logAround(ProceedingJoinPoint) advice method more readable.
  • It permits you to stub the helper method and instead of verifying that logging is done you just verify that the helper method was called for Mono results (and not called for other result types).

The test in its simplest form could look like this:

package de.scrum_master.stackoverflow.q64164101

import org.aspectj.lang.ProceedingJoinPoint
import reactor.core.publisher.Mono
import spock.lang.Specification

class LogAspectTest extends Specification {
  LogAspect logAspect = Spy()
  ProceedingJoinPoint joinPoint = Mock()

  def "aspect target method returns a Mono"() {
    given:
    joinPoint.proceed() >> Mono.just("Hello")

    when:
    logAspect.logAround(joinPoint)

    then:
    1 * logAspect.getConsumer(joinPoint, _)
  }

  def "aspect target method does not return a Mono"() {
    given:
    joinPoint.proceed() >> "dummy"

    when:
    logAspect.logAround(joinPoint)

    then:
    0 * logAspect.getConsumer(joinPoint, _)
  }
}

Please note how I use a Spy (i.e. a partial mock based on the original object) in order to selectively stub the helper method.


Update: An alternative for more integrative testing would be to configure your logging framework to log into a target which you can control and verify, e.g. log into an in-memory database or into a buffer which you can access.

kriegaex
  • 63,017
  • 15
  • 111
  • 202
  • Thanks very much for easy explanation and clean and efficient tests – Rocky4Ever Oct 02 '20 at 04:12
  • However when I run the test I got the following error.Cannot create mock for class com.optum.obapi.plans.common.log.LogAspect because Java mocks cannot mock final classes. If the code under test is written in Groovy, use a Groovy mock. – Rocky4Ever Oct 02 '20 at 04:33
  • How do we write the same program in kotlin?sorry My implementation is kotlin?when I use kotlin I had same problem as earlier pointer not calling getConsumer method if i use real class instead of Spy() otherwise I am getting above error – Rocky4Ever Oct 02 '20 at 04:39
  • NVM I was missing @Component Annotation – Rocky4Ever Oct 02 '20 at 04:50
  • Your new questions are unrelated to the original question and also to my answer. Maybe you want to ask a new question. You also want to read the Spock manual section about Groovy mocks. They behave like simple Spock mocks if used with non-Groovy classes, hence the name. My solution should work with an aspect and application implemented in Kotlin, too. – kriegaex Oct 02 '20 at 04:52
  • It Worked Thanks.Is it at-least possible to verify arguments inside log statements like joinPoint.signature.declaringTypeName, if not entire log statement – Rocky4Ever Oct 02 '20 at 04:53
  • Oh, one more thing. When not using a spy but a mock or stub for a Kotlin class, make sure the class and its public methods are not final, otherwise Spock cannot subclass it in order to mock it. You need to open the class. I am developing a tool named Sarek which can help with Kotlin classes, but for now let's keep it simple. – kriegaex Oct 02 '20 at 05:35