Bug 40260 - null pointer exception in pattern layout (in spacePad method)
Summary: null pointer exception in pattern layout (in spacePad method)
Status: RESOLVED WONTFIX
Alias: None
Product: Log4j - Now in Jira
Classification: Unclassified
Component: Layout (show other bugs)
Version: 1.2
Hardware: Other Windows XP
: P2 major
Target Milestone: ---
Assignee: log4j-dev
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2006-08-15 21:45 UTC by Dario Andrade
Modified: 2008-06-20 13:14 UTC (History)
2 users (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Dario Andrade 2006-08-15 21:45:09 UTC
It is being used in a worker thread by xapool 1.5.0 as seen on the
Stacktrace:

Exception in thread "Thread-3" java.lang.NullPointerException
        at org.apache.log4j.helpers.PatternConverter.spacePad
(PatternConverter.java:106)
        at org.apache.log4j.helpers.PatternConverter.format
(PatternConverter.java:82)
        at org.apache.log4j.PatternLayout.format(PatternLayout.java:503)
        at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:301)
        at org.apache.log4j.WriterAppender.append(WriterAppender.java:159)
        at org.apache.log4j.AppenderSkeleton.doAppend
(AppenderSkeleton.java:230)
        at 
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders
(AppenderAttachableImpl.java:65)
        at org.apache.log4j.Category.callAppenders(Category.java:203)
        at org.apache.log4j.Category.forcedLog(Category.java:388)
        at org.apache.log4j.Category.log(Category.java:853)
        at org.apache.commons.logging.impl.Log4JLogger.info
(Log4JLogger.java:133)
        at org.enhydra.jdbc.util.Logger.info(Logger.java:43)
        at org.enhydra.jdbc.pool.GenericPool.cleanUp(GenericPool.java:737)
        at org.enhydra.jdbc.pool.PoolKeeper.run(PoolKeeper.java:60)
        at java.lang.Thread.run(Thread.java:595)
Comment 1 Kay Abendroth 2006-11-12 10:53:41 UTC
There's much more information needed.
Are you using log4j-1.2.14?
What are you doing when this is going to happen?

Can you provide a TestCase to reproduce this behaviour?
Comment 2 Rachel Wilson 2007-01-12 10:04:08 UTC
I am also getting the same error and same stack trace

I am using log4j-1-2.14.jar, and tomcat 5.5.17

The exception, for me at least, occurs after "auto" deploying a new application
war file in tomcat's webapps dir ie.  without stopping tomcat.

I had just installed log4j-1-2.14 after hitting bug 40159
Comment 3 Jacob Kjome 2007-01-13 10:22:38 UTC
Where do you have Log4j installed?  Is it in the WEB-INF/lib of each webapp,
Tomcat's common/lib, both?

When you talk about the "autodeploy", are you dropping a WAR for the first time
into Tomcat or reloading an existing application after you've made an update and
replaced the existing WAR with a new one at runtime, trigging the "autodeploy"?


Jake
Comment 4 Rachel Wilson 2007-01-15 02:12:56 UTC
I have the jar file in both the WEB-INF/lib dir of the webapp and common/lib

"autoDeploy":  the latter.  replacing the war file and stopping/starting Tomcat
works fine, i only get this error if i replace the war file while tomcat is
already running.  I get the same error if i use Tomcat's online manager app to
stop/start/undeploy/redeploy the same war file
Comment 5 Rachel Wilson 2007-01-15 09:00:12 UTC
I managed to get tomcat autoDeploy to work without generating this error but
whether (a) it is the underlying cause of the original posters problem  and/or
(b) there is still something that could be improved in log4j's exception
handling i couldn't say.

Having just upgraded from Tomcat 4 where we were (for historical reasons) using
log4j's PropertyConfigurator in a servlet to load a log4j configuration file
held in our own directory for all our configuration files.  As soon as I renamed
this config file to log4j.properties and put it in the WEB-INF/classes directory
then I could autoDeploy sucessfully, as you might expect.

I appreciate that this is how we are instructed to use log4j, especially in
Tomcat5, but given how the autoDeployment worked before upgrading to tomcat 5 i
was a little surprised that it didnt still work and that the error message was
so obscure
Comment 6 G. Ann Campbell 2008-06-20 05:27:26 UTC
I'm seeing this same problem:

Tomcat6 on Linux
log4j-1.2.7.jar loaded from WEB-INF/lib

This happens whether I stop/start the application from the Tomcat console or undeploy/deploy a new copy of the war (also via console.) This does not happen if I bounce Tomcat itself.

I have a singleton running in its own thread. When the application is stopped, that singleton thread apparently remains in the JVM.

When the app restarts, it checks for the existence of an old thread and if found, interrupts the thread.

