We use the followwing logging.properties in our WebApplication: ----------%<--------------------%<---------------- handlers = 1tivoli.java.util.logging.FileHandler, 2product.java.util.logging.FileHandler # Handlers for the root logger .handlers = 1tivoli.java.util.logging.FileHandler, 2product.java.util.logging.FileHandler 1tivoli.java.util.logging.FileHandler.level = INFO 1tivoli.java.util.logging.FileHandler.pattern = /var/log/product/tivoli%g.log # limit Output to 1MB 1tivoli.java.util.logging.FileHandler.limit=1048576 # Limit rotation to 10 Logs ... 1tivoli.java.util.logging.FileHandler.count=10 1tivoli.java.util.logging.FileHandler.append=true 1tivoli.java.util.logging.FileHandler.formatter=de.customer.product.tivoli.TivoliFormatter 2product.java.util.logging.FileHandler.level = FINEST 2product.java.util.logging.FileHandler.pattern = /var/log/product/product%g.log # limit Output to 1MB 2product.java.util.logging.FileHandler.limit=1048576 # Limit rotation to 5 Logs ... 2product.java.util.logging.FileHandler.count=5 2product.java.util.logging.FileHandler.append=true 2product.java.util.logging.FileHandler.formatter=java.util.logging.SimpleFormatter ----------%<--------------------%<---------------- When using apache-tomcat-5.5.23 every Line in the Logfiles is duplicated. Debugging I found that the TivoliFormatter is actually created twice. And the root-logger has actually 4 Handlers and not two as intended. This does not allow us an upgrade beyond 5.5.20. Found on Linux64Bit and Windows-XP, both with JDK 1.5_R11
java.util.logging.FileHandler extends java.util.logging.StreamHandler. The no-args constructors for these two classes both make a call to the configure() method, which is why you see two TivoliFormatters created when the tivoli handler is set up. This shouldn't cause duplication, though; the first formatter to be created is simply discarded, and only the second is used. Could you give more information about your setup? I can't duplicate this problem. Is that your entire logging.properties file? How does your code use the logger? If I put these lines into a test servlet: Logger logger = Logger.getLogger(""); logger.severe("Handlers: " + Arrays.asList(logger.getHandlers())); and make a request to it (using your logging.properties file), the console shows that the root logger has two handlers (both FileHandlers).
More Infos: * The bug does not appear when all our classes are in the bootclasspath (as we do for testing via eclipse) but only when deployed as war/jar * We use a root context and deploy it as ROOT.war (although this is not really documented as beeing supported this way) * The TivoliFormatter has only a default Constructor The first usage that was duplicated works as follows: public class ProductContextListener implements ServletContextListener { private static Logger log = Logger.getLogger(ProductContextListener .class.getName()); ... public void contextInitialized(ServletContextEvent anEvent) { ... log.info("Starting Product Version " + version); ... } } Our global logging.properties is as follows: --------------%<---------------%<----------------- handlers = 1catalina.java.util.logging.FileHandler # Handlers for the root logger .handlers = 1catalina.java.util.logging.FileHandler 1catalina.java.util.logging.FileHandler.level = INFO 1catalina.java.util.logging.FileHandler.pattern = /var/log/ucs/catalina%g.log # limit Output to 1MB 1catalina.java.util.logging.FileHandler.limit=1048576 # Limit rotation to 10 Logs ... 1catalina.java.util.logging.FileHandler.count=10 # 1catalina.java.util.logging.FileHandler.append=true 1catalina.java.util.logging.FileHandler.formatter=java.util.logging.SimpleFormatter --------------%<---------------%<----------------- Our server XML is as follows: --------------%<---------------%<----------------- <Server port="8005" shutdown="****"> <!-- server.xml for deployed tomcat 5 --> <Service name="Product"> <Connector port="8080" maxKeepAliveRequests="100000" maxThreads="200" minSpareThreads="20" maxSpareThreads="100" enableLookups="false" acceptCount="20" /> <Engine name="Product" defaultHost="localhost"> <Host name="localhost" appBase="webapps" > <Context path="" cookies="false" docBase="ROOT.war" cachingAllowed="false" processTlds="false" unpackWAR="true" reloadable="false"> <Manager pathname="" /> </Context> </Host> </Engine> </Service> </Server> --------------%<---------------%<----------------- Hmm, perhaps the Problem happens when using a ROOT <Context path="" ../> only ? web.xml was copied from tomcat 5.5.20 We use the following properties (in eclipse) to start tomcat. ---------------%<-----------------%<----------------------- -Dcatalina.home="${TOMCAT5}" -Dcatalina.base="${workspace_loc:de.customer.product}/ext/tomcat5" -Djava.endorsed.dirs="${TOMCAT5}}/common/endorsed" -Djava.io.tmpdir="${TOMCAT5}/temp" -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file="${workspace_loc:de.customer.product}/ext/tomcat5/conf/logging.properties" ---------------%<-----------------%<----------------------- On linux we use a similar init.d script: ---------------%<-----------------%<----------------------- On linux we use a similar init.d script: #!/bin/sh # # Startup script for product UserConfigurationSystem # $Id: product,v 1.7 2007/04/10 08:53:50 kha Exp $ # # /etc/init.d/product # ### BEGIN INIT INFO # Provides: product # Required-Start: mysql # Default-Start: 3 5 # Default-Stop: 0 1 2 6 # Short-Description: product - Our super duper product # Description: A Small tomcat based web-app as XML-RPCProvider # against a fat MySQL Database ### END INIT INFO # # Check for missing binaries (stale symlinks should not happen) # Note: Special treatment of stop for LSB conformance CATALINA_HOME=/opt/app/product/apache-tomcat CATALINA_BASE=/opt/app/product/service CATALINA_BIN=$CATALINA_HOME/bin/catalina.sh test -x $FOO_BIN || { echo "$CATALINA_BIN not installed"; if [ "$1" = "stop" ]; then exit 0; else exit 5; fi; } JAVA_HOME=/usr/java/jdk1.5.0_11 JRE_HOME=$JAVA_HOME/jre CATALINA_OPTS= USER=product CATALINA_OPTS=-Dde.customer.product.confDir=/etc/product CATALINA_OPTS="$CATALINA_OPTS -Xbootclasspath/a:/opt/app/product/service/lib/product-tivoli.jar" # CATALINA_OPTS="$CATALINA_OPTS -ea -esa -Xdebug -Xrunjdwp:transport=dt_socket,address=9099,server=y,suspend=n" CATALINA_TMPDIR=/var/opt/app/product/tmp su - $USER -c "export JAVA_HOME=$JAVA_HOME;\ export JRE_HOME=$JRE_HOME;\ export CATALINA_OPTS='$CATALINA_OPTS';\ export JAVA_OPTS='$JAVA_OPTS';\ export CATALINA_HOME=$CATALINA_HOME;\ export CATALINA_BASE=$CATALINA_BASE;\ export CATALINA_TMPDIR=$CATALINA_TMPDIR;\ $CATALINA_HOME/bin/catalina.sh $1" ---------------%<-----------------%<----------------------- Thats all I can give you so far, as we must deliver the product next week ;-)
The problem was trivial (handlers for the root logger are added twice if they are specified using .handlers). Workaround: remove .handlers (what's the purpose exactly if it's the same as handlers; of course, I suppose it has the same purpose as that Context element in the server.xml).
Thanks for the Workaround: As I Understand it: handlers - configures all availeable Handlers .handlers - are the Handlers for the root-logger e.g. org.apache.tomcat.handlers - would be handlers for theses packages only Feels like the root context is silently used as parking area for the handlers ;-) Thanks again
> Feels like the root context is silently used > as parking area for the handlers ;-) That's how Java Logging works, so JULI is consistent with that - all handlers defined in the "handlers" property are automatically added to the root logger. If you want a subset just add a ".handlers" property listing the subset.