# Confusion regarding Threads.@spawn performance

**URL:** <https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210>\
**Category:** General Usage\
**Created:** [July 17, 2020, 6:25am UTC](https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210 "2020-07-17T06:25:01Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**Author:** ![Samuel\_Ainsworth](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/samuel_ainsworth/32/15644_2.png) [@Samuel\_Ainsworth](https://discourse.julialang.org/u/Samuel_Ainsworth)\
**Post date:** [July 17, 2020, 6:25am UTC](https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210/1 "2020-07-17T06:25:01Z")

</div>

I’m not able to use `Threads.@spawn` with the kind of performance I’d expect:

```julia
samuela@n64:~/dev/research/julia/odecontrol$ JULIA_NUM_THREADS=32 julia --project
               _
   _ _ _(_)_ | Documentation: https://docs.julialang.org
  (_) | (_) (_) |
   _ _ _| |_ __ _ | Type "?" for help, "]?" for Pkg help.
  | | | | | | |/ _` | |
  | | |_| | | | (_| | | Version 1.4.2 (2020-05-23)
 _/ |\ __'_|_|_|\__'_| | Official https://julialang.org/ release
|__/ |

julia> using LinearAlgebra

julia> using BenchmarkTools

julia> @time svdvals(rand(1000, 1000))
  0.102739 seconds (33 allocations: 15.859 MiB)
1000-element Array{Float64,1}:
 499.9432747031465
   ⋮
   0.009891244161685905

julia> @time svdvals(rand(1000, 1000))
  0.104076 seconds (12 allocations: 15.839 MiB, 3.85% gc time)
1000-element Array{Float64,1}:
 500.352084696701
   ⋮
   0.0012637056839913821

```

Ok, so the SVD takes about 100ms. Got it.

```julia
julia> @time Threads.@spawn svdvals(rand(1000, 1000))
  0.003804 seconds (6.58 k allocations: 380.660 KiB)
Task (runnable) @0x00007f829b07b340

julia> @time Threads.@spawn svdvals(rand(1000, 1000))
  0.000123 seconds (27 allocations: 2.203 KiB)
Task (runnable) @0x00007f829d945870

```

We can spawn a thread for the SVD and get back a Task in ~0.1ms. It stands to reason then that we should be able to spin up 1000 Tasks in the same way in about 100ms. But instead this code just hangs forever:

```julia
julia> @time [Threads.@spawn svdvals(rand(1000, 1000)) for _ in 1:1000]
..................

```

Why is that? Am I hitting some kind of thread limit?

---

<div class="post-metadata">

**Author:** ![ChrisRackauckas](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/chrisrackauckas/32/77_2.png) [@ChrisRackauckas](https://discourse.julialang.org/u/ChrisRackauckas)\
**Post date:** [July 17, 2020, 6:33am UTC](https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210/2 "2020-07-17T06:33:06Z")

</div>

`svd` should already be multithreaded, so I presume that spawning threads over that just isn’t a good idea since BLAS threads don’t currently compose, so it’s probably running thousands of simultaneous threads simultaneously there.

---

<div class="post-metadata">

**Author:** ![tkf](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tkf/32/17635_2.png) [@tkf](https://discourse.julialang.org/u/tkf)\
**Post date:** [July 17, 2020, 7:39am UTC](https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210/3 "2020-07-17T07:39:59Z")

</div>

> [@Samuel\_Ainsworth](#):
>
> `julia> @time Threads.@spawn svdvals(rand(1000, 1000))`

> [@Samuel\_Ainsworth](#):
>
> `julia> @time [Threads.@spawn svdvals(rand(1000, 1000)) for _ in 1:1000]`

Note that you are only starting the computation and not waiting for them. Maybe what you wanted to write was `@time @sync Threads.@spawn svdvals(rand(1000, 1000))` and `map(fetch, [Threads.@spawn svdvals(rand(1000, 1000)) for _ in 1:1000])`. However, spawning 1000 tasks at once does not sound like a good idea (although it doesn’t matter much here since `svdvals` is a compute-intensive function). It’d be better to chunk the iteration space.

In general, I highly recommend to _not_ use `@spawn` directly unless you are in very low-level programming mode. For high-level computations like this, consider one of

- [GitHub - tro3/ThreadPools.jl: Improved thread management for background and nonuniform tasks in Julia. Docs at https://tro3.github.io/ThreadPools.jl](https://github.com/tro3/ThreadPools.jl)
- [GitHub - mohamed82008/KissThreading.jl: Simple patterns supporting working with threads in Julia](https://github.com/mohamed82008/KissThreading.jl)
- [GitHub - baggepinnen/ThreadTools.jl: Some tools for working with threads in Julia](https://github.com/baggepinnen/ThreadTools.jl)
- [GitHub - Jutho/Strided.jl: A Julia package for strided array views and efficient manipulations thereof](https://github.com/Jutho/Strided.jl)
- [GitHub - mcabbott/Tullio.jl: ⅀](https://github.com/mcabbott/Tullio.jl)
- [GitHub - invenia/Parallelism.jl: A library for threaded and distributed parallelism.](https://github.com/invenia/Parallelism.jl)
- [GitHub - tkf/ThreadsX.jl: Parallelized Base functions](https://github.com/tkf/ThreadsX.jl)

But, if you use only `svdvals` (or other threaded functions from BLAS) in threads and not other functions, it doesn’t make sense to combine it with threads in Julia, as @ChrisRackauckas mentioned.

* * *

Just in case you _did_ mean to measure an overhead of just _starting_ a task, a better way is probably something like

```julia
julia> function onlystart()
           t = Task(() -> nothing)
           t.sticky = false
           schedule(t)
       end
onlystart (generic function with 1 method)

julia> @time onlystart()
  0.000005 seconds (4 allocations: 704 bytes)
Task (done) @0x00007f6e31dbb5b0

julia> @time onlystart()
  0.000003 seconds (4 allocations: 704 bytes)
Task (done) @0x00007f6e31dbdae0

```

Note that I don’t need to use `svdvals` or anything to measure the time for “spinning up” a task; it’s the same for any task.

Repeatedly calling `@time Threads.@spawn ...` is not a good idea because it’d includes compile time and `Threads.@spawn` would create a new closure every time. Using `@btime` is always a good idea but doing this here is a bit tricky:

```julia
julia> const TASKREF = Ref(onlystart())
Base.RefValue{Task}(Task (done) @0x00007f41d66e2710)

julia> @btime (TASKREF[] = onlystart()) setup = wait(TASKREF[])
  162.337 ns (4 allocations: 723 bytes)
Task (done) @0x00007f41d4370010

```

I’m not sure if this is a relevant performance characteristic, though. You’d probably want to know the overhead of starting _and_ waiting for a task:

```julia
julia> @btime wait(Threads.@spawn nothing)
  1.712 μs (5 allocations: 726 bytes)

julia> @btime foreach(wait, [Threads.@spawn nothing for _ in 1:Threads.nthreads()]);
  2.937 μs (21 allocations: 2.93 KiB)

```

* * *

_Just_ in case you’ve understood everything already but was wondering why `@time [Threads.@spawn svdvals(rand(1000, 1000)) for _ in 1:1000]` doesn’t finish quickly, I think this is because Julia is using cooperative multitasking. Once all the tasks hits the BLAS function and `ccall`ing the external function, they block Julia scheduler to do anything so it’d look like the scheduler just hangs. My guess is that all Julia threads hit `ccall` once `@time` tries to print something to stdout (which yields to the scheduler).

---

<div class="post-metadata">

**Author:** ![Samuel\_Ainsworth](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/samuel_ainsworth/32/15644_2.png) [@Samuel\_Ainsworth](https://discourse.julialang.org/u/Samuel_Ainsworth)\
**Post date:** [July 17, 2020, 8:27pm UTC](https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210/4 "2020-07-17T20:27:34Z")

</div>

> [@ChrisRackauckas](#):
>
> `svd` should already be multithreaded, so I presume that spawning threads over that just isn’t a good idea since BLAS threads don’t currently compose, so it’s probably running thousands of simultaneous threads simultaneously there.

Yeah I need to get a better “work” function. Sleeping would prob be easier I suppose…

> [@tkf](#):
>
> _Just_ in case you’ve understood everything already but was wondering why `@time [Threads.@spawn svdvals(rand(1000, 1000)) for _ in 1:1000]` doesn’t finish quickly, I think this is because Julia is using cooperative multitasking. Once all the tasks hits the BLAS function and `ccall` ing the external function, they block Julia scheduler to do anything so it’d look like the scheduler just hangs. My guess is that all Julia threads hit `ccall` once `@time` tries to print something to stdout (which yields to the scheduler).

Ah, yes I think this is the answer I was looking for. I’m still not sure I understand why `@time` is so problematic… Each thread will invoke a ccall to BLAS, but why does the scheduler block before printing out the array of tasks?

Also thanks for the pointers to higher-level packages! I’ll check those out.

---

<div class="post-metadata">

**Author:** ![tkf](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/tkf/32/17635_2.png) [@tkf](https://discourse.julialang.org/u/tkf)\
**Post date:** [July 19, 2020, 4:43am UTC](https://discourse.julialang.org/t/confusion-regarding-threads-spawn-performance/43210/5 "2020-07-19T04:43:27Z")

</div>

This is because the scheduler stops the current task (which is executing the REPL) and start executing the other tasks waiting for the CPU resource.

Here is a self-contained MWE:

```julia
function intensive_computation()
    started = time_ns()
    while time_ns() - started < 1_000_000_000
    end
end

@show Threads.nthreads()
let t0 = time_ns()
    tasks = [Threads.@spawn(intensive_computation()) for _ in 1:Threads.nthreads()]
    t1 = time_ns()
    print("all ")
    t2 = time_ns()
    println("spawned")
    t3 = time_ns()
    foreach(wait, tasks)
    t4 = time_ns()
    @show (t1 - t0) / 1_000_000
    @show (t2 - t1) / 1_000_000
    @show (t3 - t2) / 1_000_000
    @show (t4 - t3) / 1_000_000
end

```

With `julia1.5 -t2`, it prints

```julia
Threads.nthreads() = 2
all spawned
(t1 - t0) / 1000000 = 38.178896
(t2 - t1) / 1000000 = 1002.921738
(t3 - t2) / 1000000 = 0.052758
(t4 - t3) / 1000000 = 7.701817

```

Notice that `t1`-to-`t2` (which just calls `print("all ")`) is the longest and it matches with the total computation time required for this MWE. If you run this, you can see that it “hangs” briefly just after printing `all`. That is to say, the I/O `print("all ")` _looks_ like blocking the execution. The `julia` runtime tries to share the CPU resource fairly to the tasks and switches to one of the `Threads.@spawn(intensive_computation())` task, hoping they let go the CPU “soon enough.” However, this doesn’t happen with compute-intensive task, especially when you are `ccall`ing external libraries.

I think this is happening in the `@time` example in the OP. Indeed, `Base.time_print` called from `@time` first prints empty spaces (typically)

[https://github.com/JuliaLang/julia/blob/b07594dac02dc5a8e01c14444d63a27a131ebe7d/base/timing.jl#L105-L107](https://github.com/JuliaLang/julia/blob/b07594dac02dc5a8e01c14444d63a27a131ebe7d/base/timing.jl#L105-L107)

So, it looks like `print("all ")` in the MWE that blocks printing the rest of the result. My guess is that you’d see what you expected (~100 ms) if you waited long enough for all the task to complete (~100 seconds?). Here is what I see with 10 tasks:

```julia
julia> @time svdvals(rand(1000, 1000));
  0.171515 seconds (11 allocations: 15.839 MiB)

julia> t0 = time_ns()
       @time [Threads.@spawn svdvals(rand(1000, 1000)) for _ in 1:10]
       t1 = time_ns()
       (t1 - t0) / 10^9
  0.032784 seconds (51.69 k allocations: 3.062 MiB)
1.909254835

```

Notice that the time to complete the full `@time ...` expression is much longer than what `@time` itself reports.