logfellow / logstash-logback-encoder

Logback JSON encoder and appenders
Apache License 2.0
2.44k stars 407 forks source link

Update to 7.4 breaks log ingestion #981

Closed otbe closed 1 year ago

otbe commented 1 year ago

Describe the bug In one of our projectes I upgraded the version from 7.3 to 7.4 and now I get the following exceptions:

2023-06-21 08:02:49,591 \|-ERROR in net.logstash.logback.appender.LogstashTcpSocketAppender[logstash] - Unable to process event: 'java.time.Instant ch.qos.logback.classic.spi.ILoggingEvent.getInstant()' java.lang.NoSuchMethodError: 'java.time.Instant ch.qos.logback.classic.spi.ILoggingEvent.getInstant()'
--
2023-06-21 08:02:49 | at java.lang.NoSuchMethodError: 'java.time.Instant ch.qos.logback.classic.spi.ILoggingEvent.getInstant()'
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.loggingevent.LoggingEventFormattedTimestampJsonProvider.getTimestampAsInstant(LoggingEventFormattedTimestampJsonProvider.java:29)
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.loggingevent.LoggingEventFormattedTimestampJsonProvider.getTimestampAsInstant(LoggingEventFormattedTimestampJsonProvider.java:25)
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.AbstractFormattedTimestampJsonProvider.writeTo(AbstractFormattedTimestampJsonProvider.java:164)
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.JsonProviders.writeTo(JsonProviders.java:78)
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.AbstractCompositeJsonFormatter.writeEventToGenerator(AbstractCompositeJsonFormatter.java:290)
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.AbstractCompositeJsonFormatter$JsonFormatter.writeEvent(AbstractCompositeJsonFormatter.java:190)
2023-06-21 08:02:49 | at    at net.logstash.logback.composite.AbstractCompositeJsonFormatter.writeEvent(AbstractCompositeJsonFormatter.java:156)
2023-06-21 08:02:49 | at    at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:106)
2023-06-21 08:02:49 | at    at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:80)
2023-06-21 08:02:49 | at    at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:36)
2023-06-21 08:02:49 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.encode(AbstractLogstashTcpSocketAppender.java:654)
2023-06-21 08:02:49 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.writeEvent(AbstractLogstashTcpSocketAppender.java:616)
2023-06-21 08:02:49 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.onEvent(AbstractLogstashTcpSocketAppender.java:580)
2023-06-21 08:02:49 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.onEvent(AbstractLogstashTcpSocketAppender.java:291)
2023-06-21 08:02:49 | at    at net.logstash.logback.appender.AsyncDisruptorAppender$EventClearingEventHandler.onEvent(AsyncDisruptorAppender.java:363)
2023-06-21 08:02:49 | at    at net.logstash.logback.appender.AsyncDisruptorAppender$EventClearingEventHandler.onEvent(AsyncDisruptorAppender.java:350)
2023-06-21 08:02:49 | at    at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:168)
2023-06-21 08:02:49 | at    at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
2023-06-21 08:02:49 | at    at java.base/java.lang.Thread.run(Thread.java:829)
\|-WARN in net.logstash.logback.appender.LogstashTcpSocketAppender[logstash] - Log destination my-logstash.tld:3004: Encoder failed to encode event. Dropping event. com.fasterxml.jackson.core.JsonGenerationException: Can not start an object, expecting field name (context: Object)
--
2023-06-21 08:02:53 | at com.fasterxml.jackson.core.JsonGenerationException: Can not start an object, expecting field name (context: Object)
2023-06-21 08:02:53 | at    at com.fasterxml.jackson.core.JsonGenerator._reportError(JsonGenerator.java:2733)
2023-06-21 08:02:53 | at    at com.fasterxml.jackson.core.json.JsonGeneratorImpl._reportCantWriteValueExpectName(JsonGeneratorImpl.java:262)
2023-06-21 08:02:53 | at    at com.fasterxml.jackson.core.json.UTF8JsonGenerator._verifyValueWrite(UTF8JsonGenerator.java:1179)
2023-06-21 08:02:53 | at    at com.fasterxml.jackson.core.json.UTF8JsonGenerator.writeStartObject(UTF8JsonGenerator.java:375)
2023-06-21 08:02:53 | at    at com.fasterxml.jackson.core.util.JsonGeneratorDelegate.writeStartObject(JsonGeneratorDelegate.java:212)
2023-06-21 08:02:53 | at    at net.logstash.logback.composite.AbstractCompositeJsonFormatter.writeEventToGenerator(AbstractCompositeJsonFormatter.java:289)
2023-06-21 08:02:53 | at    at net.logstash.logback.composite.AbstractCompositeJsonFormatter$JsonFormatter.writeEvent(AbstractCompositeJsonFormatter.java:190)
2023-06-21 08:02:53 | at    at net.logstash.logback.composite.AbstractCompositeJsonFormatter.writeEvent(AbstractCompositeJsonFormatter.java:156)
2023-06-21 08:02:53 | at    at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:106)
2023-06-21 08:02:53 | at    at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:80)
2023-06-21 08:02:53 | at    at net.logstash.logback.encoder.CompositeJsonEncoder.encode(CompositeJsonEncoder.java:36)
2023-06-21 08:02:53 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.encode(AbstractLogstashTcpSocketAppender.java:654)
2023-06-21 08:02:53 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.writeEvent(AbstractLogstashTcpSocketAppender.java:616)
2023-06-21 08:02:53 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.onEvent(AbstractLogstashTcpSocketAppender.java:580)
2023-06-21 08:02:53 | at    at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.onEvent(AbstractLogstashTcpSocketAppender.java:291)
2023-06-21 08:02:53 | at    at net.logstash.logback.appender.AsyncDisruptorAppender$EventClearingEventHandler.onEvent(AsyncDisruptorAppender.java:363)
2023-06-21 08:02:53 | at    at net.logstash.logback.appender.AsyncDisruptorAppender$EventClearingEventHandler.onEvent(AsyncDisruptorAppender.java:350)
2023-06-21 08:02:53 | at    at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:168)
2023-06-21 08:02:53 | at    at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
2023-06-21 08:02:53 |  

