Socket closed and null pointer exception when read/write to S3

[espen-grodem]

After upgrading to WS SDK for Java 2.x, we have occasionally gotten Socket closed exceptions when writing to S3. The error not on every write but quite often. Our client is defined as following

private S3Client getS3Client(IConfiguration configuration) {
        ClientOverrideConfiguration clientOverrideConfiguration =
            ClientOverrideConfiguration.builder()
                .retryPolicy(
                    RetryPolicy.builder(RetryMode.ADAPTIVE)
                        .numRetries(3)
                        .build())
                .apiCallAttemptTimeout(Duration.ofMillis(500))
                .build();
        UrlConnectionHttpClient.Builder httpClientBuilder = UrlConnectionHttpClient.builder()
            .connectionTimeout(Duration.ofMillis(100));
        
return S3Client.builder()
            .httpClientBuilder(httpClientBuilder)
            .overrideConfiguration(clientOverrideConfiguration)
            .region(Region.of(configuration.getRegion()))
            .credentialsProvider(DefaultCredentialsProvider.create())
            .build();
    }

and the method for read and write to S3 as this:

public void putObject(String content, String name) {
        try {
            logger.info("Writing {} to S3.", name);
            s3.putObject(p -> p.bucket(bucketName).key(name), RequestBody.fromString(content));
        } catch (SdkClientException e) {
            throw new SolverWrapperException(e.getMessage(), e);
        }
    }


    public JSONObject getJsonObjectFromS3FileWithRetries(String name) {
        for (int retries = 0; retries < 3; retries++) {
            try {
                return getJsonObjectFromS3File(name);
            } catch (SolverWrapperException e) {
                logger.warn("Failed to get object from S3. Retrying...", e);
            }
            try {
                TimeUnit.SECONDS.sleep(1);
            } catch (InterruptedException e) {
                logger.error("Interrupted while waiting for retry.", e);
                Thread.currentThread().interrupt();
            }
        }
        throw new SolverWrapperException("Failed to get object from S3 after 3 retries.");
    }

    /**
     * Get an object from S3 as an JSONObject
     */
    public JSONObject getJsonObjectFromS3File(String name) {

        logger.info("Reading {} from S3.", name);
        GetObjectRequest request = GetObjectRequest.builder()
            .bucket(bucketName)
            .key(name)
            .build();

        try (ResponseInputStream<GetObjectResponse> object = s3.getObject(request)) {
            SdkBytes content = SdkBytes.fromInputStream(object);
            String objStr = content.asUtf8String();
            return JSON.parseStringToJsonAware(objStr, parser);
        } catch (IOException e) {
            throw new SolverWrapperException(e.getMessage(), e);
        }
    }`

To deal with the Socket closed exceptions I made the following changes to the S3 client:

• Increased apiCallAttermptTimeout to 600 ms
• Defined apiCallTimeout to 6 seconds

This resultet in nullPointerExceptions occasionally when reading from S3.

Can anyone help me with this?

Stacktrace for both errors are pasted bellow

Stacktrace for Socket closed

java.io.UncheckedIOException: java.net.SocketException: Socket closed
--
at software.amazon.awssdk.utils.FunctionalUtils.asRuntimeException(FunctionalUtils.java:180)
at software.amazon.awssdk.utils.FunctionalUtils.lambda$safeSupplier$4(FunctionalUtils.java:110)
at software.amazon.awssdk.utils.FunctionalUtils.invokeSafely(FunctionalUtils.java:136)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.lambda$tryGetOutputStream$0(UrlConnectionHttpClient.java:324)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.getAndHandle100Bug(UrlConnectionHttpClient.java:360)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.tryGetOutputStream(UrlConnectionHttpClient.java:324)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.call(UrlConnectionHttpClient.java:301)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.call(UrlConnectionHttpClient.java:274)
at software.amazon.awssdk.core.internal.util.MetricUtils.measureDurationUnsafe(MetricUtils.java:67)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.executeHttpRequest(MakeHttpRequestStage.java:77)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:56)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:39)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:72)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:42)
at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:78)
at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:40)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:52)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:37)
at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:81)
at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:36)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:56)
at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:36)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.executeWithTimer(ApiCallTimeoutTrackingStage.java:80)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:60)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:42)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:50)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:32)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:37)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:26)
at software.amazon.awssdk.core.internal.http.AmazonSyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonSyncHttpClient.java:196)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.invoke(BaseSyncClientHandler.java:103)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.doExecute(BaseSyncClientHandler.java:171)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.lambda$execute$1(BaseSyncClientHandler.java:82)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.measureApiCallSuccess(BaseSyncClientHandler.java:179)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.execute(BaseSyncClientHandler.java:76)
at software.amazon.awssdk.core.client.handler.SdkSyncClientHandler.execute(SdkSyncClientHandler.java:45)
at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.execute(AwsSyncClientHandler.java:56)
at software.amazon.awssdk.services.s3.DefaultS3Client.putObject(DefaultS3Client.java:8783)
at software.amazon.awssdk.services.s3.S3Client.putObject(S3Client.java:17277)
at com.visma.of.solverwrapper.aws.s3.S3Handler.putObject(S3Handler.java:84)
at com.visma.of.solverwrapper.aws.s3.S3Util.writeJsonObjectToS3Path(S3Util.java:34)
at com.visma.of.solverwrapper.aws.solver.RunSimpleSolverHandler.handleRequest(RunSimpleSolverHandler.java:62)
at com.visma.of.solverwrapper.aws.solver.RunSimpleSolverHandler.handleRequest(RunSimpleSolverHandler.java:25)
at lambdainternal.EventHandlerLoader$PojoHandlerAsStreamHandler.handleRequest(EventHandlerLoader.java:205)
at lambdainternal.EventHandlerLoader$2.call(EventHandlerLoader.java:905)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:261)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:200)
at lambdainternal.AWSLambda.main(AWSLambda.java:194)
Caused by: java.net.SocketException: Socket closed
at java.base/java.net.SocketInputStream.read(Unknown Source)
at java.base/java.net.SocketInputStream.read(Unknown Source)
at java.base/sun.security.ssl.SSLSocketInputRecord.read(Unknown Source)
at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(Unknown Source)
at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(Unknown Source)
at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(Unknown Source)
at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(Unknown Source)
at java.base/java.io.BufferedInputStream.fill(Unknown Source)
at java.base/java.io.BufferedInputStream.read1(Unknown Source)
at java.base/java.io.BufferedInputStream.read(Unknown Source)
at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(Unknown Source)
at java.base/sun.net.www.http.HttpClient.parseHTTP(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.expect100Continue(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getOutputStream0(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getOutputStream(Unknown Source)
at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getOutputStream(Unknown Source)
at software.amazon.awssdk.utils.FunctionalUtils.lambda$safeSupplier$4(FunctionalUtils.java:108)
... 53 more

Stacktrace for the nullPointer

SEVERE: java.lang.NullPointerException
--
java.lang.RuntimeException: java.lang.NullPointerException
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getHeaderField(Unknown Source)
at java.base/java.net.HttpURLConnection.getResponseCode(Unknown Source)
at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(Unknown Source)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.getResponseCodeSafely(UrlConnectionHttpClient.java:424)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.call(UrlConnectionHttpClient.java:307)
at software.amazon.awssdk.http.urlconnection.UrlConnectionHttpClient$RequestCallable.call(UrlConnectionHttpClient.java:274)
at software.amazon.awssdk.core.internal.util.MetricUtils.measureDurationUnsafe(MetricUtils.java:67)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.executeHttpRequest(MakeHttpRequestStage.java:77)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:56)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:39)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:72)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:42)
at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:78)
at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:40)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:52)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:37)
at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:81)
at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:36)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:56)
at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:36)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.executeWithTimer(ApiCallTimeoutTrackingStage.java:80)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:60)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:42)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:50)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:32)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:37)
at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:26)
at software.amazon.awssdk.core.internal.http.AmazonSyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonSyncHttpClient.java:196)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.invoke(BaseSyncClientHandler.java:103)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.doExecute(BaseSyncClientHandler.java:171)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.lambda$execute$0(BaseSyncClientHandler.java:68)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.measureApiCallSuccess(BaseSyncClientHandler.java:179)
at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.execute(BaseSyncClientHandler.java:62)
at software.amazon.awssdk.core.client.handler.SdkSyncClientHandler.execute(SdkSyncClientHandler.java:52)
at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.execute(AwsSyncClientHandler.java:63)
at software.amazon.awssdk.services.s3.DefaultS3Client.getObject(DefaultS3Client.java:4483)
at software.amazon.awssdk.services.s3.S3Client.getObject(S3Client.java:7916)
at software.amazon.awssdk.services.s3.S3Client.getObject(S3Client.java:8161)
at com.visma.of.solverwrapper.aws.s3.S3Handler.getJsonObjectFromS3File(S3Handler.java:114)
at com.visma.of.solverwrapper.aws.s3.S3Handler.getJsonObjectFromS3FileWithRetries(S3Handler.java:94)
at com.visma.of.solverwrapper.validator.RequestValidator.runValidator(RequestValidator.java:34)
at com.visma.of.solverwrapper.aws.validator.RunValidatorHandler.handleRequest(RunValidatorHandler.java:39)
at com.visma.of.solverwrapper.aws.validator.RunValidatorHandler.handleRequest(RunValidatorHandler.java:19)
at lambdainternal.EventHandlerLoader$PojoHandlerAsStreamHandler.handleRequest(EventHandlerLoader.java:205)
at lambdainternal.EventHandlerLoader$2.call(EventHandlerLoader.java:905)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:261)
at lambdainternal.AWSLambda.startRuntime(AWSLambda.java:200)
at lambdainternal.AWSLambda.main(AWSLambda.java:194)
Caused by: java.lang.NullPointerException
at java.base/sun.net.www.protocol.http.HttpURLConnection.writeRequests(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(Unknown Source)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
... 54 more

[debora-ito]

I went to the code to see what UrlConnectionHttpClient#getResponseCodeSafely is doing, and found this comment:

aws-sdk-java-v2/http-clients/url-connection-client/src/main/java/software/amazon/awssdk/http/urlconnection/UrlConnectionHttpClient.java

Lines 412 to 424 in f8c1cb0

	/**
	* {@link sun.net.www.protocol.http.HttpURLConnection#getInputStream0()} has been observed to intermittently throw
	* {@link NullPointerException}s for reasons that still require further investigation, but are assumed to be due to a
	* bug in the JDK. Propagating such NPEs is confusing for users and are not subject to being retried on by the default
	* retry policy configuration, so instead we bias towards propagating these as {@link IOException}s.
	* <p>
	* TODO: Determine precise root cause of intermittent NPEs, submit JDK bug report if applicable, and consider applying
	* this behavior only on unpatched JVM runtime versions.
	*/
	private static int getResponseCodeSafely(HttpURLConnection connection) throws IOException {
	Validate.paramNotNull(connection, "connection");
	try {
	return connection.getResponseCode();

@espen-grodem you wrote the error does not happen every time, how often does it happen?
Which JDK are you using?

[espen-grodem]

We run optimization jobs where the client is regularly polling for new results, so we make a lot reads/writes to S3. Therefore the error is happening quite often, and we had to revert the changes after a couple of hours due to the error happening 5-6 times.
In that time we had made an estimated 300-400 reads to S3.

JDK version is:
openjdk 11.0.16 2022-07-19 LTS OpenJDK Runtime Environment Corretto-11.0.16.8.1 (build 11.0.16+8-LTS) OpenJDK 64-Bit Server VM Corretto-11.0.16.8.1 (build 11.0.16+8-LTS, mixed mode)

[espen-grodem]

@debora-ito do you any suggestion of how this can be fixed?

[dacort]

@espen-grodem I've also recently run into this with the exact same stack trace and SDK version (2.20.131) on corretto 1.8.0_422.

Did you ever find a root cause or fix?

[steveloughran]

It'd be nice if a subclass of IOE was returned, TransientIOException for example, so that layers above could decide what to do based on exception type. Otherwise people will need to look at the error text and that is incredibly brittle, especially for an exception which happens so rarely.