Backport Structured Audit Logging #33894

albertzaharovits · 2018-09-20T11:51:37Z

This is the backport of #31931 .

Following the conclusion on #31046 (comment) , this backport resurrects the previous logging format, such that both are enabled side by side for the 6.x releases. This is achieved by adding another appender with it's own pattern layout in the log4j configuration. This pattern layout "emulates" the previous format. Codewise, the same log4j StringMapMessage event is used to generate the log lines in both formats. There are truly no guarantees that the "emulated" format is 100% the old one (besides my 🦅 eyes).

Unit tests check both layouts by parsing the log4j2.properties file as a resource. There are some qa integ tests in the sql projects that parse the audit log when security is enabled. Those only parse the new format.

This commit 1ca9d19 adds the "emulated" format (the other commit is the backport).

Changes the format of log events in the audit logfile. It also changes the filename suffix from `_access` to `_audit`. The new entry format is consistent with Elastic Common Schema. Entries are formatted as JSON with no nested objects and field names have a dotted syntax. Moreover, log entries themselves are not spaced by commas and there is exactly one entry per line. In addition, entry fields are ordered, unlike a typical JSON doc, such that a human would not strain his eyes over jumbled fields from one line to the other; the order is defined in the log4j2 properties file. The implementation utilizes the log4j2's `StringMapMessage`. This means that the application builds the log event as a map and the log4j logic (the appender's layout) handle the format internally. The layout, such as the set of printed fields and their order, can be changed at runtime without restarting the node.

elasticmachine · 2018-09-20T11:51:38Z

Pinging @elastic/es-security

albertzaharovits · 2018-09-20T13:26:30Z

.../core/src/test/java/org/elasticsearch/xpack/core/security/audit/logfile/CapturingLogger.java

-        final MockAppender appender = new MockAppender(name);
+        attachNewMockAppender(logger, IMPLICIT_APPENDER_NAME, layout);
+        return logger;
+    }


The CapturingLogger can optionally have several appenders. By default it has only one named __implicit.

albertzaharovits · 2018-09-20T13:27:03Z

.../core/src/test/java/org/elasticsearch/xpack/core/security/audit/logfile/CapturingLogger.java

+            }
+        }
+        return true;
+    }


Is empty can optionally check multiple appenders.

.../core/src/test/java/org/elasticsearch/xpack/core/security/audit/logfile/CapturingLogger.java

bizybot · 2018-09-26T10:47:10Z

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

@@ -1,9 +1,101 @@
+appender.deprecated_audit_rolling.type = RollingFile
+appender.deprecated_audit_rolling.name = deprecated_audit_rolling
+appender.deprecated_audit_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_access.log


Does this mean that when customers upgrade to say 6.5 version, they will have two logs being populated:
*_access.log and *_audit.log at the same time? Depending on whether the customer has done right steps to get away from old logging, it might result into two logs being populated (unknowingly constraining the system).
I think it would be better to keep old one enabled and the new one disabled and let customers go and move from the old appender to new appender.

@bizybot See the discussion starting here #31046 (comment)

Basically, Filebeat has to support whatever format we're defaulting too. So if we're not enabling the new appender in 6.x Filebeat will not use this in 6.x, so we might as well not port this to 6.x because Filebeat is the important reason we do this (sort of, the root reason is to get rid of the IndexAuditTrail, but we need Filebeat to consume or logs before we can do that).

And since we ❤️ our users, we don't want to break any systems they have set up right now that are consuming the present format. So, the compromise is to enable both of them.

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

jaymode · 2018-10-01T03:11:30Z

There are truly no guarantees that the "emulated" format is 100% the old one (besides my 🦅 eyes).

I am having a hard time with this. I think we should put in more effort here to validate or keep the existing way as is; I think we can accomplish this by having a special logger for the legacy format. This allows us to keep the pre-existing log statements alongside the new map format that uses a different logger. What do you think?

albertzaharovits · 2018-10-01T15:52:32Z

I think we can accomplish this by having a special logger for the legacy format.

@jaymode I am thinking of cherrie-picking the old LoggingAuditTrail, rename it, and then enabling it when logfile output is on. This is the only way, in my opinion, to guarantee that the legacy format is 100% identical. Copy pasting the message building logic alongside the new StringMapMessage building is no better than what I am proposing herein.
I remember previously considering this, but don't remember the conclusion (probably something about the tests), I will give it a try, though.

jaymode · 2018-10-01T17:47:34Z

I am good with that approach @albertzaharovits.

This reverts commit 1ca9d19.

albertzaharovits · 2018-10-05T08:48:47Z

