Skip to content

most of the profile runtime is in task_done_hook unless threads = 1 #41713

@tpapp

Description

@tpapp

When the number of threads is not 1, a lot of time is reported in task_done_hook. This makes profiling results confusing. julia -t 1 is a workaround.

julia> VERSION
v"1.8.0-DEV.271"

julia> using Profile

julia> f(n) = [sum(randn(100)) for _ in 1:n]
f (generic function with 1 method)

julia> f(1);

julia> @profile f(10^5);

julia> Profile.print(; maxdepth = 3)
Overhead ╎ [+additional indent] Count File:Line; Function
=========================================================
   ╎261  @Base/client.jl:495; _start()
   ╎ 261  @Base/client.jl:309; exec_options(opts::Base.JLOptions)
   ╎  261  @Base/client.jl:379; run_main_repl(interactive::Bool, quiet::Bool, banner::Bool, history_file::Bool, color_set::Bool)
   ╎   261  @Base/essentials.jl:716; invokelatest
   ╎530  @Base/task.jl:531; task_done_hook(t::Task)
   ╎ 530  @Base/task.jl:823; wait()
529530  @Base/task.jl:814; poptask(W::Base.InvasiveLinkedListSynchronized{Task})
   ╎265  @Base/threadingconstructs.jl:178; (::Distributed.var"#145#147")()
   ╎ 265  @Distributed/src/remotecall.jl:260; macro expansion
   ╎  265  @Base/condition.jl:78; lock
   ╎   265  @Base/lock.jl:187; lock(f::Distributed.var"#146#148", l::ReentrantLock)
  1╎1    @Random/src/normal.jl:38; randn(rng::Random.TaskLocalRNG)
  2╎2    @Random/src/normal.jl:70; randn_unlikely(rng::Random.TaskLocalRNG, idx::Int64, rabs::Int64, x::Float64)
Total snapshots: 1060

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions