Skip to content

NPE in TransformingAsyncResponseHandler#onError #1812

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
ktulinger opened this issue May 4, 2020 · 15 comments
Closed

NPE in TransformingAsyncResponseHandler#onError #1812

ktulinger opened this issue May 4, 2020 · 15 comments
Labels
bug This issue is a bug. p2 This is a standard priority issue

Comments

@ktulinger
Copy link

Describe the bug

From time to time, we get an ERROR log from TransformingAsyncResponseHandler telling us that there was an NPE. It does not affect our app in any way, however it feels that it shouldn't throw that.

Expected Behavior

No log record nor NPE.

Current Behavior

We get this log statement after NPE has been raised in aws sdk core

5352c77fa1b2:2020-05-04 09:36:31,681 [speculation-executor-1] ERROR s.a.a.c.i.h.BaseAsyncClientHandler - Error thrown from TransformingAsyncResponseHandler#onError, ignoring.
5352c77fa1b2:java.lang.NullPointerException: null
5352c77fa1b2:	at software.amazon.awssdk.core.internal.http.async.AsyncResponseHandler.onError(AsyncResponseHandler.java:76)
5352c77fa1b2:	at software.amazon.awssdk.core.internal.http.async.CombinedResponseAsyncHttpResponseHandler.onError(CombinedResponseAsyncHttpResponseHandler.java:70)
5352c77fa1b2:	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.lambda$doExecute$3(BaseAsyncClientHandler.java:223)
5352c77fa1b2:	at software.amazon.awssdk.utils.FunctionalUtils.runAndLogError(FunctionalUtils.java:40)
5352c77fa1b2:	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.doExecute(BaseAsyncClientHandler.java:220)
5352c77fa1b2:	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:86)
5352c77fa1b2:	at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52)
5352c77fa1b2:	at software.amazon.awssdk.services.dynamodb.DefaultDynamoDbAsyncClient.query(DefaultDynamoDbAsyncClient.java:2707)
...
(our code)

Steps to Reproduce

I don't know a deterministic way.

Possible Solution

I realize that the NPE comes from AsyncResponseHandler:

    @Override
    public void onError(Throwable err) {
        streamFuture.completeExceptionally(err);
    }

where streamFuture is null, as prepare() has not been called yet.

Context

The context is we're doing an async requests to ddb, and for some requests we may cancel them via future.cancel(). Apart from that we're not doing anything special with our query requests.

Your Environment

AWS-SDK: 2.13.8
Java: 12

@ktulinger ktulinger added bug This issue is a bug. needs-triage This issue or PR still needs to be triaged. labels May 4, 2020
@zoewangg
Copy link
Contributor

zoewangg commented May 5, 2020

Thank you for reporting the issue! We will look into it.

@zoewangg zoewangg removed the needs-triage This issue or PR still needs to be triaged. label May 5, 2020
@adamu
Copy link

adamu commented May 19, 2020

I am also seeing this error when attempting to call SqsAsyncClient.receiveMessage(). In my case, the mesage is not received. The error doesn't occur in in v2.12.0.

ERROR [sof.ama.aws.cor.int.han.BaseAsyncClientHandler] (executor-thread-1) Error thrown from TransformingAsyncResponseHandler#onError, ignoring.: java.lang.NullPointerException
	at software.amazon.awssdk.core.internal.http.async.AsyncResponseHandler.onError(AsyncResponseHandler.java:76)
	at software.amazon.awssdk.core.internal.http.async.CombinedResponseAsyncHttpResponseHandler.onError(CombinedResponseAsyncHttpResponseHandler.java:70)
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.lambda$doExecute$3(BaseAsyncClientHandler.java:223)
	at software.amazon.awssdk.utils.FunctionalUtils.runAndLogError(FunctionalUtils.java:40)
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.doExecute(BaseAsyncClientHandler.java:220)
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:86)
	at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52)
	at software.amazon.awssdk.services.sqs.DefaultSqsAsyncClient.receiveMessage(DefaultSqsAsyncClient.java:1149)

@dazito
Copy link

dazito commented Jun 29, 2020

Any news regarding this issue?
This is also happening to me on the S3 client and in my case it fails to upload the file to S3.
Stack trace:

s.a.a.c.i.h.BaseAsyncClientHandler       : Error thrown from TransformingAsyncResponseHandler#onError, ignoring.

java.lang.NullPointerException: null
	at software.amazon.awssdk.core.internal.http.async.AsyncResponseHandler.onError(AsyncResponseHandler.java:76) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.lambda$doExecute$3(BaseAsyncClientHandler.java:223) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.utils.FunctionalUtils.runAndLogError(FunctionalUtils.java:40) ~[utils-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.doExecute(BaseAsyncClientHandler.java:220) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:86) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52) ~[aws-core-2.13.26.jar:na]
	at software.amazon.awssdk.services.s3.DefaultS3AsyncClient.putObject(DefaultS3AsyncClient.java:7762) ~[s3-2.13.26.jar:na]
	(...)

software.amazon.awssdk.core.exception.SdkClientException: null
	at software.amazon.awssdk.core.exception.SdkClientException$BuilderImpl.build(SdkClientException.java:98) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.AmazonAsyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonAsyncHttpClient.java:185) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.invoke(BaseAsyncClientHandler.java:262) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.doExecute(BaseAsyncClientHandler.java:204) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.handler.BaseAsyncClientHandler.execute(BaseAsyncClientHandler.java:86) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.awscore.client.handler.AwsAsyncClientHandler.execute(AwsAsyncClientHandler.java:52) ~[aws-core-2.13.26.jar:na]
	at software.amazon.awssdk.services.s3.DefaultS3AsyncClient.putObject(DefaultS3AsyncClient.java:7762) ~[s3-2.13.26.jar:na]
	(...)
