And even further into the black magic of logging configuration within tomcat...

[Dan Armbrust <da...@gmail.com>]

So, after my long thread to figure out the missing stack traces from a
bad listener configuration, I _thought_ I knew what I needed to
correct.

It seemed that Tomcat was trying to use log4j shipped with my webapp,
before my webapp had configured log4j.
Supplying a log4.properties file in the WEB-INF\classes folder with a
temporary log4j configuration seemed to fix the problem.

Until... I deployed two webapps within tomcat.

The second (and subsequent) webapps _still_ have the problem of trying
to log to a log4j which isn't configured - resulting in all error
messages being lost.

I turned on log4j debugging (-Dlog4j.debug=true) - and here is what I
see as tomcat starts:


INFO: Starting service Catalina
Apr 2, 2009 5:01:22 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5.25
Apr 2, 2009 5:01:22 PM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
log4j: Trying to find [log4j.xml] using context classloader WebappClassLoader
  delegate: false
  repositories:
    /WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@17200b4
.
log4j: Trying to find [log4j.xml] using WebappClassLoader
  delegate: false
  repositories:
    /WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@17200b4
 class loader.
log4j: Trying to find [log4j.xml] using ClassLoader.getSystemResource().
log4j: Trying to find [log4j.properties] using context classloader
WebappClassLoader
  delegate: false
  repositories:
    /WEB-INF/classes/
----------> Parent Classloader:
org.apache.catalina.loader.StandardClassLoader@17200b4
.
log4j: Using URL
[file:/opt/foo/tomcat/webapps/app1/WEB-INF/classes/log4j.properties]
for automatic log4j configuration.
log4j: Reading configuration from URL
file:/opt/foo/tomcat/webapps/app1/WEB-INF/classes/log4j.properties
log4j: Parsing for [root] with value=[WARN, Console].
<snip>
log4j: Finished configuring.

And then I see output that lets me know that my dynamic configuration
of log4j has occurred.  Everything is good so far.  No warnings have
been shown.
Now, tomcat starts the second webapp - this is all that I see:

log4j:WARN No appenders could be found for logger
(org.apache.commons.digester.Digester.sax).
log4j:WARN Please initialize the log4j system properly.

And then it lets me know that it has finished my dynamic log4j configuration.

So, why didn't log4j try to find the log4j.properties file for the
second webapp?  I'm certainly no guru of how the visibility works
between the webapps and their various classloaders - buy why is log4j
in the second webapp deciding not to configure itself?  And sure
enough, if I break the listener in the web.xml for the second webapp,
the stack trace is lost.

There is definitely a bug here, but I don't know if the bug is in
Tomcat or in Log4j.

Any thoughts?

Thanks,

Dan

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

Re: And even further into the black magic of logging configuration within tomcat...

[Christopher Schultz <ch...@christopherschultz.net>]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Dan,

On 4/6/2009 5:42 PM, Dan Armbrust wrote:
> System.setProperty("log4j.defaultInitOverride", "true");
> 
> And also, since this is a global JVM variable, one webapp setting this
> property would affect the behaviour of other webapps - but again, it
> would be order dependant.

Ugh. That'll do it. You might want to suggest to the log4j guys that
    -Dlog4j.debug=true
 +
    -Dlog4j.defaultInitOverride=true
 =
    Warning message that default initialization is disabled due to the
    presence of the log4j.defaultInitOverride System property

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAknaeYIACgkQ9CaO5/Lv0PD6DgCfcH7FaxCwDCDZfRYjHaeqR2X4
o6YAn1IAsalPe7ZEvMFm4CkBvj+lJBmh
=VXY8
-----END PGP SIGNATURE-----

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

Re: And even further into the black magic of logging configuration within tomcat...

[Dan Armbrust <da...@gmail.com>]

> If you deploy more than one
> webapp, log4j doesn't attempt to self-configure in the second or any
> subsequent webapps.
>

Just to close out this thread - no big surprise here - I found the bug
in a library that I was deploying in one of my webapps that caused
this behaviour.

Some code was executing this:

System.setProperty("log4j.defaultInitOverride", "true");

in a static init block.

Depending on the order that the static init blocks would be run (this
first, or log4j's first) would change whether log4j would try to
configure itself, since log4j pays attention to that System variable.

And also, since this is a global JVM variable, one webapp setting this
property would affect the behaviour of other webapps - but again, it
would be order dependant.

Dan

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

Re: And even further into the black magic of logging configuration within tomcat...

[Dan Armbrust <da...@gmail.com>]

On Thu, Apr 2, 2009 at 9:55 PM, Caldarale, Charles R
<Ch...@unisys.com> wrote:
>> From: Dan Armbrust [mailto:daniel.armbrust.list@gmail.com]
>> Subject: And even further into the black magic of logging configuration
>> within tomcat...
>>
>> So, why didn't log4j try to find the log4j.properties
>> file for the second webapp?
>
> Verify that you have separate log4j.properties files in the WEB-INF/classes directories of each webapp, and that there's not a permissions problem with them being accessed by whatever userid Tomcat is running under.

Yep.  It exists.

>
> Where is your log4j.jar located?  You should have separate ones in each webapp's WEB-INF/lib directory;

Yes again.

I think that _this_ bug explains why so many people have issues
getting log4j configured in tomcat.  If you deploy more than one
webapp, log4j doesn't attempt to self-configure in the second or any
subsequent webapps.

I'm going to go hunt in some log4j code, and try to understand how
log4j goes about deciding if it should search for a log4j.properties
file.  But I suspect that the problem is in Tomcat - Something is
probably being stored in a class loader that is visible to all
webapps, when it should not be.  So Log4j thinks that it is already
configured in webapp 2 - but it's not, because all of the appenders,
etc, are in the classloader specific to webapp 1.

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

RE: And even further into the black magic of logging configuration within tomcat...

["Caldarale, Charles R" <Ch...@unisys.com>]

> From: Dan Armbrust [mailto:daniel.armbrust.list@gmail.com]
> Subject: And even further into the black magic of logging configuration
> within tomcat...
> 
> So, why didn't log4j try to find the log4j.properties 
> file for the second webapp?

Verify that you have separate log4j.properties files in the WEB-INF/classes directories of each webapp, and that there's not a permissions problem with them being accessed by whatever userid Tomcat is running under.

> There is definitely a bug here, but I don't know if the 
> bug is in Tomcat or in Log4j.

Where is your log4j.jar located?  You should have separate ones in each webapp's WEB-INF/lib directory; if you place log4j.jar in Tomcat's lib directory - or anywhere the common, system, or bootstrap class loaders could find it - you may well end up with the symptoms you're observing.  You could try -verbose:class to see where classes are being loaded from, if you want to wade through a whole lot of output.

 - Chuck


THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.


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