You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Rachel Wilson <r....@qmul.ac.uk> on 2007/02/27 18:20:48 UTC

log4j exception only when stopping and starting a web application

I am deploying an unpacked webapp directory to TOMCAT_HOME/webapps/myapp,
If i (stop and) start tomcat then my application runs fine and the logging
works fine.  However if i stop the application (successfully, it seems) and
restart it using Tomcats manager app then I get the following error:

2007-02-27 16:21:17,671 ERROR http-8080-Processor3
org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager] -
FAIL - Application at context path /myapp could not be started
java.lang.NullPointerException
	at
org.apache.log4j.helpers.PatternConverter.spacePad(PatternConverter.java:106
)
	at
org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:68)
	at org.apache.log4j.PatternLayout.format(PatternLayout.java:503)
	at
org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:301)
	at
org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:236)
	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(Append
erAttachableImpl.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.debug(Log4JLogger.java:171)
	at qmul.jndirealm.JNDIRealm.open(JNDIRealm.java:1592)
	at qmul.jndirealm.JNDIRealm.start(JNDIRealm.java:1690)
	at
org.apache.catalina.core.StandardContext.start(StandardContext.java:4097)




Configuration details
---------------------
Tomcat 5.5.17
Windows XP

I am using server-minimal.xml
I have a context.xml in my webapp's META-INF dir
I have an application specific log4j.properties file in my webapps
WEB-INF/classes dir
I have an log4j.properties file in TOMCAT_HOME/common/classes


The closest I can find on the web to my problems are the following threads
but there is no clear solution in my situation

http://www.junlu.com/msg/295563.html
http://www.mail-archive.com/log4j-dev@logging.apache.org/msg06424.html


This is especially strange because the configuration must have been correct
initially in order for everything to work in the first instance.
So what changes when an application is stopped and started in order to cause
this error?

I have run out of things to check now, can anybody suggest any more leads?


---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: log4j exception only when stopping and starting a web application

Posted by Tim Lucia <ti...@yahoo.com>.
It's not necessarily bad to use Singletons.  You have to be certain that
they do not hold references to themselves or their class or they cannot be
unloaded.  Google for: permgen log4j.

One thing about log4j -- you should have an ServletContextListener that
shuts down log4j properly:

public class ApplicationLifecycleListener implements ServletContextListener
{
    public void contextDestroyed(ServletContextEvent sce) 
    {
        LogFactory.release(Thread.currentThread().getContextClassLoader());
    }
}

Tim

> -----Original Message-----
> From: Rachel Wilson [mailto:r.l.wilson@qmul.ac.uk]
> Sent: Wednesday, February 28, 2007 12:10 PM
> To: 'Tomcat Users List'
> Subject: RE: log4j exception only when stopping and starting a web
> application
> 
> 
> >  This problem is pretty common when restarting web applications.
> Libraries
> >  that use singletons etc. don't get reinitialized correctly when the web
> >  application is reloaded.
> 
> Blimey, that sounds like a serious flaw :S
> 
> Do you know why they don't get reinitialized properly?  Could you give me
> a
> pointer so i can diagnose if this is truly the case in our situation?
> (not
> that i don't believe you but before i tell our administrators that they're
> going to have to do everything differently i'd like to be able to give
> them
> some evidence)
> 
> My administrator assures me that this didn't used to be the case for
> tomcat
> 4.x so what changed i wonder?
> 
> By the way, a couple of things that may be of interest and some further
> relevant questions:
> 
> [1] To cut a long diagnostic story short I found that if you removed the
> leading 3 from the %3x portion of my layout conversionpattern then that
> error is no longer encountered, the webapp restarts and the user is able
> to
> log in.  BUT after my user is successfully returned from LDAP
> authorization
> and (is supposed to be) redirected back to the first page of my
> application... processing stops, all i get is a blank screen and the url
> that ends in j_security_check.  But no errors are logged anywhere that i
> can
> see.
> 
> Q.  Could this be caused by the same reinitialization problem?  We do use
> singletons in our own code.
> 
> [2]  The exact same stop/start problems occur if i deploy a war file under
> /webapps where we specify unpacked="false".  This isn't too surprising,
> however...... my colleague deploys his webapps under a
> $TOMCAT_HOME/myWarfiles directory and has changed the docBase.  (He did
> this
> because of the annoying context.xml deleting/management behaviour and his
> reluctance to include configuration files in a war file to be passed to
> development)  but he can stop/start undeploy/redeploy his (packed)
> warfiles
> with no problem.
> 
> Q.  How does this fit with the reinitialization issue you describe?
> 
> 
> 
> ---------------------------------------------------------------------
> To start a new topic, e-mail: users@tomcat.apache.org
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org




---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: log4j exception only when stopping and starting a web application

Posted by Rachel Wilson <r....@qmul.ac.uk>.
>  This problem is pretty common when restarting web applications. Libraries
>  that use singletons etc. don't get reinitialized correctly when the web
>  application is reloaded.

Blimey, that sounds like a serious flaw :S

Do you know why they don't get reinitialized properly?  Could you give me a
pointer so i can diagnose if this is truly the case in our situation?  (not
that i don't believe you but before i tell our administrators that they're
going to have to do everything differently i'd like to be able to give them
some evidence)

My administrator assures me that this didn't used to be the case for tomcat
4.x so what changed i wonder?

By the way, a couple of things that may be of interest and some further
relevant questions:  

[1] To cut a long diagnostic story short I found that if you removed the
leading 3 from the %3x portion of my layout conversionpattern then that
error is no longer encountered, the webapp restarts and the user is able to
log in.  BUT after my user is successfully returned from LDAP authorization
and (is supposed to be) redirected back to the first page of my
application... processing stops, all i get is a blank screen and the url
that ends in j_security_check.  But no errors are logged anywhere that i can
see.

Q.  Could this be caused by the same reinitialization problem?  We do use
singletons in our own code.

[2]  The exact same stop/start problems occur if i deploy a war file under
/webapps where we specify unpacked="false".  This isn't too surprising,
however...... my colleague deploys his webapps under a
$TOMCAT_HOME/myWarfiles directory and has changed the docBase.  (He did this
because of the annoying context.xml deleting/management behaviour and his
reluctance to include configuration files in a war file to be passed to
development)  but he can stop/start undeploy/redeploy his (packed) warfiles
with no problem.

Q.  How does this fit with the reinitialization issue you describe?



---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: log4j exception only when stopping and starting a web application

Posted by Gary Evesson <ga...@evesson.com>.
On 2/28/07, Rachel Wilson <r....@qmul.ac.uk> wrote:
>
> >> It looks like you have bad syntax in you log4j.properties file.
> If that were the case, i would have expected it to fail the first time i
> started the application?
>
> to be clear, here are the steps to reproduce the error
> [1] deploy an unpacked webapp "myapp" to $TOMCAT_HOME/webapps/myapp
> [2] start tomcat
> [3] all webapps start and work fine, both tomcat and application logging
> works fine
> [4] using the /manager webapp stop myapp
> [5] myapp (seems to) shut down fine
> [6] using the /manager webapp start myapp
> [7] myapp does not start because of the reported error


Sorry, didn't realize this was happening on a reload.

This problem is pretty common when restarting web applications. Libraries
that use singletons etc. don't get reinitialized correctly when the web
application is reloaded. These can be tough to track down, because more
often than not, the issue is not in your code. Oddly enough I haven't seen
this particular error coming out of log4j before...

Once your library count gets higher, it becomes harder and harder to keep
the applications reloading properly - more from memory leaks through the
reload more than anything else. We gave up on it and restart tomcat. We run
a cluster, so restarting just one version of tomcat has little effect on our
system.

Your log4j.properties looks OK to me.

-- 
Gary Evesson

RE: log4j exception only when stopping and starting a web application

Posted by Rachel Wilson <r....@qmul.ac.uk>.
>> It looks like you have bad syntax in you log4j.properties file.
If that were the case, i would have expected it to fail the first time i
started the application?

to be clear, here are the steps to reproduce the error
[1] deploy an unpacked webapp "myapp" to $TOMCAT_HOME/webapps/myapp
[2] start tomcat
[3] all webapps start and work fine, both tomcat and application logging
works fine
[4] using the /manager webapp stop myapp
[5] myapp (seems to) shut down fine
[6] using the /manager webapp start myapp
[7] myapp does not start because of the reported error

It might also be worth mentioning that my application requires the user to
log in and is then redirected to an LDAP server for authentication.

But, just in case you are right I stripped the log4j.properties down to
something very simple and i still get the same error *only* after stopping
and restarting the application via the manager application.  

I attached my stripped down versions of the log4j.properties files just in
case you can spot something (oh please don't let there be a typo :))


log4j.properties in webapps/myapp/WEB-INF/classes
-------------------------------------------------
log.home=C:/Tomcat 5.5/logs
app.name=myapp

# root logger sends INFO level messages to debug and error appenders
log4j.rootLogger=DEBUG,A1

# define the debug appender
log4j.appender.A1=org.apache.log4j.RollingFileAppender
log4j.appender.A1.Append=true
log4j.appender.A1.File=${log.home}/${app.name}/myapp.log
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %3x
%c - %m%n


# define the tomcat appender for Tomcat messages specific to this
application
log4j.appender.tomcat=org.apache.log4j.RollingFileAppender
log4j.appender.tomcat.Append=true
log4j.appender.tomcat.File=${log.home}/${app.name}/tomcat.log
log4j.appender.tomcat.layout=org.apache.log4j.PatternLayout
log4j.appender.tomcat.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p
%c %3x - %m%n



log4j.properties in $TOMCAT_HOME/common/classes
-----------------------------------------------
log4j.rootLogger=INFO, R
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=${catalina.home}/logs/tomcat.log
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d %p %t %c - %m%n





---------------------------------------------------------------------
To start a new topic, e-mail: users@tomcat.apache.org
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: log4j exception only when stopping and starting a web application

Posted by Gary Evesson <ga...@evesson.com>.
On 2/27/07, Rachel Wilson <r....@qmul.ac.uk> wrote:
>
>
> I am deploying an unpacked webapp directory to TOMCAT_HOME/webapps/myapp,
> If i (stop and) start tomcat then my application runs fine and the logging
> works fine.  However if i stop the application (successfully, it seems)
> and
> restart it using Tomcats manager app then I get the following error:
>
> 2007-02-27 16:21:17,671 ERROR http-8080-Processor3
> org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager] -
> FAIL - Application at context path /myapp could not be started
> java.lang.NullPointerException
>         at
> org.apache.log4j.helpers.PatternConverter.spacePad(PatternConverter.java
> :106
> )
>         at
> org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:68)
>

It looks like you have bad syntax in you log4j.properties file.

-- 
Gary Evesson