log4j:ERROR Error occured while converting date

Question

I found this exception in my logs:

log4j:ERROR Error occured while converting date. java.lang.NullPointerException at java.lang.System.arraycopy(Native Method) at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:328) at java.lang.StringBuffer.getChars(StringBuffer.java:201) at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.java:130) at java.text.DateFormat.format(DateFormat.java:316) at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(PatternParser.java:443) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:65) at org.apache.log4j.PatternLayout.format(PatternLayout.java:506) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310) at org.apache.log4j.WriterAppender.append(WriterAppender.java:162) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66) at org.apache.log4j.Category.callAppenders(Category.java:206) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.info(Category.java:666) at org.obliquid.db.ConnectionManager.releaseConnection(ConnectionManager.java:313) at org.obliquid.db.ConnectionManager.finalize(ConnectionManager.java:331) at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method) at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83) at java.lang.ref.Finalizer.access$100(Finalizer.java:14) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)

I think it could be caused by my log4j.properties file, in particular by ConversionPattern. Any idea on how to fix?

#Updated at Wed Sep 14 21:57:51 CEST 2011
#Wed Sep 14 21:57:51 CEST 2011
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.rootLogger=INFO, stdout
log4j.appender.R.File=yamweb.log
log4j.appender.R.MaxFileSize=1000KB
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.MaxBackupIndex=1
log4j.appender.R.layout.ConversionPattern=%p %t %c - %m%n
log4j.appender.R=org.apache.log4j.RollingFileAppender

log4j.appender.stdout.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout

log4j.logger.yamweb=DEBUG
log4j.logger.org.springframework=INFO
log4j.logger.org.springframework.beans=DEBUG
log4j.logger.com.amazonaws=WARN

UPDATE: Actually, looking at the PatternLayout JavaDoc, I don't even mention a date format.

d Used to output the date of the logging event. The date conversion specifier may be followed by a date format specifier enclosed between braces. For example, %d{HH:mm:ss,SSS} or %d{dd MMM yyyy HH:mm:ss,SSS}. If no date format specifier is given then ISO8601 format is assumed.

I've added an explicit conversion pattern: %d{yyyy-MM-dd HH:mm:ss} [%t] %p %c - %m%n-- looking at the log and I will let you know if it helps.

UPDATE 2: the problem didn't happen anymore.

Answer 1

It seems this is a very rare situation. Googling for the error turned up the following discussion from 2006, something to do with class un-loading:
http://comments.gmane.org/gmane.comp.jakarta.log4j.user/13835

I did look at the code in question. If lastTimeString was somehow
not initialized on class reload, then there could be a NPE on the
call to getChars(). However, short of a some failure in the VM or a
class reloading hack, I don't see how lastTimeString could be null.

EDIT: See question above for a solution:

I've added an explicit conversion pattern: %d{yyyy-MM-dd HH:mm:ss} [%t] %p %c - %m%n

This also seemed to work for the following question: NPE with Perf4j and Log4j.