Caused by: software.amazon.awssdk.core.exception.SdkInterruptedException: null
	at software.amazon.awssdk.core.internal.http.InterruptMonitor.checkInterrupted(InterruptMonitor.java:40) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApplyTransactionIdStage.execute(ApplyTransactionIdStage.java:43) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApplyTransactionIdStage.execute(ApplyTransactionIdStage.java:29) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.13.26.jar:na]
	at software.amazon.awssdk.core.internal.http.AmazonAsyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonAsyncHttpClient.java:181) ~[sdk-core-2.13.26.jar:na]
	... 12 common frames omitted

Downgrading to version 2.5.8 works fine.

@pavelkuchin
Copy link

Same issue here

@ohshazbot
Copy link

I bit this pretty hard and consistently. Root cause ended up being because I didn't setup an Xray segment for the thread the call was being made in so the call was failing with the xray interceptor in the sqs client, but I was only able to find that out by repackaging the aws sdk code with a println in AsyncResponseHandler.onError. I would say that this is pretty unusable in it's current form :'(

@RealTYPICAL
Copy link

This reproduced the issue consistently for me:

S3AsyncClient s3AsyncClient = S3AsyncClient.create();

Thread thread = new Thread(() -> s3AsyncClient.copyObject(CopyObjectRequest.builder().build()));

thread.interrupt();
thread.start();
thread.join();

I would expect this to throw an AbortedException/CancellationException/InterruptedException however due to the bug it's a NullPointerException.

@Jamalarm
Copy link

We are also seeing this error frequently using the Kinesis library during a putRecords operation. A fix would be appreciated.

@elrob
Copy link

elrob commented Aug 30, 2021

also experiencing this with latest SqsAsyncClient with sdk version: 2.17.29 and Java 11

aws-sdk-java-automation pushed a commit that referenced this issue Nov 3, 2021

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature. The key has expired.
Exclude connectchat from japicmp check
@OliverGavin
Copy link

For anyone else who landed here that is also using Reactor (and was confused by the logs they were seeing) or who might be incorrectly using the SDK;

I had code similar to this:

byte[] data = ...	
String key = ...
CompletableFuture<PutObjectResponse> future = client.putObject(	
       PutObjectRequest.builder().bucket(bucket).key(key).build(),	
       AsyncRequestBody.fromBytes(data)	

);
return Mono.fromFuture(future)
          .retryWhen(...)	
          .doOnSuccess(res -> {...})	
          .onErrorResume((throwable) -> {...});

The issue is that Mono.fromFuture(future) will not re-execute the already completed future (which failed).
Subsequent retries will then also fail for the same reason.

PutObjectRequest request = PutObjectRequest.builder().bucket(bucket).key(key).build();	
AsyncRequestBody requestBody = AsyncRequestBody.fromBytes(data);	

return Mono.defer(() -> {	
  // Defer the creation of the future until subscription.	
  // This allows retries to create a new future on each attempt.	
  CompletableFuture<PutObjectResponse> future = client.putObject(request, requestBody);	
  return Mono.fromFuture(future);	
})
.retryWhen(...)	
.doOnSuccess(res -> {...})	
.onErrorResume((throwable) -> {...});

The above code uses Mono.defer() to delay the creation of the CompletableFuture and allows retries to create a new future on each attempt.

Now of course this does not fix the underlying issue with the SDK which is logging a misleading/unnecessary error - just thought this would be helpful for others who might also have been using the SDK wrong.

I think I have a patch for that though!
I was able to stop the NullPointerException but I need to write some tests and validate my fix isn't breaking anything first.

@yasminetalby yasminetalby added the p2 This is a standard priority issue label Nov 12, 2022
@jenshoffmann1331
Copy link

Hey AWS. This issue is open for about 3 years and we are still affected by this in one of our production systems. Can you please give us a timeline for when this will be fixed? Thank you so much!

@yasminetalby
Copy link

Hello @jenshoffmann1331 ,

Thank you very much for reaching out. We unfortunately do not have any current publicly available timeline. I will bring this issue back up for discussion.
Are you able to work around this?

Best,

Yasmine

@artembilan
Copy link

Strange that this is still not fixed.
I believe the problem is here in the BaseAsyncClientHandler.doExecute():

  invoke(marshalled,
                       finalizeSdkHttpRequestContext.asyncRequestBody().orElse(null),
                       inputT,
                       executionContext,
                       new AsyncAfterTransmissionInterceptorCallingResponseHandler<>(asyncResponseHandler,
                                                                                     executionContext));

That new AsyncAfterTransmissionInterceptorCallingResponseHandler() is never prepare()d.

Unfortunately we cannot override AwsAsyncClientHandler to workaround the problem:

    protected DefaultDynamoDbAsyncClient(SdkClientConfiguration clientConfiguration) {
        this.clientHandler = new AwsAsyncClientHandler(clientConfiguration);

I really would like to know the reason behind my failure instead of just plain NPE...

Thanks for understanding!

@seantsb
Copy link

seantsb commented Nov 7, 2023

@debora-ito
Copy link
Member

Yes this should be fixed now, thank you @seantsb for pointing out.

If anyone is still experiencing these NPEs, please upgrade your SDK version (version 2.21.1 includes the fix, but latest is best) and open a new issue.

Copy link

This issue is now closed. Comments on closed issues are hard for our team to see.
If you need more assistance, please open a new issue that references this one.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug This issue is a bug. p2 This is a standard priority issue
Projects
None yet