Audit Trail using log4j

Audit trail is used in most of the applications to track the activities performed by a user (e.g. resources accessed or changes made within the system). Audit trails of applications are generally stored in the database; as they require filtering based on different attributes like userid, date/time, activity etc. and sometime the logs are required to generate reports.

Traditional approach with in java application for audit trailing is to use jdbc. This approach is not only cumbersome but has few pitfalls. E.g. the audit feature cannot be switched off unless the application has been designed to do so. Similarly; a product may require different level of audit logs depending upon the environment where it is being implemented. E.g. an application deployed for guest user may not require auditing at all but same application if installed in a high secured zone may require very fine level of auditing.

With traditional approach of using jdbc; application can audit logs only in database. The application may require logging the audit trails to multiple locations (e.g. to file system/ console) apart from database.  While maintenance; it may even be required to know from which class the audit message has been generated. Traditionally a log (using log4j or java logging api) is written before/after making jdbc call to record audit in database. But it is at the mercy of developer if has written such code while auditing each log.

 Since most of the features mentioned above comes inherent with logging APIs such as log4j. It would be a good idea to use such logging API itself for auditing as well.

This article would use log4j for logging audit trail and mysql as database for storing them.

Let’s first define the information we want our application to capture for auditing purpose. Say we want to maintain audit id, user id, timestamp, audit level, activity and activity detail in our audit. We would create our audit table in the database using following sql statement:

CREATE TABLE AUDIT(

    AUDIT_ID INT PRIMARY KEY AUTO_INCREMENT,

    USER_ID VARCHAR(50),

    TIMESTAMP TIMESTAMP,

    LEVEL   VARCHAR(5),

    ACTIVITY VARCHAR(50),

    ACTIVITY_DETAIL VARCHAR(1000)

 );

Since AUDIT_ID is a auto generated column and information regarding TIMESTAMP and LEVEL can be provided log4j; hence our code needs not to take these columns into account. We only need to consider how to pass application level information like userid, activity and activity detail to logger.

It would be a good idea to create a wrapper over Logger that can take care of passing all the application level information like userid, activity etc. to logger.

Let’s create a class that would encapsulate logger and would act our one stop point for auditing.

package myapplication.audit;

import org.apache.log4j.Level;

import org.apache.log4j.Logger;

import org.apache.log4j.MDC;

public class AuditLogger {

      public static void debug (String userid, String activity,

String activityDetail) {

   …

}    

public static void info (String userid, String activity,

…

String activityDetail) {

               …

}

You may create other methods for different log levels. In case mutilple log levels are not required in your application; you may create single method with name audit.

We are going to use two features of Log4J: MDC and FQCN. Mapped diagnostic context (MDC) would be used to add additional information like user id and activity to the logs.

package myapplication.audit;

import org.apache.log4j.Level;

import org.apache.log4j.Logger;

import org.apache.log4j.MDC;

public class AuditLogger {

      

       private static String FQCN =  "myapplication.audit.AuditLogger";

      

       public static void info (String userid, String activity, String activityDetail) {

              MDC.put("userid", userid);

              MDC.put("activity", activity);

              Logger.getLogger(AuditLogger.class.getName()).log(FQCN, Level.INFO,  activityDetail, null);

              MDC.clear();

       }

       …

…

}

Please note we have shown a method with the name info() which logs audit trail with level INFO. We can have additional methods with others log levels as well.

Additional information like userid and activity has been passed by application to the logger using MDC. Once the information has been audited; the information has been later on cleared using clear() method of MDC.

We have configured JDBCAppender and configured database information along with SQL statement to insert audit trail in the database. Please note JDBCAppender doesn’t require PatternLayout.

xml version="1.0" encoding="UTF-8"?>

DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

       <appender name="FILE" class="org.apache.log4j.RollingFileAppender">

              <param name="File" value="logs/audit.log">param>

              <param name="Append" value="true">param>

              <layout class="org.apache.log4j.PatternLayout">

                     <param name="ConversionPattern"

                           value="%d %-5p [%t] %C{3} (%F:%L) - %m%n">param>

              layout>

       appender>

      

       <appender name="DB" class="org.apache.log4j.jdbc.JDBCAppender">

              <param name="URL" value="jdbc:mysql://localhost/auditschema"/>

              <param name="driver" value="com.mysql.jdbc.Driver"/>

              <param name="user" value="root"/>

              <param name="password" value="admin"/>

              <param name="sql" value="INSERT INTO AUDIT(USER_ID, TIMESTAMP, LEVEL, ACTIVITY, ACTIVITY_DETAIL) VALUES('%X{userid}','%d{yyyy-MM-dd HH:mm:ss.SSS}','%p', '%X{activity}', '%m')"/>

      

       appender>

       <appender name="NULL" class="org.apache.log4j.varia.NullAppender">appender>

      

       <category  name="myapplication.audit">

              <priority value="DEBUG">priority>

              <appender-ref ref="FILE">appender-ref>

              <appender-ref ref="DB">appender-ref>

       category>

       <category  name="myapplication.test">

              <priority value="DEBUG">priority>

              <appender-ref ref="FILE">appender-ref>

       category>

      

       <root>

              <priority value="off">priority>

              <appender-ref ref="NULL">appender-ref>

       root>

      

log4j:configuration>

Please note we have defined separate category for audit “myapplication.audit” within log4j configuration. Further all the loggers have been created using “AuditLogger.class.getName()” e.g. Logger.getLogger(AuditLogger.class.getName()) where the value of AuditLogger.class.getName() is “myapplication.audit.AuditLogger”. Configuring a category with “myapplication.audit” would allow switching off audit logs if required.

Create a program to test auditing.

package myapplication.test;

import myapplication.audit.AuditLogger;

import org.apache.log4j.Logger;

public class TestAudit {

   public static void main (String args[]) {

         Logger.getLogger(TestAudit.class).debug("Before audit");

         AuditLogger.info("ashutosh","accesed", "User edit page");

         Logger.getLogger(TestAudit.class).debug("after audit");

   }

}

Compile it and execute it. Below is the output from mysql on querying audit table.

mysql> select * from audit;

Below are the logs shown from file after compiling and running the program.

2012-01-12 16:04:21,538 DEBUG [main] myapplication.test.TestAudit (TestAudit.java:10) - Before audit

2012-01-12 16:04:21,541 INFO  [main] myapplication.test.TestAudit (TestAudit.java:11) - User edit page

2012-01-12 16:04:21,767 DEBUG [main] myapplication.test.TestAudit (TestAudit.java:12) - after audit

Please note the output for both application log and audit has been redirected to file. This way you can easily track application logs and audit from same place.  We can also see the value of caller issuing the logging request is “myapplication.test.TestAudit” instead of “myapplication.audit.AuditLogger”; it has been achieved by using FQCN.

Logger.getLogger(AuditLogger.class.getName()).log(FQCN, Level.INFO,  activityDetail, null);

This method allows logging messages from a wrapper class.