Update to 7.4 breaks log ingestion

Question

Update to 7.4 breaks log ingestion

otbe opened this issue a year ago · 4 comments

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.

logstash-logback-encoder version 7.4
logback version 1.2.11
jackson version 2.14.2
java version 11 (corretto)
springboot 2.7.11

Answer 1 · 2023-06-21T06:35:00.000Z

Logback 1.2 support has been dropped with 7.4, see #970

Answer 2 · 2023-06-21T06:50:04.000Z

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.

Answer 3 · 2023-06-21T11:23:23.000Z

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

Answer 4 · 2023-06-23T18:29:59.000Z

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