@jaymode I have reverted the "emulated" format logic and cherry-picked LoggingAuditTrail and LoggingAuditTrailTests from 6.x and renamed them DeprecatedLoggingAuditTrail and DeprecatedLoggingAuditTrailTests respectively.
The DeprecatedLoggingAuditTrail had all it's settings, as well as EventFilterPolicyRegistry, EventFilterPolicy and AuditEventMetaInfo static inner classes removed, as it is using the ones from the LoggingAuditTrail.

albertzaharovits · 2018-10-05T09:14:27Z

@bizybot @jaymode this is ready for another round. Would you please take another look?

albertzaharovits · 2018-10-15T15:48:55Z

test this please

albertzaharovits · 2018-10-15T16:26:37Z

Task :qa:vagrant:vagrantUbuntu1404#up FAILED ~~run gradle build tests~~ run sample packaging tests

albertzaharovits · 2018-10-15T16:27:35Z

run sample packaging tests

albertzaharovits · 2018-10-15T17:05:22Z

org.gradle.launcher.daemon.client.DaemonDisappearedException: Gradle build daemon disappeared unexpectedly (it may have been killed or may have crashed) run gradle build tests

albertzaharovits · 2018-10-15T17:40:21Z

https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+pull-request/1647/consoleFull
Failed with:

...
17:22:43     Caused by: java.io.FileNotFoundException: /tmp/.gradle-test-kit-jenkins/caches/4.10/scripts-remapped/build_5ja2t0gai22z6i9he69emifxd/bierx9xgpipif9vv3my944rer/cp_proj525a2f1efef12369079491b50deb9f6c/metadata/metadata.bin (No such file or directory)
17:22:43     	at org.gradle.groovy.scripts.internal.DefaultScriptCompilationHandler.loadFromDir(DefaultScriptCompilationHandler.java:209)
17:22:43     	... 106 more
...
17:22:43     > Configure project :
17:22:43     Evaluating root project 'elasticsearch-build-resources' using build file '/var/lib/jenkins/workspace/elastic+elasticsearch+pull-request/buildSrc/src/testKit/elasticsearch-build-resources/build.gradle'.
17:22:43 
17:22:43     FAILURE: Build failed with an exception.
17:22:43 
17:22:43     * What went wrong:
17:22:43     A problem occurred configuring root project 'elasticsearch-build-resources'.
17:22:43     > Failed to deserialize script metadata extracted for build file '/var/lib/jenkins/workspace/elastic+elasticsearch+pull-request/buildSrc/src/testKit/elasticsearch-build-resources/build.gradle'

run gradle build tests

jaymode

I left a couple of comments. Otherwise LGTM

x-pack/plugin/security/build.gradle

x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/Security.java

albertzaharovits · 2018-10-17T11:28:18Z

10:59:50 FAILURE: Build failed with an exception.
10:59:50 
10:59:50 * What went wrong:
10:59:50 Could not set the value of environment variable 'ghprbPullLongDescription': could not convert string to current locale
10:59:50 
10:59:50 * Try:
10:59:50 Run with --debug option to get more log output. Run with --scan to get full insights.
10:59:50 
10:59:50 * Exception is:
10:59:50 net.rubygrapefruit.platform.NativeException: Could not set the value of environment variable 'ghprbPullLongDescription': could not convert string to current locale
10:59:50 	at net.rubygrapefruit.platform.internal.DefaultProcess.setEnvironmentVariable(DefaultProcess.java:71)
10:59:50 	at net.rubygrapefruit.platform.internal.WrapperProcess.setEnvironmentVariable(WrapperProcess.java:84)
10:59:50 	at org.gradle.internal.nativeintegration.processenvironment.NativePlatformBackedProcessEnvironment.setNativeEnvironmentVariable(NativePlatformBackedProcessEnvironment.java:36)
10:59:50 	at org.gradle.internal.nativeintegration.processenvironment.AbstractProcessEnvironment.setEnvironmentVariable(AbstractProcessEnvironment.java:67)
10:59:50 	at org.gradle.internal.nativeintegration.processenvironment.AbstractProcessEnvironment.maybeSetEnvironment(AbstractProcessEnvironment.java:41)
10:59:50 	at org.gradle.launcher.daemon.server.exec.EstablishBuildEnvironment.doBuild(EstablishBuildEnvironment.java:65)
10:59:50 	at org.gradle.launcher.daemon.server.exec.BuildCommandOnly.execute(BuildCommandOnly.java:36)
10:59:50 	at org.gradle.launcher.daemon.server.api.DaemonCommandExecution.proceed(DaemonCommandExecution.java:122)
10:59:50 	at org.gradle.launcher.daemon.server.exec.StartBuildOrRespondWithBusy$1.run(StartBuildOrRespondWithBusy.java:50)
10:59:50 	at org.gradle.launcher.daemon.server.DaemonStateCoordinator$1.run(DaemonStateCoordinator.java:295)
10:59:50 	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
10:59:50 	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
10:59:50 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
10:59:50 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
10:59:50 	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
10:59:50 	at java.lang.Thread.run(Thread.java:748)

