unit test failing if Log Member object (@Slf4j isn't found groovy.lang.MissingPropertyException: No such property: log for class:

Question

I'm helping my development team with some logging code in our framework.

using spring AOP I've created a groovy class called LoggingAspect. Its main purpose is to log method execution times for classes in com.zions.comon.services.logging directories and annotated with @Loggable.

Since some classes already have @sl4j logging I need to detect if hat log member objects exists and use the built in @slf4j logging for that class. If it doesn't I need to execute the @sl4j annotation in aspect logging code.

The first statement in the try block will check if log member exists on object. If it does, then iLog will get set to incoming object's logger. However I'm not sure how to complete the rest of the code Once I detect the log member object. I don't expect anyone to write this code for me but would appreciate any suggestions/areas of researcoh on how to do this - such as using "if"

The logic should go something like:

1. Intercept and calculate method logging times in select classes
2. Check for existing log member object that indicates @slf4j is already present in class
3. If log member object exits use @sl4j logging features already built into that class
4. If log member object doesnt exist use @slf4j logging in logging Aspect code.

any help would be appreciated

"logging flow diagram"

Reverted code to original version - My LoggingAspect code looks like this at the moment

package com.zions.common.services.logging

import groovy.util.logging.Slf4j
import org.slf4j.Logger
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.context.annotation.Configuration
import org.springframework.context.annotation.EnableAspectJAutoProxy

@Aspect
@Configuration
@Slf4j
@EnableAspectJAutoProxy(proxyTargetClass=true)
public class LoggingAspect {
     * 
     * This is a Logging Aspect for the Loggable annotation that calculates method runtimes
     * for all methods under classes annotated with @Loggable*/

    /**
     * Logs execution time of method under aspect.
     * 
     * @param joinPoint - method under join
     * @return actual return of method under join point.
     * @throws Throwable
     */
    @Around('execution (* *(..)) && !execution(* *.getMetaClass()) && @within(com.zions.common.services.logging.Loggable)')
    public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {

                def obj = joinPoint.this
                Logger iLog = log
                long start = System.currentTimeMillis();
                Object proceed = joinPoint.proceed();
                long executionTime = System.currentTimeMillis() - start;

                try {

                    /*First statement of try block attempts to test if log members exist on object.
                     If it does, then iLog will get set to incoming object's logger*/

                    obj.log.isInfoEnabled()
                    iLog = obj.log
                } catch (e) {}

                iLog.info("${joinPoint.getSignature()} executed in ${executionTime}ms");
                return proceed;
            }
        }

If its helpful my logging Annotation is

package com.zions.common.services.logging

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/* Logging annotation to be used at class level
 * Loggable annotation for all methods of a class annotated with the @Loggable annotation*/

    @Target(ElementType.TYPE)
    @Retention(RetentionPolicy.RUNTIME)
    public @interface Loggable {}

I've added a junit test class that validates when log member is found - The line 'iLog = obj.log' get's called from the LoggingAspect code and the test is PASSING.

LoggingAspectSpecification.groovy

package com.zions.common.services.logging

import static org.junit.Assert.*

import groovy.util.logging.Slf4j
import org.junit.Test
import org.springframework.beans.factory.annotation.Autowired
import org.springframework.boot.test.context.TestConfiguration
import org.springframework.context.annotation.Bean
import org.springframework.context.annotation.ComponentScan
import org.springframework.context.annotation.Profile
import org.springframework.context.annotation.PropertySource
import org.springframework.test.context.ContextConfiguration

import spock.lang.Specification

@ContextConfiguration(classes=[LoggingAspectSpecificationConfig])
class LoggingAspectSpecification extends Specification {

    @Autowired
    SomeClass someClass

    def 'Main flow for timing log'() {
        setup: 'class to be logged'

    when: 'execute something with class testing log'
    someClass.methodOne()
    someClass.methodTwo()

    then: 'validate something logged'
    true
    }

}


@TestConfiguration
@Profile("test")
@ComponentScan(["com.zions.common.services.logging"])
@PropertySource("classpath:test.properties")
class LoggingAspectSpecificationConfig {

    @Bean
    SomeClass someClass() {
        return new SomeClass()
    }

}

@Loggable
@Slf4j
class SomeClass {

    def methodOne() {
        log.info('run methodOne')

    }

    def methodTwo() {
        log.info('run methodTwo')
    }
}

However my unit test is failing with classes that do not have @Slf4j meaning it will execute with the logger of the aspect instead of the pointcut object. The full error trace is:

groovy.lang.MissingPropertyException: No such property: log for class: com.zions.common.services.logging.SomeClass2
    at com.zions.common.services.logging.SomeClass2.methodOne(LoggingAspectSpecification2.groovy:55)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:747)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
    at com.zions.common.services.logging.LoggingAspect.logExecutionTime(LoggingAspect.groovy:42)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:643)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:632)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.zions.common.services.logging.LoggingAspectSpecification2.Main flow for timing log(LoggingAspectSpecification2.groovy:27)

The second unit test code is below - (the only difference is that @Slf4j) is not present in the classes.

LoggingAspectSpecification2.groovy

    package com.zions.common.services.logging

    import static org.junit.Assert.*
    import groovy.util.logging.Log    
    import groovy.util.logging.Slf4j
    import org.junit.Test
    import org.springframework.beans.factory.annotation.Autowired
    import org.springframework.boot.test.context.TestConfiguration
    import org.springframework.context.annotation.Bean
    import org.springframework.context.annotation.ComponentScan
    import org.springframework.context.annotation.Profile
    import org.springframework.context.annotation.PropertySource
    import org.springframework.test.context.ContextConfiguration

    import spock.lang.Specification

    @ContextConfiguration(classes=[LoggingAspectSpecificationConfig2])
    class LoggingAspectSpecification2 extends Specification {

        @Autowired
        SomeClass2 someClass2

        def 'Main flow for timing log'() {
            setup: 'class to be logged'

        when: 'execute something with class testing log'
        someClass2.methodOne()
        someClass2.methodTwo()

        then: 'validate something logged'
        true
        }

    }

<!-- language: lang-groovy -->

    @TestConfiguration
    @Profile("test")
    @ComponentScan(["com.zions.common.services.logging"])
    @PropertySource("classpath:test.properties")
    class LoggingAspectSpecificationConfig2 {

        @Bean
        SomeClass2 someClass2() {
            return new SomeClass2()
        }

    }

<!-- language: lang-groovy -->

    @Loggable


class SomeClass2 {
        def methodOne() {

            int  x=10, y=20;
            System.out.println(x+y+" testing the aspect logging code");

        }

        def methodTwo() {
           int  x=10, y=20;
           System.out.println(x+y+" testing the aspect logging code");
        }
    }

I'm guessing something's wrong in my LoggingAspect code in the Try Catch block?

Answer 1

To resolve the error and get my unit test to pass without @Slf4j or @Log - I had to add a println statement to the SomeClass2 code as in,

    int  x=10, y=20;
    System.out.println(x+y+" testing the apsect logging code");

adding @Log just gave it another built in log member similar to @Slf4j - adding the println statement and removing the @Log annotation force the LoggingAspect code to execute. Unit test is passing.