ZALANDO LOGBOOK 

Do you need http request and response logging without it polluting your business code? Use Zalando Logbook and add this aspect to your stack! In this post we will add logging for all http requests and play around with the configurations.

For more in depth information take a look at the project’s gihub page here.

We will use an existing project with a http API from this previous post on micronaut and graphQL. And the complete code for this post can be found on github here.

Setup of logbook

First of all we need to add the dependencies for logbook.

<dependency>
  <groupId>org.zalando</groupId>
  <artifactId>logbook-core</artifactId>
  <version>${logbook.version}</version>
</dependency>
<dependency>
  <groupId>org.zalando</groupId>
  <artifactId>logbook-netty</artifactId>
  <version>${logbook.version}</version>
</dependency>

Next up we define a logbook factory that will hold the configuration later on.

@Factory
public class LogbookFactory {
    @Singleton
    public Logbook logbook() {
        return Logbook.create();
    }
}

And finally we need to invoke logbook on every http call we receive. With Micronaut we do this by implementing an event listener. We listen for the creation of the netty pipeline that is used to handle the request. Here is the implementation of defining method.

@Override
public ChannelPipelineCustomizer onCreated(BeanCreatedEvent<ChannelPipelineCustomizer> event) {
    ChannelPipelineCustomizer customizer = event.getBean();
    customizer.doOnConnect(pipeline -> {
        pipeline.addAfter(
                ChannelPipelineCustomizer.HANDLER_HTTP_SERVER_CODEC,
                "logbook",
                new LogbookServerHandler(logbook)
        );
        return pipeline;
    });

    return customizer;
}

Note that we add the LogbookServerHandler after one of the first handlings of the http request. Also note that this is completely outside of our business logic. Implementing logging as an aspect has a lot of advantages.

And one last thing… The logging is done on trace level so we need to set the level for this logger in our logback.xml.

<logger name="org.zalando.logbook" level="TRACE"/>

See it in action

When we fire up our application and send it a request we see that the whole request and the whole response is logged.

And that’s that, no further configuration needed. We could make it a bit more dynamic by adding the loggers management endpoint provided by micronaut. Add the dependency if you didn’t already and enable it in the application.yml.

<dependency>
  <groupId>io.micronaut</groupId>
  <artifactId>micronaut-management</artifactId>
</dependency>

endpoints:
  loggers:
    enabled: true
    write-sensitive: false

Note that we only read access is enabled by default. We want to change the level at runtime so set the write-sensitive to false.

A quick call to the loggers endpoint gives a list of all the available loggers. (I use httpie to do this call. An introduction can be found here.)

But we can filter this to only the logger we are interested in with jq. (More on that can be found here)

If we would like to disable the logging of all requests we could set this logger to a higher level.

And voila, no more requests are logged.

Further features of zalando logbook

Now that we have the basics in place we want to edit this to our own needs. Logbook works in different phases and we can implement our own requirements and plug them into the logbook bean we defined.

First of all we have the condition phase where we can exclude specific requests from this resource expensive task. Here we exclude the health endpoint that is called (in our imaginary example) every 10 seconds by Kubernetes.

Logbook.builder()
    .condition(exclude(requestTo("/health")))
    .build()

Next up we have the filtering phase where some parts of the request can be changed or emitted from the final log statement. Here we will replace the password variable with a placeholder and also prevent sensitive authorization headers to be printed.

Logbook.builder()
    .condition(exclude(requestTo("/health")))
    .queryFilter(replaceQuery("password", "<secret>"))
    .headerFilter(authorization())
    .build();

The final two phases formatting and writing are mostly used together in a sink. Here you define how the information is turned into a string. (The writer does the actual transformation.) In our examle we want to format the logging into key-value pairs, perfect for splunk to process.

Logbook.builder()
    .condition(exclude(requestTo("/health")))
    .queryFilter(replaceQuery("password", "<secret>"))
    .headerFilter(authorization())
    .sink(new DefaultSink(
        new SplunkHttpLogFormatter(),
        new DefaultHttpLogWriter()))
    .build();

Note that all these implementations provided by logbook can be replaced by your own tailored implementations. The zalando logbook API is very extendable by its modulare setup.

Hopefully you are now able to use Zalando Logbook in your own projects and log all requests as an aspect. Happy logging!