SECURITY_STATUS is 590615 - S3 download hang after partial parts have completed

[daiyy]

This behave only happened under Windows.
When downloading large S3 object with S3AsyncClient in java
Application will hang when only partial parts have completed.

[DEBUG] [2023-03-11T15:02:50Z] [000005e0] [S3MetaRequest] - id=000001CB43412B40: 11 out of 24 parts have completed.

trace log report a shutdown connection because of SECURITY_STATUS is 590615, which I believe leads to remain parts get no chance to start again.

[TRACE] [2023-03-11T15:02:54Z] [000009ec] [dns] - static: remaining record count for host 0
[TRACE] [2023-03-11T15:02:54Z] [000009ec] [dns] - static: remaining record count for host 7
[DEBUG] [2023-03-11T15:02:55Z] [000009ec] [dns] - static: resolving host mt-test1.s3.cn-north-1.amazonaws.com.cn
[DEBUG] [2023-03-11T15:02:55Z] [000009ec] [dns] - static: resolved record: 54.222.51.15
[DEBUG] [2023-03-11T15:02:55Z] [000009ec] [dns] - static, resolving host mt-test1.s3.cn-north-1.amazonaws.com.cn successful, returned 1 addresses
[DEBUG] [2023-03-11T15:02:55Z] [000009ec] [dns] - static: new address resolved 54.222.51.15 for host mt-test1.s3.cn-north-1.amazonaws.com.cn caching
[TRACE] [2023-03-11T15:02:55Z] [000009ec] [dns] - static: remaining record count for host 0
[TRACE] [2023-03-11T15:02:55Z] [000009ec] [dns] - static: remaining record count for host 8
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [event-loop] - id=000001CB42EA3F40: wake up with 1 events to process.
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [event-loop] - id=000001CB42EA3F40: invoking handler.
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [socket] - id=000001CB4320DFC0 handle=0000000000000928: socket readable event triggered
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [socket-handler] - id=000001CB42EB1D20: socket is now readable
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [socket-handler] - id=000001CB42EB1D20: invoking read. Downstream window 18446744073709551615, max_to_read 262144
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [channel] - id=000001CB42F7EF40: acquired message 000001CB41A3E1C0 of capacity 262144 from pool 000001CB4329D180. Requested size was 262144
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [socket] - id=000001CB4320DFC0 handle=0000000000000928: reading from socket
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [socket] - id=000001CB4320DFC0 handle=0000000000000928: read 31 bytes from socket
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [socket-handler] - id=000001CB42EB1D20: read 31 from socket
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [channel] - id=000001CB42F7EF40: sending read message of size 31, from slot 000001CB4437E050 to slot 000001CB4437F4F0 with handler 000001CB443D0E80.
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [tls-handler] - id=000001CB443D0E80: processing incoming message of size 31
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [tls-handler] - id=000001CB443D0E80: Alert received. Message sender has shut down the connection. SECURITY_STATUS is 590615.
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [channel] - id=000001CB42F7EF40: channel shutdown task is scheduled
[TRACE] [2023-03-11T15:02:55Z] [000018e8] [channel] - id=000001CB42F7EF40: scheduling task with wrapper task id 000001CB42F7F120.

Is this a expected behave on Windows ?

[TingDaoK]

It's not expected for sure. But, with the limited info here, I cannot really tell what's going on that lead to the hang.

Can you send us the full log? You can send it via email dengket@amazon.com. Thanks

[TingDaoK]

[DEBUG] [2023-03-11T15:18:03Z] [000002bc] [S3MetaRequest] - id=000001E6C662B9D0: Download paused because read window is zero. You must increment to window to continue.

This is the reason your download hangs. Very likely you enabled the read backpressure, but didn't call aws_s3_meta_request_increment_read_window.

Check the documents here.

[daiyy]

Aha, In aws-sdk-java-v2 enable_read_backpressure was set to true by default.

I am able to complete large object download process by setting a larger initialReadBufferSizeInBytes

Thanks !

[graebm]

Please open an issue at aws-sdk-java-v2. aws-c-io is a C library handling TLS, which is not the cause of your issue.

The Java S3 TransferManager has its own API that wraps some of the API concepts down here in the C libraries. The C libraries have this concept of read window to manage flow control, but the TransferManager uses Reactive Streams APIs. The PR where these 2 systems were integrated is here: aws/aws-sdk-java-v2#3533

Based on the log message about "read window is zero"...

If you are using S3TransferManager.download(), it's likely the download is hanging because you need to request more data from the subscription (I might be using the wrong terms here, I'm not a Java pro)

OR

If you are using S3TransferManager.downloadFile(), it's possible there's a bug in how S3TransferManager coordinates flow control with the C code.