When shutting down an application using a RollingFileAppender in tomcat we have : log4j:ERROR Error occured while converting date. java.lang.NullPointerException at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:329) at java.lang.StringBuffer.getChars(StringBuffer.java:202) at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.java:120) at java.text.DateFormat.format(DateFormat.java:314) at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(PatternParser.java:436) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:56) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:299) at org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:225) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:194) at org.apache.log4j.Category.forcedLog(Category.java:379) at org.apache.log4j.Category.log(Category.java:844) at org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:110) at org.apache.catalina.cluster.session.DeltaSession.readObject(DeltaSession.java:1369) at org.apache.catalina.cluster.session.DeltaSession.readObjectData(DeltaSession.java:890) at org.apache.catalina.cluster.session.DeltaManager.deserializeSessions(DeltaManager.java:741) at org.apache.catalina.cluster.session.DeltaManager.handleALL_SESSION_DATA(DeltaManager.java:1648) at org.apache.catalina.cluster.session.DeltaManager.messageReceived(DeltaManager.java:1495) at org.apache.catalina.cluster.session.DeltaManager.messageDataReceived(DeltaManager.java:1267) at org.apache.catalina.cluster.session.ClusterSessionListener.messageReceived(ClusterSessionListener.java:85) at org.apache.catalina.cluster.tcp.SimpleTcpCluster.receive(SimpleTcpCluster.java:1163) at org.apache.catalina.cluster.tcp.ClusterReceiverBase.messageDataReceived(ClusterReceiverBase.java:418) at org.apache.catalina.cluster.io.ObjectReader.execute(ObjectReader.java:107) at org.apache.catalina.cluster.tcp.TcpReplicationThread.drainChannel(TcpReplicationThread.java:139) at org.apache.catalina.cluster.tcp.TcpReplicationThread.run(TcpReplicationThread.java:69)
Is it possible for you to provide a simple test case that produces this error? Does the issue only occur when shutting down a clustered app?
It's hard to write a test case to produce this error... All I can tell you is that this happens on a 2 node cluster, when redeploying an application. I assume the application class-loader (log4j jar is in WEB-INF/lib) has already made some clean-up while the replication thread starts a session replication that involves logging.
Does the issue occur if you move log4j.jar up to a non-webapp-specific classloader location, e.g. $CATALINA_HOME/common/lib?
I'm afraid I can't perform that test : the application is running in a production environment along with other appliaction. I can't afford to risk to reduce the stability of the system. Maybe I should post this bug in the Tomcat product ?
I get the same error message in Eclipse when I use the manager webapp that comes with tomcat 5 to reload a webapp. I've got the log4j-1.2.8.jar jar in WEB-INF/lib/ and common/lib/ I'm running Apache Tomcat/5.5.16 Prop file: log4j.threshold=ALL log4j.rootLogger=INFO, R #### writes to a file log4j.appender.R=org.apache.log4j.RollingFileAppender log4j.appender.R.File=${catalina.home}/logs/nac/nac.log log4j.appender.R.layout=org.apache.log4j.PatternLayout log4j.appender.R.layout.ConversionPattern=%d [%c{1}] %p - %n %m%n%n log4j.appender.R.MaxFileSize=100MB log4j.appender.R.MaxBackupIndex=5 #### velocity log level ##log4j.appender.R.apache.velocity.runtime.log.SimpleLog4JLogSystem=ERROR log4j.logger.org.apache.velocity=FATAL log4j.logger.org.apache.struts.validator=ERROR log4j.logger.org.apache.struts.tiles=ERROR log4j.logger.org.apache.commons.beanutils=ERROR stack trace: log4j:ERROR Error occured while converting date. java.lang.NullPointerException at java.lang.System.arraycopy(Native Method) at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:331) at java.lang.StringBuffer.getChars(StringBuffer.java:202) at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.java:120) at java.text.DateFormat.format(DateFormat.java:314) at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(PatternParser.java:436) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:56) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292) at org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:225) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:193) at org.apache.catalina.session.StandardManager.start(StandardManager.java:638) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4136) at org.apache.catalina.core.StandardContext.reload(StandardContext.java:2990) at org.apache.catalina.manager.ManagerServlet.reload(ManagerServlet.java:906) at org.apache.catalina.manager.ManagerServlet.doGet(ManagerServlet.java:353) at javax.servlet.http.HttpServlet.service(HttpServlet.java:689) at javax.servlet.http.HttpServlet.service(HttpServlet.java:802) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:524) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684) at java.lang.Thread.run(Thread.java:595) This bug occurs often but not everytime.
Take a look at ASF BZ 39699: http://issues.apache.org/bugzilla/show_bug.cgi?id=39699 I think that this is the same as your issue, and it was fixed in Tomcat >5.5.17.
I'm seeing a similar bug during an app reload. log4j-1.2.8 and commons-logging (1.1) in WEB-INF/lib. If I move them to common/lib and plop down a log4j.properties the bug goes away but this blows my log configuration (WEB-INF/classes/log4j.properties) for my app out of the water INFO: Reloading this Context has started log4j:ERROR Error occured while converting date. java.lang.NullPointerException at java.lang.System.arraycopy(Native Method) at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:3 31) at java.lang.StringBuffer.getChars(StringBuffer.java:202) at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.j ava:120) at java.text.DateFormat.format(DateFormat.java:314) at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(P atternParser.java:436) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.jav a:56) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292) at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileA ppender.java:349) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders (AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:19 3) at org.apache.catalina.session.StandardManager.doLoad(StandardManager.ja va:412) at org.apache.catalina.session.StandardManager.load(StandardManager.java :321) at org.apache.catalina.session.StandardManager.start(StandardManager.jav a:637) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4 166) at org.apache.catalina.core.StandardContext.reload(StandardContext.java: 3025) at org.apache.catalina.loader.WebappLoader.backgroundProcess(WebappLoade r.java:432) at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBas e.java:1278) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1570) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1579) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1579) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.r un(ContainerBase.java:1559) at java.lang.Thread.run(Thread.java:595) log4j:ERROR Error occured while converting date. java.lang.NullPointerException at java.lang.System.arraycopy(Native Method) at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:3 31) at java.lang.StringBuffer.getChars(StringBuffer.java:202) at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.j ava:120) at java.text.DateFormat.format(DateFormat.java:314) at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(P atternParser.java:436) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.jav a:56) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292) at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileA ppender.java:349) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders (AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:19 3) at org.apache.catalina.session.StandardManager.start(StandardManager.jav a:639) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4 166) at org.apache.catalina.core.StandardContext.reload(StandardContext.java: 3025) at org.apache.catalina.loader.WebappLoader.backgroundProcess(WebappLoade r.java:432) at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBas e.java:1278) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1570) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1579) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1579) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.r un(ContainerBase.java:1559) at java.lang.Thread.run(Thread.java:595) Apr 23, 2007 11:00:07 AM org.apache.commons.modeler.Registry registerComponent SEVERE: Null component Catalina:type=JspMonitor,name=jsp,WebModule=//localhost/e sa,J2EEApplication=none,J2EEServer=none Apr 23, 2007 11:00:07 AM org.apache.catalina.core.ContainerBase backgroundProces s WARNING: Exception processing loader WebappLoader[/esa] background process java.lang.NullPointerException at org.apache.log4j.NDC.get(NDC.java:201) at org.apache.log4j.spi.LoggingEvent.getNDC(LoggingEvent.java:229) at org.apache.log4j.helpers.PatternParser$BasicPatternConverter.convert( PatternParser.java:393) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.jav a:56) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292) at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileA ppender.java:349) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders (AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:19 3) at org.apache.catalina.session.StandardManager.start(StandardManager.jav a:639) at org.apache.catalina.core.StandardContext.start(StandardContext.java:4 166) at org.apache.catalina.core.StandardContext.reload(StandardContext.java: 3025) at org.apache.catalina.loader.WebappLoader.backgroundProcess(WebappLoade r.java:432) at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBas e.java:1278) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1570) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1579) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.p rocessChildren(ContainerBase.java:1579) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.r un(ContainerBase.java:1559) at java.lang.Thread.run(Thread.java:595) log4j:ERROR Error occured while converting date. java.lang.NullPointerException at java.lang.System.arraycopy(Native Method) at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:3 31) at java.lang.StringBuffer.getChars(StringBuffer.java:202) at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.j ava:120) at java.text.DateFormat.format(DateFormat.java:314) at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(P atternParser.java:436) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.jav a:56) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292) at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileA ppender.java:349) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders (AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:169 ) at org.apache.catalina.authenticator.FormAuthenticator.forwardToLoginPag e(FormAuthenticator.java:319) at org.apache.catalina.authenticator.FormAuthenticator.authenticate(Form Authenticator.java:244) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authentica torBase.java:491) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.j ava:127) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.j ava:117) at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommon AccessLogValve.java:482) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineVal ve.java:108) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.jav a:151) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java :870) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.p rocessConnection(Http11BaseProtocol.java:665) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpo int.java:528) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFol lowerWorkerThread.java:81) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP ool.java:685) at java.lang.Thread.run(Thread.java:595) Apr 23, 2007 11:00:10 AM org.apache.catalina.connector.CoyoteAdapter service SEVERE: An exception or error occurred in the container during the request proce ssing java.lang.NullPointerException at org.apache.log4j.helpers.PatternConverter.spacePad(PatternConverter.j ava:98) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.jav a:71) at org.apache.log4j.PatternLayout.format(PatternLayout.java:495) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292) at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileA ppender.java:349) at org.apache.log4j.WriterAppender.append(WriterAppender.java:150) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders (AppenderAttachableImpl.java:57) at org.apache.log4j.Category.callAppenders(Category.java:187) at org.apache.log4j.Category.forcedLog(Category.java:372) at org.apache.log4j.Category.log(Category.java:864) at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:169 ) at org.apache.catalina.authenticator.FormAuthenticator.forwardToLoginPag e(FormAuthenticator.java:319) at org.apache.catalina.authenticator.FormAuthenticator.authenticate(Form Authenticator.java:244) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authentica torBase.java:491) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.j ava:127) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.j ava:117) at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommon AccessLogValve.java:482) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineVal ve.java:108) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.jav a:151) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java :870) at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.p rocessConnection(Http11BaseProtocol.java:665) at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpo int.java:528) at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFol lowerWorkerThread.java:81) at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP ool.java:685) at java.lang.Thread.run(Thread.java:595) Exception in thread "Timer-9" java.lang.NullPointerException at com.mchange.v2.log.log4j.Log4jMLog$Log4jMLogger.isLoggable(Log4jMLog. java:255) at com.mchange.v2.resourcepool.BasicResourcePool$CheckIdleResourcesTask. run(BasicResourcePool.java:1961) at java.util.TimerThread.mainLoop(Timer.java:512) at java.util.TimerThread.run(Timer.java:462)
I have just come across this issue in TC 6. Log4J ist in webbapp's /WEB-INF/lib. no default log4j.properties but customized Log4j settings controlled by webapp In TC 5.0 in the same setup this did not occur.
Marking as WORKSFORME as I think this is the Tomcat class reload issue. Refile a new bug report, if there is new information.