Tuesday, December 15, 2009

Using a Syslog appender in log4j

The log4j framework has several appenders and one of them is the SyslogAppender. This appender lets you append log messages to syslog, a popular logging service on Unix and Linux. To use this appender, just add this to your log4j.xml configuration file:
<appender name="syslog" class="org.apache.log4j.net.SyslogAppender">
  <param name="Facility" value="USER"/>
  <param name="SyslogHost" value="localhost"/>
  <param name="Threshold" value="WARN"/>
  <layout class="org.apache.log4j.PatternLayout">
    <param name="ConversionPattern" value="%d{MMM dd HH:mm:ss} MYAPP: %-5p %m%n"/>
  </layout>
</appender>
You can use the usual log4j API to log messages:
public class AppWithStandardLogger {
  private static final Logger logger = Logger.getLogger(AppWithStandardLogger.class);

  public void someMethod() {
    try {
       // ...
    } catch (ConnectionException e) {
       logger.fatal("#Failed to connect to database", e);
    }
  }
}

Severity level mapping

If you use logger.fatal(), the standard log4j syslog appender will log this message with the highest syslog severity, which is level 0, "emerg". This level is usually reserved for the most urgent operating system related messages and on most Unix systems will print the message on the terminal session of every logged in user. For most applications, this is probably not what you want. If an application encounters a fatal error, it should log the message as a lower level like "critical", level 2. You can do this by implementing an appender which overrides the "append" method:
import org.apache.log4j.Level;
import org.apache.log4j.spi.LoggingEvent;

/**
 * Appender that fixes level mapping to syslog.
 */
public class SyslogAppender extends org.apache.log4j.net.SyslogAppender {
 @Override
 public void append(LoggingEvent event) {
  Level log4jLevel = event.getLevel();
  Level newLevel = null;
  if (log4jLevel.equals(Level.FATAL)) {
   newLevel = SyslogLevel.FATAL;
  } else {
   newLevel = event.getLevel();
  }
  LoggingEvent newLoggingEvent = new LoggingEvent(
    event.getFQNOfLoggerClass(), event.getLogger(), event.getTimeStamp(), newLevel,
    event.getMessage(), event.getThreadName(), event.getThrowableInformation(),
    event.getNDC(), event.getLocationInformation(), event.getProperties());
  super.append(newLoggingEvent);
 }

 /**
  * Fix for level mapping - log4j "fatal" is mapped to syslog "critical".
  */
 public static class SyslogLevel extends Level {
  private static final long serialVersionUID = 1L;
  public static final Level FATAL = new SyslogLevel(FATAL_INT, "FATAL", 2);
  
  protected SyslogLevel(int level, String levelStr, int syslogEquivalent) {
   super(level, levelStr, syslogEquivalent);
  }
 }
}
This custom appender will map the log4j "fatal" messages to syslog "critical" (level 2) severity.

Stack traces

With log4j you can also log the stack trace when you pass the exception as extra parameter. In my work the syslog system will pass the messages through to Tivoli and this monitoring system should not receive stack traces. With a custom log4j PatternLayout, we can filter out stack traces by overriding the ignoresThrowable() method:
import org.apache.log4j.PatternLayout;

/**
 * Layout that prevents stack traces to be logged.
 */
public class NoStackTracePatternLayout extends PatternLayout {
 @Override
 public boolean ignoresThrowable() {
  return false;
 }
}

Putting it together

To use both the custom Appender and Layout, use this configuration:
    <appender name="syslog" class="net.kazed.log4j.SyslogAppender">
     <param name="Facility" value="USER"/>
     <param name="SyslogHost" value="localhost"/>
     <param name="Threshold" value="WARN"/>
     <layout class="net.kazed.log4j.NoStackTracePatternLayout">
       <param name="ConversionPattern" value="%d{MMM dd HH:mm:ss} MYAPP: %-5p %m%n"/>
     </layout>
    </appender>
The code is unchanged, we only changed the configuration.

Using a named syslog logger

If you want to have control over what and how the application logs to the log file and syslog, you could configure a separate logger with a name:
    <logger name="monitoring">
      <level value="WARN" />
      <appender-ref ref="syslog" />
    </logger>
In the code, you refer to the "monitoring" logger and you can log a different message to the monitoring system:
public class AppWithNamedLogger {
 private static final Logger logger = Logger.getLogger(AppWithNamedLogger.class);
 private static final Logger monitorLogger = Logger.getLogger("monitoring");
 
    public void someMethod() {
     try {
   throw new ConnectionException();
   // ...
  } catch (ConnectionException e) {
   logger.fatal("Failed to connect to database", e);
   monitorLogger.error("Failure to connect to database");
  }
 }
}
As you can see, we must change the code and add a second logger and use this to log explicitly to the monitoring system.

Conclusion

When logging to a monitoring system you can avoid changes to the source code by changing the configuration and add the monitoring logger. The standard syslog appender implementation maps the log4j fatal to syslog emerg, which level is too high for most Unix/Linux installations. A custom appender can fix this mapping. To avoid logging stack traces, you can implement custom Layout. With a named logger you can log special messages explicitly to the monitoring system. This requires changing the code.