From 288fd09316dbcc64771653255003a17616f690e2 Mon Sep 17 00:00:00 2001 From: Steve Loughran Date: Fri, 7 Mar 2025 18:41:50 +0000 Subject: [PATCH] HADOOP-19455. S3A: SDK client to log metrics at TRACE Switch is in client; commented out in test log properties; covered in troubleshooting doc Change-Id: If70447d8eb3d3d0e03db5c169cd1aabf844931bd --- .../hadoop/fs/s3a/DefaultS3ClientFactory.java | 12 +++++- .../tools/hadoop-aws/troubleshooting_s3a.md | 42 +++++++++++++++++++ .../src/test/resources/log4j.properties | 3 ++ 3 files changed, 56 insertions(+), 1 deletion(-) diff --git a/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/DefaultS3ClientFactory.java b/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/DefaultS3ClientFactory.java index 7b686130ce30c..a0b23103b6f88 100644 --- a/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/DefaultS3ClientFactory.java +++ b/hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/DefaultS3ClientFactory.java @@ -29,6 +29,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.event.Level; import software.amazon.awssdk.awscore.util.AwsHostNameUtils; import software.amazon.awssdk.core.client.config.ClientOverrideConfiguration; import software.amazon.awssdk.core.client.config.SdkAdvancedClientOption; @@ -38,6 +39,7 @@ import software.amazon.awssdk.http.auth.spi.scheme.AuthScheme; import software.amazon.awssdk.http.nio.netty.NettyNioAsyncHttpClient; import software.amazon.awssdk.identity.spi.AwsCredentialsIdentity; +import software.amazon.awssdk.metrics.LoggingMetricPublisher; import software.amazon.awssdk.regions.Region; import software.amazon.awssdk.s3accessgrants.plugin.S3AccessGrantsPlugin; import software.amazon.awssdk.services.s3.S3AsyncClient; @@ -211,12 +213,20 @@ private , ClientT> Build final ClientOverrideConfiguration.Builder override = createClientOverrideConfiguration(parameters, conf); - S3BaseClientBuilder s3BaseClientBuilder = builder + S3BaseClientBuilder s3BaseClientBuilder = builder .overrideConfiguration(override.build()) .credentialsProvider(parameters.getCredentialSet()) .disableS3ExpressSessionAuth(!parameters.isExpressCreateSession()) .serviceConfiguration(serviceConfiguration); + if (LOG.isTraceEnabled()) { + // if this log is set to debug then we turn on logging of SDK metrics. + // The metrics itself will log at info; it is just that reflection work + // would be needed to change that setting safely for shaded and unshaded aws artifacts. + s3BaseClientBuilder.overrideConfiguration(o -> + o.addMetricPublisher(LoggingMetricPublisher.create())); + } + if (conf.getBoolean(HTTP_SIGNER_ENABLED, HTTP_SIGNER_ENABLED_DEFAULT)) { // use an http signer through an AuthScheme final AuthScheme signer = diff --git a/hadoop-tools/hadoop-aws/src/site/markdown/tools/hadoop-aws/troubleshooting_s3a.md b/hadoop-tools/hadoop-aws/src/site/markdown/tools/hadoop-aws/troubleshooting_s3a.md index 55ebf7614c17f..2b39f0572123a 100644 --- a/hadoop-tools/hadoop-aws/src/site/markdown/tools/hadoop-aws/troubleshooting_s3a.md +++ b/hadoop-tools/hadoop-aws/src/site/markdown/tools/hadoop-aws/troubleshooting_s3a.md @@ -1359,6 +1359,48 @@ execchain.MainClientExec (MainClientExec.java:execute(284)) - Connection can be ``` + +To log the output of the AWS SDK metrics, set the log +`org.apache.hadoop.fs.s3a.DefaultS3ClientFactory` to `TRACE`. +This will then turn on logging of the internal SDK metrics.4 + +These will actually be logged at INFO in the log +``` +software.amazon.awssdk.metrics.LoggingMetricPublisher +``` + +```text +INFO metrics.LoggingMetricPublisher (LoggerAdapter.java:info(165)) - Metrics published: +MetricCollection(name=ApiCall, metrics=[ +MetricRecord(metric=MarshallingDuration, value=PT0.000092041S), +MetricRecord(metric=RetryCount, value=0), +MetricRecord(metric=ApiCallSuccessful, value=true), +MetricRecord(metric=OperationName, value=DeleteObject), +MetricRecord(metric=EndpointResolveDuration, value=PT0.000132792S), +MetricRecord(metric=ApiCallDuration, value=PT0.064890875S), +MetricRecord(metric=CredentialsFetchDuration, value=PT0.000017458S), +MetricRecord(metric=ServiceEndpoint, value=https://buckets3.eu-west-2.amazonaws.com), +MetricRecord(metric=ServiceId, value=S3)], children=[ +MetricCollection(name=ApiCallAttempt, metrics=[ + MetricRecord(metric=TimeToFirstByte, value=PT0.06260225S), + MetricRecord(metric=SigningDuration, value=PT0.000293083S), + MetricRecord(metric=ReadThroughput, value=0.0), + MetricRecord(metric=ServiceCallDuration, value=PT0.06260225S), + MetricRecord(metric=HttpStatusCode, value=204), + MetricRecord(metric=BackoffDelayDuration, value=PT0S), + MetricRecord(metric=TimeToLastByte, value=PT0.064313667S), + MetricRecord(metric=AwsRequestId, value=RKZD44SE5DW91K1G)], children=[ + MetricCollection(name=HttpClient, metrics=[ + MetricRecord(metric=AvailableConcurrency, value=1), + MetricRecord(metric=LeasedConcurrency, value=0), + MetricRecord(metric=ConcurrencyAcquireDuration, value=PT0S), + MetricRecord(metric=PendingConcurrencyAcquires, value=0), + MetricRecord(metric=MaxConcurrency, value=512), + MetricRecord(metric=HttpClientName, value=Apache)], children=[]) + ]) + ]) +``` + ### Enable S3 Server-side Logging The [Auditing](auditing) feature of the S3A connector can be used to generate diff --git a/hadoop-tools/hadoop-aws/src/test/resources/log4j.properties b/hadoop-tools/hadoop-aws/src/test/resources/log4j.properties index 7b8dd3c11fcdc..737e4f7eef863 100644 --- a/hadoop-tools/hadoop-aws/src/test/resources/log4j.properties +++ b/hadoop-tools/hadoop-aws/src/test/resources/log4j.properties @@ -102,3 +102,6 @@ log4j.logger.org.apache.hadoop.fs.s3a.S3AStorageStatistics=INFO # services it launches itself. # log4.logger.org.apache.hadoop.service=DEBUG +# log this at trace to trigger enabling the +# log4j.logger.org.apache.hadoop.fs.s3a.DefaultS3ClientFactory=TRACE +