Skip to content

Commit ce737d3

Browse files
n1v0lgn1v0lg
authored
Improve RCS-related logging (#94818)
This is a first pass at extending logging for the new remote cluster security model. I've focused on authentication and authorization and did not dig into port and network related code. I propose we do this iteratively.
1 parent cd1fdd1 commit ce737d3

File tree

7 files changed

+138
-29
lines changed

7 files changed

+138
-29
lines changed

‎x-pack/plugin/core/src/main/java/org/elasticsearch/xpack/core/security/authc/Authentication.java‎

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1292,7 +1292,17 @@ static Map<String, Object> maybeRewriteMetadataForCrossClusterAccessAuthenticati
12921292
assert metadata.containsKey(CROSS_CLUSTER_ACCESS_AUTHENTICATION_KEY)
12931293
: "metadata must contain authentication object for cross cluster access authentication";
12941294
final Authentication authenticationFromMetadata = (Authentication) metadata.get(CROSS_CLUSTER_ACCESS_AUTHENTICATION_KEY);
1295-
if (authenticationFromMetadata.getEffectiveSubject().getTransportVersion().after(olderVersion)) {
1295+
final TransportVersion effectiveSubjectVersion = authenticationFromMetadata.getEffectiveSubject().getTransportVersion();
1296+
if (effectiveSubjectVersion.after(olderVersion)) {
1297+
logger.trace(
1298+
() -> "Cross cluster access authentication has authentication field in metadata ["
1299+
+ authenticationFromMetadata
1300+
+ "] that may require a rewrite from version ["
1301+
+ effectiveSubjectVersion
1302+
+ "] to ["
1303+
+ olderVersion
1304+
+ "]"
1305+
);
12961306
final Map<String, Object> rewrittenMetadata = new HashMap<>(metadata);
12971307
rewrittenMetadata.put(
12981308
CROSS_CLUSTER_ACCESS_AUTHENTICATION_KEY,

‎x-pack/plugin/core/src/main/java/org/elasticsearch/xpack/core/security/authz/permission/LimitedRole.java‎

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,8 +7,11 @@
77

88
package org.elasticsearch.xpack.core.security.authz.permission;
99

10+
import org.apache.logging.log4j.LogManager;
11+
import org.apache.logging.log4j.Logger;
1012
import org.apache.lucene.util.automaton.Automaton;
1113
import org.elasticsearch.cluster.metadata.IndexAbstraction;
14+
import org.elasticsearch.common.Strings;
1215
import org.elasticsearch.core.Nullable;
1316
import org.elasticsearch.transport.TransportRequest;
1417
import org.elasticsearch.xpack.core.security.authc.Authentication;
@@ -34,6 +37,8 @@
3437
* provided role.
3538
*/
3639
public final class LimitedRole implements Role {
40+
41+
private static final Logger logger = LogManager.getLogger(LimitedRole.class);
3742
private final Role baseRole;
3843
private final Role limitedByRole;
3944

@@ -128,12 +133,26 @@ public RoleDescriptorsIntersection getRoleDescriptorsIntersectionForRemoteCluste
128133
final RoleDescriptorsIntersection baseIntersection = baseRole.getRoleDescriptorsIntersectionForRemoteCluster(remoteClusterAlias);
129134
// Intersecting with empty descriptors list should result in an empty intersection.
130135
if (baseIntersection.roleDescriptorsList().isEmpty()) {
136+
logger.trace(
137+
() -> "Base role ["
138+
+ Strings.arrayToCommaDelimitedString(baseRole.names())
139+
+ "] does not define any role descriptors for remote cluster alias ["
140+
+ remoteClusterAlias
141+
+ "]"
142+
);
131143
return RoleDescriptorsIntersection.EMPTY;
132144
}
133145
final RoleDescriptorsIntersection limitedByIntersection = limitedByRole.getRoleDescriptorsIntersectionForRemoteCluster(
134146
remoteClusterAlias
135147
);
136148
if (limitedByIntersection.roleDescriptorsList().isEmpty()) {
149+
logger.trace(
150+
() -> "Limited-by role ["
151+
+ Strings.arrayToCommaDelimitedString(limitedByRole.names())
152+
+ "] does not define any role descriptors for remote cluster alias ["
153+
+ remoteClusterAlias
154+
+ "]"
155+
);
137156
return RoleDescriptorsIntersection.EMPTY;
138157
}
139158
final List<Set<RoleDescriptor>> mergedIntersection = new ArrayList<>(

‎x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/CrossClusterAccessAuthenticationService.java‎

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -104,7 +104,9 @@ public void authenticate(final String action, final TransportRequest request, fi
104104
validate(crossClusterAccessSubjectInfo);
105105
writeAuthToContext(
106106
authcContext,
107-
authentication.toCrossClusterAccess(maybeRewriteForCrossClusterAccessUser(crossClusterAccessSubjectInfo)),
107+
authentication.toCrossClusterAccess(
108+
maybeRewriteForCrossClusterAccessUser(authcContext.getRequest(), crossClusterAccessSubjectInfo)
109+
),
108110
listener
109111
);
110112
} catch (Exception ex) {
@@ -120,12 +122,14 @@ public AuthenticationService getAuthenticationService() {
120122
}
121123

122124
private CrossClusterAccessSubjectInfo maybeRewriteForCrossClusterAccessUser(
125+
AuthenticationService.AuditableRequest request,
123126
CrossClusterAccessSubjectInfo crossClusterAccessSubjectInfo
124127
) {
125128
final Authentication authentication = crossClusterAccessSubjectInfo.getAuthentication();
126129
final Subject effectiveSubject = authentication.getEffectiveSubject();
127130
final User user = effectiveSubject.getUser();
128131
if (CrossClusterAccessUser.is(user)) {
132+
logger.debug("Request [{}] performed by internal user [{}]. Will use pre-defined role descriptors", request, user.principal());
129133
return CrossClusterAccessUser.subjectInfoWithRoleDescriptors(
130134
effectiveSubject.getTransportVersion(),
131135
effectiveSubject.getRealm().getNodeName()
@@ -185,7 +189,6 @@ private void validate(final CrossClusterAccessSubjectInfo crossClusterAccessSubj
185189
}
186190
}
187191
}
188-
189192
}
190193

191194
private Version getMinNodeVersion() {
@@ -213,11 +216,14 @@ private void writeAuthToContext(
213216
authentication.writeToContext(context.getThreadContext());
214217
context.getRequest().authenticationSuccess(authentication);
215218
} catch (Exception e) {
216-
logger.debug(() -> format("Failed to store authentication [%s] for request [%s]", authentication, context.getRequest()), e);
219+
logger.debug(
220+
() -> format("Failed to store authentication [%s] for cross cluster request [%s]", authentication, context.getRequest()),
221+
e
222+
);
217223
withRequestProcessingFailure(context, e, listener);
218224
return;
219225
}
220-
logger.trace("Established authentication [{}] for request [{}]", authentication, context.getRequest());
226+
logger.trace("Established authentication [{}] for cross cluster request [{}]", authentication, context.getRequest());
221227
listener.onResponse(authentication);
222228
}
223229
}

‎x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authz/store/RoleDescriptorStore.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -139,6 +139,11 @@ public void resolveCrossClusterAccessRoleReference(
139139
) {
140140
final Set<RoleDescriptor> roleDescriptors = crossClusterAccessRoleReference.getRoleDescriptorsBytes().toRoleDescriptors();
141141
if (roleDescriptors.isEmpty()) {
142+
logger.debug(
143+
() -> "Cross cluster access role reference ["
144+
+ crossClusterAccessRoleReference.id()
145+
+ "] resolved to an empty role descriptor set."
146+
);
142147
listener.onResponse(RolesRetrievalResult.EMPTY);
143148
return;
144149
}

‎x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/transport/CrossClusterAccessServerTransportFilter.java‎

Lines changed: 31 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,8 @@
77

88
package org.elasticsearch.xpack.security.transport;
99

10+
import org.apache.logging.log4j.LogManager;
11+
import org.apache.logging.log4j.Logger;
1012
import org.elasticsearch.action.ActionListener;
1113
import org.elasticsearch.action.admin.cluster.remote.RemoteClusterNodesAction;
1214
import org.elasticsearch.action.admin.cluster.shards.ClusterSearchShardsAction;
@@ -35,11 +37,15 @@
3537
import java.util.stream.Collectors;
3638
import java.util.stream.Stream;
3739

40+
import static org.elasticsearch.core.Strings.format;
3841
import static org.elasticsearch.transport.RemoteClusterService.REMOTE_CLUSTER_HANDSHAKE_ACTION_NAME;
3942
import static org.elasticsearch.xpack.core.security.authc.CrossClusterAccessSubjectInfo.CROSS_CLUSTER_ACCESS_SUBJECT_INFO_HEADER_KEY;
4043
import static org.elasticsearch.xpack.security.authc.CrossClusterAccessHeaders.CROSS_CLUSTER_ACCESS_CREDENTIALS_HEADER_KEY;
4144

4245
final class CrossClusterAccessServerTransportFilter extends ServerTransportFilter {
46+
47+
private static final Logger logger = LogManager.getLogger(CrossClusterAccessServerTransportFilter.class);
48+
4349
// pkg-private for testing
4450
static final Set<String> ALLOWED_TRANSPORT_HEADERS;
4551
static {
@@ -118,12 +124,17 @@ protected void authenticate(
118124
final ActionListener<Authentication> authenticationListener
119125
) {
120126
if (false == Security.CONFIGURABLE_CROSS_CLUSTER_ACCESS_FEATURE.check(licenseState)) {
121-
authenticationListener.onFailure(
127+
onFailureWithDebugLog(
128+
securityAction,
129+
request,
130+
authenticationListener,
122131
LicenseUtils.newComplianceException(Security.CONFIGURABLE_CROSS_CLUSTER_ACCESS_FEATURE.getName())
123132
);
124-
125133
} else if (false == CROSS_CLUSTER_ACCESS_ACTION_ALLOWLIST.contains(securityAction)) {
126-
authenticationListener.onFailure(
134+
onFailureWithDebugLog(
135+
securityAction,
136+
request,
137+
authenticationListener,
127138
new IllegalArgumentException(
128139
"action ["
129140
+ securityAction
@@ -134,7 +145,7 @@ protected void authenticate(
134145
try {
135146
validateHeaders();
136147
} catch (Exception ex) {
137-
authenticationListener.onFailure(ex);
148+
onFailureWithDebugLog(securityAction, request, authenticationListener, ex);
138149
return;
139150
}
140151
crossClusterAccessAuthcService.authenticate(securityAction, request, authenticationListener);
@@ -167,4 +178,20 @@ private void ensureRequiredHeaderInContext(ThreadContext threadContext, String r
167178
}
168179
}
169180

181+
private static void onFailureWithDebugLog(
182+
final String securityAction,
183+
final TransportRequest request,
184+
final ActionListener<Authentication> authenticationListener,
185+
final Exception ex
186+
) {
187+
logger.debug(
188+
() -> format(
189+
"Cross cluster access request [%s] for action [%s] rejected before authentication",
190+
request.getClass(),
191+
securityAction
192+
),
193+
ex
194+
);
195+
authenticationListener.onFailure(ex);
196+
}
170197
}

‎x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/transport/RemoteClusterCredentialsResolver.java‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -42,5 +42,10 @@ public Optional<RemoteClusterCredentials> resolve(final String clusterAlias) {
4242
}
4343
}
4444

45-
record RemoteClusterCredentials(String clusterAlias, String credentials) {}
45+
record RemoteClusterCredentials(String clusterAlias, String credentials) {
46+
@Override
47+
public String toString() {
48+
return "RemoteClusterCredentials{clusterAlias='" + clusterAlias + "', credentials='::es_redacted::'}";
49+
}
50+
}
4651
}

‎x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/transport/SecurityServerTransportInterceptor.java‎

Lines changed: 56 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -57,6 +57,7 @@
5757
import java.util.Optional;
5858
import java.util.function.Function;
5959

60+
import static org.elasticsearch.core.Strings.format;
6061
import static org.elasticsearch.transport.RemoteClusterPortSettings.REMOTE_CLUSTER_PROFILE;
6162
import static org.elasticsearch.transport.RemoteClusterPortSettings.REMOTE_CLUSTER_SERVER_ENABLED;
6263
import static org.elasticsearch.xpack.core.security.authc.Authentication.VERSION_CROSS_CLUSTER_ACCESS_REALM;
@@ -303,7 +304,7 @@ private <T extends TransportResponse> void sendWithCrossClusterAccessHeaders(
303304
final String remoteClusterAlias = remoteClusterCredentials.clusterAlias();
304305

305306
if (connection.getTransportVersion().before(VERSION_CROSS_CLUSTER_ACCESS_REALM)) {
306-
throw new IllegalArgumentException(
307+
throw illegalArgumentExceptionWithDebugLog(
307308
"Settings for remote cluster ["
308309
+ remoteClusterAlias
309310
+ "] indicate cross cluster access headers should be sent but target cluster version ["
@@ -312,18 +313,27 @@ private <T extends TransportResponse> void sendWithCrossClusterAccessHeaders(
312313
);
313314
}
314315

315-
logger.debug(
316-
"Sending [{}] request to [{}] with cross cluster access headers for [{}] action",
317-
request.getClass(),
318-
remoteClusterAlias,
319-
action
316+
logger.trace(
317+
() -> format(
318+
"Sending [%s] request for [%s] action to [%s] with cross cluster access headers",
319+
request.getClass(),
320+
action,
321+
remoteClusterAlias
322+
)
320323
);
321324

322325
final Authentication authentication = securityContext.getAuthentication();
323326
assert authentication != null : "authentication must be present in security context";
324327

325328
final User user = authentication.getEffectiveSubject().getUser();
326329
if (SystemUser.is(user)) {
330+
logger.trace(
331+
"Request [{}] for action [{}] towards [{}] initiated by the system user. "
332+
+ "Sending request with internal cross cluster access user headers",
333+
request.getClass(),
334+
action,
335+
remoteClusterAlias
336+
);
327337
final var crossClusterAccessHeaders = new CrossClusterAccessHeaders(
328338
remoteClusterCredentials.credentials(),
329339
CrossClusterAccessUser.subjectInfoWithEmptyRoleDescriptors(
@@ -333,14 +343,23 @@ private <T extends TransportResponse> void sendWithCrossClusterAccessHeaders(
333343
);
334344
sendWithCrossClusterAccessHeaders(crossClusterAccessHeaders, connection, action, request, options, handler);
335345
} else if (User.isInternal(user)) {
336-
final String message = "internal user [" + user.principal() + "] should not be used for cross cluster requests";
346+
final String message = "Internal user [" + user.principal() + "] should not be used for cross cluster requests";
337347
assert false : message;
338-
throw new IllegalArgumentException(message);
348+
throw illegalArgumentExceptionWithDebugLog(message);
339349
} else {
340350
authzService.getRoleDescriptorsIntersectionForRemoteCluster(
341351
remoteClusterAlias,
342352
authentication.getEffectiveSubject(),
343353
ActionListener.wrap(roleDescriptorsIntersection -> {
354+
logger.trace(
355+
() -> format(
356+
"Subject [%s] has role descriptors intersection [%s] for action [%s] towards remote cluster [%s]",
357+
authentication.getEffectiveSubject(),
358+
roleDescriptorsIntersection,
359+
action,
360+
remoteClusterAlias
361+
)
362+
);
344363
if (roleDescriptorsIntersection.isEmpty()) {
345364
throw authzService.remoteActionDenied(authentication, action, remoteClusterAlias);
346365
}
@@ -375,6 +394,11 @@ private <T extends TransportResponse> void sendWithCrossClusterAccessHeaders(
375394
contextRestoreHandler.handleException(new SendRequestTransportException(connection.getNode(), action, e));
376395
}
377396
}
397+
398+
private static IllegalArgumentException illegalArgumentExceptionWithDebugLog(String message) {
399+
logger.debug(message);
400+
return new IllegalArgumentException(message);
401+
}
378402
};
379403
}
380404

@@ -541,18 +565,17 @@ public String toString() {
541565
public void messageReceived(T request, TransportChannel channel, Task task) {
542566
try (ThreadContext.StoredContext ctx = threadContext.newStoredContextPreservingResponseHeaders()) {
543567
String profile = channel.getProfileName();
544-
ServerTransportFilter filter = profileFilters.get(profile);
545-
546-
if (filter == null) {
547-
if (TransportService.DIRECT_RESPONSE_PROFILE.equals(profile)) {
548-
// apply the default filter to local requests. We never know what the request is or who sent it...
549-
filter = profileFilters.get("default");
550-
} else {
551-
String msg = "transport profile [" + profile + "] is not associated with a transport filter";
552-
throw new IllegalStateException(msg);
553-
}
554-
}
568+
ServerTransportFilter filter = getServerTransportFilter(profile);
555569
assert filter != null;
570+
assert request != null;
571+
logger.trace(
572+
() -> format(
573+
"Applying transport filter [%s] for transport profile [%s] on request [%s]",
574+
filter.getClass(),
575+
profile,
576+
request.getClass()
577+
)
578+
);
556579

557580
final AbstractRunnable receiveMessage = getReceiveRunnable(request, channel, task);
558581
final ActionListener<Void> filterListener;
@@ -591,6 +614,20 @@ public void onResponse(Void unused) {
591614

592615
}
593616
}
617+
618+
private ServerTransportFilter getServerTransportFilter(String profile) {
619+
final ServerTransportFilter filter = profileFilters.get(profile);
620+
if (filter != null) {
621+
return filter;
622+
}
623+
if (TransportService.DIRECT_RESPONSE_PROFILE.equals(profile)) {
624+
// apply the default filter to local requests. We never know what the request is or who sent it...
625+
return profileFilters.get("default");
626+
} else {
627+
String msg = "transport profile [" + profile + "] is not associated with a transport filter";
628+
throw new IllegalStateException(msg);
629+
}
630+
}
594631
}
595632

596633
private abstract static class AbstractFilterListener implements ActionListener<Void> {

0 commit comments

Comments
 (0)