Structured audit logging

x-pack/plugin/core/src/main/config/log4j2.properties

@@ -1,9 +1,36 @@
 appender.audit_rolling.type = RollingFile
 appender.audit_rolling.name = audit_rolling
-appender.audit_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_access.log
+appender.audit_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_audit.log
 appender.audit_rolling.layout.type = PatternLayout
-appender.audit_rolling.layout.pattern = [%d{ISO8601}] %m%n
-appender.audit_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_access-%d{yyyy-MM-dd}.log
+appender.audit_rolling.layout.pattern = {\
+                "@timestamp":"%d{ISO8601}"\
+                %varsNotEmpty{, "node.name":"%enc{%map{node.name}}{JSON}"}\
+                %varsNotEmpty{, "host.name":"%enc{%map{host.name}}{JSON}"}\
+                %varsNotEmpty{, "host.ip":"%enc{%map{host.ip}}{JSON}"}\
+                %varsNotEmpty{, "event.type":"%enc{%map{event.type}}{JSON}"}\
+                %varsNotEmpty{, "event.action":"%enc{%map{event.action}}{JSON}"}\
+                %varsNotEmpty{, "user.name":"%enc{%map{user.name}}{JSON}"}\
+                %varsNotEmpty{, "user.run_by.name":"%enc{%map{user.run_by.name}}{JSON}"}\
+                %varsNotEmpty{, "user.run_as.name":"%enc{%map{user.run_as.name}}{JSON}"}\
+                %varsNotEmpty{, "user.realm":"%enc{%map{user.realm}}{JSON}"}\
+                %varsNotEmpty{, "user.run_by.realm":"%enc{%map{user.run_by.realm}}{JSON}"}\
+                %varsNotEmpty{, "user.run_as.realm":"%enc{%map{user.run_as.realm}}{JSON}"}\
+                %varsNotEmpty{, "user.roles":%map{user.roles}}\
+                %varsNotEmpty{, "origin.type":"%enc{%map{origin.type}}{JSON}"}\
+                %varsNotEmpty{, "origin.address":"%enc{%map{origin.address}}{JSON}"}\
+                %varsNotEmpty{, "realm":"%enc{%map{realm}}{JSON}"}\
+                %varsNotEmpty{, "url.path":"%enc{%map{url.path}}{JSON}"}\
+                %varsNotEmpty{, "url.query":"%enc{%map{url.query}}{JSON}"}\
+                %varsNotEmpty{, "request.body":"%enc{%map{request.body}}{JSON}"}\
+                %varsNotEmpty{, "action":"%enc{%map{action}}{JSON}"}\
+                %varsNotEmpty{, "request.name":"%enc{%map{request.name}}{JSON}"}\
+                %varsNotEmpty{, "indices":%map{indices}}\
+                %varsNotEmpty{, "opaque_id":"%enc{%map{opaque_id}}{JSON}"}\
+                %varsNotEmpty{, "transport.profile":"%enc{%map{transport.profile}}{JSON}"}\
+                %varsNotEmpty{, "rule":"%enc{%map{rule}}{JSON}"}\
+                %varsNotEmpty{, "event.category":"%enc{%map{event.category}}{JSON}"}\
+                }%n
+appender.audit_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_audit-%d{yyyy-MM-dd}.log
 appender.audit_rolling.policies.type = Policies
 appender.audit_rolling.policies.time.type = TimeBasedTriggeringPolicy
 appender.audit_rolling.policies.time.interval = 1

x-pack/plugin/core/src/test/java/org/elasticsearch/xpack/core/security/audit/logfile/CapturingLogger.java

@@ -10,10 +10,12 @@
 import org.apache.logging.log4j.Logger;
 import org.apache.logging.log4j.core.LogEvent;
 import org.apache.logging.log4j.core.LoggerContext;
+import org.apache.logging.log4j.core.StringLayout;
 import org.apache.logging.log4j.core.appender.AbstractAppender;
 import org.apache.logging.log4j.core.config.Configuration;
 import org.apache.logging.log4j.core.config.LoggerConfig;
 import org.apache.logging.log4j.core.filter.RegexFilter;
+import org.elasticsearch.common.Nullable;
 import org.elasticsearch.common.logging.ESLoggerFactory;
 import org.elasticsearch.common.logging.Loggers;
 
@@ -22,12 +24,13 @@
 
 public class CapturingLogger {
 
-    public static Logger newCapturingLogger(final Level level) throws IllegalAccessException {
+    public static Logger newCapturingLogger(final Level level, @Nullable StringLayout layout) throws IllegalAccessException {
+        // careful, don't "bury" this on the call stack, unless you know what you're doing
         final StackTraceElement caller = Thread.currentThread().getStackTrace()[2];
         final String name = caller.getClassName() + "." + caller.getMethodName() + "." + level.toString();
         final Logger logger = ESLoggerFactory.getLogger(name);
         Loggers.setLevel(logger, level);
-        final MockAppender appender = new MockAppender(name);
+        final MockAppender appender = new MockAppender(name, layout);
         appender.start();
         Loggers.addAppender(logger, appender);
         return logger;
@@ -58,8 +61,8 @@ private static class MockAppender extends AbstractAppender {
         public final List<String> debug = new ArrayList<>();
         public final List<String> trace = new ArrayList<>();
 
-        private MockAppender(final String name) throws IllegalAccessException {
-            super(name, RegexFilter.createFilter(".*(\n.*)*", new String[0], false, null, null), null);
+        private MockAppender(final String name, StringLayout layout) throws IllegalAccessException {
+            super(name, RegexFilter.createFilter(".*(\n.*)*", new String[0], false, null, null), layout);
         }
 
         @Override
@@ -68,25 +71,33 @@ public void append(LogEvent event) {
                 // we can not keep a reference to the event here because Log4j is using a thread
                 // local instance under the hood
                 case "ERROR":
-                    error.add(event.getMessage().getFormattedMessage());
+                    error.add(formatMessage(event));
                     break;
                 case "WARN":
-                    warn.add(event.getMessage().getFormattedMessage());
+                    warn.add(formatMessage(event));
                     break;
                 case "INFO":
-                    info.add(event.getMessage().getFormattedMessage());
+                    info.add(formatMessage(event));
                     break;
                 case "DEBUG":
-                    debug.add(event.getMessage().getFormattedMessage());
+                    debug.add(formatMessage(event));
                     break;
                 case "TRACE":
-                    trace.add(event.getMessage().getFormattedMessage());
+                    trace.add(formatMessage(event));
                     break;
                 default:
                     throw invalidLevelException(event.getLevel());
             }
         }
 
+        private String formatMessage(LogEvent event) {
+            if (getLayout() != null) {
+                return ((StringLayout) getLayout()).toSerializable(event);
+            } else {
+                return event.getMessage().getFormattedMessage();
+            }
+        }
+
         private IllegalArgumentException invalidLevelException(Level level) {
             return new IllegalArgumentException("invalid level, expected [ERROR|WARN|INFO|DEBUG|TRACE] but was [" + level + "]");
         }