annotation based Logger injection in Spring with Kotlin

what’s it all about

In this post I show how to implement an annotation-based Logger injection in Spring when writing the application with Kotlin .

The used technique is quite far from new, basically what I do is implement a BeanPostProcessor which scans the properties of the beans for fields annotated with a custom annotation and sets these fields to a Logger instance. Examples how to implement this in Java can be found on the web, here I show the Kotlin version.

In this example I have an innovative REST controller wich has the ability to say hello. This controller has an injected service to do the processing of the incoming name. The reason for implementing this in two classes is that I want to show 2 different ways to inject a Logger.

The whole project for this example is available on GitHub .

The setup

I use Spring-Boot to setup the project. There is nothing special in relation to boot here, but it gets me fast on the track. I created my project from within IntelliJ IDEA as a Spring-Boot project, but you can use https://start.spring.io/ as well. Language is Kotlin, and the only dependency needed is web.

The logging configuration

I added a simple logback.xml to my project:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>
    <logger name="com.sothawo" level="DEBUG"/>
    <root level="WARN"/>
</configuration>

this sets the global level to WARN, and everything from my code to DEBUG.

The classes that get a Logger injected

The first class I show is HelloService, this is a Spring component which has one method that takes a string, and returns it concatenated to “hello “, and of course this is logged. In this class the Logger is injected in a normal property of the class by using the @Slf4jLogger annotation which I will show later:

package com.sothawo

import org.slf4j.Logger
import org.springframework.stereotype.Service

/**
 * @author P.J. Meisch (pj.meisch@sothawo.com)
 */
@Service
class HelloService {

    @Slf4jLogger
    lateinit var log: Logger

    fun sayHello(name: String): String {
        log.info("saying hello to: $name")
        return "hello $name"
    }
}

Using a normal property would create multiple instances of the same Logger-name if multiple HelloService instances were created (which they aren’t, but if you would change the scope this might happen). Therefore a better solution is to put the Logger in the companion object . This can be seen in the HelloController class:

package com.sothawo

import org.slf4j.Logger
import org.springframework.beans.factory.annotation.Autowired
import org.springframework.http.ResponseEntity
import org.springframework.web.bind.annotation.GetMapping
import org.springframework.web.bind.annotation.PathVariable
import org.springframework.web.bind.annotation.RequestMapping
import org.springframework.web.bind.annotation.RestController

/**
 * @author P.J. Meisch (pj.meisch@sothawo.com)
 */
@RestController
@RequestMapping("/hello")
class HelloController(val helloService: HelloService) {

    @GetMapping("/{name}")
    fun sayHello(@PathVariable name: String): ResponseEntity {
        log.info("sayHello called with arg $name")
        return ResponseEntity.ok(helloService.sayHello(name))
    }

    companion object {
        @Slf4jLogger
        lateinit var log: Logger
    }
}

The annotation and injection code

package com.sothawo

import org.slf4j.LoggerFactory
import org.springframework.beans.factory.config.BeanPostProcessor
import org.springframework.stereotype.Component
import kotlin.reflect.KMutableProperty
import kotlin.reflect.full.companionObjectInstance
import kotlin.reflect.full.declaredMemberProperties

/**
 * @author P.J. Meisch (pj.meisch@sothawo.com)
 */

@Target(AnnotationTarget.PROPERTY)
annotation class Slf4jLogger

@Component
class LoggingInjector : BeanPostProcessor {

    override fun postProcessBeforeInitialization(bean: Any, beanName: String) =
            bean.also {
                try {
                    val loggerName = it::class.java.canonicalName!!
                    processObject(it, loggerName)
                    it::class.companionObjectInstance?.let { companion ->
                        processObject(companion, loggerName)
                    }
                } catch (ignored: Throwable) {
                    // ignore exceptions, keep the object as it is. not every required class may be found on the classpath as
                    // SpringBoot tries to load notexisting stuff as well
                }
            }

    private fun processObject(target: Any, loggerName: String) {
        target::class.declaredMemberProperties.forEach { property ->
            if (property is KMutableProperty<*>) {
                property.annotations
                        .filterIsInstance(<Slf4jLogger>)
                        .forEach {
                            property.setter.call(target, LoggerFactory.getLogger(loggerName))
                        }
            }
        }
    }
}

First I create the annotation with the AnnotationTarget.PROPERTY (lines 14, 15). Then I define a Spring component that implements the BeanPostProcessor interface. The postProcessAfterInitialization method does nothing, it just returns the bean that is passed in, the magic happens in postProcessBeforeInitialization. Here, if the bean that is passed in is not null, it is passed into my processObject method, and then I check if there is a companion object and analyze this in the same way. The Logger name is built from the bean’s class as I do not want to have the companion object’s name in there.

In the processObject method I iterate over the properties of the target object that was passed in. For each property I check if it has the @SLF4JLogger annotation and if so I set it’s value to a newly created Logger instance with the requested name.

The output

When running the program and issuing a call like

curl localhost:8080/hello/world

the log output shows:

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v1.5.4.RELEASE)

2017-07-12 15:58:32.567  INFO 2797 --- [           main] KotlinSpringLoggerInjectionApplicationKt : Starting KotlinSpringLoggerInjectionApplicationKt on pjm.local with PID 2797 (/Users/peter/Entwicklung/sothawo/kotlin-spring-logger-injection/target/classes started by peter in /Users/peter/Entwicklung/sothawo/kotlin-spring-logger-injection)
2017-07-12 15:58:32.571 DEBUG 2797 --- [           main] KotlinSpringLoggerInjectionApplicationKt : Running with Spring Boot v1.5.4.RELEASE, Spring v4.3.9.RELEASE
2017-07-12 15:58:32.571  INFO 2797 --- [           main] KotlinSpringLoggerInjectionApplicationKt : No active profile set, falling back to default profiles: default
2017-07-12 15:58:35.423  INFO 2797 --- [           main] KotlinSpringLoggerInjectionApplicationKt : Started KotlinSpringLoggerInjectionApplicationKt in 3.355 seconds (JVM running for 3.776)
2017-07-12 15:58:51.745  INFO 2797 --- [nio-8080-exec-1] com.sothawo.HelloController              : sayHello called with arg world
2017-07-12 15:58:51.745  INFO 2797 --- [nio-8080-exec-1] com.sothawo.HelloService                 : saying hello to: world

Conclusion

As shown here it is pretty simple to process annotation in Kotlin and use this for custom injection in Spring. Especially statments like annotations.filter { it is Slf4jLogger } are a pretty cool feature.