The interrupted thread tries to log the interruption (at the INFO level) just before the stopThread() call. The null pointer exception is thrown as a result.

Logging is not configured using PropertyConfigurator, but by hand in a company framework I'm using:

    org.apache.log4j.LogManager.resetConfiguration();

    LogMessage logMessage = new LogMessage(LogLevel.DEBUG);
    logMessage.append("Configuring default logger");

    logFilePath = System.getProperty("log_file_path");
    if (logFilePath == null)
    {
      logFilePath = this.appAbsolutePath;
      logMessage.append("Log file environment variable could not be found - defaulting to application absolute path.");
    }
    else
    {
      if (!logFilePath.endsWith("\\"))
        logFilePath = logFilePath + "\\";
    }

    Element rootElement = null;
    Element defaultLoggerElement = null;
    PatternLayout defaultOutputPattern = null;
    String defaultLevel = null;

    try
    {
      rootElement = JDOMHelper.getRootElement(this.getClass(), DTD_FILE, CONFIG_FILE, true);
    }
    catch (JDOMHelperException e)
    {
      throw new ServiceException("JDOMHelperException in LogService.reloadConfig(): " + e.getMessage());
    }

    defaultLoggerElement = rootElement.getChild(DEFAULT_LOGGER_ELEMENT);

    // See if we have any over-riding destinations for the "default" (root) logger.
    // They will be added later, after the "destinations" are defined.
    List defaultDestinations = getDestinations(defaultLoggerElement);

    defaultOutputPattern = getOutputPattern(defaultLoggerElement, logMessage);
    defaultLevel = getLoggerLevel(defaultLoggerElement);
    logMessage.append("Creating default Console logger.");

    ConsoleAppender consoleAppender = new ConsoleAppender(defaultOutputPattern);

    // This is used only to configure the "Root Logger".
    Logger logger = repository.getRootLogger();

    // Remove any previous appenders to reconfigure the logging options.
    logger.removeAllAppenders();
    logger.addAppender(consoleAppender);

    logMessage.append("Setting default Console Logger to " + defaultLevel + " level");

    logger.setLevel(LogLevel.toLevel(defaultLevel));

    // Get the other loggers, if there are any.
    // Element loggers = rootElement.getChild(LOGGER_ELEMENT);

    logger.debug(logMessage.getMessage());

    List destinationList = rootElement.getChildren(DESTINATION_ELEMENT);
    if (destinationList == null || destinationList.size() == 0)
      logger.debug("No log destinations defined.");
    else
    {
      int destinationCount = destinationList.size();
      Element currentDestinationElement = null;
      for (int i = 0; i < destinationCount; i++)
        addDestination((Element) destinationList.get(i));
    }

    if (defaultDestinations != null)
    {
      logMessage = new LogMessage();

      // Clear the root logger for the over-riding appenders.
      logger.removeAllAppenders();

      String appenderName = null;
      Appender appender = null;
      for (int i = 0; i < defaultDestinations.size(); i++)
      {
        appenderName = (String) defaultDestinations.get(i);
        appender = (Appender) destinations.get(appenderName);
        if (appender == null)
          logMessage.append("Destination " + appenderName + " is not a valid logging destination.");
        else
        {
          logMessage.append("Adding " + appenderName + " destination to default logger.");
          logger.addAppender(appender);
        }
        appender = null;
      }
      LogLog.debug(logMessage.toString());
    }

    List loggerList = rootElement.getChildren(LOGGER_ELEMENT);

    if (loggerList == null || loggerList.size() == 0)
      logger.debug("No Loggers other than the default defined.");
    else
    {
      int loggerCount = loggerList.size();
      Element currentLoggerElement = null;
      for (int i = 0; i < loggerCount; i++)
      {
        addLogger((Element) loggerList.get(i));
      }
    }

    if (destinations != null)
    {
      destinations.clear();
      destinations = null;
    }
Comment 7 G. Ann Campbell 2008-06-20 10:33:12 UTC
realized that it might also be helpful to know that my pattern looks like this:

%d{MM/dd@HH:mm} - [%-5p] - %m%n

And that the exception goes away if I remove the padding:

%d{MM/dd@HH:mm} - [%p] - %m%n
Comment 8 Curt Arnold 2008-06-20 13:14:16 UTC
This appears to be the result of Tomcat's class loader breaking what should be invariants in log4j.  See https://issues.apache.org/bugzilla/show_bug.cgi?id=41939 for a discussion.

In addition to the Tomcat options to stop nulling out static members on shutdown (described in the other thread), you might try using the EnhancedPatternLayout in the extras companion (http://logging.apache.org/log4j/companions/extras) which may less susceptible to this issue since it doesn't use static member variables to add space padding.

Sorry, but this does seem a Tomcat issue and log4j can't defend itself against a class loader that attacks its invariants.