Logging in java Part-2

In the Part-1 I discussed about different logging frameworks in java. In this part I'll discuss about setting up slf4j and logback in your project.

Maven dependencies:
slf4j-api: Contains interfaces for LoggerFactoryBinder, MDCAdaptor and MarkerFactoryBinder which will be implemented by any slf4j compatible logger service like logback. slf4j-api also contains implementation of some features which actual logging framework might not have like MDC.
logback-core: It contains classes and utilities with default and abstract level implementation which is used in logback-classic.
logback-classic: Implementation of slf4j-api, logback-core and logback-classic can be used without slf4j-api in a project just like log4j.
jcl-over-slf4j: Implementation of commons-logging to forward logging statements written with commons-logging into slf4j logging.
log4j-over-slf4j: Minimal implementation of log4j to forward logging statements written with log4j into slf4j logging.
jul-to-slf4j: Provides a SLF4J BridgeHandler which will redirect all JUL log records to the SLF4J API based logging.

   org.slf4j
   slf4j-api
   1.7.6
  

  ch.qos.logback
  logback-core
  1.1.1
 

  ch.qos.logback
  logback-classic
  1.1.1
 
 

   org.slf4j
   log4j-over-slf4j
   1.7.6
  

   org.slf4j
   jcl-over-slf4j
   1.7.6
  

   org.slf4j
   jul-to-slf4j
   1.7.6
  

   javax.mail
   mail
   1.4
  

In this blog I'll discuss about advanced options like MDC backed per customer logging in a web environment, per customer custom logging level control and email appender. logback.xml starts with configuration tag where you can define if automatic scanning of logback.xml is enabled you can also control scanning period. If debug="true" is specified then logback will also log its initialization steps, it is good practice to make it true always because it helps in detecting logback initialization problem quickly.

Per user log generation:
I am assuming that per user log generation is done in a web environment. To achieve this you must create an MDC entry containing user_email (or any unique identifier) for each request and remove it after completion of request. You must be keeping user email in session till user is logged in. Below is the definition of "PERUSER_LOGGING_APPENDER" which creates logging files like ../user_email/app.log.

    
      user_email
      unknown-user
    
    
      
  
   ${log.directory.name}/${user_email}/app.log
    
    
        ${log.directory.name}/${user_email}/app-%d{yyyy-MM-dd}.log
       
    
           
          %date{dd-MMM-yyyy HH:mm:ss.SSS} [%thread] %-5level %c %method - %msg%n %ex
       
  
    
  

SMTP Appender:
Logback provides SMTP appender which is used to send logs on email. This appender is configured with a Marker "SEND_EMAIL" also all logging events with logging level less than WARNING are discarded by this appender.

 
  
    
        
          WARN
        
     
     
     
            SEND_EMAIL
            ACCEPT
            DENY
        
        
            SEND_EMAIL
        
  
        
     
     
     true
     toaddress1@gmail.com
     toaddress2@gmail.com 
     fromaddress1@gmail.com
        ERROR : %X{host_name} %logger
        
        
          %date{dd-MMM-yyyy HH:mm:ss.SSS} %X{user_email} [%thread] %-5level %c %method - %n%msg%n%ex
        
        
       
      1
     
    

logger.error("SEND_EMAIL", "Exception in processing request.", e);

Marker class:

package com.changingtechblog.example;

import org.slf4j.Marker;
import org.slf4j.MarkerFactory;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.filter.AbstractMatcherFilter;
import ch.qos.logback.core.spi.FilterReply;

/**
 * Used to filter marked logging statement.
 * 
 *  <filter class="com.changingtechblog.example.MarkerFilter">
 *      <marker>MarkerName</marker>
 *      <onMatch>ACCEPT</onMatch>
 *      <onMismatch>DENY</onMismatch>
 *  </filter>
 *  <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator">
 *      <marker>MarkerName</marker>
 *  </evaluator>
 * 
* 
 * @author Mukesh Kumar
 */
public class MarkerFilter extends AbstractMatcherFilter<ILoggingEvent> {

 private Marker markerToMatch;

 @Override
 public void start() {
      if (this.markerToMatch != null) {
           super.start();
      } 
      else {
           addError(String.format("The marker property must be set for [%s]", getName()));
      }
 }
 
 @Override
 public FilterReply decide(ILoggingEvent event) {
  Marker marker = event.getMarker();
      if (!isStarted()) {
           return FilterReply.NEUTRAL;
      }

      if (marker == null) {
           return onMismatch;
      }

      if (markerToMatch.contains(marker)) {
           return onMatch;
      }
      return onMismatch;
 }
 
 public void setMarker(String markerStr) {
      if (markerStr != null) {
           markerToMatch = MarkerFactory.getMarker(markerStr);
      }
 }
}

Per customer logging control:

  
     user_email 
     mukesh.kumar120in@gmail.com 
     DEBUG
     ACCEPT
  

MDCMatchingFilter:

package com.changingtechblog.example;

import org.slf4j.MDC;
import org.slf4j.Marker;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.turbo.MatchingFilter;
import ch.qos.logback.core.spi.FilterReply;


/**
 * Filter used to modify logger level for a particular mdc value at runtime.
 * It can be configured in logback.xml as:
 * 
 * <turboFilter class="com.changingtechblog.example.MDCMatchingFilter">
 *    <mdcKey>user_email</mdcKey> 
 *    <values>mukesh.kumar120in@gmail.com</values> 
 *    <OnMatch>ACCEPT</OnMatch>
 *      <logLevel>DEBUG</logLevel>
 * </turboFilter>
 * 
* 
 * You can even specify multiple values of user_email as comma separated. 
 *
 * @author Mukesh Kumar
 */
public class MDCMatchingFilter extends MatchingFilter {
 
 public static final String LOGGING_APPENDER_KEY = "user_email";
 public static final String HOSTNAME_KEY = "host_name";

 String mdcKey;
 String values;
 String logLevel;

 @Override
 public FilterReply decide(Marker marker, Logger logger, Level level, String format, 
               Object[] params, Throwable t) {
  
  if (!isStarted()) {
        return FilterReply.NEUTRAL;
  }
  
  if (mdcKey == null || values == null) {
   return FilterReply.NEUTRAL;
  }

  String value = MDC.get(mdcKey);
  if(value == null) {
   return FilterReply.NEUTRAL;
  }
  
  if(values != null && !values.trim().equals("")) {
   String[] emails = values.trim().split("[,]");
   for(String email : emails) {
    if (value.contains(email.trim().toLowerCase())) {
     if (level.isGreaterOrEqual(Level.valueOf(logLevel))) {
      return onMatch;
     } 
     else {
      return FilterReply.DENY;
     }
    }
   }
  }
  return onMismatch;
 }

 public void setMdcKey(String mdcKey) {
  this.mdcKey = mdcKey;
 }

 public void setValues(String values) {
  this.values = values;
 }

 public void setLogLevel(String logLevel) {
  if(logLevel != null) {
   this.logLevel = logLevel.trim();
  }
  else {
   this.logLevel = "DEBUG";
  }
 }
 
 @Override
 public void start() {
  if (mdcKey != null && values != null) {
   String value = MDC.get(mdcKey);
   if(value != null) {
    super.start();
   }
  }
 }
}

Finally you will have to define root logger

Slf4j has support for all other popular logging frameworks. Most of the libraries are already using slf4j for logging but in case if your project is using multiple logging libraries and if you can move to slf4j based logging then you have to remove all those logging libraries(like log4j.jar, apache-commons.jar) and put slf4j based libraries which are listed at the start of this article. Below is an example illustrating use of multiple types of logging methods in a slf4j based setup.

package com.changingtechblog.example;

import org.apache.commons.logging.Log;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

public class LogbackLogger {

 private static final Logger logbackLogger = LoggerFactory
   .getLogger(LogbackLogger.class);
 private static final org.apache.log4j.Logger log4jLogger = org.apache.log4j.Logger
   .getLogger(LogbackLogger.class);
 private static final Log jclLogger = org.apache.commons.logging.LogFactory
   .getLog(LogbackLogger.class);
 private static final java.util.logging.Logger julLogger = java.util.logging.Logger
   .getLogger("com.changingtechblog.example.LogbackLogger");

 public static void main(String[] args) {
  logbackLogger.info("Logback logging");
  log4jLogger.info("Log4j logging");
  jclLogger.info("JCL logging");
  julLogger.info("JUL logging");
 }
}

Output:
2014-02-12 13:44:53,632 13:44:53.632 [main] INFO c.c.example.LogbackLogger - Logback logging
2014-02-12 13:44:53,633 13:44:53.633 [main] INFO c.c.example.LogbackLogger - Log4j logging
2014-02-12 13:44:53,633 13:44:53.633 [main] INFO c.c.example.LogbackLogger - JCL logging
12 Feb, 2014 1:44:53 PM com.changingtechblog.example.LogbackLogger main INFO: JUL logging