From d36b1026a50fceec1a18f614326a779c4d450f68 Mon Sep 17 00:00:00 2001 From: Igor Motov Date: Fri, 6 Jul 2018 15:46:50 -0400 Subject: [PATCH 1/2] Add opaque_id to audit logging Logs opaque_id if it is available with all audit log messages. Relates #31521 --- .../audit/logfile/LoggingAuditTrail.java | 190 ++++++++++-------- .../audit/logfile/LoggingAuditTrailTests.java | 95 +++++---- .../qa/sql/security/SqlSecurityTestCase.java | 2 +- 3 files changed, 163 insertions(+), 124 deletions(-) diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java index 5706f79011ac5..ceb0f88495b29 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java @@ -23,6 +23,7 @@ import org.elasticsearch.common.util.concurrent.ThreadContext; import org.elasticsearch.node.Node; import org.elasticsearch.rest.RestRequest; +import org.elasticsearch.tasks.Task; import org.elasticsearch.threadpool.ThreadPool; import org.elasticsearch.transport.TransportMessage; import org.elasticsearch.xpack.core.security.authc.Authentication; @@ -180,11 +181,11 @@ public void authenticationSuccess(String realm, User user, RestRequest request) if (events.contains(AUTHENTICATION_SUCCESS) && (eventFilterPolicyRegistry.ignorePredicate() .test(new AuditEventMetaInfo(Optional.of(user), Optional.of(realm), Optional.empty(), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}], request_body=[{}]", - localNodeInfo.prefix, principal(user), realm, request.uri(), request.params(), restRequestContent(request)); + logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}], opaque_id=[{}], request_body=[{}]", + localNodeInfo.prefix, principal(user), realm, request.uri(), request.params(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}]", localNodeInfo.prefix, - principal(user), realm, request.uri(), request.params()); + logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}], opaque_id=[{}]", + localNodeInfo.prefix, principal(user), realm, request.uri(), request.params(), opaqueId()); } } } @@ -197,13 +198,14 @@ public void authenticationSuccess(String realm, User user, String action, Transp .test(new AuditEventMetaInfo(Optional.of(user), Optional.of(realm), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], indices=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), principal(user), realm, action, - arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName()); + arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], request=[{}]", + logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), principal(user), realm, action, - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } } } @@ -217,12 +219,13 @@ public void anonymousAccessDenied(String action, TransportMessage message) { .test(new AuditEventMetaInfo(Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, - arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName()); + arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName()); + logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, + message.getClass().getSimpleName(), opaqueId()); } } } @@ -233,11 +236,11 @@ public void anonymousAccessDenied(RestRequest request) { if (events.contains(ANONYMOUS_ACCESS_DENIED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}], request_body=[{}]", localNodeInfo.prefix, - hostAttributes(request), request.uri(), restRequestContent(request)); + logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}], opaque_id=[{}], request_body=[{}]", localNodeInfo.prefix, + hostAttributes(request), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}]", localNodeInfo.prefix, hostAttributes(request), - request.uri()); + logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, + hostAttributes(request), request.uri(), opaqueId()); } } } @@ -250,13 +253,14 @@ public void authenticationFailed(AuthenticationToken token, String action, Trans .test(new AuditEventMetaInfo(Optional.of(token), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], indices=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, - arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName()); + arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], request=[{}]", + logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } } } @@ -267,10 +271,11 @@ public void authenticationFailed(RestRequest request) { if (events.contains(AUTHENTICATION_FAILED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}], request_body=[{}]", localNodeInfo.prefix, - hostAttributes(request), request.uri(), restRequestContent(request)); + logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}], opaque_id=[{}], request_body=[{}]", localNodeInfo.prefix, + hostAttributes(request), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}]", localNodeInfo.prefix, hostAttributes(request), request.uri()); + logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, + hostAttributes(request), request.uri(), opaqueId()); } } } @@ -283,12 +288,13 @@ public void authenticationFailed(String action, TransportMessage message) { .test(new AuditEventMetaInfo(Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], indices=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), action, arrayToCommaDelimitedString(indices.get()), - message.getClass().getSimpleName()); + logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, + arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName()); + logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, + message.getClass().getSimpleName(), opaqueId()); } } } @@ -300,11 +306,12 @@ public void authenticationFailed(AuthenticationToken token, RestRequest request) && (eventFilterPolicyRegistry.ignorePredicate() .test(new AuditEventMetaInfo(Optional.of(token), Optional.empty(), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}], request_body=[{}]", localNodeInfo.prefix, - hostAttributes(request), token.principal(), request.uri(), restRequestContent(request)); + logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}], opaque_id=[{}], request_body=[{}]", + localNodeInfo.prefix, hostAttributes(request), token.principal(), request.uri(), opaqueId(), + restRequestContent(request)); } else { - logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}]", localNodeInfo.prefix, hostAttributes(request), - token.principal(), request.uri()); + logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}], opaque_id=[{}]", + localNodeInfo.prefix, hostAttributes(request), token.principal(), request.uri(), opaqueId()); } } } @@ -319,13 +326,14 @@ public void authenticationFailed(String realm, AuthenticationToken token, String if (indices.isPresent()) { logger.info( "{}[transport] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], action=[{}], indices=[{}], " - + "request=[{}]", + + "request=[{}], opaque_id=[{}]", localNodeInfo.prefix, realm, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, - arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName()); + arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], action=[{}], request=[{}]", + logger.info("{}[transport] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], action=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, realm, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } } } @@ -337,12 +345,13 @@ public void authenticationFailed(String realm, AuthenticationToken token, RestRe && (eventFilterPolicyRegistry.ignorePredicate() .test(new AuditEventMetaInfo(Optional.of(token), Optional.of(realm), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}], request_body=[{}]", - localNodeInfo.prefix, realm, hostAttributes(request), token.principal(), request.uri(), + logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}], opaque_id=[{}], " + + "request_body=[{}]", + localNodeInfo.prefix, realm, hostAttributes(request), token.principal(), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}]", localNodeInfo.prefix, realm, - hostAttributes(request), token.principal(), request.uri()); + logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}], opaque_id=[{}]", + localNodeInfo.prefix, realm, hostAttributes(request), token.principal(), request.uri(), opaqueId()); } } } @@ -357,14 +366,15 @@ public void accessGranted(Authentication authentication, String action, Transpor Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), subject(authentication), - arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName()); + logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), + arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } } } @@ -378,14 +388,15 @@ public void accessDenied(Authentication authentication, String action, Transport Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), subject(authentication), - arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName()); + logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), + arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } } } @@ -395,10 +406,11 @@ localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), s public void tamperedRequest(RestRequest request) { if (events.contains(TAMPERED_REQUEST) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [tampered_request]\t{}, uri=[{}], request_body=[{}]", localNodeInfo.prefix, hostAttributes(request), - request.uri(), restRequestContent(request)); + logger.info("{}[rest] [tampered_request]\t{}, uri=[{}], opaque_id=[{}], request_body=[{}]", localNodeInfo.prefix, + hostAttributes(request), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [tampered_request]\t{}, uri=[{}]", localNodeInfo.prefix, hostAttributes(request), request.uri()); + logger.info("{}[rest] [tampered_request]\t{}, uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, hostAttributes(request), + request.uri(), opaqueId()); } } } @@ -411,12 +423,13 @@ public void tamperedRequest(String action, TransportMessage message) { .test(new AuditEventMetaInfo(Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [tampered_request]\t{}, action=[{}], indices=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), action, arrayToCommaDelimitedString(indices.get()), - message.getClass().getSimpleName()); + logger.info("{}[transport] [tampered_request]\t{}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, + arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [tampered_request]\t{}, action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName()); + logger.info("{}[transport] [tampered_request]\t{}, action=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, + originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName(), + opaqueId()); } } } @@ -430,13 +443,13 @@ public void tamperedRequest(User user, String action, TransportMessage request) .test(new AuditEventMetaInfo(Optional.of(user), Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], indices=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, request, localNodeInfo), principal(user), action, - arrayToCommaDelimitedString(indices.get()), request.getClass().getSimpleName()); + logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, request, localNodeInfo), principal(user), action, + arrayToCommaDelimitedString(indices.get()), request.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], request=[{}]", localNodeInfo.prefix, + logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, request, localNodeInfo), principal(user), action, - request.getClass().getSimpleName()); + request.getClass().getSimpleName(), opaqueId()); } } } @@ -445,16 +458,16 @@ public void tamperedRequest(User user, String action, TransportMessage request) @Override public void connectionGranted(InetAddress inetAddress, String profile, SecurityIpFilterRule rule) { if (events.contains(CONNECTION_GRANTED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { - logger.info("{}[ip_filter] [connection_granted]\torigin_address=[{}], transport_profile=[{}], rule=[{}]", localNodeInfo.prefix, - NetworkAddress.format(inetAddress), profile, rule); + logger.info("{}[ip_filter] [connection_granted]\torigin_address=[{}], transport_profile=[{}], rule=[{}], opaque_id=[{}]", + localNodeInfo.prefix, NetworkAddress.format(inetAddress), profile, rule, opaqueId()); } } @Override public void connectionDenied(InetAddress inetAddress, String profile, SecurityIpFilterRule rule) { if (events.contains(CONNECTION_DENIED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { - logger.info("{}[ip_filter] [connection_denied]\torigin_address=[{}], transport_profile=[{}], rule=[{}]", localNodeInfo.prefix, - NetworkAddress.format(inetAddress), profile, rule); + logger.info("{}[ip_filter] [connection_denied]\torigin_address=[{}], transport_profile=[{}], rule=[{}], opaque_id=[{}]", + localNodeInfo.prefix, NetworkAddress.format(inetAddress), profile, rule, opaqueId()); } } @@ -466,15 +479,15 @@ public void runAsGranted(Authentication authentication, String action, Transport Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), - arrayToCommaDelimitedString(roleNames), action, - message.getClass().getSimpleName()); + logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), + arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } } } @@ -488,14 +501,15 @@ public void runAsDenied(Authentication authentication, String action, TransportM Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]", + logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " + + "opaque_id=[{}]", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), - message.getClass().getSimpleName()); + message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}]", localNodeInfo.prefix, - originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), - arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName()); + logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), + arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } } } @@ -507,12 +521,13 @@ public void runAsDenied(Authentication authentication, RestRequest request, Stri && (eventFilterPolicyRegistry.ignorePredicate().test(new AuditEventMetaInfo(Optional.of(authentication.getUser()), Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}], request_body=[{}]", localNodeInfo.prefix, - hostAttributes(request), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), request.uri(), - restRequestContent(request)); + logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}], request_body=[{}], opaque_id=[{}]", + localNodeInfo.prefix, hostAttributes(request), runAsSubject(authentication), + arrayToCommaDelimitedString(roleNames), request.uri(), restRequestContent(request), opaqueId()); } else { - logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}]", localNodeInfo.prefix, hostAttributes(request), - runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), request.uri()); + logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, + hostAttributes(request), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), request.uri(), + opaqueId()); } } } @@ -552,6 +567,15 @@ protected static String originAttributes(ThreadContext threadContext, TransportM return restOriginTag(threadContext).orElse(transportOriginTag(message).orElse(localNodeInfo.localOriginTag)); } + private String opaqueId() { + String opaqueId = threadContext.getHeader(Task.X_OPAQUE_ID); + if (opaqueId != null) { + return opaqueId; + } else { + return ""; + } + } + private static Optional restOriginTag(ThreadContext threadContext) { final InetSocketAddress restAddress = RemoteHostHeader.restRemoteAddress(threadContext); if (restAddress == null) { diff --git a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java index 408d3e797e5a3..8babc98ea4077 100644 --- a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java +++ b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java @@ -25,6 +25,7 @@ import org.elasticsearch.common.xcontent.XContentType; import org.elasticsearch.mock.orig.Mockito; import org.elasticsearch.rest.RestRequest; +import org.elasticsearch.tasks.Task; import org.elasticsearch.test.ESTestCase; import org.elasticsearch.test.rest.FakeRestRequest; import org.elasticsearch.test.rest.FakeRestRequest.Builder; @@ -122,6 +123,7 @@ protected String expectedMessage() { private ClusterService clusterService; private ThreadContext threadContext; private boolean includeRequestBody; + private String opaqueId; @Before public void init() throws Exception { @@ -145,6 +147,12 @@ public void init() throws Exception { when(clusterService.getClusterSettings()).thenReturn(clusterSettings); prefix = LoggingAuditTrail.LocalNodeInfo.resolvePrefix(settings, localNode); threadContext = new ThreadContext(Settings.EMPTY); + if (randomBoolean()) { + opaqueId = randomAlphaOfLength(10); + threadContext.putHeader(Task.X_OPAQUE_ID, opaqueId); + } else { + opaqueId = ""; + } } public void testAnonymousAccessDeniedTransport() throws Exception { @@ -155,10 +163,10 @@ public void testAnonymousAccessDeniedTransport() throws Exception { auditTrail.anonymousAccessDenied("_action", message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [anonymous_access_denied]\t" + origins + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [anonymous_access_denied]\t" + origins + - ", action=[_action], request=[MockMessage]"); + ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -179,10 +187,10 @@ public void testAnonymousAccessDeniedRest() throws Exception { auditTrail.anonymousAccessDenied(request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [anonymous_access_denied]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], request_body=[" + expectedMessage + "]"); + NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [anonymous_access_denied]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri]"); + NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -202,10 +210,10 @@ public void testAuthenticationFailed() throws Exception { if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + ", principal=[_principal], action=[_action], indices=[" + indices(message) + - "], request=[MockIndicesRequest]"); + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + - ", principal=[_principal], action=[_action], request=[MockMessage]"); + ", principal=[_principal], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -224,10 +232,10 @@ public void testAuthenticationFailedNoToken() throws Exception { auditTrail.authenticationFailed("_action", message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + - ", action=[_action], request=[MockMessage]"); + ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -248,11 +256,11 @@ public void testAuthenticationFailedRest() throws Exception { auditTrail.authenticationFailed(new MockToken(), request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], request_body=[" + + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri]"); + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -273,10 +281,10 @@ public void testAuthenticationFailedRestNoToken() throws Exception { auditTrail.authenticationFailed(request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], request_body=[" + expectedMessage + "]"); + NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri]"); + NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -303,10 +311,10 @@ public void testAuthenticationFailedRealm() throws Exception { if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [realm_authentication_failed]\trealm=[_realm], " + origins + ", principal=[_principal], action=[_action], indices=[" + indices(message) + "], " + - "request=[MockIndicesRequest]"); + "request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [realm_authentication_failed]\trealm=[_realm], " + origins + - ", principal=[_principal], action=[_action], request=[MockMessage]"); + ", principal=[_principal], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } } @@ -327,11 +335,11 @@ public void testAuthenticationFailedRealmRest() throws Exception { auditTrail.authenticationFailed("_realm", new MockToken(), request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [realm_authentication_failed]\trealm=[_realm], origin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], request_body=[" + + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [realm_authentication_failed]\trealm=[_realm], origin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri]"); + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "]"); } } @@ -353,10 +361,10 @@ public void testAccessGranted() throws Exception { : "principal=[_username], realm=[authRealm]") + ", roles=[" + role + "]"; if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[_action], request=[MockMessage]"); + ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -384,11 +392,11 @@ public void testAccessGrantedInternalSystemAction() throws Exception { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", principal=[" + SystemUser.INSTANCE.principal() + "], realm=[authRealm], roles=[" + role + "], action=[internal:_action], indices=[" + indices(message) - + "], request=[MockIndicesRequest]"); + + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", principal=[" + SystemUser.INSTANCE.principal() + "], realm=[authRealm], roles=[" + role - + "], action=[internal:_action], request=[MockMessage]"); + + "], action=[internal:_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } } @@ -410,10 +418,11 @@ public void testAccessGrantedInternalSystemActionNonSystemUser() throws Exceptio : "principal=[_username], realm=[authRealm]") + ", roles=[" + role + "]"; if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[internal:_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[internal:_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], " + + "opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[internal:_action], request=[MockMessage]"); + ", action=[internal:_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -442,10 +451,10 @@ public void testAccessDenied() throws Exception { : "principal=[_username], realm=[authRealm]") + ", roles=[" + role + "]"; if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [access_denied]\t" + origins + ", " + userInfo + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_denied]\t" + origins + ", " + userInfo + - ", action=[_action], request=[MockMessage]"); + ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -466,10 +475,10 @@ public void testTamperedRequestRest() throws Exception { auditTrail.tamperedRequest(request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [tampered_request]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], request_body=[" + expectedMessage + "]"); + NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [tampered_request]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri]"); + NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -489,10 +498,10 @@ public void testTamperedRequest() throws Exception { auditTrail.tamperedRequest(action, message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + - ", action=[_action], request=[MockMessage]"); + ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -516,10 +525,10 @@ public void testTamperedRequestWithUser() throws Exception { auditTrail.tamperedRequest(user, action, message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + ", " + userInfo + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + ", " + userInfo + - ", action=[_action], request=[MockMessage]"); + ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -537,7 +546,8 @@ public void testConnectionDenied() throws Exception { final SecurityIpFilterRule rule = new SecurityIpFilterRule(false, "_all"); auditTrail.connectionDenied(inetAddress, "default", rule); assertMsg(logger, Level.INFO, String.format(Locale.ROOT, prefix + - "[ip_filter] [connection_denied]\torigin_address=[%s], transport_profile=[%s], rule=[deny %s]", + "[ip_filter] [connection_denied]\torigin_address=[%s], transport_profile=[%s], rule=[deny %s], " + + "opaque_id=[" + opaqueId + "]", NetworkAddress.format(inetAddress), "default", "_all")); // test disabled @@ -562,7 +572,8 @@ public void testConnectionGranted() throws Exception { auditTrail = new LoggingAuditTrail(settings, clusterService, logger, threadContext); auditTrail.connectionGranted(inetAddress, "default", rule); assertMsg(logger, Level.INFO, String.format(Locale.ROOT, prefix + "[ip_filter] [connection_granted]\torigin_address=[%s], " + - "transport_profile=[default], rule=[allow default:accept_all]", NetworkAddress.format(inetAddress))); + "transport_profile=[default], rule=[allow default:accept_all], opaque_id=[" + opaqueId + "]", + NetworkAddress.format(inetAddress))); } public void testRunAsGranted() throws Exception { @@ -577,12 +588,13 @@ public void testRunAsGranted() throws Exception { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_granted]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], " + + "opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_granted]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], request=[MockMessage]"); + + role + "], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -605,12 +617,13 @@ public void testRunAsDenied() throws Exception { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_denied]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_denied]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], request=[MockMessage]"); + + role + "], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -667,10 +680,11 @@ public void testAuthenticationSuccessRest() throws Exception { if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_success]\t" + userInfo + ", realm=[_realm], uri=[_uri], params=[" + params - + "], request_body=[" + expectedMessage + "]"); + + "], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, - prefix + "[rest] [authentication_success]\t" + userInfo + ", realm=[_realm], uri=[_uri], params=[" + params + "]"); + prefix + "[rest] [authentication_success]\t" + userInfo + ", realm=[_realm], uri=[_uri], params=[" + params + + "], opaque_id=[" + opaqueId + "]"); } // test disabled @@ -701,10 +715,11 @@ public void testAuthenticationSuccessTransport() throws Exception { auditTrail.authenticationSuccess(realm, user, "_action", message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_success]\t" + origins + ", " + userInfo - + ", realm=[_realm], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]"); + + ", realm=[_realm], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], " + + "opaque_id=[" + opaqueId + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_success]\t" + origins + ", " + userInfo - + ", realm=[_realm], action=[_action], request=[MockMessage]"); + + ", realm=[_realm], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); } // test disabled diff --git a/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java b/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java index 83047c93da327..cb4afcb594d94 100644 --- a/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java +++ b/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java @@ -557,7 +557,7 @@ public void assertLogs() throws Exception { Pattern logPattern = Pattern.compile( ("PART PART PART PART origin_type=PART, origin_address=PART, principal=PART, realm=PART, " + "(?:run_as_principal=IGN, )?(?:run_as_realm=IGN, )?(?:run_by_principal=PART, )?(?:run_by_realm=PART, )?" - + "roles=PART, action=\\[(.*?)\\], (?:indices=PART, )?request=PART") + + "roles=PART, action=\\[(.*?)\\], (?:indices=PART, )?request=PART, opaque_id=PART") .replace(" ", "\\s+").replace("PART", "\\[([^\\]]*)\\]").replace("IGN", "\\[[^\\]]*\\]")); // fail(logPattern.toString()); while ((line = logReader.readLine()) != null) { From cf54f9f824d83ca8b8c9908860a2b98e8e973579 Mon Sep 17 00:00:00 2001 From: Igor Motov Date: Mon, 9 Jul 2018 13:36:35 -0400 Subject: [PATCH 2/2] Don't show opaque_id=[] if opaque id is not present --- .../audit/logfile/LoggingAuditTrail.java | 85 ++++++++---------- .../audit/logfile/LoggingAuditTrailTests.java | 90 +++++++++---------- .../qa/sql/security/SqlSecurityTestCase.java | 2 +- 3 files changed, 83 insertions(+), 94 deletions(-) diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java index ceb0f88495b29..5da6a9eb77cdd 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrail.java @@ -181,10 +181,10 @@ public void authenticationSuccess(String realm, User user, RestRequest request) if (events.contains(AUTHENTICATION_SUCCESS) && (eventFilterPolicyRegistry.ignorePredicate() .test(new AuditEventMetaInfo(Optional.of(user), Optional.of(realm), Optional.empty(), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}], opaque_id=[{}], request_body=[{}]", + logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}]{}, request_body=[{}]", localNodeInfo.prefix, principal(user), realm, request.uri(), request.params(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}], opaque_id=[{}]", + logger.info("{}[rest] [authentication_success]\t{}, realm=[{}], uri=[{}], params=[{}]{}", localNodeInfo.prefix, principal(user), realm, request.uri(), request.params(), opaqueId()); } } @@ -198,12 +198,11 @@ public void authenticationSuccess(String realm, User user, String action, Transp .test(new AuditEventMetaInfo(Optional.of(user), Optional.of(realm), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], indices=[{}], request=[{}], " + - "opaque_id=[{}]", + logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), principal(user), realm, action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [authentication_success]\t{}, {}, realm=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), principal(user), realm, action, message.getClass().getSimpleName(), opaqueId()); } @@ -219,11 +218,11 @@ public void anonymousAccessDenied(String action, TransportMessage message) { .test(new AuditEventMetaInfo(Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [anonymous_access_denied]\t{}, action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName(), opaqueId()); } @@ -236,10 +235,10 @@ public void anonymousAccessDenied(RestRequest request) { if (events.contains(ANONYMOUS_ACCESS_DENIED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}], opaque_id=[{}], request_body=[{}]", localNodeInfo.prefix, + logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}]{}, request_body=[{}]", localNodeInfo.prefix, hostAttributes(request), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, + logger.info("{}[rest] [anonymous_access_denied]\t{}, uri=[{}]{}", localNodeInfo.prefix, hostAttributes(request), request.uri(), opaqueId()); } } @@ -253,12 +252,11 @@ public void authenticationFailed(AuthenticationToken token, String action, Trans .test(new AuditEventMetaInfo(Optional.of(token), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], indices=[{}], request=[{}], " + - "opaque_id=[{}]", + logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [authentication_failed]\t{}, principal=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, message.getClass().getSimpleName(), opaqueId()); } @@ -271,10 +269,10 @@ public void authenticationFailed(RestRequest request) { if (events.contains(AUTHENTICATION_FAILED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}], opaque_id=[{}], request_body=[{}]", localNodeInfo.prefix, + logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}]{}, request_body=[{}]", localNodeInfo.prefix, hostAttributes(request), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, + logger.info("{}[rest] [authentication_failed]\t{}, uri=[{}]{}", localNodeInfo.prefix, hostAttributes(request), request.uri(), opaqueId()); } } @@ -288,11 +286,11 @@ public void authenticationFailed(String action, TransportMessage message) { .test(new AuditEventMetaInfo(Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [authentication_failed]\t{}, action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName(), opaqueId()); } @@ -306,11 +304,11 @@ public void authenticationFailed(AuthenticationToken token, RestRequest request) && (eventFilterPolicyRegistry.ignorePredicate() .test(new AuditEventMetaInfo(Optional.of(token), Optional.empty(), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}], opaque_id=[{}], request_body=[{}]", + logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}]{}, request_body=[{}]", localNodeInfo.prefix, hostAttributes(request), token.principal(), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}], opaque_id=[{}]", + logger.info("{}[rest] [authentication_failed]\t{}, principal=[{}], uri=[{}]{}", localNodeInfo.prefix, hostAttributes(request), token.principal(), request.uri(), opaqueId()); } } @@ -326,12 +324,11 @@ public void authenticationFailed(String realm, AuthenticationToken token, String if (indices.isPresent()) { logger.info( "{}[transport] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], action=[{}], indices=[{}], " - + "request=[{}], opaque_id=[{}]", + + "request=[{}]{}", localNodeInfo.prefix, realm, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], action=[{}], request=[{}], " - + "opaque_id=[{}]", + logger.info("{}[transport] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, realm, originAttributes(threadContext, message, localNodeInfo), token.principal(), action, message.getClass().getSimpleName(), opaqueId()); } @@ -345,12 +342,12 @@ public void authenticationFailed(String realm, AuthenticationToken token, RestRe && (eventFilterPolicyRegistry.ignorePredicate() .test(new AuditEventMetaInfo(Optional.of(token), Optional.of(realm), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}], opaque_id=[{}], " + logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}]{}, " + "request_body=[{}]", localNodeInfo.prefix, realm, hostAttributes(request), token.principal(), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}], opaque_id=[{}]", + logger.info("{}[rest] [realm_authentication_failed]\trealm=[{}], {}, principal=[{}], uri=[{}]{}", localNodeInfo.prefix, realm, hostAttributes(request), token.principal(), request.uri(), opaqueId()); } } @@ -366,13 +363,12 @@ public void accessGranted(Authentication authentication, String action, Transpor Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " - + "opaque_id=[{}]", + logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [access_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } @@ -388,13 +384,12 @@ public void accessDenied(Authentication authentication, String action, Transport Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " - + "opaque_id=[{}]", + logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [access_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), subject(authentication), arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } @@ -406,10 +401,10 @@ localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), s public void tamperedRequest(RestRequest request) { if (events.contains(TAMPERED_REQUEST) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [tampered_request]\t{}, uri=[{}], opaque_id=[{}], request_body=[{}]", localNodeInfo.prefix, + logger.info("{}[rest] [tampered_request]\t{}, uri=[{}]{}, request_body=[{}]", localNodeInfo.prefix, hostAttributes(request), request.uri(), opaqueId(), restRequestContent(request)); } else { - logger.info("{}[rest] [tampered_request]\t{}, uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, hostAttributes(request), + logger.info("{}[rest] [tampered_request]\t{}, uri=[{}]{}", localNodeInfo.prefix, hostAttributes(request), request.uri(), opaqueId()); } } @@ -423,11 +418,11 @@ public void tamperedRequest(String action, TransportMessage message) { .test(new AuditEventMetaInfo(Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [tampered_request]\t{}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [tampered_request]\t{}, action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [tampered_request]\t{}, action=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, + logger.info("{}[transport] [tampered_request]\t{}, action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), action, message.getClass().getSimpleName(), opaqueId()); } @@ -443,11 +438,11 @@ public void tamperedRequest(User user, String action, TransportMessage request) .test(new AuditEventMetaInfo(Optional.of(user), Optional.empty(), Optional.empty(), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], indices=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, request, localNodeInfo), principal(user), action, arrayToCommaDelimitedString(indices.get()), request.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], request=[{}], opaque_id=[{}]", localNodeInfo.prefix, + logger.info("{}[transport] [tampered_request]\t{}, {}, action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, request, localNodeInfo), principal(user), action, request.getClass().getSimpleName(), opaqueId()); } @@ -458,7 +453,7 @@ localNodeInfo.prefix, originAttributes(threadContext, request, localNodeInfo), p @Override public void connectionGranted(InetAddress inetAddress, String profile, SecurityIpFilterRule rule) { if (events.contains(CONNECTION_GRANTED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { - logger.info("{}[ip_filter] [connection_granted]\torigin_address=[{}], transport_profile=[{}], rule=[{}], opaque_id=[{}]", + logger.info("{}[ip_filter] [connection_granted]\torigin_address=[{}], transport_profile=[{}], rule=[{}]{}", localNodeInfo.prefix, NetworkAddress.format(inetAddress), profile, rule, opaqueId()); } } @@ -466,7 +461,7 @@ public void connectionGranted(InetAddress inetAddress, String profile, SecurityI @Override public void connectionDenied(InetAddress inetAddress, String profile, SecurityIpFilterRule rule) { if (events.contains(CONNECTION_DENIED) && (eventFilterPolicyRegistry.ignorePredicate().test(AuditEventMetaInfo.EMPTY) == false)) { - logger.info("{}[ip_filter] [connection_denied]\torigin_address=[{}], transport_profile=[{}], rule=[{}], opaque_id=[{}]", + logger.info("{}[ip_filter] [connection_denied]\torigin_address=[{}], transport_profile=[{}], rule=[{}]{}", localNodeInfo.prefix, NetworkAddress.format(inetAddress), profile, rule, opaqueId()); } } @@ -479,13 +474,12 @@ public void runAsGranted(Authentication authentication, String action, Transport Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " - + "opaque_id=[{}]", + logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [run_as_granted]\t{}, {}, roles=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } @@ -501,13 +495,12 @@ public void runAsDenied(Authentication authentication, String action, TransportM Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), indices)) == false) { final LocalNodeInfo localNodeInfo = this.localNodeInfo; if (indices.isPresent()) { - logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}], " + - "opaque_id=[{}]", + logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], indices=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), action, arrayToCommaDelimitedString(indices.get()), message.getClass().getSimpleName(), opaqueId()); } else { - logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}], opaque_id=[{}]", + logger.info("{}[transport] [run_as_denied]\t{}, {}, roles=[{}], action=[{}], request=[{}]{}", localNodeInfo.prefix, originAttributes(threadContext, message, localNodeInfo), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), action, message.getClass().getSimpleName(), opaqueId()); } @@ -521,11 +514,11 @@ public void runAsDenied(Authentication authentication, RestRequest request, Stri && (eventFilterPolicyRegistry.ignorePredicate().test(new AuditEventMetaInfo(Optional.of(authentication.getUser()), Optional.of(effectiveRealmName(authentication)), Optional.of(roleNames), Optional.empty())) == false)) { if (includeRequestBody) { - logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}], request_body=[{}], opaque_id=[{}]", + logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}], request_body=[{}]{}", localNodeInfo.prefix, hostAttributes(request), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), request.uri(), restRequestContent(request), opaqueId()); } else { - logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}], opaque_id=[{}]", localNodeInfo.prefix, + logger.info("{}[rest] [run_as_denied]\t{}, {}, roles=[{}], uri=[{}]{}", localNodeInfo.prefix, hostAttributes(request), runAsSubject(authentication), arrayToCommaDelimitedString(roleNames), request.uri(), opaqueId()); } @@ -570,7 +563,7 @@ protected static String originAttributes(ThreadContext threadContext, TransportM private String opaqueId() { String opaqueId = threadContext.getHeader(Task.X_OPAQUE_ID); if (opaqueId != null) { - return opaqueId; + return ", opaque_id=[" + opaqueId + "]"; } else { return ""; } diff --git a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java index 8babc98ea4077..1059e22abd663 100644 --- a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java +++ b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/audit/logfile/LoggingAuditTrailTests.java @@ -148,8 +148,9 @@ public void init() throws Exception { prefix = LoggingAuditTrail.LocalNodeInfo.resolvePrefix(settings, localNode); threadContext = new ThreadContext(Settings.EMPTY); if (randomBoolean()) { - opaqueId = randomAlphaOfLength(10); - threadContext.putHeader(Task.X_OPAQUE_ID, opaqueId); + String id = randomAlphaOfLength(10); + threadContext.putHeader(Task.X_OPAQUE_ID, id); + opaqueId = ", opaque_id=[" + id + "]"; } else { opaqueId = ""; } @@ -163,10 +164,10 @@ public void testAnonymousAccessDeniedTransport() throws Exception { auditTrail.anonymousAccessDenied("_action", message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [anonymous_access_denied]\t" + origins + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [anonymous_access_denied]\t" + origins + - ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -187,10 +188,10 @@ public void testAnonymousAccessDeniedRest() throws Exception { auditTrail.anonymousAccessDenied(request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [anonymous_access_denied]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); + NetworkAddress.format(address) + "], uri=[_uri]" + opaqueId + ", request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [anonymous_access_denied]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "]"); + NetworkAddress.format(address) + "], uri=[_uri]" + opaqueId); } // test disabled @@ -210,10 +211,10 @@ public void testAuthenticationFailed() throws Exception { if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + ", principal=[_principal], action=[_action], indices=[" + indices(message) + - "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + - ", principal=[_principal], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", principal=[_principal], action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -232,10 +233,10 @@ public void testAuthenticationFailedNoToken() throws Exception { auditTrail.authenticationFailed("_action", message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_failed]\t" + origins + - ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -256,11 +257,11 @@ public void testAuthenticationFailedRest() throws Exception { auditTrail.authenticationFailed(new MockToken(), request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri]" + opaqueId + ", request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "]"); + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri]" + opaqueId); } // test disabled @@ -281,10 +282,10 @@ public void testAuthenticationFailedRestNoToken() throws Exception { auditTrail.authenticationFailed(request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); + NetworkAddress.format(address) + "], uri=[_uri]" + opaqueId + ", request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_failed]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "]"); + NetworkAddress.format(address) + "], uri=[_uri]" + opaqueId); } // test disabled @@ -311,10 +312,10 @@ public void testAuthenticationFailedRealm() throws Exception { if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [realm_authentication_failed]\trealm=[_realm], " + origins + ", principal=[_principal], action=[_action], indices=[" + indices(message) + "], " + - "request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + "request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [realm_authentication_failed]\trealm=[_realm], " + origins + - ", principal=[_principal], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", principal=[_principal], action=[_action], request=[MockMessage]" + opaqueId); } } @@ -335,11 +336,11 @@ public void testAuthenticationFailedRealmRest() throws Exception { auditTrail.authenticationFailed("_realm", new MockToken(), request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [realm_authentication_failed]\trealm=[_realm], origin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri]" + opaqueId + ", request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [realm_authentication_failed]\trealm=[_realm], origin_address=[" + - NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri], opaque_id=[" + opaqueId + "]"); + NetworkAddress.format(address) + "], principal=[_principal], uri=[_uri]" + opaqueId); } } @@ -361,10 +362,10 @@ public void testAccessGranted() throws Exception { : "principal=[_username], realm=[authRealm]") + ", roles=[" + role + "]"; if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -392,11 +393,11 @@ public void testAccessGrantedInternalSystemAction() throws Exception { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", principal=[" + SystemUser.INSTANCE.principal() + "], realm=[authRealm], roles=[" + role + "], action=[internal:_action], indices=[" + indices(message) - + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", principal=[" + SystemUser.INSTANCE.principal() + "], realm=[authRealm], roles=[" + role - + "], action=[internal:_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + + "], action=[internal:_action], request=[MockMessage]" + opaqueId); } } @@ -418,11 +419,10 @@ public void testAccessGrantedInternalSystemActionNonSystemUser() throws Exceptio : "principal=[_username], realm=[authRealm]") + ", roles=[" + role + "]"; if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[internal:_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], " + - "opaque_id=[" + opaqueId + "]"); + ", action=[internal:_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_granted]\t" + origins + ", " + userInfo + - ", action=[internal:_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[internal:_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -451,10 +451,10 @@ public void testAccessDenied() throws Exception { : "principal=[_username], realm=[authRealm]") + ", roles=[" + role + "]"; if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [access_denied]\t" + origins + ", " + userInfo + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [access_denied]\t" + origins + ", " + userInfo + - ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -475,10 +475,10 @@ public void testTamperedRequestRest() throws Exception { auditTrail.tamperedRequest(request); if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [tampered_request]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); + NetworkAddress.format(address) + "], uri=[_uri]" + opaqueId + ", request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [tampered_request]\torigin_address=[" + - NetworkAddress.format(address) + "], uri=[_uri], opaque_id=[" + opaqueId + "]"); + NetworkAddress.format(address) + "], uri=[_uri]" + opaqueId); } // test disabled @@ -498,10 +498,10 @@ public void testTamperedRequest() throws Exception { auditTrail.tamperedRequest(action, message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + - ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -525,10 +525,10 @@ public void testTamperedRequestWithUser() throws Exception { auditTrail.tamperedRequest(user, action, message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + ", " + userInfo + - ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" + opaqueId + "]"); + ", action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [tampered_request]\t" + origins + ", " + userInfo + - ", action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + ", action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -546,8 +546,7 @@ public void testConnectionDenied() throws Exception { final SecurityIpFilterRule rule = new SecurityIpFilterRule(false, "_all"); auditTrail.connectionDenied(inetAddress, "default", rule); assertMsg(logger, Level.INFO, String.format(Locale.ROOT, prefix + - "[ip_filter] [connection_denied]\torigin_address=[%s], transport_profile=[%s], rule=[deny %s], " + - "opaque_id=[" + opaqueId + "]", + "[ip_filter] [connection_denied]\torigin_address=[%s], transport_profile=[%s], rule=[deny %s]" + opaqueId, NetworkAddress.format(inetAddress), "default", "_all")); // test disabled @@ -572,7 +571,7 @@ public void testConnectionGranted() throws Exception { auditTrail = new LoggingAuditTrail(settings, clusterService, logger, threadContext); auditTrail.connectionGranted(inetAddress, "default", rule); assertMsg(logger, Level.INFO, String.format(Locale.ROOT, prefix + "[ip_filter] [connection_granted]\torigin_address=[%s], " + - "transport_profile=[default], rule=[allow default:accept_all], opaque_id=[" + opaqueId + "]", + "transport_profile=[default], rule=[allow default:accept_all]" + opaqueId, NetworkAddress.format(inetAddress))); } @@ -588,13 +587,12 @@ public void testRunAsGranted() throws Exception { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_granted]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], " - + "opaque_id=[" + opaqueId + "]"); + + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_granted]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + + role + "], action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -617,13 +615,12 @@ public void testRunAsDenied() throws Exception { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_denied]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], opaque_id=[" - + opaqueId + "]"); + + role + "], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [run_as_denied]\t" + origins + ", principal=[_username], realm=[authRealm], run_as_principal=[running as], run_as_realm=[lookRealm], roles=[" - + role + "], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + + role + "], action=[_action], request=[MockMessage]" + opaqueId); } // test disabled @@ -680,11 +677,11 @@ public void testAuthenticationSuccessRest() throws Exception { if (includeRequestBody) { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_success]\t" + userInfo + ", realm=[_realm], uri=[_uri], params=[" + params - + "], opaque_id=[" + opaqueId + "], request_body=[" + expectedMessage + "]"); + + "]" + opaqueId + ", request_body=[" + expectedMessage + "]"); } else { assertMsg(logger, Level.INFO, prefix + "[rest] [authentication_success]\t" + userInfo + ", realm=[_realm], uri=[_uri], params=[" + params - + "], opaque_id=[" + opaqueId + "]"); + + "]" + opaqueId); } // test disabled @@ -715,11 +712,10 @@ public void testAuthenticationSuccessTransport() throws Exception { auditTrail.authenticationSuccess(realm, user, "_action", message); if (message instanceof IndicesRequest) { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_success]\t" + origins + ", " + userInfo - + ", realm=[_realm], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest], " - + "opaque_id=[" + opaqueId + "]"); + + ", realm=[_realm], action=[_action], indices=[" + indices(message) + "], request=[MockIndicesRequest]" + opaqueId); } else { assertMsg(logger, Level.INFO, prefix + "[transport] [authentication_success]\t" + origins + ", " + userInfo - + ", realm=[_realm], action=[_action], request=[MockMessage], opaque_id=[" + opaqueId + "]"); + + ", realm=[_realm], action=[_action], request=[MockMessage]" + opaqueId); } // test disabled diff --git a/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java b/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java index cb4afcb594d94..83047c93da327 100644 --- a/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java +++ b/x-pack/qa/sql/security/src/test/java/org/elasticsearch/xpack/qa/sql/security/SqlSecurityTestCase.java @@ -557,7 +557,7 @@ public void assertLogs() throws Exception { Pattern logPattern = Pattern.compile( ("PART PART PART PART origin_type=PART, origin_address=PART, principal=PART, realm=PART, " + "(?:run_as_principal=IGN, )?(?:run_as_realm=IGN, )?(?:run_by_principal=PART, )?(?:run_by_realm=PART, )?" - + "roles=PART, action=\\[(.*?)\\], (?:indices=PART, )?request=PART, opaque_id=PART") + + "roles=PART, action=\\[(.*?)\\], (?:indices=PART, )?request=PART") .replace(" ", "\\s+").replace("PART", "\\[([^\\]]*)\\]").replace("IGN", "\\[[^\\]]*\\]")); // fail(logPattern.toString()); while ((line = logReader.readLine()) != null) {