Under certain conditions meta requests are retried after receiving non-recoverable S3 error responses. #264
Comments
|
Thank you for reporting the issue and the detail investigation! |
|
Which language CRT are you using to get at aws-c-s3? aws-crt-java? aws-crt-cpp? btw thank you for the AMAZING deep dive writeup. It really helped us dive right into a fix |
*Issue #:* awslabs/aws-c-s3#264 *Description of changes:* Fix issue where an HTTP connection closing after the response was received, but before the request was completely sent, was treated as an error. An HTTP exchange is now considered successful as long as the complete response was received. This fix was made in aws-c-http: awslabs/aws-c-http#431
Awesome! I'll give it a test soon to ensure that my issue has been fixed.
I'm using the C CRT libraries directly.
Of course! I try to provide the level of detail in problem descriptions and debug information that I'd like to receive myself. Thank you two for the quick turnaround. |
|
The changes in awslabs/aws-c-http@0600662 appear to fix the issue, thanks! FWIW, I haven't encountered this as an issue, but it does seem to me that it might make sense to finish transmitting the (current) request even after receiving a complete |
|
We thought about it. part of conversation can be found here The reasons that we just end transmitting after
|
|
I saw that conversation, and my reading of the RFC is that no additional requests following the current in-progress request may be sent after receiving Looking at curl's commit history, their behavior of terminating of in-progress body transmissions upon receipt of a 200 response with That being said, since this curl behavior has existed since 2008, that probably means that this is not a situation that is encountered often, so it may not matter what the client's behavior is in practice. |
Hello,
I have noticed that when using the AWS CRT to upload S3 objects with auto-ranged
PUT requests, occasionally when the server sends an error response, instead of
the meta request immediately terminating and invoking
struct aws_s3_meta_request_options.finish_callback, the meta request will be retrieduntil the maximum number of retry attempts has been met at which point the
finish callback will be invoked with either
AWS_IO_SOCKET_CLOSEDorAWS_ERROR_HTTP_CONNECTION_CLOSED.After some investigation, I believe this happens if and only if the request body
is still in the process of being transmitted when the error response (with a
Connection: closeheader) has been received, followed by a subsequent TCP FINor TLS
close_notifyalert.When the
Connection: closeheader is received,aws-c-http/source/h1_connection.c:s_decoder_on_header()setsincoming_stream->is_final_stream = true. Then inaws-c-http/source/h1_connection.c:s_decoder_on_done(), after seeing thatis_final_streamis set,is called, which sets
connection->thread_data.is_reading_stopped = true, butdoes not indicate at all to its leftward slot or the channel as a whole to stop
reading.
Later in
aws-c-http/source/h1_connection.c:s_decoder_on_done(), ifincoming_stream->is_outgoing_message_doneis set, thens_stream_complete()is called, and (since
is_final_streamis set),s_connection_close()iscalled and
finally leads to
aws_channel_shutdown()being called.But if
is_outgoing_message_doneis not set, then the leftward slot willcontinue its read loop and immediately encounter the TCP FIN (when cleartext
HTTP is being used) or TLS
close_notifyalert (when HTTPS is being used).In the HTTP case, the
aws_socket_read()call inaws-c-io/socket_channel_handler.c:s_do_read()will get a zero-length read andraise
AWS_IO_SOCKET_CLOSED.In the HTTPS case (at least in s2n builds), the
s2n_recv()call inaws-c-io/source/s2n/s2n_tls_channel_handler.c:s_s2n_handler_process_read_message()will get a zero-length read, the
close_notifyalert will be logged, and returnwith
AWS_OP_SUCCESS. I haven't quite tracked down the exact code path yet, butthis ends up with
aws-c-http/source/h1_connection.c:s_stream_complete()beinginvoked with
AWS_ERROR_HTTP_CONNECTION_CLOSED.This
AWS_IO_SOCKET_CLOSEDorAWS_ERROR_HTTP_CONNECTION_CLOSEDvalueeventually propagates to
aws-c-s3/source/s3_meta_request.c:s_s3_meta_request_send_request_finish_helper(). Sincethis error code does not match
AWS_ERROR_S3_INVALID_RESPONSE_STATUSorAWS_ERROR_S3_NON_RECOVERABLE_ASYNC_ERROR,finish_codeis set toAWS_S3_CONNECTION_FINISH_CODE_RETRY, and the meta request is tried againdespite the error response from the S3 server potentially being non-recoverable.
I am not sure if the proper solution to this lies in
aws-c-s3(e.g. changingthe logic for when a meta request should be retried),
aws-c-http(e.g. signalits leftward slot to stop reading once a complete
Connection: closeresponsehas been processed),
aws-c-io(e.g. change the socket and TLS handler logic tobe able to stop reading immediately when signaled by its rightward slot), or
some combination of the three, but I figured that raising the issue in the
top-level repo would make the most sense. Let me know if this issue would be
more appropriate in one of the other CRT repos instead.
It may also make sense to consider:
Logic to immediately stop transmitting a request when a response that
indicates failure has been received (perhaps if the HTTP response status >=
300) to avoid potentially triggering a RST from the server
Ensuring that a response is gracefully handled even if a RST, TLS alert, or
write error is received after having received a complete response. I have seen
instances where instead of the zero read in
aws-c-io/source/posix/socket.c:aws_socket_read(), anECONNRESETwasreceived--looking at a pcap of the stream a RST had been received immediately
after the FIN.
I have also seen
AWS_IO_TLS_ERROR_WRITE_FAILUREraised after theclose_notifyTLS alert was received, but this case also ends up withAWS_ERROR_HTTP_CONNECTION_CLOSEDbeing propagated toaws-c-s3/source/s3_meta_request.c:s_s3_meta_request_send_request_finish_helper().Here are some log snippets of such failures that I was able to reproduce using
both HTTP and HTTPS and using the AWS S3 servers and a third-party, nominally
S3-compatible server that I spun up locally for testing (I have seen this error
behavior using both HTTP and HTTPS with both the AWS S3 servers and the
third-party local server). Note that the
AWS_LL_TRACEmessages that werelogged are listed with level DEBUG due to my logger implementation.
Log snippet using HTTP with FIN/zero read
Log snippet using HTTP with ECONNRESET
Log snippet using HTTPS
Log snippet using HTTPS with `AWS_IO_TLS_ERROR_WRITE_FAILURE` mentioned
The CRT library versions that I'm currently using are
aws-c-auth: v0.6.25
aws-c-cal: v0.5.21
aws-c-common: v0.8.12
aws-c-compression: v0.2.16
aws-checksums: v0.1.14
aws-c-http: v0.7.5
aws-c-io: v0.13.18
aws-c-s3: v0.2.5
aws-c-sdkutils: v0.1.7
s2n-tls: v1.3.38
but I had seen this behavior for many months across multiple earlier versions
before finding the time to try to track down the error to a reportable issue.
Let me know if there is any additional information that you would like me to
provide.
Thank you,
Alex
The text was updated successfully, but these errors were encountered: