Sunday, November 22, 2009

Working Around JSVC's Logging Limitations

JSVC is a popular option for people using Tomcat as their web container. The main advantage of JSVC is that it allows downgrading the user running a process (since most Linux systems require the root user to open a port below 1024), and also acts as a watchdog to restart the JVM if it crashes. However one big problem with JSVC is that it can only write the output of the JVM it's hosting to two files on the filesystem corresponding to stdout and stderr. This is problematic since it doesn't allow for log rotation or any other form of redirection.

At Kikini, we created a logging solution to append log statements into SimpleDB so that logs from all our machines end up in a central location, unbounded by normal filesystem limits, and easily query-able against and monitored, allowing us to react quickly to diagnose problems. The simplest way to use our logger is to redirect the output from the target process to the stdin of our logging process. However JVSC makes this rather difficult since it is hard-coded to only write to files on the filesystem.

Fortunately we have a trick up our sleeve in the form of UNIX named pipes, which can use as a target for JSVC to write to and a source for the logger to read from:
mkfifo pipe.out
mkfifo pipe.err
/usr/bin/startlogger.sh STDOUT < pipe.out
/usr/bin/startlogger.sh STDERR < pipe.err
/usr/bin/jsvc -outfile pipe.out -errfile pipe.err ...
Now JSVC will start up, and write into the pipes we created, which will be redirected into the mylogger processes.

4 comments:

  1. Good ol' named pipes. Have you seen any issues with this? I'm not familiar enough with jsvc to know its threading profile but would your implementation of hard-coding the pipe names still work in a multithreaded scenario? I ask because I had problems with that once.

    Also, have you looked at log4j?

    ReplyDelete
  2. Been running for a few months, admittedly without high volume, but haven't seen any problem. I don't think threads come into play here, jsvc is a native app which forks a java process to host Tomcat, and internally redirects stdout/stderr of the java process to the output files specified in the command.

    For our components we're using slf4j, which is an abstraction above log4j. We use logback as our implementation, which is extremely flexible, and in fact my SimpleDB logger is implemented as a logback appender.

    I guess where you're going is: why not use Tomcat's internal logging mechanism to specify that we want the output to go to a file, log rotator, custom SimpleDB logger, etc? This is certainly possible, as Tomcat does use log4j, and instructions on how to leverage this are available. But as the documentation itself admits, a bit of voodoo is needed. Ultimately though that is the best solution and what I plan to do once I have the time :)

    ReplyDelete
  3. what does startlogger.sh do? Its not on my centos 5.4 system

    ReplyDelete
  4. startlogger.sh is meant as an example. It would be a process that reads from stdin and writes to a logging system. In my case this is a custom script that loads my SimpleDB logger.

    ReplyDelete