Friday, March 2, 2007

A recipe for logging in your java webap

Logging in your web application is one of those things that should take 2 seconds to set up before you can just forget about it. You don't really want to invest a lot of time figuring out how it works. In many cases, it does work just like this, until it doesn't.

Recently, my log4j.properties has started to be ignored on my developer machine. Why? It could be many things - tomcat upgrades, log4j upgrades, commons-logging changes, library conflicts, classloader problems, etc. Because I work on many applications simultaneously, there are small differences between them, often with the newest apps using the newest dependencies, so logging is not necessarily identical across them. And of course, you know it's probably something simple, so often the best remedy is to keep working, and the solution will present itself at some point. But it hasn't, and it has become irksome to keep using the container configuration. So it was time to dig in and figure out what was going on.

That has finally led me to this excellent article:

http://minaret.biz/tips/tomcatLogging.html

All I've wanted for some time is an article telling me the preferred way to set up logging in your web app. Of course, it cannot be so simple.

The main thing to realize is that while your app is the producer of log information at various detail levels, it is not within its responsibility to decide what to do with that information. The target container should decide this.

Imagine you're in charge of the deployment server, and you have several apps running, all of which produce log information. All of a sudden you get this one app which insists on using its own log impl, writes it to some strange location, and writes a ton of stuff all over everywhere. Would you want to dig into the app and figure out how to configure it yourself, or just use your own "master" config to dictate its logging?

So you need to ask yourself, am I deploying my app to a common container, where there are multiple apps running? Furthermore, am I in control of the logging configuration?

We'll deal with the case where the answers to both these questions are yes. This assumes you can do whatever you want to your tomcat config, both on deployment and on developer machines. We will end up with a completely controlled logging environment in both developer and deployed scenarios.

So first, you need to follow the instructions in Geoff Mottram's article. I'll reiterate:
  1. Install Tomcat (5.5.17), make sure it is not running before next step
  2. Obtain commons-logging.jar (1.1)
  3. Copy the commons-logging.jar file from the distribution into your Tomcat common/lib directory.
  4. Obtain log4j.jar (1.2.14)
  5. Copy the log4j.jar file from the distribution into your Tomcat common/lib directory.
  6. Create a log4j.properties file in your Tomcat common/classes directory (see Geoff's article).
  7. Remove the existing log4j.xml if it is there (or use that file if you're comfortable with the xml format for configuration).
  8. Remove logging.properties from conf (this produces catalina.out, and all the rotating admin, manager,host-manager, etc log files)
  9. For now, make sure there is no log4j config in your webapp, nor a log4j.jar, nor any commons-logging.jar - these jars are fine for compiling during dev, but make sure they don't get into the final webapp (war) distribution
  10. In your app, LogFactory.getLog(Hello.class).info("Hello!!!!!");
  11. Restart Tomcat.


Now you should just have two rotating files in your logs directory. You can control all your apps' logging from that single log4j config, either in a mode suitable for development (ie log4j.logger.ca.ucalgary.commons.mt3=DEBUG) or deployment (ie log4j.logger.ca.ucalgary.commons.mt3=INFO). And because you're a responsible app developer, you have no sys.out's or sys.err's, but have logical messages sent to TRACE < DEBUG < INFO < WARN < ERROR < FATAL, so that they can be logged as needed.

If you need to send log messages to separate files, then you need to do what Geoff terms WEB-INF logging. Add a log4j.properties to your webapp/WEB-INF/classes and commons-logging-1.1.jar, log4j-1.2.14.jar to webapp/WEB-INF/lib. I haven't quite figured out this log4j.properties though.

log4j.logger.ca.ucalgary.commons.mt3=DEBUG, R1

log4j.appender.R1=org.apache.log4j.DailyRollingFileAppender
log4j.appender.R1.DatePattern='.'yyyy-MM-dd
log4j.appender.R1.File=/usr/local/tomcat/logs/mt3.log
log4j.appender.R1.layout=org.apache.log4j.PatternLayout
log4j.appender.R1.layout.ConversionPattern=%d %p %c - %m%n


This works fine, but log4j might complain about other appenders:
log4j:WARN No appenders could be found for logger (org.apache.commons.digester.Digester.sax).
log4j:WARN Please initialize the log4j system properly.


I'm not sure why the addition of an app-specific logger suddenly means that sax cannot find it's appender anymore.

2 comments:

Julian said...

Another good link:

http://www.mobilefish.com/developer/log4j/log4j.html

Julian said...

Another one:

http://www.vipan.com/htdocs/log4jhelp.html