HDDS-376. Create custom message structure for use in AuditLogging

Contributed by Dinesh Chitlangia.

hadoop-hdds/common/src/main/java/org/apache/hadoop/ozone/audit/AuditLogger.java

@@ -21,10 +21,8 @@ import com.google.common.annotations.VisibleForTesting;
 import org.apache.logging.log4j.Level;
 import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Marker;
-import org.apache.logging.log4j.message.StructuredDataMessage;
 import org.apache.logging.log4j.spi.ExtendedLogger;
 
-import java.util.Map;
 
 /**
  * Class to define Audit Logger for Ozone.
@@ -32,16 +30,13 @@ import java.util.Map;
 public class AuditLogger {
 
   private ExtendedLogger logger;
-
-  private static final String SUCCESS = AuditEventStatus.SUCCESS.getStatus();
-  private static final String FAILURE = AuditEventStatus.FAILURE.getStatus();
   private static final String FQCN = AuditLogger.class.getName();
   private static final Marker WRITE_MARKER = AuditMarker.WRITE.getMarker();
   private static final Marker READ_MARKER = AuditMarker.READ.getMarker();
 
   /**
    * Parametrized Constructor to initialize logger.
-   * @param type
+   * @param type Audit Logger Type
    */
   public AuditLogger(AuditLoggerType type){
     initializeLogger(type);
@@ -60,68 +55,53 @@ public class AuditLogger {
     return logger;
   }
 
-  public void logWriteSuccess(AuditAction type, Map<String, String> data) {
-    logWriteSuccess(type, data, Level.INFO);
+  public void logWriteSuccess(AuditMessage msg) {
+    logWriteSuccess(Level.INFO, msg);
   }
 
-  public void logWriteSuccess(AuditAction type, Map<String, String> data, Level
-      level) {
-    StructuredDataMessage msg = new StructuredDataMessage("", SUCCESS,
-        type.getAction(), data);
+  public void logWriteSuccess(Level level, AuditMessage msg) {
     this.logger.logIfEnabled(FQCN, level, WRITE_MARKER, msg, null);
   }
 
-
-  public void logWriteFailure(AuditAction type, Map<String, String> data) {
-    logWriteFailure(type, data, Level.INFO, null);
+  public void logWriteFailure(AuditMessage msg) {
+    logWriteFailure(Level.ERROR, msg);
   }
 
-  public void logWriteFailure(AuditAction type, Map<String, String> data, Level
-      level) {
-    logWriteFailure(type, data, level, null);
+  public void logWriteFailure(Level level, AuditMessage msg) {
+    logWriteFailure(level, msg, null);
   }
 
-  public void logWriteFailure(AuditAction type, Map<String, String> data,
-      Throwable exception) {
-    logWriteFailure(type, data, Level.INFO, exception);
+  public void logWriteFailure(AuditMessage msg, Throwable exception) {
+    logWriteFailure(Level.ERROR, msg, exception);
   }
 
-  public void logWriteFailure(AuditAction type, Map<String, String> data, Level
-      level, Throwable exception) {
-    StructuredDataMessage msg = new StructuredDataMessage("", FAILURE,
-        type.getAction(), data);
+  public void logWriteFailure(Level level, AuditMessage msg,
+      Throwable exception) {
     this.logger.logIfEnabled(FQCN, level, WRITE_MARKER, msg, exception);
   }
 
-  public void logReadSuccess(AuditAction type, Map<String, String> data) {
-    logReadSuccess(type, data, Level.INFO);
+  public void logReadSuccess(AuditMessage msg) {
+    logReadSuccess(Level.INFO, msg);
   }
 
-  public void logReadSuccess(AuditAction type, Map<String, String> data, Level
-      level) {
-    StructuredDataMessage msg = new StructuredDataMessage("", SUCCESS,
-        type.getAction(), data);
+  public void logReadSuccess(Level level, AuditMessage msg) {
     this.logger.logIfEnabled(FQCN, level, READ_MARKER, msg, null);
   }
 
-  public void logReadFailure(AuditAction type, Map<String, String> data) {
-    logReadFailure(type, data, Level.INFO, null);
+  public void logReadFailure(AuditMessage msg) {
+    logReadFailure(Level.ERROR, msg);
   }
 
-  public void logReadFailure(AuditAction type, Map<String, String> data, Level
-      level) {
-    logReadFailure(type, data, level, null);
+  public void logReadFailure(Level level, AuditMessage msg) {
+    logReadFailure(level, msg, null);
   }
 
-  public void logReadFailure(AuditAction type, Map<String, String> data,
-      Throwable exception) {
-    logReadFailure(type, data, Level.INFO, exception);
+  public void logReadFailure(AuditMessage msg, Throwable exception) {
+    logReadFailure(Level.ERROR, msg, exception);
   }
 
-  public void logReadFailure(AuditAction type, Map<String, String> data, Level
-      level, Throwable exception) {
-    StructuredDataMessage msg = new StructuredDataMessage("", FAILURE,
-        type.getAction(), data);
+  public void logReadFailure(Level level, AuditMessage msg,
+      Throwable exception) {
     this.logger.logIfEnabled(FQCN, level, READ_MARKER, msg, exception);
   }
 

hadoop-hdds/common/src/main/java/org/apache/hadoop/ozone/audit/AuditMessage.java

@@ -0,0 +1,64 @@
+/**
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with this
+ * work for additional information regarding copyright ownership.  The ASF
+ * licenses this file to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ * <p>
+ * http://www.apache.org/licenses/LICENSE-2.0
+ * <p>
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,WITHOUT
+ * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+ * License for the specific language governing permissions and limitations under
+ * the License.
+ */
+package org.apache.hadoop.ozone.audit;
+
+import org.apache.logging.log4j.message.Message;
+
+import java.util.Map;
+
+/**
+ * Defines audit message structure.
+ */
+public class AuditMessage implements Message {
+
+  private String message;
+
+  public AuditMessage(String user, String ip, String op,
+      Map<String, String> params, String ret){
+
+    this.message = String.format("user=%s ip=%s op=%s %s ret=%s",
+                                  user, ip, op, params, ret);
+  }
+
+  @Override
+  public String getFormattedMessage() {
+    return message;
+  }
+
+  @Override
+  public String getFormat() {
+    return null;
+  }
+
+  @Override
+  public Object[] getParameters() {
+    return new Object[0];
+  }
+
+  @Override
+  public Throwable getThrowable() {
+    return null;
+  }
+
+  /**
+   * Use when there are custom string to be added to default msg.
+   * @param customMessage custom string
+   */
+  private void appendMessage(String customMessage) {
+    this.message += customMessage;
+  }
+}

hadoop-hdds/common/src/main/java/org/apache/hadoop/ozone/audit/package-info.java

@@ -46,7 +46,7 @@ package org.apache.hadoop.ozone.audit;
  * **** Auditable ***
  * This is an interface to mark an entity as auditable.
  * This interface must be implemented by entities requiring audit logging.
- * For example - KSMVolumeArgs, KSMBucketArgs.
+ * For example - OMVolumeArgs, OMBucketArgs.
  * The implementing class must override toAuditMap() to return an
  * instance of Map<Key, Value> where both Key and Value are String.
  *
@@ -81,6 +81,11 @@ package org.apache.hadoop.ozone.audit;
  * *** AuditMarker ***
  * Enum to define various Audit Markers used in AuditLogging.
  *
+ * *** AuditMessage ***
+ * Entity to define an audit message to be logged
+ * It will generate a message formatted as:
+ * user=xxx ip=xxx op=XXXX_XXXX {key=val, key1=val1..} ret=XXXXXX
+ *
  * ****************************************************************************
  *                              Usage
  * ****************************************************************************
@@ -88,14 +93,16 @@ package org.apache.hadoop.ozone.audit;
  * 1. Get a logger by specifying the appropriate logger type
  * Example: ExtendedLogger AUDIT = new AuditLogger(AuditLoggerType.OMLogger)
  *
- * 2. Log Read/Write and Success/Failure event as needed.
+ * 2. Construct an instance of AuditMessage
+ *
+ * 3. Log Read/Write and Success/Failure event as needed.
  * Example
- * AUDIT.logWriteSuccess(AuditAction type, Map<String, String> data, Level
- * level)
+ * AUDIT.logWriteSuccess(Level level, AuditMessage msg)
  *
  * If logging is done without specifying Level, then Level implicitly
- * defaults to INFO
- * AUDIT.logWriteSuccess(AuditAction type, Map<String, String> data)
+ * defaults to INFO for xxxxSuccess() and ERROR for xxxxFailure()
+ * AUDIT.logWriteSuccess(AuditMessage msg)
+ * AUDIT.logWriteFailure(AuditMessage msg)
  *
  * See sample invocations in src/test in the following class:
  * org.apache.hadoop.ozone.audit.TestOzoneAuditLogger

hadoop-hdds/common/src/test/java/org/apache/hadoop/ozone/audit/TestOzoneAuditLogger.java

@@ -28,6 +28,7 @@ import org.slf4j.LoggerFactory;
 import java.io.File;
 import java.io.IOException;
 import java.util.List;
+import java.util.Map;
 
 import static org.junit.Assert.assertTrue;
 
@@ -36,10 +37,29 @@ import static org.junit.Assert.assertTrue;
  */
 public class TestOzoneAuditLogger {
 
-  private static final Logger LOG = LoggerFactory.getLogger
-      (TestOzoneAuditLogger.class.getName());
-  private static AuditLogger AUDIT = new AuditLogger(AuditLoggerType.OMLOGGER);
-  public DummyEntity auditableObj = new DummyEntity();
+  private static final Logger LOG =
+      LoggerFactory.getLogger(TestOzoneAuditLogger.class.getName());
+
+  private static final AuditLogger AUDIT =
+      new AuditLogger(AuditLoggerType.OMLOGGER);
+
+  private static final String SUCCESS = AuditEventStatus.SUCCESS.name();
+  private static final String FAILURE = AuditEventStatus.FAILURE.name();
+
+  private static final Map<String, String> PARAMS =
+      new DummyEntity().toAuditMap();
+
+  private static final AuditMessage WRITE_FAIL_MSG = new AuditMessage("john",
+      "192.168.0.1", DummyAction.CREATE_VOLUME.name(), PARAMS, FAILURE);
+
+  private static final AuditMessage WRITE_SUCCESS_MSG = new AuditMessage("john",
+      "192.168.0.1", DummyAction.CREATE_VOLUME.name(), PARAMS, SUCCESS);
+
+  private static final AuditMessage READ_FAIL_MSG = new AuditMessage("john",
+      "192.168.0.1", DummyAction.READ_VOLUME.name(), PARAMS, FAILURE);
+
+  private static final AuditMessage READ_SUCCESS_MSG = new AuditMessage("john",
+      "192.168.0.1", DummyAction.READ_VOLUME.name(), PARAMS, SUCCESS);
 
   @BeforeClass
   public static void setUp(){
@@ -48,13 +68,13 @@ public class TestOzoneAuditLogger {
 
   @AfterClass
   public static void tearDown() {
-      File file = new File("audit.log");
-      if (FileUtils.deleteQuietly(file)) {
-        LOG.info(file.getName() +
-            " has been deleted as all tests have completed.");
-      } else {
-        LOG.info("audit.log could not be deleted.");
-      }
+    File file = new File("audit.log");
+    if (FileUtils.deleteQuietly(file)) {
+      LOG.info(file.getName() +
+          " has been deleted as all tests have completed.");
+    } else {
+      LOG.info("audit.log could not be deleted.");
+    }
   }
 
   /**
@@ -62,20 +82,31 @@ public class TestOzoneAuditLogger {
    */
   @Test
   public void logInfoWriteSuccess() throws IOException {
-    AUDIT.logWriteSuccess(DummyAction.CREATE_VOLUME, auditableObj.toAuditMap(), Level.INFO);
-    String expected = "[INFO ] OMAudit - CREATE_VOLUME [ key1=\"value1\" " +
-        "key2=\"value2\"] SUCCESS";
+    AUDIT.logWriteSuccess(Level.INFO, WRITE_SUCCESS_MSG);
+    String expected =
+        "[INFO ] OMAudit - " + WRITE_SUCCESS_MSG.getFormattedMessage();
+    verifyLog(expected);
+  }
+
+  /**
+   * Test to verify default log level is INFO when logging success events.
+   */
+  @Test
+  public void verifyDefaultLogLevelForSuccess() throws IOException {
+    AUDIT.logWriteSuccess(WRITE_SUCCESS_MSG);
+    String expected =
+        "[INFO ] OMAudit - " + WRITE_SUCCESS_MSG.getFormattedMessage();
     verifyLog(expected);
   }
 
   /**
-   * Test to verify default log level is INFO
+   * Test to verify default log level is ERROR when logging failure events.
    */
   @Test
-  public void verifyDefaultLogLevel() throws IOException {
-    AUDIT.logWriteSuccess(DummyAction.CREATE_VOLUME, auditableObj.toAuditMap());
-    String expected = "[INFO ] OMAudit - CREATE_VOLUME [ key1=\"value1\" " +
-        "key2=\"value2\"] SUCCESS";
+  public void verifyDefaultLogLevelForFailure() throws IOException {
+    AUDIT.logWriteFailure(WRITE_FAIL_MSG);
+    String expected =
+        "[ERROR] OMAudit - " + WRITE_FAIL_MSG.getFormattedMessage();
     verifyLog(expected);
   }
 
@@ -84,9 +115,9 @@ public class TestOzoneAuditLogger {
    */
   @Test
   public void logErrorWriteFailure() throws IOException {
-    AUDIT.logWriteFailure(DummyAction.CREATE_VOLUME, auditableObj.toAuditMap(), Level.ERROR);
-    String expected = "[ERROR] OMAudit - CREATE_VOLUME [ key1=\"value1\" " +
-        "key2=\"value2\"] FAILURE";
+    AUDIT.logWriteFailure(Level.ERROR, WRITE_FAIL_MSG);
+    String expected =
+        "[ERROR] OMAudit - " + WRITE_FAIL_MSG.getFormattedMessage();
     verifyLog(expected);
   }
 
@@ -95,11 +126,10 @@ public class TestOzoneAuditLogger {
    */
   @Test
   public void notLogReadEvents() throws IOException {
-    AUDIT.logReadSuccess(DummyAction.READ_VOLUME, auditableObj.toAuditMap(), Level.INFO);
-    AUDIT.logReadFailure(DummyAction.READ_VOLUME, auditableObj.toAuditMap(), Level.INFO);
-    AUDIT.logReadFailure(DummyAction.READ_VOLUME, auditableObj.toAuditMap(), Level.ERROR);
-    AUDIT.logReadFailure(DummyAction.READ_VOLUME, auditableObj.toAuditMap(), Level.ERROR,
-        new Exception("test"));
+    AUDIT.logReadSuccess(Level.INFO, READ_SUCCESS_MSG);
+    AUDIT.logReadFailure(Level.INFO, READ_FAIL_MSG);
+    AUDIT.logReadFailure(Level.ERROR, READ_FAIL_MSG);
+    AUDIT.logReadFailure(Level.ERROR, READ_FAIL_MSG, new Exception("test"));
     verifyNoLog();
   }
 
@@ -108,34 +138,34 @@ public class TestOzoneAuditLogger {
    */
   @Test
   public void notLogDebugEvents() throws IOException {
-    AUDIT.logWriteSuccess(DummyAction.CREATE_VOLUME, auditableObj.toAuditMap(), Level.DEBUG);
-    AUDIT.logReadSuccess(DummyAction.READ_VOLUME, auditableObj.toAuditMap(), Level.DEBUG);
+    AUDIT.logWriteSuccess(Level.DEBUG, WRITE_SUCCESS_MSG);
+    AUDIT.logReadSuccess(Level.DEBUG, READ_SUCCESS_MSG);
     verifyNoLog();
   }
 
   private void verifyLog(String expected) throws IOException {
     File file = new File("audit.log");
     List<String> lines = FileUtils.readLines(file, (String)null);
-      final int retry = 5;
-      int i = 0;
-      while (lines.isEmpty() && i < retry) {
-        lines = FileUtils.readLines(file, (String)null);
-        try {
-          Thread.sleep( 500 * (i + 1));
-        } catch(InterruptedException ie) {
-          Thread.currentThread().interrupt();
-          break;
-        }
-        i++;
+    final int retry = 5;
+    int i = 0;
+    while (lines.isEmpty() && i < retry) {
+      lines = FileUtils.readLines(file, (String)null);
+      try {
+        Thread.sleep(500 * (i + 1));
+      } catch(InterruptedException ie) {
+        Thread.currentThread().interrupt();
+        break;
       }
+      i++;
+    }
 
-      // When log entry is expected, the log file will contain one line and
-      // that must be equal to the expected string
-      assertTrue(lines.size() != 0);
-      assertTrue(expected.equalsIgnoreCase(lines.get(0)));
-      //empty the file
-      lines.remove(0);
-      FileUtils.writeLines(file, lines, false);
+    // When log entry is expected, the log file will contain one line and
+    // that must be equal to the expected string
+    assertTrue(lines.size() != 0);
+    assertTrue(expected.equalsIgnoreCase(lines.get(0)));
+    //empty the file
+    lines.remove(0);
+    FileUtils.writeLines(file, lines, false);
   }
 
   private void verifyNoLog() throws IOException {