Multithread issue(julia 1.71)

[caseykneale]

Conditions: Ubuntu/MacOS, Julia 1.7.1/1.6.5
Related issues: #94 , #110

Note: the examples here are MRE's and are not what the troublesome code looks like. It seems like a multi-threaded julia application calling Azure/Downloads suffers sporadically from this issue.

The error looks like this(where the last 3 lines repeat seemingly forever):

     From worker 4:    ┌ Error: 2022-03-14T16:11:24.498 (txn_id: 1044876555423232961)
     From worker 4:    │ curl_multi_socket_action: 8
     From worker 4:    └ @ Downloads.Curl /build/source/usr/share/julia/stdlib/v1.7/Downloads/src/Curl/utils.jl:36

Can sometimes reproduce with: JULIA_NUM_THREADS=4 julia171

using Downloads

Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
    open("/tmp/cool$url", "w") do io
        resp = Downloads.request("http://google.com"; output=io, method="GET")
    end
end

If this does not reproduce the curl_multi_socket_action bug rerun the Threads.@threads loop until it happens (typically takes 1-5 executions).

Also sporadically reproduces without the explicit I/O scope/pattern with the same frequency, ie:

using Downloads
Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
    resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
end

Maybe more/less interesting: without the output field(ie: Downloads.request("http://google.com"; method="GET")) there is another nondeterministic error that infrequently occurs..:

ERROR: TaskFailedException
Stacktrace:
 [1] wait
   @ ./task.jl:334 [inlined]
 [2] threading_run(func::Function)
   @ Base.Threads ./threadingconstructs.jl:38
 [3] top-level scope
   @ ./threadingconstructs.jl:97

    nested task error: val already in a list
    Stacktrace:
      [1] try_yieldto(undo::typeof(Base.ensure_rescheduled))
        @ Base ./task.jl:777
      [2] wait()
        @ Base ./task.jl:837
      [3] wait(c::Base.GenericCondition{ReentrantLock})
        @ Base ./condition.jl:123
      [4] take_buffered(c::Channel{Any})
        @ Base ./channels.jl:389
      [5] take!
        @ ./channels.jl:383 [inlined]
      [6] sync_end(c::Channel{Any})
        @ Base.Experimental ./experimental.jl:64
      [7] macro expansion
        @ ./experimental.jl:102 [inlined]
      [8] (::Downloads.var"#9#18"{Base.DevNull, Base.DevNull, String, Vector{Pair{String, String}}, Float64, Nothing, Bool, Bool, String, Int64, Bool, Bool})(easy::Downloads.Curl.Easy)
        @ Downloads ~/julia-1.7.1/share/julia/stdlib/v1.7/Downloads/src/Downloads.jl:347
      [9] with_handle(f::Downloads.var"#9#18"{Base.DevNull, Base.DevNull, String, Vector{Pair{String, String}}, Float64, Nothing, Bool, Bool, String, Int64, Bool, Bool}, handle::Downloads.Curl.Easy)
        @ Downloads.Curl ~/julia-1.7.1/share/julia/stdlib/v1.7/Downloads/src/Curl/Curl.jl:64
     [10] #8
        @ ~/julia-1.7.1/share/julia/stdlib/v1.7/Downloads/src/Downloads.jl:311 [inlined]
     [11] arg_write(f::Downloads.var"#8#17"{Base.DevNull, String, Vector{Pair{String, String}}, Float64, Nothing, Bool, Bool, String, Int64, Bool, Bool}, arg::Base.DevNull)
        @ ArgTools ~/julia-1.7.1/share/julia/stdlib/v1.7/ArgTools/src/ArgTools.jl:112
     [12] #7
        @ ~/julia-1.7.1/share/julia/stdlib/v1.7/Downloads/src/Downloads.jl:310 [inlined]
     [13] arg_read
        @ ~/julia-1.7.1/share/julia/stdlib/v1.7/ArgTools/src/ArgTools.jl:61 [inlined]
     [14] request(url::String; input::Nothing, output::Nothing, method::String, headers::Vector{Pair{String, String}}, timeout::Float64, progress::Nothing, verbose::Bool, throw::Bool, downloader::Nothing)
        @ Downloads ~/julia-1.7.1/share/julia/stdlib/v1.7/Downloads/src/Downloads.jl:309
     [15] macro expansion
        @ ./REPL[2]:2 [inlined]
     [16] (::var"#124#threadsfor_fun#9"{Vector{String}})(onethread::Bool)
        @ Main ./threadingconstructs.jl:85
     [17] (::var"#124#threadsfor_fun#9"{Vector{String}})()
        @ Main ./threadingconstructs.jl:52

Any help or guidance appreciated

[StefanKarpinski]

As noted in the issues you linked, Downloads was not threadsafe in Julia 1.7; the Julia 1.8 release is the first one that is threadsafe. As also noted in those issues, you don't need to use threads to do concurrent downloads, you can just uses tasks.

[caseykneale]

Thanks for the quick reply.

FWIW: I ran the MRE on Julia 1.8beta. The error seems to be gone but - unfortunately if you run the loop maybe 10 times or so (YMMV) you'll get an infinite loop/hanging execution. So the failure mode is different, but it does still seem to fail, unfortunately.

One thing I would like to mention is: this problem appears to happen in programs which are not just threaded loops downloading files. For example, someone(our situation) could have a multithreaded client (say Azure.jl) where downloading files is a only a small "part" of what is happening. So the Task suggestion doesn't work as well there.

[StefanKarpinski]

I cannot reproduce that on Julia 1.8-beta1 or Julia master on macOS. What operating system are you trying this on and what is the exact MWE?

[caseykneale]

ubuntu@ip-172-31-11-132:~/dev/raicode$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.4 LTS
Release:        20.04
Codename:       focal

Version 1.8.0-beta1 (2022-02-23)

JULIA_NUM_THREADS=4 julia18b

              _
   _       _ _(_)_     |  Documentation: https://docs.julialang.org
  (_)     | (_) (_)    |
   _ _   _| |_  __ _   |  Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` |  |
  | | |_| | | | (_| |  |  Version 1.8.0-beta1 (2022-02-23)
 _/ |\__'_|_|_|\__'_|  |  Official https://julialang.org/ release
|__/                   |

julia> using Downloads

julia> Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end

julia> Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end

julia> Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end

julia> Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end

julia> Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end
this hangs forever

[StefanKarpinski]

I just tried it on the exact same LSB without issues. Not sure what to do given the inability to repro.

[giordano]

For what is worth, that works for me with Julia master on Linux:

julia> @time Threads.@threads for url in 1:400
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end
 40.885960 seconds (229.03 k allocations: 13.134 MiB, 0.13% compilation time)

julia> Threads.nthreads()
4

[ericphanson]

the Julia 1.8 release is the first one that is threadsafe

1.7.3 should be too, since we backported the fixes (#175)

[caseykneale]

For what is worth, that works for me with Julia master on Linux:

julia> @time Threads.@threads for url in 1:400
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end
 40.885960 seconds (229.03 k allocations: 13.134 MiB, 0.13% compilation time)

julia> Threads.nthreads()
4

it works the first randn times that it's run, but if I run it consecutively in the REPL (not hammering it either - ie: waiting for cursor to come back), I get intermittent infinite loop conditions. This is similar to the curl bug - in that I could run the code some number of times before seg faulting. REPL is still frozen from when I made the last post.

I could make a little video but its pretty boring to watch. Maybe it's nothing or linked only to the REPL, but I dunno, it seems like undesirable behavior.

[StefanKarpinski]

I did the same thing, hitting up in the REPL twenty or so times, running the threaded loop repeatedly. No hangs. I think to debug this further we need some deeper debugging on a system that exhibits the behavior.

[caseykneale]

Could run an RR trace on it if I could reproduce it in a script. I'll let you know how that goes - maybe tomorrow.

[caseykneale]

I was able to reproduce it in a script, but it is intermittant(IE: may require 3-10 attempts)

Script:

using Downloads

Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
end

Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
end

Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
end

Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
end

Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
           resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
end
println("did not hang")

Script is called via: JULIA_NUM_THREADS=4 julia18b repro.jl

Please try running this a few times in succession (ideally on linux/ubuntu), if that fails I will try to submit an RR.

Attempts from the console look like this:

ubuntu@ip-:~/dev/mre_downloads$ JULIA_NUM_THREADS=4 julia18b repro.jl 
did not hang
ubuntu@ip-:~/dev/mre_downloads$ JULIA_NUM_THREADS=4 julia18b repro.jl 
did not hang
ubuntu@ip-:~/dev/mre_downloads$ JULIA_NUM_THREADS=4 julia18b repro.jl 
did not hang
ubuntu@ip-:~/dev/mre_downloads$ JULIA_NUM_THREADS=4 julia18b repro.jl 
did not hang
ubuntu@ip-:~/dev/mre_downloads$ JULIA_NUM_THREADS=4 julia18b repro.jl 

(where the last execution is stuck)

[ericphanson]

I get a hang too:

julia> using Downloads

julia> for i = 1:100
       Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
                  resp = Downloads.request("http://google.com"; output="/tmp/cool_$url", method="GET")
       end
       println("$i did not hang")
       end
1 did not hang
2 did not hang
3 did not hang
4 did not hang
5 did not hang
6 did not hang
7 did not hang
8 did not hang
9 did not hang
10 did not hang
11 did not hang
12 did not hang
13 did not hang
14 did not hang
15 did not hang
16 did not hang
17 did not hang
18 did not hang
19 did not hang
20 did not hang
21 did not hang
22 did not hang
23 did not hang
24 did not hang
25 did not hang
26 did not hang
27 did not hang
28 did not hang
29 did not hang
30 did not hang
31 did not hang
32 did not hang
33 did not hang
34 did not hang
35 did not hang
36 did not hang
37 did not hang
38 did not hang
39 did not hang
40 did not hang
41 did not hang
42 did not hang
43 did not hang
44 did not hang

(Then it hung on 45). When I ctrl-c out:

^C^C^C^C^C^CWARNING: Force throwing a SIGINT
^C^CERROR: InterruptException:
Stacktrace:
 [1] try_yieldto(undo::typeof(Base.ensure_rescheduled))
   @ Base ./task.jl:834
 [2] wait()
   @ Base ./task.jl:894
 [3] wait(c::Base.GenericCondition{Base.Threads.SpinLock})
   @ Base ./condition.jl:124
 [4] _wait(t::Task)
   @ Base ./task.jl:304
 [5] wait
   @ ./task.jl:343 [inlined]
 [6] threading_run(fun::var"#307#threadsfor_fun#62"{var"#307#threadsfor_fun#61#63"{Vector{String}}}, static::Bool)
   @ Base.Threads ./threadingconstructs.jl:38
 [7] macro expansion
   @ ./threadingconstructs.jl:89 [inlined]
 [8] top-level scope
   @ ./REPL[4]:2

On

julia> versioninfo()
Julia Version 1.8.0-beta1
Commit 7b711ce699 (2022-02-23 15:09 UTC)
Platform Info:
  OS: Linux (x86_64-pc-linux-gnu)
  CPU: 4 × Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-13.0.1 (ORCJIT, skylake-avx512)
  Threads: 4 on 4 virtual cores

shell> lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.3 LTS
Release:        20.04
Codename:       focal

[caseykneale]

Nice change to the MRE :)

I wouldn't be surprised if this issue is different from the original one presented at the start of this (might be google thinking we're doing a DoS), but it does seem to be unintended behavior that could break something in a hard way to diagnose while in production.

[ericphanson]

Hm, well if I change it to

for i = 1:100
       Threads.@threads for url in ["1","2","3","4","5","6","7","8"]
                  resp = Downloads.request("https://httpbingo.julialang.org"; output="/tmp/cool_$url", method="GET")
       end
       sleep(1)
       println("$i did not hang")
end

I get to 46 and then it hangs, same stacktrace.

Would hope httpbingo.julialang.org doesn't mind lots of requests.