qos-ch / logback

The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch
Other
2.97k stars 1.28k forks source link

Randomly occuring NPE when logging #822

Open nadrian4 opened 2 months ago

nadrian4 commented 2 months ago

Hi, I'm working with Java 17, SLF4j 2.0.12 and logback 1.5.2 and from time to time I randomly get following error when I try to log something:

java.lang.NullPointerException: Cannot invoke "ch.qos.logback.core.Appender.doAppend(Object)" because "appenderArray[i]" is null
        at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
        at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:272)
        at ch.qos.logback.classic.Logger.callAppenders(Logger.java:259)
        at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:426)
        at ch.qos.logback.classic.Logger.filterAndLog_1(Logger.java:402)
        at ch.qos.logback.classic.Logger.info(Logger.java:588)

The configuration file is as below:

<configuration scan="true" scanPeriod="120 seconds">
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>log/history.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>log/history-%d{MM-dd-yyyy}.log</fileNamePattern>
        </rollingPolicy>
        <encoder>
            <pattern>%date{HH:mm:ss.SSS} %-5level %logger{0} - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
        <queueSize>1024</queueSize>
        <neverBlock>true</neverBlock>
        <appender-ref ref="FILE" />
    </appender>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%date{HH:mm:ss.SSS} %-5level %logger{0} - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="stash" class="net.logstash.logback.appender.LogstashUdpSocketAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <host>logstash</host>
        <port>5056</port>
        <layout class="net.logstash.logback.layout.LogstashLayout">
            <customFields>{"userDir":"${user.dir}","hostname":"${HOSTNAME}"}</customFields>
        </layout>
    </appender>
    <root level="INFO">
        <appender-ref ref="stash" />
        <appender-ref ref="ASYNC" />
    </root>
</configuration>

What could be the cause?

ceki commented 2 weeks ago

@nadrian4 Can you tell when this issue occurs? Is it during or after reconfiguration? Do you have an idea on the approximate number of threads in your application?

Are the logging threads regular threads or virtual threads? (You are running on JDK 17.)

ceki commented 2 weeks ago

@nadrian4 I have tried to reproduce this issue but without success. Does the issue occur if you do not use LogstashUdpSocketAppender? Do you change the logback.xml configuration file often?

Which OS is this? What type of CPU?