0

I've been trying to configure spring-boot 2.1 with webflux to store access logs in JSON. Moreover I need to have information like protocol, status code as separate JSON fields (not a part of a message). Looking at the internet I found logstash-logback-encoder. Which seems to have everything I need. But during runtime I get following error:

ERROR in ch.qos.logback.core.FileAppender[accessLog] - Appender [accessLog] failed to append. java.lang.ClassCastException: ch.qos.logback.classic.spi.LoggingEvent cannot be cast to ch.qos.logback.access.spi.IAccessEvent
at java.lang.ClassCastException: ch.qos.logback.classic.spi.LoggingEvent cannot be cast to ch.qos.logback.access.spi.IAccessEvent
at  at net.logstash.logback.composite.accessevent.AccessEventFormattedTimestampJsonProvider.getTimestampAsMillis(AccessEventFormattedTimestampJsonProvider.java:20)
at  at net.logstash.logback.composite.FormattedTimestampJsonProvider.writeTo(FormattedTimestampJsonProvider.java:149)
at  at net.logstash.logback.composite.JsonProviders.writeTo(JsonProviders.java:77)
at  at net.logstash.logback.composite.CompositeJsonFormatter.writeEventToGenerator(CompositeJsonFormatter.java:189)
at  at net.logstash.logback.composite.CompositeJsonFormatter.writeEventToOutputStream(CompositeJsonFormatter.java:166)
at  at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:122)
at  at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:34)
at  at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:230)
at  at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
at  at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at  at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at  at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at  at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at  at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at  at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
at  at ch.qos.logback.classic.Logger.info(Logger.java:591)
at  at reactor.util.Loggers$Slf4JLogger.info(Loggers.java:255)
at  at reactor.netty.http.server.AccessLog.log(AccessLog.java:104)
at  at reactor.netty.http.server.AccessLogHandler.lambda$write$0(AccessLogHandler.java:77)
at  at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
at  at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:504)
at  at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:483)
at  at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
at  at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
at  at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48)
at  at io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:696)
at  at io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:258)
at  at io.netty.channel.nio.AbstractNioByteChannel.doWriteInternal(AbstractNioByteChannel.java:216)
at  at io.netty.channel.nio.AbstractNioByteChannel.doWrite0(AbstractNioByteChannel.java:209)
at  at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:397)
at  at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
at  at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:360)
at  at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:901)
at  at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1396)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
at  at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
at  at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:533)
at  at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:115)
at  at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:358)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
at  at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
at  at io.netty.channel.ChannelDuplexHandler.flush(ChannelDuplexHandler.java:117)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
at  at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
at  at io.netty.channel.ChannelDuplexHandler.flush(ChannelDuplexHandler.java:117)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
at  at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)

My configuration is fairly simple :

<appender name="accessLog" class="ch.qos.logback.core.FileAppender">
    <file>${LOGS}/access_log.log</file>
    <encoder class="net.logstash.logback.encoder.LogstashAccessEncoder"/>
</appender>

<logger name="reactor.netty.http.server.AccessLog" level="DEBUG" additivity="false">
    <appender-ref ref="accessLog"/>
</logger>

At this point I got stuck. I've been searching internet and looking into logback code but still I have no idea what to do to have AccessEvent which contains much more information, instead of LoggingEvent

arrow
  • 1
  • 1
  • 2

1 Answers1

1

The LogstashAccessEncoder from logstash-logback-encoder requires logback-access, which provides AccessEvents. logback-access is only available for jetty and tomcat. It is not available for reactor-netty.

Reactor-netty's reactor.netty.http.server.AccessLog just uses a standard log event (not an AccessEvent). So, if you want to use logstash-logback-encoder, you would use a LogstashEncoder instead of a LogstashAccessEncoder, like this:

<appender name="accessLog" class="ch.qos.logback.core.FileAppender">
    <file>${LOGS}/access_log.log</file>
    <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
</appender>

<logger name="reactor.netty.http.server.AccessLog" level="DEBUG" additivity="false">
    <appender-ref ref="accessLog"/>
</logger>

The downside is that LogstashEncoder knows nothing about an HTTP request. It just knows about log events logged via a Logger. Therefore, you cannot configure which HTTP details are logged when using a LogstashEncoder like you can when using LogstashAccessEncoder. Instead, your log event will just show the details provided by reactor.netty.http.server.AccessLog as part of the log message. The details will not be available as separate fields in the JSON output. Although, since logstash-logback-encoder is extremely customizable, you could write a custom JsonProvider that parsed the log message from reactor.netty.http.server.AccessLog and split it out into separate JSON fields.

Phil Clay
  • 4,028
  • 17
  • 22