Open Sebo11 opened 6 months ago
Hello, I created a new Micronaut project (version 4.3.1) and tested the behavior again. It still fails occasionally with the same error. However, in the fresh application it only needs 2 attempts instead of 6. I can't explain why exactly as the dependencies and the setup are the same in my opinion.
Don't know if it is worth it to look into it.
Comments on closed issues are hard for our team to see. If you need more assistance, please either tag a team member or open a new issue that references this one. If you wish to keep having a conversation with other community members under this issue feel free to do so.
Hi, thanks for the report! I've set up a local application using Micronaut, but I can't replicate this behavior.
Can you please configure logMode = LogMode.LogRequest
on the client and share some logs (with sensitive information redacted) demonstrating the problematic requests being retried and then finally succeeding? It will help determine what it changing in the request to make it succeed.
Hello, sorry for the late response. Here the requested logs :)
Like always after the sixth request it somehow gets trough. However, like mentioned before it does not happen a lot. Every 20 request or so.
15:24:29.029 [default-nioEventLoopGroup-1-3] DEBUG a.s.k.r.http.operation.AuthHandler - resolved endpoint: Endpoint(uri=https://example-bucket.s3.eu-central-1.amazonaws.com, headers=null, attributes={AttributeKey(aws.smithy.kotlin#endpointAuthSchemes)=[AuthOptionImpl(schemeId=AuthSchemeId(i
d=aws.auth#sigv4), attributes={AttributeKey(aws.smithy.kotlin.signing#AwsSigningRegion)=eu-central-1, AttributeKey(aws.smithy.kotlin.signing#AwsSigningService)=s3, AttributeKey(aws.smithy.kotlin.signing#UseDoubleUriEncode)=false})]})
15:24:29.029 [default-nioEventLoopGroup-1-3] DEBUG a.s.k.r.a.a.DefaultAwsSignerImpl - Calculated signature: 416437ca1204259b13badc097e54b87aab915e307ddc825c48a9d4efa74b20e3
15:24:29.030 [default-nioEventLoopGroup-1-3] DEBUG httpTraceMiddleware - HttpRequest:
GET /?list-type=2&prefix=documents%2Ffc6cb449-326e-4926-b6a7-58599791a0d7
Host: https://example-bucket.s3.eu-central-1.amazonaws.com
User-Agent: aws-sdk-kotlin/1.0.54 ua/2.0 api/s3#1.0.54 os/windows#10.0 lang/kotlin#1.9.22 md/javaVersion#21.0.2 md/jvmName#Java_HotSpotTM_64-Bit_Server_VM md/jvmVersion#21.0.2+13-LTS-58
x-amz-user-agent: aws-sdk-kotlin/1.0.54
amz-sdk-invocation-id: 551be614-830f-4bad-a4b8-56e242692085
amz-sdk-request: attempt=1; max=10
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240226T142429Z
X-Amz-Security-Token: securityToken
Authorization: AWS4-HMAC-SHA256 Credential=AAAAAAAAAAAAAAAAAAAA/20240226/eu-central-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;x-amz-content-sha256;x-amz-date;x-amz-security-token;x-amz-user-agent, Signature=416437ca1204259b13badc097e54b87aab915e307ddc825c48a9d4efa74b20e3
15:24:29.449 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.h.middleware.RetryMiddleware - retrying request, attempt 2
15:24:29.449 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.http.operation.AuthHandler - resolved endpoint: Endpoint(uri=https://https://example-bucket.s3.eu-central-1.amazonaws.com, headers=null, attributes={AttributeKey(aws.smithy.kotlin#endpointAuthSchemes)=[AuthOptionImpl(schemeId=AuthSchemeId(id=
aws.auth#sigv4), attributes={AttributeKey(aws.smithy.kotlin.signing#AwsSigningRegion)=eu-central-1, AttributeKey(aws.smithy.kotlin.signing#AwsSigningService)=s3, AttributeKey(aws.smithy.kotlin.signing#UseDoubleUriEncode)=false})]})
15:24:29.450 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.a.a.DefaultAwsSignerImpl - Calculated signature: 10f692f13983e1b42442bb12f138fbde4ee6f8ea0e1c0fac80bc77b66c6653e1
15:24:29.450 [DefaultDispatcher-worker-13] DEBUG httpTraceMiddleware - HttpRequest:
GET /?list-type=2&prefix=documents%2Ffc6cb449-326e-4926-b6a7-58599791a0d7
Host: https://example-bucket.s3.eu-central-1.amazonaws.com
User-Agent: aws-sdk-kotlin/1.0.54 ua/2.0 api/s3#1.0.54 os/windows#10.0 lang/kotlin#1.9.22 md/javaVersion#21.0.2 md/jvmName#Java_HotSpotTM_64-Bit_Server_VM md/jvmVersion#21.0.2+13-LTS-58
x-amz-user-agent: aws-sdk-kotlin/1.0.54
amz-sdk-invocation-id: 551be614-830f-4bad-a4b8-56e242692085
amz-sdk-request: attempt=2; max=10
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240226T142429Z
X-Amz-Security-Token: securityToken
Authorization: AWS4-HMAC-SHA256 Credential=AAAAAAAAAAAAAAAAAAAA/20240226/eu-central-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;x-amz-content-sha256;x-amz-date;x-amz-security-token;x-amz-user-agent, Signature=10f692f13983e1b42442bb12f138fbde4ee6f8ea0e1c0fac80bc77b66c6653e1
15:24:29.795 [DefaultDispatcher-worker-20] DEBUG a.s.k.r.h.middleware.RetryMiddleware - retrying request, attempt 3
15:24:29.796 [DefaultDispatcher-worker-20] DEBUG a.s.k.r.http.operation.AuthHandler - resolved endpoint: Endpoint(uri=https://https://example-bucket.s3.eu-central-1.amazonaws.com, headers=null, attributes={AttributeKey(aws.smithy.kotlin#endpointAuthSchemes)=[AuthOptionImpl(schemeId=AuthSchemeId(id=
aws.auth#sigv4), attributes={AttributeKey(aws.smithy.kotlin.signing#AwsSigningRegion)=eu-central-1, AttributeKey(aws.smithy.kotlin.signing#AwsSigningService)=s3, AttributeKey(aws.smithy.kotlin.signing#UseDoubleUriEncode)=false})]})
15:24:29.796 [DefaultDispatcher-worker-20] DEBUG a.s.k.r.a.a.DefaultAwsSignerImpl - Calculated signature: f3b55ed40eefbb74e0e41ca9496e1029f8ff351d68fdfaa9cea3c37b1ec427b7
15:24:29.797 [DefaultDispatcher-worker-20] DEBUG httpTraceMiddleware - HttpRequest:
GET /?list-type=2&prefix=documents%2Ffc6cb449-326e-4926-b6a7-58599791a0d7
Host: https://example-bucket.s3.eu-central-1.amazonaws.com
User-Agent: aws-sdk-kotlin/1.0.54 ua/2.0 api/s3#1.0.54 os/windows#10.0 lang/kotlin#1.9.22 md/javaVersion#21.0.2 md/jvmName#Java_HotSpotTM_64-Bit_Server_VM md/jvmVersion#21.0.2+13-LTS-58
x-amz-user-agent: aws-sdk-kotlin/1.0.54
amz-sdk-invocation-id: 551be614-830f-4bad-a4b8-56e242692085
amz-sdk-request: attempt=3; max=10
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240226T142429Z
X-Amz-Security-Token: securityToken
Authorization: AWS4-HMAC-SHA256 Credential=AAAAAAAAAAAAAAAAAAAA/20240226/eu-central-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;x-amz-content-sha256;x-amz-date;x-amz-security-token;x-amz-user-agent, Signature=f3b55ed40eefbb74e0e41ca9496e1029f8ff351d68fdfaa9cea3c37b1ec427b7
15:24:30.066 [DefaultDispatcher-worker-20] DEBUG a.s.k.r.h.middleware.RetryMiddleware - retrying request, attempt 4
15:24:30.067 [DefaultDispatcher-worker-20] DEBUG a.s.k.r.http.operation.AuthHandler - resolved endpoint: Endpoint(uri=https://https://example-bucket.s3.eu-central-1.amazonaws.com, headers=null, attributes={AttributeKey(aws.smithy.kotlin#endpointAuthSchemes)=[AuthOptionImpl(schemeId=AuthSchemeId(id=
aws.auth#sigv4), attributes={AttributeKey(aws.smithy.kotlin.signing#AwsSigningRegion)=eu-central-1, AttributeKey(aws.smithy.kotlin.signing#AwsSigningService)=s3, AttributeKey(aws.smithy.kotlin.signing#UseDoubleUriEncode)=false})]})
15:24:30.068 [DefaultDispatcher-worker-20] DEBUG a.s.k.r.a.a.DefaultAwsSignerImpl - Calculated signature: c46c59d8f3bc4990336f52ebc36fcc8e3b70ce8e037cdf05fcca13aa7ff81937
15:24:30.068 [DefaultDispatcher-worker-20] DEBUG httpTraceMiddleware - HttpRequest:
GET /?list-type=2&prefix=documents%2Ffc6cb449-326e-4926-b6a7-58599791a0d7
Host: https://example-bucket.s3.eu-central-1.amazonaws.com
User-Agent: aws-sdk-kotlin/1.0.54 ua/2.0 api/s3#1.0.54 os/windows#10.0 lang/kotlin#1.9.22 md/javaVersion#21.0.2 md/jvmName#Java_HotSpotTM_64-Bit_Server_VM md/jvmVersion#21.0.2+13-LTS-58
x-amz-user-agent: aws-sdk-kotlin/1.0.54
amz-sdk-invocation-id: 551be614-830f-4bad-a4b8-56e242692085
amz-sdk-request: attempt=4; max=10
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240226T142430Z
X-Amz-Security-Token: securityToken
Authorization: AWS4-HMAC-SHA256 Credential=AAAAAAAAAAAAAAAAAAAA/20240226/eu-central-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;x-amz-content-sha256;x-amz-date;x-amz-security-token;x-amz-user-agent, Signature=c46c59d8f3bc4990336f52ebc36fcc8e3b70ce8e037cdf05fcca13aa7ff81937
15:24:30.315 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
15:24:30.315 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled.
15:24:30.804 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.h.middleware.RetryMiddleware - retrying request, attempt 5
15:24:30.804 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.http.operation.AuthHandler - resolved endpoint: Endpoint(uri=https://https://example-bucket.s3.eu-central-1.amazonaws.com, headers=null, attributes={AttributeKey(aws.smithy.kotlin#endpointAuthSchemes)=[AuthOptionImpl(schemeId=AuthSchemeId(id=
aws.auth#sigv4), attributes={AttributeKey(aws.smithy.kotlin.signing#AwsSigningRegion)=eu-central-1, AttributeKey(aws.smithy.kotlin.signing#AwsSigningService)=s3, AttributeKey(aws.smithy.kotlin.signing#UseDoubleUriEncode)=false})]})
15:24:30.805 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.a.a.DefaultAwsSignerImpl - Calculated signature: 001bf3ba8b261c022ce2f040ad2c5073cf30d5841e7ee312a89842c28c1d2657
15:24:30.805 [DefaultDispatcher-worker-13] DEBUG httpTraceMiddleware - HttpRequest:
GET /?list-type=2&prefix=documents%2Ffc6cb449-326e-4926-b6a7-58599791a0d7
Host: https://example-bucket.s3.eu-central-1.amazonaws.com
User-Agent: aws-sdk-kotlin/1.0.54 ua/2.0 api/s3#1.0.54 os/windows#10.0 lang/kotlin#1.9.22 md/javaVersion#21.0.2 md/jvmName#Java_HotSpotTM_64-Bit_Server_VM md/jvmVersion#21.0.2+13-LTS-58
x-amz-user-agent: aws-sdk-kotlin/1.0.54
amz-sdk-invocation-id: 551be614-830f-4bad-a4b8-56e242692085
amz-sdk-request: attempt=5; max=10
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240226T142430Z
X-Amz-Security-Token: securityToken
Authorization: AWS4-HMAC-SHA256 Credential=AAAAAAAAAAAAAAAAAAAA/20240226/eu-central-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;x-amz-content-sha256;x-amz-date;x-amz-security-token;x-amz-user-agent, Signature=001bf3ba8b261c022ce2f040ad2c5073cf30d5841e7ee312a89842c28c1d2657
15:24:31.931 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.h.middleware.RetryMiddleware - retrying request, attempt 6
15:24:31.933 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.http.operation.AuthHandler - resolved endpoint: Endpoint(uri=https://https://example-bucket.s3.eu-central-1.amazonaws.com, headers=null, attributes={AttributeKey(aws.smithy.kotlin#endpointAuthSchemes)=[AuthOptionImpl(schemeId=AuthSchemeId(id=
aws.auth#sigv4), attributes={AttributeKey(aws.smithy.kotlin.signing#AwsSigningRegion)=eu-central-1, AttributeKey(aws.smithy.kotlin.signing#AwsSigningService)=s3, AttributeKey(aws.smithy.kotlin.signing#UseDoubleUriEncode)=false})]})
15:24:31.934 [DefaultDispatcher-worker-13] DEBUG a.s.k.r.a.a.DefaultAwsSignerImpl - Calculated signature: b443cc2ec0581a82ab2cc410678b2e67eef0a617a718837ac31908d5562f7235
15:24:31.935 [DefaultDispatcher-worker-13] DEBUG httpTraceMiddleware - HttpRequest:
GET /?list-type=2&prefix=documents%2Ffc6cb449-326e-4926-b6a7-58599791a0d7
Host: https://example-bucket.s3.eu-central-1.amazonaws.com
User-Agent: aws-sdk-kotlin/1.0.54 ua/2.0 api/s3#1.0.54 os/windows#10.0 lang/kotlin#1.9.22 md/javaVersion#21.0.2 md/jvmName#Java_HotSpotTM_64-Bit_Server_VM md/jvmVersion#21.0.2+13-LTS-58
x-amz-user-agent: aws-sdk-kotlin/1.0.54
amz-sdk-invocation-id: 551be614-830f-4bad-a4b8-56e242692085
amz-sdk-request: attempt=6; max=10
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20240226T142431Z
X-Amz-Security-Token: securityToken
Authorization: AWS4-HMAC-SHA256 Credential=AAAAAAAAAAAAAAAAAAAA/20240226/eu-central-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;host;x-amz-content-sha256;x-amz-date;x-amz-security-token;x-amz-user-agent, Signature=b443cc2ec0581a82ab2cc410678b2e67eef0a617a718837ac31908d5562f7235
15:24:32.099 [DefaultDispatcher-worker-20] DEBUG httpTraceMiddleware - HttpResponse: 200: OK
Describe the bug
When executing below code it randomly happens that the call to s3 fails with an IO Exception (exception is inserted below). I cannot put a precise number on it but I guess this happens once every 20 request or so. It can be "fixed" when the attempts are upped to more than 5. Because when this happens it failes always exactly 5 times with the 6th attempt going trough somehow.
I cannot explain why this occurs and why it always fails 5 times with the 6th attempt going trough.
with this factory
the resulting exception
Expected behavior
Not failing randomly exactly 5 times when this error occurs.
Current behavior
Like explained before the error which is thrown.
Here with more attempts set going trough
Steps to Reproduce
The framework in use is Micronaut in the version 4.2.2 . The s3 bucket itself has several objects in it and returns with the prefix key 10 elements.
The code was started locally via Gradle (version 8.4) and invoked over the micronaut controoler via Postman. Note that the same behavior is present in the cloud environment.
with this factory
with these build.gradle.kts file
Possible Solution
No response
Context
I want to show the user the s3 objects which the user has saved in the cloud via a web app. However at some point the request fails randomly (locally and in the cloud).
AWS Kotlin SDK version used
1.0.54
Platform (JVM/JS/Native)
Java 21.0.2 with gradle 8.4
Operating System and version
Windows 10 Pro