Log4j 2
  1. Log4j 2
  2. LOG4J2-651

Log4j 2 throws ArrayIndexOutOfBoundsException

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 2.0-rc2
    • Component/s: None
    • Labels:
      None

      Description

      Sometimes, logging throws java.lang.ArrayIndexOutOfBoundsException:

      2014-05-23 01:01:37,019 ERROR An exception occurred processing Appender Err java.lang.ArrayIndexOutOfBoundsException: 6
              at org.apache.logging.log4j.core.impl.ThrowableProxy.formatElements(ThrowableProxy.java:269)
              at org.apache.logging.log4j.core.impl.ThrowableProxy.getExtendedStackTrace(ThrowableProxy.java:232)
              at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:72)
              at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
              at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:172)
              at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:52)
              at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:45)
              at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:118)
              at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:85)
              at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
              at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:276)
              at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:239)
      

      Here is configuration:

      <Configuration status="warn">
      
      <Appenders>
          <Async name="Async" bufferSize="2048" blocking="${BLOCKING_LOG}">
              <appender-ref ref="A1"/>
              <appender-ref ref="Err"/>
          </Async>
      
          <Async name="Async-profiler" bufferSize="2048" blocking="${BLOCKING_LOG}">
              <appender-ref ref="Profiler"/>
          </Async>
      
          <RollingFile name="A1" fileName="${GFT_VAR}/log/${target}.log" filePattern="${GFT_VAR}/log/${target}.log.%i">
              <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
              <DefaultRolloverStrategy max="3"/>
              <Policies>
                  <SizeBasedTriggeringPolicy size="50Mb"/>
              </Policies>
          </RollingFile>
      
          <RollingFile name="Err" fileName="${GFT_VAR}/log/${target}.err" filePattern="${GFT_VAR}/log/${target}.err.%i">
              <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
              <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
              <DefaultRolloverStrategy max="2"/>
              <Policies>
                  <SizeBasedTriggeringPolicy size="10MB"/>
              </Policies>
          </RollingFile>
      
          <RollingFile name="Profiler" fileName="${GFT_VAR}/log/${target}.stat"
                       filePattern="${GFT_VAR}/log/${target}.stat.%i">
              <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
              <DefaultRolloverStrategy max="3"/>
              <Policies>
                  <SizeBasedTriggeringPolicy size="10MB"/>
              </Policies>
          </RollingFile>
      
      </Appenders>
      
      <Loggers>
          <Root level="debug">
              <AppenderRef ref="Async"/>
          </Root>
      
          <Logger name="net.sf" level="info">
              <AppenderRef ref="Async"/>
          </Logger>
      
          <Logger name="org.springframework.jdbc.core.JdbcTemplate" level="info">
              <AppenderRef ref="Async"/>
          </Logger>
      
          <Logger name="gft.service.stats.PoolableMetrics" additivity="false" level="info">
              <AppenderRef ref="Async"/>
          </Logger>
      
          <Logger name="gft.util.profiling.Profiler" additivity="false">
              <AppenderRef ref="Async-profiler"/>
          </Logger>
      
      </Loggers>
      
      </Configuration>
      

        Issue Links

          Activity

          Nikita Koval created issue -
          Nikita Koval made changes -
          Field Original Value New Value
          Description Sometimes, logging throws {{java.lang.ArrayIndexOutOfBoundsException}}:
          {noformat}
          2014-05-23 01:01:37,019 ERROR An exception occurred processing Appender Err java.lang.ArrayIndexOutOfBoundsException: 6
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.formatElements(ThrowableProxy.java:269)
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.getExtendedStackTrace(ThrowableProxy.java:232)
                  at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:72)
                  at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:172)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:52)
                  at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:45)
                  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:118)
                  at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:85)
                  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:276)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:239)
          {noformat}

          Here is configuration:
          {code}
          <Configuration status="warn">

          <Appenders>
              <Async name="Async" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="A1"/>
                  <appender-ref ref="Err"/>
              </Async>

              <Async name="Async-profiler" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="Profiler"/>
              </Async>

              <RollingFile name="A1" fileName="${GFT_VAR}/log/${target}.log" filePattern="${GFT_VAR}/log/${target}.log.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="50Mb"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Err" fileName="${GFT_VAR}/log/${target}.err" filePattern="${GFT_VAR}/log/${target}.err.%i">
                  <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="2"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Profiler" fileName="${GFT_VAR}/log/${target}.stat"
                           filePattern="${GFT_VAR}/log/${target}.stat.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

          </Appenders>

          <Loggers>
              <Root level="debug">
                  <AppenderRef ref="Async"/>
              </Root>

              <Logger name="net.sf" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="org.springframework.jdbc.core.JdbcTemplate" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.service.stats.PoolableMetrics" additivity="false" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.util.profiling.Profiler" additivity="false">
                  <AppenderRef ref="Async-profiler"/>
              </Logger>

          </Loggers>

          </Configuration>
          {code}
          Sometimes, logging throws ~java.lang.ArrayIndexOutOfBoundsException~:
          {noformat}
          2014-05-23 01:01:37,019 ERROR An exception occurred processing Appender Err java.lang.ArrayIndexOutOfBoundsException: 6
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.formatElements(ThrowableProxy.java:269)
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.getExtendedStackTrace(ThrowableProxy.java:232)
                  at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:72)
                  at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:172)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:52)
                  at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:45)
                  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:118)
                  at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:85)
                  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:276)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:239)
          {noformat}

          Here is configuration:
          {code}
          <Configuration status="warn">

          <Appenders>
              <Async name="Async" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="A1"/>
                  <appender-ref ref="Err"/>
              </Async>

              <Async name="Async-profiler" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="Profiler"/>
              </Async>

              <RollingFile name="A1" fileName="${GFT_VAR}/log/${target}.log" filePattern="${GFT_VAR}/log/${target}.log.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="50Mb"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Err" fileName="${GFT_VAR}/log/${target}.err" filePattern="${GFT_VAR}/log/${target}.err.%i">
                  <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="2"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Profiler" fileName="${GFT_VAR}/log/${target}.stat"
                           filePattern="${GFT_VAR}/log/${target}.stat.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

          </Appenders>

          <Loggers>
              <Root level="debug">
                  <AppenderRef ref="Async"/>
              </Root>

              <Logger name="net.sf" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="org.springframework.jdbc.core.JdbcTemplate" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.service.stats.PoolableMetrics" additivity="false" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.util.profiling.Profiler" additivity="false">
                  <AppenderRef ref="Async-profiler"/>
              </Logger>

          </Loggers>

          </Configuration>
          {code}
          Nikita Koval made changes -
          Description Sometimes, logging throws ~java.lang.ArrayIndexOutOfBoundsException~:
          {noformat}
          2014-05-23 01:01:37,019 ERROR An exception occurred processing Appender Err java.lang.ArrayIndexOutOfBoundsException: 6
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.formatElements(ThrowableProxy.java:269)
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.getExtendedStackTrace(ThrowableProxy.java:232)
                  at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:72)
                  at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:172)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:52)
                  at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:45)
                  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:118)
                  at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:85)
                  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:276)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:239)
          {noformat}

          Here is configuration:
          {code}
          <Configuration status="warn">

          <Appenders>
              <Async name="Async" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="A1"/>
                  <appender-ref ref="Err"/>
              </Async>

              <Async name="Async-profiler" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="Profiler"/>
              </Async>

              <RollingFile name="A1" fileName="${GFT_VAR}/log/${target}.log" filePattern="${GFT_VAR}/log/${target}.log.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="50Mb"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Err" fileName="${GFT_VAR}/log/${target}.err" filePattern="${GFT_VAR}/log/${target}.err.%i">
                  <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="2"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Profiler" fileName="${GFT_VAR}/log/${target}.stat"
                           filePattern="${GFT_VAR}/log/${target}.stat.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

          </Appenders>

          <Loggers>
              <Root level="debug">
                  <AppenderRef ref="Async"/>
              </Root>

              <Logger name="net.sf" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="org.springframework.jdbc.core.JdbcTemplate" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.service.stats.PoolableMetrics" additivity="false" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.util.profiling.Profiler" additivity="false">
                  <AppenderRef ref="Async-profiler"/>
              </Logger>

          </Loggers>

          </Configuration>
          {code}
          Sometimes, logging throws java.lang.ArrayIndexOutOfBoundsException:
          {noformat}
          2014-05-23 01:01:37,019 ERROR An exception occurred processing Appender Err java.lang.ArrayIndexOutOfBoundsException: 6
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.formatElements(ThrowableProxy.java:269)
                  at org.apache.logging.log4j.core.impl.ThrowableProxy.getExtendedStackTrace(ThrowableProxy.java:232)
                  at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:72)
                  at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:172)
                  at org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:52)
                  at org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:45)
                  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:118)
                  at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:85)
                  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:276)
                  at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:239)
          {noformat}

          Here is configuration:
          {code}
          <Configuration status="warn">

          <Appenders>
              <Async name="Async" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="A1"/>
                  <appender-ref ref="Err"/>
              </Async>

              <Async name="Async-profiler" bufferSize="2048" blocking="${BLOCKING_LOG}">
                  <appender-ref ref="Profiler"/>
              </Async>

              <RollingFile name="A1" fileName="${GFT_VAR}/log/${target}.log" filePattern="${GFT_VAR}/log/${target}.log.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="50Mb"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Err" fileName="${GFT_VAR}/log/${target}.err" filePattern="${GFT_VAR}/log/${target}.err.%i">
                  <ThresholdFilter level="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="2"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

              <RollingFile name="Profiler" fileName="${GFT_VAR}/log/${target}.stat"
                           filePattern="${GFT_VAR}/log/${target}.stat.%i">
                  <PatternLayout pattern="[%d] [%t] %-5p %c - %m%n"/>
                  <DefaultRolloverStrategy max="3"/>
                  <Policies>
                      <SizeBasedTriggeringPolicy size="10MB"/>
                  </Policies>
              </RollingFile>

          </Appenders>

          <Loggers>
              <Root level="debug">
                  <AppenderRef ref="Async"/>
              </Root>

              <Logger name="net.sf" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="org.springframework.jdbc.core.JdbcTemplate" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.service.stats.PoolableMetrics" additivity="false" level="info">
                  <AppenderRef ref="Async"/>
              </Logger>

              <Logger name="gft.util.profiling.Profiler" additivity="false">
                  <AppenderRef ref="Async-profiler"/>
              </Logger>

          </Loggers>

          </Configuration>
          {code}
          Hide
          Gary Gregory added a comment -

          Does this happen in trunk as well?

          Thank you,
          Gary

          Show
          Gary Gregory added a comment - Does this happen in trunk as well? Thank you, Gary
          Hide
          Nikita Koval added a comment -

          In trunk this bug was fixed. Thank you!

          With best regards,
          Nikita Koval

          Show
          Nikita Koval added a comment - In trunk this bug was fixed. Thank you! With best regards, Nikita Koval
          Hide
          Gary Gregory added a comment -

          Fixed in trunk as reported by the user.

          Show
          Gary Gregory added a comment - Fixed in trunk as reported by the user.
          Gary Gregory made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Fix Version/s 2.0-rc2 [ 12326292 ]
          Resolution Fixed [ 1 ]
          Nikita Koval made changes -
          Link This issue is cloned as LOG4J2-799 [ LOG4J2-799 ]
          Transition Time In Source Status Execution Times Last Executer Last Execution Date
          Open Open Resolved Resolved
          2d 21h 17m 1 Gary Gregory 26/May/14 16:14

            People

            • Assignee:
              Unassigned
              Reporter:
              Nikita Koval
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Time Tracking

                Estimated:
                Original Estimate - 2h
                2h
                Remaining:
                Remaining Estimate - 2h
                2h
                Logged:
                Time Spent - Not Specified
                Not Specified

                  Development