awslabs / aws-sdk-kotlin

Multiplatform AWS SDK for Kotlin
Apache License 2.0
411 stars 49 forks source link

NullPointerException with getObject #1322

Closed jingyouu closed 1 month ago

jingyouu commented 5 months ago

Describe the bug

I run the following code (same as the example) to fetch s3 bucket file

S3Client{region = "us-east-1"}.use{ s3 -> s3.getObject(request){ //do nothing to make sure the error is not coming from my logic } }

And it always throw the error below when I first run the application If I added a retry line to call the function again, it works as expected in the second call.

java.lang.NullPointerException: Cannot invoke "java.util.Map.size()" because "m" is null at java.base/java.util.HashMap.putMapEntries(HashMap.java:495) at java.base/java.util.HashMap.putAll(HashMap.java:783) at java.base/java.util.Collections$SynchronizedMap.putAll(Collections.java:2682) at ch.qos.logback.classic.util.LogbackMDCAdapter.setContextMap(LogbackMDCAdapter.java:197) at org.slf4j.MDC.setContextMap(MDC.java:264) at aws.smithy.kotlin.runtime.telemetry.logging.slf4j.Slf4j1xLogRecordBuilderAdapter.emit(Slf4j1xLoggerAdapter.kt:67) at aws.smithy.kotlin.runtime.telemetry.logging.CoroutineContextLogExtKt.log(CoroutineContextLogExt.kt:93) at aws.smithy.kotlin.runtime.telemetry.logging.CoroutineContextLogExtKt.debug(CoroutineContextLogExt.kt:189) at aws.smithy.kotlin.runtime.telemetry.logging.ContextAwareLogger.debug(CoroutineContextLogExt.kt:244) at aws.smithy.kotlin.runtime.telemetry.logging.Logger$DefaultImpls.debug$default(Logger.kt:29) at aws.smithy.kotlin.runtime.identity.IdentityProviderChain$resolve$suspendImpl$$inlined$withSpan$default$1.invokeSuspend(CoroutineContextTraceExt.kt:138) at aws.smithy.kotlin.runtime.identity.IdentityProviderChain$resolve$suspendImpl$$inlined$withSpan$default$1.invoke(CoroutineContextTraceExt.kt) at aws.smithy.kotlin.runtime.identity.IdentityProviderChain$resolve$suspendImpl$$inlined$withSpan$default$1.invoke(CoroutineContextTraceExt.kt) at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:89) at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext(Builders.common.kt:165) at kotlinx.coroutines.BuildersKt.withContext(Unknown Source) at aws.smithy.kotlin.runtime.identity.IdentityProviderChain.resolve$suspendImpl(IdentityProviderChain.kt:93) at aws.smithy.kotlin.runtime.identity.IdentityProviderChain.resolve(IdentityProviderChain.kt) at aws.smithy.kotlin.runtime.auth.awscredentials.CredentialsProviderChain.resolve(CredentialsProviderChain.kt:22) at aws.smithy.kotlin.runtime.identity.IdentityProvider$DefaultImpls.resolve$default(IdentityProvider.kt:22) at aws.smithy.kotlin.runtime.auth.awscredentials.CachedCredentialsProvider$resolve$3.invokeSuspend(CachedCredentialsProvider.kt:63) at aws.smithy.kotlin.runtime.auth.awscredentials.CachedCredentialsProvider$resolve$3.invoke(CachedCredentialsProvider.kt) at aws.smithy.kotlin.runtime.auth.awscredentials.CachedCredentialsProvider$resolve$3.invoke(CachedCredentialsProvider.kt) at aws.smithy.kotlin.runtime.util.CachedValue.getOrLoad(CachedValue.kt:80) at aws.smithy.kotlin.runtime.auth.awscredentials.CachedCredentialsProvider.resolve(CachedCredentialsProvider.kt:61) at aws.sdk.kotlin.runtime.auth.credentials.DefaultChainCredentialsProvider.resolve(DefaultChainCredentialsProvider.kt:74) at aws.sdk.kotlin.runtime.auth.credentials.internal.ManagedCredentialsProvider.resolve(ManagedCredentialsProvider.kt) at aws.smithy.kotlin.runtime.http.operation.AuthHandler.call(SdkOperationExecution.kt:283) at aws.smithy.kotlin.runtime.http.operation.AuthHandler.call(SdkOperationExecution.kt:259) at aws.sdk.kotlin.runtime.http.middleware.AwsRetryHeaderMiddleware.handle(AwsRetryHeaderMiddleware.kt:39) at aws.sdk.kotlin.runtime.http.middleware.AwsRetryHeaderMiddleware.handle(AwsRetryHeaderMiddleware.kt:26) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.io.middleware.Phase.handle(Phase.kt:67) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware.tryAttempt-BWLJW6A(RetryMiddleware.kt:78) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware.access$tryAttempt-BWLJW6A(RetryMiddleware.kt:31) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware$handle$result$outcome$1$invokeSuspend$$inlined$withSpan$default$1.invokeSuspend(CoroutineContextTraceExt.kt:136) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware$handle$result$outcome$1$invokeSuspend$$inlined$withSpan$default$1.invoke(CoroutineContextTraceExt.kt) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware$handle$result$outcome$1$invokeSuspend$$inlined$withSpan$default$1.invoke(CoroutineContextTraceExt.kt) at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:89) at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext(Builders.common.kt:165) at kotlinx.coroutines.BuildersKt.withContext(Unknown Source) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware$handle$result$outcome$1.invokeSuspend(RetryMiddleware.kt:134) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware$handle$result$outcome$1.invoke(RetryMiddleware.kt) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware$handle$result$outcome$1.invoke(RetryMiddleware.kt) at aws.smithy.kotlin.runtime.retries.StandardRetryStrategy.doTryLoop(StandardRetryStrategy.kt:60) at aws.smithy.kotlin.runtime.retries.StandardRetryStrategy.retry$suspendImpl(StandardRetryStrategy.kt:40) at aws.smithy.kotlin.runtime.retries.StandardRetryStrategy.retry(StandardRetryStrategy.kt) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware.handle(RetryMiddleware.kt:46) at aws.smithy.kotlin.runtime.http.middleware.RetryMiddleware.handle(RetryMiddleware.kt:31) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.http.operation.MutateHandler.call(SdkOperationExecution.kt:256) at aws.smithy.kotlin.runtime.http.operation.MutateHandler.call(SdkOperationExecution.kt:253) at aws.smithy.kotlin.runtime.io.middleware.ModifyRequestMiddleware.handle(ModifyRequest.kt:26) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.io.middleware.ModifyRequestMiddleware.handle(ModifyRequest.kt:26) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.io.middleware.Phase.handle(Phase.kt:67) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.http.operation.SerializeHandler.call(SdkOperationExecution.kt:249) at aws.smithy.kotlin.runtime.http.operation.SerializeHandler.call(SdkOperationExecution.kt:231) at aws.smithy.kotlin.runtime.http.operation.InitializeHandler.call(SdkOperationExecution.kt:228) at aws.smithy.kotlin.runtime.io.middleware.Phase.handle(Phase.kt:63) at aws.smithy.kotlin.runtime.io.middleware.DecoratedHandler.call(Middleware.kt:44) at aws.smithy.kotlin.runtime.http.operation.OperationHandler.call(SdkOperationExecution.kt:208) at aws.smithy.kotlin.runtime.http.operation.OperationHandler.call(SdkOperationExecution.kt:200) at aws.smithy.kotlin.runtime.http.operation.SdkHttpOperationKt$execute$$inlined$withSpan$1.invokeSuspend(CoroutineContextTraceExt.kt:126) at aws.smithy.kotlin.runtime.http.operation.SdkHttpOperationKt$execute$$inlined$withSpan$1.invoke(CoroutineContextTraceExt.kt) at aws.smithy.kotlin.runtime.http.operation.SdkHttpOperationKt$execute$$inlined$withSpan$1.invoke(CoroutineContextTraceExt.kt) at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:89) at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext(Builders.common.kt:165) at kotlinx.coroutines.BuildersKt.withContext(Unknown Source) at aws.smithy.kotlin.runtime.http.operation.SdkHttpOperationKt.execute(SdkHttpOperation.kt:179) at aws.sdk.kotlin.services.s3.DefaultS3Client.getObject(DefaultS3Client.kt:2078) at com.saks.product.detail.url.redirect.FetchRedirectDataService.fetchRedirectProductID$suspendImpl(FetchRedirectDataService.kt:56) at com.saks.product.detail.url.redirect.FetchRedirectDataService.fetchRedirectProductID(FetchRedirectDataService.kt) at com.saks.product.detail.url.redirect.FetchRedirectDataService$updateRedirectProductIDSet$1.invokeSuspend(FetchRedirectDataService.kt:31) at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:274) at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85) at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59) at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source) at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38) at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source) at com.saks.product.detail.url.redirect.FetchRedirectDataService.updateRedirectProductIDSet(FetchRedirectDataService.kt:29) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-06-05 13:04:38,755 ERROR [scheduling-1] c.s.p.d.u.r.FetchRedirectDataService::fetchRedirectProductID$suspendImpl:75 - Fetch object from s3Client failed with error message: kotlin.Unit 2024-06-05 13:04:38,755 DEBUG [scheduling-1] c.s.p.d.u.r.FetchRedirectDataService::invokeSuspend:32 - RedirectURLSet size: 0

