Log4j 2
  1. Log4j 2
  2. LOG4J2-177

ERROR StatusLogger An exception occurred processing Appender udpsocket java.lang.NullPointerException

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0-beta4
    • Fix Version/s: 2.0-beta5
    • Component/s: Appenders
    • Labels:
      None

      Description

      This seems to be a race condition of some kind. Two threads are exiting at almost exactly the same time, and both print a message as they exit. This exception happens every 3 or 4 times the code is run, so it's easily reproducible.

      ERROR StatusLogger An exception occurred processing Appender udpsocket java.lang.NullPointerException
      at org.apache.logging.log4j.core.net.DatagramOutputStream.flush(DatagramOutputStream.java:93)
      at org.apache.logging.log4j.core.appender.OutputStreamManager.flush(OutputStreamManager.java:146)
      at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:117)
      at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
      at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:335)
      at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:316)
      at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:281)
      at org.apache.logging.log4j.core.Logger.log(Logger.java:108)
      at org.apache.logging.log4j.spi.AbstractLogger.trace(AbstractLogger.java:250)
      at com.galmont.automation.framework.gui.handlers.RunCycleHandler$2.run(RunCycleHandler.java:128)
      at java.lang.Thread.run(Unknown Source)

      My configuration file:

      <?xml version="1.0" encoding="UTF-8"?>
      <configuration status="OFF">

      <appenders>
      <Console name="console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d

      {HH:mm:ss.SSS}

      [%t] %-5level %logger

      {36} - %msg%n" />
      </Console>
      <Socket name="udpsocket" host="localhost" port="90" protocol="UDP">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36}

      - %msg%n" />
      </Socket>
      <RollingFile name="RollingFile" fileName="logs/app.log" filePattern="logs/$$

      {date:yyyy-MM}

      /app-%d

      {MM-dd-yyyy}

      -%i.log.gz">
      <PatternLayout pattern="%d

      {HH:mm:ss.SSS}

      [%t] %-5level %logger

      {36}

      - %msg%n" />
      <Policies>
      <SizeBasedTriggeringPolicy size="20 MB" />
      </Policies>
      </RollingFile>
      </appenders>

      <loggers>
      <root level="trace">
      <appender-ref ref="console" />
      <appender-ref ref="udpsocket" />
      <appender-ref ref="RollingFile" />
      </root>
      </loggers>

      </configuration>

        Activity

        Hide
        Remko Popma added a comment -

        Looks like the SocketAppender defaults to immediateFlush=true, so the flush() method is called on every log event.
        At the end of the flush, the data byte array is set to null.
        If you have multiple threads logging, and the flush() method is called twice in a row, this error will occur.

        The fix is to add a null check to the flush() method implementation.

        change DatagramOutputStream.flush (line 93)
        if (this.ds != null && this.address != null) {
        to
        if (this.data != null && this.ds != null && this.address != null) {

        Show
        Remko Popma added a comment - Looks like the SocketAppender defaults to immediateFlush=true, so the flush() method is called on every log event. At the end of the flush, the data byte array is set to null. If you have multiple threads logging, and the flush() method is called twice in a row, this error will occur. The fix is to add a null check to the flush() method implementation. change DatagramOutputStream.flush (line 93) if (this.ds != null && this.address != null) { to if (this.data != null && this.ds != null && this.address != null) {
        Hide
        Ralph Goers added a comment -

        Thanks Remko! This issue was fixed in revision 1460497. Please verify and close.

        Show
        Ralph Goers added a comment - Thanks Remko! This issue was fixed in revision 1460497. Please verify and close.
        Hide
        Aaron Daniels added a comment -

        I can no longer reproduce this error in the latest code. Looks like it's fixed. Thanks!

        Show
        Aaron Daniels added a comment - I can no longer reproduce this error in the latest code. Looks like it's fixed. Thanks!

          People

          • Assignee:
            Ralph Goers
            Reporter:
            Aaron Daniels
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development