To Reproduce We use spring + logback + logstash-logback-appender like this

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <springProfile name="aws">
        <springProperty name="applicationName"
                        source="spring.application.name"/>

        <appender name="logstash"
                  class="net.logstash.logback.appender.LogstashTcpSocketAppender">
            <destination>my-logstash.tld:3004</destination>

            <!-- encoder is required -->
            <encoder class="net.logstash.logback.encoder.LogstashEncoder">
                <customFields>{"service.name":"${applicationName}"}</customFields>
            </encoder>

            <connectionStrategy>
                <random>
                    <connectionTTL>15 minutes</connectionTTL>
                </random>
            </connectionStrategy>

            <writeBufferSize>65536</writeBufferSize>
        </appender>

        <root>
            <appender-ref ref="logstash"/>
        </root>
    </springProfile>

    <springProfile name="default, local">
        <include
                resource="org/springframework/boot/logging/logback/base.xml"/>
    </springProfile>
</configuration>

Expected behavior It should not fail und logs should be ingested into logstash. Right now every log event is dropped.

Additional context Add any other context about the problem here.

mmaeller commented 1 year ago

Logback 1.2 support has been dropped with 7.4, see https://github.com/logfellow/logstash-logback-encoder/pull/970

otbe commented 1 year ago

Thanks for the quick response. Somehow I skipped this while reading the release notes. 😅 Then Im going to put it on the SB3 upgrade stack.

mmaeller commented 1 year ago

@otbe Yes, this is quite unfortunate. IMHO this change should have resulted in a version 8.0.

jreed91 commented 1 year ago

Why was this change not a major revision? This is the second version in a row that has broken our logging.