Logging with log4j on tomcat jruby-rack for a Rail

Question

I just spent the better part of 3 hours trying to get my Rails application logging with Log4j. I've finally got it working, but I'm not sure if what I did is correct. I tried various methods to no avail until my very last attempt. So I'm really looking for some validation here, perhaps some pointers and tips as well -- anything would be appreciated to be honest. I've summarized all my feeble methods into three attempts below. I'm hoping for some enlightenment on where I went wrong with each attempt -- even if it means I get ripped up.

Thanks for the help in advance!

System Specs

• Rails 3.0
• Windows Server 2008
• Log4j 1.2
• Tomact 6.0.29
• Java 6

Attempt 1 - Configured Tomcat to Use Log4J

I basically followed the guide on the Apache Tomcat website here. The steps are:

1. Create a log4j.properties file in $CATALINA_HOME/lib
2. Download and copy the log4j-x.y.z.jar into $CATALINA_HOME/lib
3. Replace $CATALINA_HOME/bin/tomcat-juli.jar with the tomcat-juli.jar from the Apache Tomcat Extras folder
4. Copy tomcat-juli-adapters.jar from the Apache Tomcat Extras folder into $CATALINA_HOME/lib
5. Delete $CATALINA_BASE/conf/logging.properties
6. Start Tomcat (as a service)

Expected Results According to the Guide

I should have seen a tomcat.log file in my $CATALINA_BASE/logs folder.

Actual Results

• No tomcat.log
• Saw three of the standard logs instead
  • jakarta_service_20101231.log
  • stderr_20101231.log
  • stdout_20101231.log

Question

• Shouldn't I have at least seen a tomcat.log file?

Attempt 2 - Use default Tomcat logging (commons-logging)

1. Reverted all the changes from the previous setup

2. Modified $CATALINA_BASE/conf/logging.properties by doing the following:

   1. Adding a setting for my application in the handlers line: 5rails3.org.apache.juli.FileHandler

   2. Adding Handler specific properties

      5rails3.org.apache.juli.FileHandler.level = FINE
      5rails3.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
      5rails3.org.apache.juli.FileHandler.prefix = rails3.
      

   3. Adding Facility specific properties

      org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/rails3].level = INFO
      org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/rails3].handlers = 4host-manager.org.apache.juli.FileHandler
      

3. Modified my web.xml by adding the following context parameter as per the Logging section of the jruby-rack README (I also modified my warbler.rb accordingly, but I opted to change the web.xml directly to test things faster).

   <context-param>
     <param-name>jruby.rack.logging</param-name>
     <param-value>commons_logging</param-value>
   </context-param>
   

4. Restarted Tomcat

Results

• A log file was created (rails3.log), however there was no log information in the file.

Attempt 2A - Use Log4j with existing set up

I decided to give Log4j another whirl with this new web.xml setting.

1. Copied the log4j.jar into my WEB-INF/lib folder

2. Created a log4j.properties file and put it into WEB-INF/classes

   log4j.rootLogger=INFO, R
   log4j.logger.javax.servlet=DEBUG
   
   log4j.appender.R=org.apache.log4j.RollingFileAppender
   log4j.appender.R.File=${catalina.base}/logs/rails3.log
   log4j.appender.R.MaxFileSize=5036KB
   log4j.appender.R.MaxBackupIndex=4
   log4j.appender.R.layout=org.apache.log4j.PatternLayout
   log4j.appender.R.layout.ConversionPattern=%d{dd MMM yyyy HH:mm:ss} [%t] %-5p %c %x - %m%n
   

3. Restarted Tomcat

Results

Same as Attempt 2

NOTE: I used log4j.logger.javax.servlet=DEBUG because I read in the jruby-rack README that all logging output is automatically redirected to the javax.servlet.ServletContext#log method. So I thought this would capture it, but I was obviously wrong.

Question

1. Why didn't this work?
2. Isn't Log4J using the commons_logging API?

Attempt 3 - Tried out slf4j (WORKED)

A bit uncertain as to why Attempt 2A didn't work, I thought to myself, maybe I can't use commons_logging for the jruby.rack.logging parameter because it's probably not using commons_logging API... (but I was still not sure). I saw slf4j as an option. I have never heard of it and out of curiosity, I decided to look it up. After reading about it briefly, I thought it was as good of a shot as any and decided to try it out following the instructions here.

Continuing from the setup of Attempt 2A:

1. Copied slf4j-api-1.6.1.jar and slf4j-simple-1.6.1.jar into my WEB-INF/lib folder
2. I also copied slf4j-log4j12-1.6.1.jar into my WEB-INF/lib folder
3. Restarted Tomcat

And VIOLA! I now have logging information going into my rails3.log file.

So the big question is:

WTF?

Even though logging seems to be working now, I'm really not sure if what I did is right. So like I said earlier, I'm really looking for some validation more or less. I'd also appreciate any pointers/tips/advice if you have any. Thanks!

Answer 1

It's possible that your early tests with commons-logging were showing zero bytes files because of bufferSize.

If your entries get flushed to the file when you stop Tomcat then this is indeed the case and you are falling foul of the default 8Kb buffer.

To disable, for immediate flushing try...

org.apache.juli.FileHandler.bufferSize = -1

on the specific handler...

So for localhost...

2localhost.org.apache.juli.FileHandler.bufferSize = -1

Answer 2

We also did various experiments and finally settled with slf4j option. Coming from Java background we knew slf4j, so we didn't go further.

<context-param>
   <param-name>jruby.rack.logging</param-name>
   <param-value>slf4j</param-value>
 </context-param>

btw, there is no need to copy slf4j-simple-1.6.1.jar into tomcat/lib or WEB-INF/lib when using slf4j-log4jxxx.jar