[LOG4J2-245] EmptyStackException when logging exceptions with Log4J2 in Java 8

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: 2.0-beta5, 2.0-beta6
• Fix Version/s: 2.0-beta7
• Component/s: Core, JCL Bridge

Environment

Java 8 (1.8.0-ea-b88)

• Assignee: Unassigned
• Reporter: Nick Williams
• Created: 09/May/13 04:06
• Updated: 18/Feb/14 14:06
• Resolved: 12/May/13 23:49

Description

[Note: the description below is the original error report. After analysis it turned out that this problem will happen unconditionally when logging a Throwable on a Java 8 JVM.]

Possibly affects earlier versions, too, but I did not check.

beta5 and beta6 are both unusable with Spring Framework. Any time an error gets logged through log4j-jcl bridge using Spring, the error below appears in the Tomcat log, masking the error that Spring was trying to log and making it very difficult to figure out what happened. I've also included my configuration file below the stack trace. The root error is happening on Tomcat 6 due to Spring bug, and that root problem is unimportant. The important problem is the Log4j error that masks it.

SEVERE: Exception sending context initialized event to listener instance of class org.springframework.web.context.ContextLoaderListener
java.util.EmptyStackException
at java.util.Stack.peek(Stack.java:102)
at org.apache.logging.log4j.core.impl.ThrowableProxy.resolvePackageData(ThrowableProxy.java:339)
at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:71)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.<init>(Log4jLogEvent.java:110)
at org.apache.logging.log4j.core.impl.Log4jLogEvent.<init>(Log4jLogEvent.java:81)
at org.apache.logging.log4j.core.config.LoggerConfig.createEvent(LoggerConfig.java:423)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:344)
at org.apache.logging.log4j.core.Logger.log(Logger.java:110)
at org.apache.logging.log4j.spi.AbstractLoggerWrapper.log(AbstractLoggerWrapper.java:55)
at org.apache.logging.log4j.spi.AbstractLogger.error(AbstractLogger.java:539)
at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:319)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:112)
at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4765)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5210)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:726)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:702)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:698)
at org.apache.catalina.startup.HostConfig.manageApp(HostConfig.java:1491)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.java:300)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:792)
at org.apache.catalina.mbeans.MBeanFactory.createStandardContext(MBeanFactory.java:468)
at org.apache.catalina.mbeans.MBeanFactory.createStandardContext(MBeanFactory.java:415)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at org.apache.tomcat.util.modeler.BaseModelMBean.invoke(BaseModelMBean.java:300)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:792)
at javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1465)
at javax.management.remote.rmi.RMIConnectionImpl.access$300(RMIConnectionImpl.java:75)
at javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1306)
at javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1398)
at javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:827)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:322)
at sun.rmi.transport.Transport$1.run(Transport.java:177)
at sun.rmi.transport.Transport$1.run(Transport.java:174)
at java.security.AccessController.doPrivileged(Native Method)
at sun.rmi.transport.Transport.serviceCall(Transport.java:173)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:556)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:811)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:670)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)

<?xml version="1.0" encoding="UTF-8"?>
<configuration status="WARN">
<appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout
pattern="%d

{HH:mm:ss.SSS}

[%t] %-5level %logger

{36} - %msg%n"/>
</Console>
<RollingFile name="WroxFileAppender" fileName="../logs/application.log"
filePattern="../logs/application-%d{MM-dd-yyyy}-%i.log">
<PatternLayout>
<pattern>%d{HH:mm:ss.SSS} [%t] %X{id} %X{username} %-5level %c{36}

%l: %msg%n</pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="10 MB" />
</Policies>
<DefaultRolloverStrategy min="1" max="4" />
</RollingFile>
</appenders>
<loggers>
<root level="warn">
<appender-ref ref="Console" />
<appender-ref ref="WroxFileAppender" />
</root>
<logger name="com.wrox" level="info" />
<logger name="org.apache" level="info" />
<logger name="org.springframework" level="info" />
</loggers>
</configuration>

Issue Links

• relates to: LOG4J2-250 (TBD) Refactor Log4jLogEvent to lazily create ThrowableProxy