run gradle build tests

CI for #34475 ran successfuly but 6.x did not had #33894 merged in yet. Closes #34627

ruflin · 2018-10-23T07:57:04Z

@ycombinator FYI, this was backported.

albertzaharovits added >feature review :Security/Audit X-Pack Audit logging v6.5.0 labels Sep 20, 2018

albertzaharovits self-assigned this Sep 20, 2018

albertzaharovits requested review from bizybot and jaymode September 20, 2018 11:51

Resurrect the previous format alongside the new one

1ca9d19

albertzaharovits force-pushed the 6.x-backport-structured-audit-trail branch from b05543c to 1ca9d19 Compare September 20, 2018 13:24

albertzaharovits commented Sep 20, 2018

View reviewed changes

bizybot reviewed Sep 26, 2018

View reviewed changes

albertzaharovits added 6 commits October 5, 2018 08:47

Revert "Resurrect the previous format alongside the new one"

259e3cc

This reverts commit 1ca9d19.

network fromatting backport

b3adbdb

Cherry-picked the old LoggingAuditTrail

0e69812

Merge branch '6.x' into 6.x-backport-structured-audit-trail

f19dce5

Cherry-picked Deprecated Unit tests

d933333

Log4j2properties ... sweeet!

c81b362

rjernst removed the review label Oct 10, 2018

albertzaharovits added 3 commits October 15, 2018 14:19

Checkstyle

29e2aea

Merge branch '6.x' into 6.x-backport-structured-audit-trail

32b90c4

Fix mistery tests

b49f504

jaymode approved these changes Oct 16, 2018

View reviewed changes

x-pack/plugin/security/build.gradle Show resolved Hide resolved

x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/Security.java Show resolved Hide resolved

Comments as per review

6bf666b

albertzaharovits merged commit 777eeae into elastic:6.x Oct 17, 2018

albertzaharovits deleted the 6.x-backport-structured-audit-trail branch October 17, 2018 22:32

albertzaharovits mentioned this pull request Oct 18, 2018

Docs for the audit logfile structured format #34584

Merged

albertzaharovits added a commit that referenced this pull request Oct 19, 2018

[CI] Fix test DeprecatedLoggingAuditTrailTests

6cf8a40

CI for #34475 ran successfuly but 6.x did not had #33894 merged in yet. Closes #34627

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Backport Structured Audit Logging #33894

Backport Structured Audit Logging #33894

albertzaharovits commented Sep 20, 2018 •

edited

Loading

elasticmachine commented Sep 20, 2018

albertzaharovits Sep 20, 2018

albertzaharovits Sep 20, 2018

bizybot Sep 26, 2018

albertzaharovits Oct 5, 2018

jaymode commented Oct 1, 2018

albertzaharovits commented Oct 1, 2018 •

edited

Loading

jaymode commented Oct 1, 2018

albertzaharovits commented Oct 5, 2018

albertzaharovits commented Oct 5, 2018

albertzaharovits commented Oct 15, 2018

albertzaharovits commented Oct 15, 2018 •

edited

Loading

albertzaharovits commented Oct 15, 2018

albertzaharovits commented Oct 15, 2018

albertzaharovits commented Oct 15, 2018

jaymode left a comment

albertzaharovits commented Oct 17, 2018

ruflin commented Oct 23, 2018

Backport Structured Audit Logging #33894

Backport Structured Audit Logging #33894

Conversation

albertzaharovits commented Sep 20, 2018 • edited Loading

elasticmachine commented Sep 20, 2018

albertzaharovits Sep 20, 2018

Choose a reason for hiding this comment

albertzaharovits Sep 20, 2018

Choose a reason for hiding this comment

bizybot Sep 26, 2018

Choose a reason for hiding this comment

albertzaharovits Oct 5, 2018

Choose a reason for hiding this comment

jaymode commented Oct 1, 2018

albertzaharovits commented Oct 1, 2018 • edited Loading

jaymode commented Oct 1, 2018

albertzaharovits commented Oct 5, 2018

albertzaharovits commented Oct 5, 2018

albertzaharovits commented Oct 15, 2018

albertzaharovits commented Oct 15, 2018 • edited Loading

albertzaharovits commented Oct 15, 2018

albertzaharovits commented Oct 15, 2018

albertzaharovits commented Oct 15, 2018

jaymode left a comment

Choose a reason for hiding this comment

albertzaharovits commented Oct 17, 2018

ruflin commented Oct 23, 2018

albertzaharovits commented Sep 20, 2018 •

edited

Loading

albertzaharovits commented Oct 1, 2018 •

edited

Loading

albertzaharovits commented Oct 15, 2018 •

edited

Loading