JuliaLang / Downloads.jl

MIT License
89 stars 34 forks source link

Too short timeout in "concurrent requests" stress test #204

Open vtjnash opened 1 year ago

vtjnash commented 1 year ago

The "expected" completion time for this test is 180 seconds, but curl is configured to fail the download after 30 seconds. This frequently fails on our noisy CI systems: https://github.com/JuliaLang/Downloads.jl/blob/0733701b0e21df6ae61a6b2fc8cec60ff1fd28dc/test/runtests.jl#L363-L372

(further RCA: mbedtls is very slow, spending substantial time in mbedtls_x509_crt_parse_file and mbedtls_ssl_handshake_client_step per connection)

StefanKarpinski commented 1 year ago

It's only configured to fail the download if it's unable to connect after 30 seconds, which seems like it should be possible. I think the actual error you're seeing it different: it's a race condition when libcurl tries to spawn too many DNS resolution threads at the same time. I've got a PR to add a semaphore to limit that.

StefanKarpinski commented 1 year ago

See https://github.com/JuliaLang/Downloads.jl/pull/205 which may help.

StefanKarpinski commented 1 year ago

Any updates on this? Has the change in #205 made any noticeable improvement here?

vtjnash commented 1 year ago

Does it pass on your machine if you make the test a bit slower (https://github.com/JuliaLang/julia/issues/46159#issuecomment-1264780069), simulating a busy CI system?

vtjnash commented 1 year ago

This still appears to be broken on CI https://buildkite.com/julialang/julia-master/builds/17441#01840c4d-589b-4b28-a107-f98e684d01d1

Downloads                                         (5) |         failed at 2022-10-24T17:46:42.410
Error During Test at C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\runtests.jl:355
  Got exception outside of a @test
  TaskFailedException
  Stacktrace:
    [1] try_yieldto(undo::typeof(Base.ensure_rescheduled))
      @ Base .\task.jl:909
    [2] wait()
      @ Base .\task.jl:973
    [3] wait(c::Base.GenericCondition{ReentrantLock})
      @ Base .\condition.jl:124
    [4] take_buffered(c::Channel{Any})
      @ Base .\channels.jl:456
    [5] take!
      @ .\channels.jl:450 [inlined]
    [6] sync_end(c::Channel{Any})
      @ Base.Experimental .\experimental.jl:64
    [7] macro expansion
      @ .\experimental.jl:102 [inlined]
    [8] macro expansion
      @ .\timing.jl:393 [inlined]
    [9] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\runtests.jl:366 [inlined]
   [10] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Test\src\Test.jl:1496 [inlined]
   [11] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\runtests.jl:356 [inlined]
   [12] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Test\src\Test.jl:1496 [inlined]
   [13] top-level scope
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\runtests.jl:4
   [14] include
      @ .\Base.jl:450 [inlined]
   [15] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\test\testdefs.jl:29 [inlined]
   [16] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Test\src\Test.jl:1496 [inlined]
   [17] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\test\testdefs.jl:23 [inlined]
   [18] macro expansion
      @ .\timing.jl:474 [inlined]
   [19] runtests(name::String, path::String, isolate::Bool; seed::UInt128)
      @ Main C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\test\testdefs.jl:21
   [20] runtests
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\test\testdefs.jl:5 [inlined]
   [21] kwcall(::NamedTuple{(:seed,), Tuple{UInt128}}, ::typeof(runtests), name::String, path::String)
      @ Main C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\test\testdefs.jl:5
   [22] invokelatest(::Any, ::Any, ::Vararg{Any}; kwargs::Base.Pairs{Symbol, UInt128, Tuple{Symbol}, NamedTuple{(:seed,), Tuple{UInt128}}})
      @ Base .\essentials.jl:812
   [23] kwcall(::NamedTuple{(:seed,), Tuple{UInt128}}, ::typeof(invokelatest), ::Any, ::Any, ::Vararg{Any})
      @ Base .\essentials.jl:807
   [24] (::Distributed.var"#110#112"{Distributed.CallMsg{:call_fetch}})()
      @ Distributed C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Distributed\src\process_messages.jl:285
   [25] run_work_thunk(thunk::Distributed.var"#110#112"{Distributed.CallMsg{:call_fetch}}, print_error::Bool)
      @ Distributed C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Distributed\src\process_messages.jl:70
   [26] macro expansion
      @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Distributed\src\process_messages.jl:285 [inlined]
   [27] (::Distributed.var"#109#111"{Distributed.CallMsg{:call_fetch}, Distributed.MsgHeader, Sockets.TCPSocket})()
      @ Distributed .\task.jl:514

      nested task error: RequestError: Failed to connect to httpbingo.julialang.org port 443 after 21025 ms: Timed out while requesting https://httpbingo.julialang.org/delay/2?id=27
      Stacktrace:
        [1] (::Downloads.var"#9#18"{IOBuffer, Base.DevNull, Nothing, Vector{Pair{String, String}}, Float64, Nothing, Bool, Nothing, Bool, String, Bool, Bool})(easy::Downloads.Curl.Easy)
          @ Downloads C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:388
        [2] with_handle(f::Downloads.var"#9#18"{IOBuffer, Base.DevNull, Nothing, Vector{Pair{String, String}}, Float64, Nothing, Bool, Nothing, Bool, String, Bool, Bool}, handle::Downloads.Curl.Easy)
          @ Downloads.Curl C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Curl\Curl.jl:90
        [3] #8
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:329 [inlined]
        [4] arg_write(f::Downloads.var"#8#17"{Base.DevNull, Nothing, Vector{Pair{String, String}}, Float64, Nothing, Bool, Nothing, Bool, String, Bool, Bool}, arg::IOBuffer)
          @ ArgTools C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\ArgTools\src\ArgTools.jl:134
        [5] #7
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:328 [inlined]
        [6] arg_read
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\ArgTools\src\ArgTools.jl:76 [inlined]
        [7] request(url::String; input::Nothing, output::IOBuffer, method::Nothing, headers::Vector{Pair{String, String}}, timeout::Float64, progress::Nothing, verbose::Bool, debug::Nothing, throw::Bool, downloader::Nothing)
          @ Downloads C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:327
        [8] request
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:295 [inlined]
        [9] #3
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:233 [inlined]
       [10] arg_write(f::Downloads.var"#3#4"{Nothing, Vector{Pair{String, String}}, Float64, Nothing, Bool, Nothing, Nothing, String}, arg::IOBuffer)
          @ ArgTools C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\ArgTools\src\ArgTools.jl:134
       [11] #download#2
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:232 [inlined]
       [12] download
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\src\Downloads.jl:221 [inlined]
       [13] (::Main.Test12Main_Downloads.var"#2#3"{Base.Pairs{Symbol, Nothing, Tuple{Symbol}, NamedTuple{(:downloader,), Tuple{Nothing}}}, String})(output::IOBuffer)
          @ Main.Test12Main_Downloads C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\setup.jl:13
       [14] sprint(::Function; context::Nothing, sizehint::Int64)
          @ Base .\strings\io.jl:114
       [15] sprint
          @ .\strings\io.jl:107 [inlined]
       [16] #download_body#1
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\setup.jl:12 [inlined]
       [17] download_body
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\setup.jl:11 [inlined]
       [18] #download_json#4
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\setup.jl:18 [inlined]
       [19] download_json
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\setup.jl:17 [inlined]
       [20] macro expansion
          @ C:\buildkite-agent\builds\win2k22-amdci6-2\julialang\julia-master\julia-82c1fb81a7\share\julia\stdlib\v1.9\Downloads\test\runtests.jl:368 [inlined]
       [21] (::Main.Test12Main_Downloads.var"#24#50"{Nothing, String, Int64})()
          @ Main.Test12Main_Downloads .\task.jl:514