Expected behavior

It should return the s3 file content consistently.

Current behavior

The NPE error seems to be coming from the SDK? Or dependencies?

Steps to Reproduce

Code provided above.

Possible Solution

No response

Context

No response

AWS SDK for Kotlin version

aws.sdk.kotlin:s3:1.0.0

Platform (JVM/JS/Native)

kotlin jvm 1.8.0

Operating system and version

macOS 14.5

jingyouu commented 5 months ago

Looks like its similar to this issue https://github.com/awslabs/aws-sdk-kotlin/issues/1256 but I am not able to resolve it with upgrading logback as the comment suggested

ianbotsf commented 5 months ago

Hi @jingyouu, I'm not able to reproduce this issue. Can you share what (if any) logging dependencies and configuration your code uses?

jingyouu commented 5 months ago

org.slf4j:slf4j-api:1.7.36 org.slf4j:slf4j-jul:1.7.36 org.apache.logging.log4j:log4j-api:2.19.0 org.apache.logging.log4j:log4j-to-slf4j:2.19.0 ch.qos.logback:logback-classic:1.2.11 ch.qos.logback:logback-core:1.2.11

ianbotsf commented 5 months ago

Interesting. You're pulling in slf4j-api:1.7.36 but the SDK already depends on slf4j-api:2.0.9. Are you forcing dependency resolution to the earlier version?

I've tried reproducing this issue, both with and without explicitly dependency resolution, and I still can't trigger the error you're seeing. Here's the relevant parts of my build.gradle.kts:

plugins {
    kotlin("jvm") version "1.9.24"
}

configurations.all {
    resolutionStrategy {
        // Explicitly downgrade to slf4j-api 1.7.36. Test still succeeds if this is commented out.
        force("org.slf4j:slf4j-api:1.7.36")
    }
}

dependencies {
    implementation(kotlin("stdlib-jdk8"))
    implementation("aws.sdk.kotlin:s3:1.2.27")

    implementation("org.slf4j:slf4j-api:1.7.36")
    implementation("org.slf4j:slf4j-jcl:1.7.36")
    implementation("org.apache.logging.log4j:log4j-api:2.19.0")
    implementation("org.apache.logging.log4j:log4j-to-slf4j:2.19.0")
    implementation("ch.qos.logback:logback-classic:1.2.11")
    implementation("ch.qos.logback:logback-core:1.2.11")
}

What does your build script look like? Is there any additional logging configuration in your environment?

jingyouu commented 5 months ago

I have plugins { id("org.springframework.boot") version "2.6.6" kotlin("jvm") version "1.8.0" kotlin("plugin.spring") version "1.6.0" }

The rest seems to be the same, but i am not enforcing to earlier version in gradle. I think the slf4j and logback version all comes from springboot 2.6.6

ianbotsf commented 5 months ago

Ah, I see. Spring Boot may bring along a lot of dependencies and/or customize the logging configuration in ways that could affect the AWS SDK. Can you share a minimal reproducible example, including a build script and logging configuration but without extraneous dependencies which are unrelated to the issue?

jingyouu commented 5 months ago

Thank you for looking into this! I reduced the build to the following `plugins { id("org.springframework.boot") version "2.6.6" id("io.spring.dependency-management") version "1.0.11.RELEASE" kotlin("jvm") version "1.8.0" kotlin("plugin.spring") version "1.6.0" }

java.sourceCompatibility = JavaVersion.VERSION_17

dependencies { implementation("org.springframework.boot:spring-boot-starter-webflux") implementation("org.springframework.boot:spring-boot-starter-actuator") implementation("org.springframework.boot:spring-boot-starter-data-redis-reactive") implementation("aws.sdk.kotlin:s3:1.2.27") implementation("com.squareup.okhttp3:okhttp:5.0.0-alpha.10")

}`

Apart for that I only have a main class calling the application and a service class with a function to call S3Client{region = "us-east-1"}.use{ s3 -> s3.getObject(request){ //do nothing to make sure the error is not coming from my logic } }

ianbotsf commented 5 months ago

Thank you for the full build definition, that was enough to reproduce it on my end. Looks like the Logback MDC adapter doesn't handle null context maps very well. Fortunately, that's a quick fix on our side. I'll have a PR up shortly!

jingyouu commented 5 months ago

Wow that would be great! Thanks a lot for your help!

ianbotsf commented 5 months ago

Actually, I started working on a hypothetical fix yesterday and unintentionally shipped it with another change. (I had intended to wait for a full repro before shipping it but my git add was a little too powerful apparently. 😶) So the fix should already published and available in aws-sdk-kotlin version v1.2.28.

Can you regress the issue on the latest version and let me know if that solves the problem for you?

jingyouu commented 5 months ago

I am still getting the same error with v1.2.28 :(

ianbotsf commented 3 months ago

@jingyouu, I'm sorry to hear you're still seeing the error with a later version of the SDK (and that it took so long to get back to you). Can you please post a copy of the most recent stack trace you're seeing?

ianbotsf commented 1 month ago

@jingyouu Are you still seeing this issue? If so, can you provide the most recent stack trace?

jingyouu commented 1 month ago

Thanks for your reply. The issue is resolved with v1.2.28 and fixing some other dependencies I believe.

On Tue, Oct 15, 2024 at 2:21 PM Ian Botsford @.***> wrote:

@jingyouu https://github.com/jingyouu Are you still seeing this issue? If so, can you provide the most recent stack trace?

— Reply to this email directly, view it on GitHub https://github.com/awslabs/aws-sdk-kotlin/issues/1322#issuecomment-2414712784, or unsubscribe https://github.com/notifications/unsubscribe-auth/ALLH6QXZ3OF4WTJJX4N2XEDZ3VMJJAVCNFSM6AAAAABI3EQKL2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMJUG4YTENZYGQ . You are receiving this because you were mentioned.Message ID: @.***>

github-actions[bot] commented 1 month ago

⚠️COMMENT VISIBILITY WARNING⚠️

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.