Skip to content

MbedTLS 1.1.1 breaks S3.put_object() #247

Description

@alyst

With the recent update, S3.put_object() of data 80000 bytes and more fails after the previous S3.get_object() of the large (>=1GB) file (at least I believe that's the pattern).

The request

using AWS; AWS.@service S3
S3.put_object(bucket, filename, Dict("body"=>copy(reinterpret(UInt8, rand(100000))), "headers"=>Dict("Content-Type"=>"application/octet-stream")))

is frozen for ~15mins, then fails with

ERROR: LoadError: AWS.AWSExceptions.AWSException: RequestTimeTooSkewed -- The difference between the request time and the current time is too large.
--
HTTP.ExceptionRequest.StatusError(403, "PUT", "/***/***", HTTP.Messages.Response:
"""
HTTP/1.1 403 Forbidden
x-amz-request-id: 8BENM0CFC6DYHVHS
x-amz-id-2: wTGC7r08IpqLTJXPQx+WgkudxWwlHxfxAPxoQ6+tAdG/l6T8gADRTbBTXRPaIr1xLfsaVtXtQW0=
Content-Type: application/xml
Transfer-Encoding: chunked
Date: Mon, 25 Jul 2022 18:09:05 GMT
Server: AmazonS3
Connection: close
 
[Message Body was streamed]""")
<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>RequestTimeTooSkewed</Code><Message>The difference between the request time and the current time is too large.</Message><RequestTime>20220725T175327Z</RequestTime><ServerTime>2022-07-25T18:09:07Z</ServerTime><MaxAllowedSkewMilliseconds>900000</MaxAllowedSkewMilliseconds><RequestId>8BENM0CFC6DYHVHS</RequestId><HostId>wTGC7r08IpqLTJXPQx+WgkudxWwlHxfxAPxoQ7+tAdG/l6T8gBDRTbBTXRPaIr1xLfsaVtXtQW0=</HostId></Error>
Stacktrace:
[1] request(::Type{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}, ::URIs.URI, ::Vararg{Any}; kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol, Symbol}, NamedTuple{(:iofunction, :require_ssl_verification, :response_stream), Tuple{Nothing, Bool, Base.BufferStream}}})
@ HTTP.ExceptionRequest ~/.julia/packages/HTTP/aTjcj/src/ExceptionRequest.jl:22
[2] request(::Type{HTTP.MessageRequest.MessageLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}, method::String, url::URIs.URI, headers::Vector{Pair{SubString{String}, SubString{String}}}, body::Vector{UInt8}; http_version::VersionNumber, target::String, parent::Nothing, iofunction::Nothing, kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol}, NamedTuple{(:require_ssl_verification, :response_stream), Tuple{Bool, Base.BufferStream}}})
@ HTTP.MessageRequest ~/.julia/packages/HTTP/aTjcj/src/MessageRequest.jl:66
[3] request(::Type{HTTP.BasicAuthRequest.BasicAuthLayer{HTTP.MessageRequest.MessageLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}, method::String, url::URIs.URI, headers::Vector{Pair{SubString{String}, SubString{String}}}, body::Vector{UInt8}; kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol}, NamedTuple{(:require_ssl_verification, :response_stream), Tuple{Bool, Base.BufferStream}}})
@ HTTP.BasicAuthRequest ~/.julia/packages/HTTP/aTjcj/src/BasicAuthRequest.jl:28
[4] #request#1
--
@ ~/.julia/packages/HTTP/aTjcj/src/TopRequest.jl:15 [inlined]
[5] macro expansion
@ ~/.julia/packages/Mocking/MsKoy/src/mock.jl:29 [inlined]
[6] (::AWS.var"#40#42"{Request, DataType, OrderedCollections.LittleDict{Symbol, Any, Vector{Symbol}, Vector{Any}}})()
@ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:221
[7] (::Base.var"#76#78"{Base.var"#76#77#79"{AWS.AWSExponentialBackoff, AWS.var"#41#43", AWS.var"#40#42"{Request, DataType, OrderedCollections.LittleDict{Symbol, Any, Vector{Symbol}, Vector{Any}}}}})(; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
@ Base ./error.jl:294
[8] (::Base.var"#76#78"{Base.var"#76#77#79"{AWS.AWSExponentialBackoff, AWS.var"#41#43", AWS.var"#40#42"{Request, DataType, OrderedCollections.LittleDict{Symbol, Any, Vector{Symbol}, Vector{Any}}}}})()
@ Base ./error.jl:290
[9] _http_request(http_backend::AWS.HTTPBackend, request::Request, response_stream::IOBuffer)
@ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:251

I've checked, that is not because of the local clock skew: the <RequestTime> is the time it was actually submitted, and <ServerTime> is the time the execution of S3.put_object() was unfrozen with the exception.

When I interrupt the request, it reveals that it's sitting in MbedTLS:

ERROR: InterruptException:
Stacktrace:
  [1] try_yieldto(undo::typeof(Base.ensure_rescheduled))
    @ Base ./task.jl:812
  [2] wait()
    @ Base ./task.jl:872
  [3] wait(c::Base.GenericCondition{Base.Threads.SpinLock})
    @ Base ./condition.jl:123
  [4] lock(rl::ReentrantLock)
    @ Base ./lock.jl:100
  [5] ssl_check_pending(ctx::MbedTLS.SSLContext)
    @ MbedTLS ~/.julia/packages/MbedTLS/bYd4w/src/ssl.jl:584
  [6] wait_for_decrypted_data(ctx::MbedTLS.SSLContext)
    @ MbedTLS ~/.julia/packages/MbedTLS/bYd4w/src/ssl.jl:299
  [7] eof
    @ ~/.julia/packages/MbedTLS/bYd4w/src/ssl.jl:176 [inlined]
  [8] read_to_buffer(t::HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}, sizehint::Int64)
    @ HTTP.ConnectionPool ~/.julia/packages/HTTP/aTjcj/src/ConnectionPool.jl:274
  [9] readuntil(t::HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}, f::Function, sizehint::Int64)
    @ HTTP.ConnectionPool ~/.julia/packages/HTTP/aTjcj/src/ConnectionPool.jl:294
 [10] readuntil
    @ ~/.julia/packages/HTTP/aTjcj/src/ConnectionPool.jl:292 [inlined]
 [11] readheaders(io::HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}, message::HTTP.Messages.Response)
    @ HTTP.Messages ~/.julia/packages/HTTP/aTjcj/src/Messages.jl:537
 [12] startread(http::HTTP.Streams.Stream{HTTP.Messages.Response, HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}})
    @ HTTP.Streams ~/.julia/packages/HTTP/aTjcj/src/Streams.jl:170
 [13] macro expansion
    @ ~/.julia/packages/HTTP/aTjcj/src/StreamRequest.jl:67 [inlined]
 [14] macro expansion
    @ ./task.jl:399 [inlined]
 [15] request(::Type{HTTP.StreamRequest.StreamLayer{Union{}}}, io::HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}, req::HTTP.Messages.Request, body::Vector{UInt8}; reached_redirect_limit::Bool, response_stream::Base.BufferStream, iofunction::Nothing, verbose::Int64, kw::Base.Pairs{Symbol, Bool, Tuple{Symbol}, NamedTuple{(:require_ssl_verification,), Tuple{Bool}}})
    @ HTTP.StreamRequest ~/.julia/packages/HTTP/aTjcj/src/StreamRequest.jl:57
 [16] request(::Type{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}, url::URIs.URI, req::HTTP.Messages.Request, body::Vector{UInt8}; proxy::Nothing, socket_type::Type, reuse_limit::Int64, kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol, Symbol}, NamedTuple{(:iofunction, :require_ssl_verification, :response_stream), Tuple{Nothing, Bool, Base.BufferStream}}})
    @ HTTP.ConnectionRequest ~/.julia/packages/HTTP/aTjcj/src/ConnectionRequest.jl:108
 [17] request(::Type{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}, ::URIs.URI, ::Vararg{Any}; kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol, Symbol}, NamedTuple{(:iofunction, :require_ssl_verification, :response_stream), Tuple{Nothing, Bool, Base.BufferStream}}})
    @ HTTP.ExceptionRequest ~/.julia/packages/HTTP/aTjcj/src/ExceptionRequest.jl:19
 [18] request(::Type{HTTP.MessageRequest.MessageLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}, method::String, url::URIs.URI, headers::Vector{Pair{SubString{String}, SubString{String}}}, body::Vector{UInt8}; http_version::VersionNumber, target::String, parent::Nothing, iofunction::Nothing, kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol}, NamedTuple{(:require_ssl_verification, :response_stream), Tuple{Bool, Base.BufferStream}}})
    @ HTTP.MessageRequest ~/.julia/packages/HTTP/aTjcj/src/MessageRequest.jl:66
 [19] request(::Type{HTTP.BasicAuthRequest.BasicAuthLayer{HTTP.MessageRequest.MessageLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}, method::String, url::URIs.URI, headers::Vector{Pair{SubString{String}, SubString{String}}}, body::Vector{UInt8}; kw::Base.Pairs{Symbol, Any, Tuple{Symbol, Symbol}, NamedTuple{(:require_ssl_verification, :response_stream), Tuple{Bool, Base.BufferStream}}})
    @ HTTP.BasicAuthRequest ~/.julia/packages/HTTP/aTjcj/src/BasicAuthRequest.jl:28
 [20] #request#1
    @ ~/.julia/packages/HTTP/aTjcj/src/TopRequest.jl:15 [inlined]
 [21] macro expansion
    @ ~/.julia/packages/Mocking/MsKoy/src/mock.jl:29 [inlined]
 [22] (::AWS.var"#40#42"{Request, DataType, OrderedCollections.LittleDict{Symbol, Any, Vector{Symbol}, Vector{Any}}})()
    @ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:221
 [23] (::Base.var"#76#78"{Base.var"#76#77#79"{AWS.AWSExponentialBackoff, AWS.var"#41#43", AWS.var"#40#42"{Request, DataType, OrderedCollections.LittleDict{Symbol, Any, Vector{Symbol}, Vector{Any}}}}})(; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Base ./error.jl:294
 [24] (::Base.var"#76#78"{Base.var"#76#77#79"{AWS.AWSExponentialBackoff, AWS.var"#41#43", AWS.var"#40#42"{Request, DataType, OrderedCollections.LittleDict{Symbol, Any, Vector{Symbol}, Vector{Any}}}}})()
    @ Base ./error.jl:290
 [25] _http_request(http_backend::AWS.HTTPBackend, request::Request, response_stream::IOBuffer)
    @ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:251
 [26] macro expansion
    @ ~/.julia/packages/Mocking/MsKoy/src/mock.jl:29 [inlined]
 [27] (::AWS.var"#33#36"{AWSConfig, Request, IOBuffer, Vector{Int64}})()
    @ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:125
 [28] (::AWS.var"#34#38"{AWS.var"#33#36"{AWSConfig, Request, IOBuffer, Vector{Int64}}, IOBuffer})()
    @ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:140
 [29] (::Base.var"#76#78"{Base.var"#76#77#79"{AWS.AWSExponentialBackoff, AWS.var"#35#39"{AWSConfig, Vector{String}, Vector{String}, Int64}, AWS.var"#34#38"{AWS.var"#33#36"{AWSConfig, Request, IOBuffer, Vector{Int64}}, IOBuffer}}})(; kwargs::Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
    @ Base ./error.jl:294
 [30] (::Base.var"#76#78"{Base.var"#76#77#79"{AWS.AWSExponentialBackoff, AWS.var"#35#39"{AWSConfig, Vector{String}, Vector{String}, Int64}, AWS.var"#34#38"{AWS.var"#33#36"{AWSConfig, Request, IOBuffer, Vector{Int64}}, IOBuffer}}})()
    @ Base ./error.jl:290
 [31] submit_request(aws::AWSConfig, request::Request; return_headers::Nothing)
    @ AWS ~/.julia/packages/AWS/E9zQ4/src/utilities/request.jl:191
 [32] (::RestXMLService)(request_method::String, request_uri::String, args::Dict{String, Any}; aws_config::AWSConfig, feature_set::AWS.FeatureSet)
    @ AWS ~/.julia/packages/AWS/E9zQ4/src/AWS.jl:284
 [33] put_object(Bucket::String, Key::String, params::Dict{String, Any}; aws_config::AWSConfig)
    @ Main.S3 ~/.julia/packages/AWS/E9zQ4/src/services/s3.jl:5285
 [34] put_object(Bucket::String, Key::String, params::Dict{String, Any})
    @ Main.S3 ~/.julia/packages/AWS/E9zQ4/src/services/s3.jl:5285

Downgrading to MbedTLS 1.1.0 seems to solve the issue.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions