feat: make AWS SDK log retries at DEBUG or TRACE levels

[pdecat]

With this change, the following messages are logged:

# grep "retrying request" .steampipe/logs/plugin-2023-11-14.log
2023-11-14 05:14:18.020 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 2
2023-11-14 05:14:19.400 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 2
2023-11-14 05:14:19.993 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 3
2023-11-14 05:14:23.015 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 2
2023-11-14 05:14:26.211 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 2
2023-11-14 05:14:26.411 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 2
2023-11-14 05:14:28.417 UTC [DEBUG] steampipe-plugin-aws.plugin: [DEBUG] 1699938850561: retrying request CloudFront/ListTagsForResource, attempt 2

[github-actions]

This PR is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 30 days.

[pdecat]

Not stale.

[ParthaI]

@pdecat, apologies for the delayed response, and thank you for submitting the PR.

We have a few questions for clarification:

• How do other well-known packages implementing AWS SDK Go v2 handle logging or customizing log levels in similar situations?
• What guidance or recommendations, if any, are provided in the AWS SDK Go v2 documentation or README regarding this?
• Did you reference any existing code or documentation while deciding to add this feature?
• Additionally, could you kindly address the existing conflict in this PR?

Thanks!

[pdecat]

Hi @ParthaI,

from memory (it's been a while 🙂), I only referred to the smithy-go logging documentation available inline https://github.com/aws/smithy-go/blob/main/logging/logger.go (Apache 2.0 license).

I just took a look at the AWS terraform provider (still MPL 2.0 license), and it does not seem to use Smithy's LogRetries feature.

Rebased and fixed the conflicts.

[pdecat]

FWIW, when debugging rate limits issues, I'm using a slightly modified version of this PR as Steampipe's DEBUG log level is already a bit too verbose to follow the AWS API requests. Also, I'm logging request/response bodies:

diff --git a/aws/service.go b/aws/service.go
index 1e68824c..dca46b3a 100644
--- a/aws/service.go
+++ b/aws/service.go
@@ -1950,10 +1950,10 @@ func getBaseClientForAccountUncached(ctx context.Context, d *plugin.QueryData, h
                configOptions = append(configOptions, config.WithCredentialsProvider(provider))
        }

-       if plugin.Logger(ctx).GetLevel() <= hclog.Debug {
+       if plugin.Logger(ctx).GetLevel() <= hclog.Info {
                logger := plugin.Logger(ctx)
                configOptions = append(configOptions, config.WithLogger(NewHCLoggerToSmithyLoggerWrapper(&logger)))
-               configOptions = append(configOptions, config.WithClientLogMode(aws.LogRetries))
+               configOptions = append(configOptions, config.WithClientLogMode(aws.LogRequestWithBody|aws.LogResponseWithBody|aws.LogRetries))
        }

        plugin.Logger(ctx).Info("getBaseClientForAccountUncached", "connection_name", d.Connection.Name, "status", "loading_config")
@@ -2030,7 +2030,7 @@ type HCLoggerToSmithyLoggerWrapper struct {
 }

 func (logger *HCLoggerToSmithyLoggerWrapper) Logf(classification logging.Classification, format string, v ...interface{}) {
-       (*logger.hclogger).Debug(fmt.Sprintf(format, v...))
+       (*logger.hclogger).Info(fmt.Sprintf(format, v...))
 }

 func NewHCLoggerToSmithyLoggerWrapper(l *hclog.Logger) *HCLoggerToSmithyLoggerWrapper {

Not sure how this could be upstreamed, maybe by introducing additional configuration settings or environment variables.

[pdecat]

Searching with Google, I just stumbled on this usage of smithy-go's LogRetries in hashicorp/aws-sdk-go-base (MPL 2.0 licensed): https://github.com/hashicorp/aws-sdk-go-base/blob/v2.0.0-beta.46/aws_config.go#L376-L382

[ParthaI]

Thanks for sharing helpful insights, @pdecat.

• According to the AWS Go SDK V2 documentation, we can track or toggle logging of specific SDK events using ClientLogMode on the client level.
• The AWS SDK internally uses the smithy-go package for logging purposes.
• ClientLogMode supports logging for various SDK events such as LogRetries, LogRequest, LogRequestWithBody, LogResponse, LogResponseWithBody, LogDeprecatedUsage, LogRequestEventMessage, and LogResponseEventMessage.
• I believe we should rely on the default logging mechanism provided by the AWS SDK. In the future, if we need to log any additional AWS SDK events, we can easily accomplish this using ClientLogMode.
• The AWS SDK only supports WARN and DEBUG log levels. However, Steampipe uses go-hclog to achieve different log levels such as TRACE, INFO, ERROR, NOLEVEL, and OFF.
• With the current changes in this PR, we can enable logging of retries by setting the Steampipe log level to TRACE or DEBUG. If we want to enable logging in any other log level supported by Steampipe, we can modify the code accordingly.

@cbruno10 / @bigdatasourav, your suggestions and opinions would be greatly appreciated!

Thank you!

[bigdatasourav]

@pdecat, Could you please resolve the conflict?

[pdecat]

Sure, rebased on main.