# Profiler Timing Related to Line 0

**URL:** <https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033>\
**Category:** New to Julia\
**Tags:** profile\
**Created:** [November 6, 2021, 1:16am UTC](https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033 "2021-11-06T01:16:20Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**Author:** ![andrew-saydjari](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/andrew-saydjari/32/19896_2.png) [@andrew-saydjari](https://discourse.julialang.org/u/andrew-saydjari)\
**Post date:** [November 6, 2021, 1:16am UTC](https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033/1 "2021-11-06T01:16:20Z")

</div>

When using the profiler via ProfileSVG I sometimes see significant traceback blocks in the flame graph coming from line “0” of a notebook cell where the function was defined. An recent example is below (sorry for not being so minimal), but I really just want to know what this indicates in general. Is this saying I should be writing more type stable functions and the compiler is upset?

```julia
function build_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)
    Δx = (widx-1)÷2
    Δy = (widy-1)÷2
    halfNp = (Np-1) ÷ 2
    Δr, Δc = cx-(halfNp+1), cy-(halfNp+1)
    for dc=0:Np-1 # column shift loop
        pcr = 1:Np-dc
        for dr=1-Np:Np-1# row loop, incl negatives
            if (dr < 0) & (dc == 0)
                continue
            end
            if dr >= 0
                prr = 1:Np-dr
            end
            if (dr < 0) & (dc > 0)
                prr = 1-dr:Np
            end

            for pc=pcr, pr=prr
                i = ((pc -1)*Np)+pr
                j = ((pc+dc-1)*Np)+pr+dr
                μ1μ2 = bimage[pr+Δr,pc+Δc]*bimage[pr+dr+Δr,pc+dc+Δc]/((widx*widy)^2)
                cov[i,j] = bism[pr+Δr,pc+Δc,dr+Np,dc+1]/(widx*widy) - μ1μ2
                if i == j
                    μ[i] = μ1μ2
                end
            end
        end
    end
    cov .*= (widx*widy)/((widx*widy)-1)
    return
end

cx=100
cy=100
Np = 33
cov = zeros(Np*Np,Np*Np)
μ = zeros(Np*Np)
bimage=rand(200,400)
bism=rand(200,400,2*Np-1, Np)
widx = 13
widy = 13
build_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)

using ProfileSVG
ProfileSVG.set_default(bgcolor=:transparent,timeunit=:s,maxframes=100000,maxdepth=300)
Profile.init(n=10^7,delay=1e-5)
ProfileSVG.@profview build_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)

```

 ![Screen Shot 2021-11-05 at 9.15.40 PM](https://global.discourse-cdn.com/julialang/original/3X/f/e/fe8855661216f05820e4ca855e58d6acdcdfc310.png)

---

<div class="post-metadata">

**Author:** ![andrew-saydjari](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/andrew-saydjari/32/19896_2.png) [@andrew-saydjari](https://discourse.julialang.org/u/andrew-saydjari)\
**Post date:** [November 6, 2021, 1:24am UTC](https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033/2 "2021-11-06T01:24:47Z")

</div>

Adding @inbounds seems to reduce this traceback bar to be an order of magnitude smaller. Is time spent bound checking expected to manifest this way?

---

<div class="post-metadata">

**Author:** ![LaurentPlagne](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/laurentplagne/32/10103_2.png) [@LaurentPlagne](https://discourse.julialang.org/u/LaurentPlagne)\
**Post date:** [January 16, 2024, 9:20am UTC](https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033/3 "2024-01-16T09:20:54Z")

</div>

I have the same question…

---

<div class="post-metadata">

**Author:** ![LaurentPlagne](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/laurentplagne/32/10103_2.png) [@LaurentPlagne](https://discourse.julialang.org/u/LaurentPlagne)\
**Post date:** [March 20, 2024, 10:21pm UTC](https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033/4 "2024-03-20T22:21:46Z")

</div>

I think that the time related to line 0 corresponds to the **overhead of the profiling**.  
I have the impression that the real time (without profiling) is correctly predicted from the rest of the profiling data.

For example, if a given optimization leads to a profiling time, excluding the line 0 related time, that is divided by two, then the real time is effectively divided by two.

My personal conclusion is then : forget about the profiler time related to line 0.

Note that I did not investigate enough to prove this assertion.

---

<div class="post-metadata">

**Author:** ![nsajko](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/nsajko/32/221187_2.png) [@nsajko](https://discourse.julialang.org/u/nsajko)\
**Post date:** [March 21, 2024, 11:26am UTC](https://discourse.julialang.org/t/profiler-timing-related-to-line-0/71033/5 "2024-03-21T11:26:37Z")

</div>

Bug report:

> <https://github.com/JuliaLang/julia/issues/53804>
>
> This example is from a Discourse \[post\](https://discourse.julialang.org/t/profil…er-timing-related-to-line-0/71033) that doesn't seem like it was ever turned into a bug report.
> 
> \`/tmp/j.jl\`:
> \`\`\`julia
> function build\_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)
> Δx = (widx-1)÷2
> Δy = (widy-1)÷2
> halfNp = (Np-1) ÷ 2
> Δr, Δc = cx-(halfNp+1), cy-(halfNp+1)
> for dc=0:Np-1 # column shift loop
> pcr = 1:Np-dc
> for dr=1-Np:Np-1# row loop, incl negatives
> if (dr \< 0) & (dc == 0)
> continue
> end
> if dr \>= 0
> prr = 1:Np-dr
> end
> if (dr \< 0) & (dc \> 0)
> prr = 1-dr:Np
> end
> 
> for pc=pcr, pr=prr
> i = ((pc -1)\*Np)+pr
> j = ((pc+dc-1)\*Np)+pr+dr
> μ1μ2 = bimage\[pr+Δr,pc+Δc\]\*bimage\[pr+dr+Δr,pc+dc+Δc\]/((widx\*widy)^2)
> cov\[i,j\] = bism\[pr+Δr,pc+Δc,dr+Np,dc+1\]/(widx\*widy) - μ1μ2
> if i == j
> μ\[i\] = μ1μ2
> end
> end
> end
> end
> cov .\*= (widx\*widy)/((widx\*widy)-1)
> return
> end
> 
> cx=100
> cy=100
> Np = 33
> cov = zeros(Np\*Np,Np\*Np)
> μ = zeros(Np\*Np)
> bimage=rand(200,400)
> bism=rand(200,400,2\*Np-1, Np)
> widx = 13
> widy = 13
> build\_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)
> 
> import Profile
> Profile.init(n=10^7,delay=1e-5)
> const opt\_checked = Val(:checked)
> const opt\_unchecked = Val(:unchecked)
> Profile.@profile build\_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)
> Profile.clear()
> \`\`\`
> 
> REPL:
> \`\`\`julia-repl
> julia\> include("/tmp/j.jl")
> 
> julia\> Profile.@profile build\_cov!(cov,μ,cx,cy,bimage,bism,Np,widx,widy)
> 
> julia\> Profile.print()
> Overhead ╎ \[+additional indent\] Count File:Line; Function
> =========================================================
> ╎549 @Base/client.jl:543; \_start()
> ╎ 549 @Base/client.jl:569; repl\_main
> ╎ 549 @Base/client.jl:432; run\_main\_repl(interactive::Bool, quiet::Bool, banner::Symbol, history\_file::Bool, color\_set::Bool)
> ╎ 549 @Base/essentials.jl:1027; invokelatest
> ╎ 549 @Base/essentials.jl:1030; #invokelatest#2
> ╎ 549 @Base/client.jl:448; (::Base.var"#1130#1132"{Bool, Symbol, Bool})(REPL::Module)
> ╎ ╎ 549 …i4-5/julialang/julia-master/usr/share/julia/stdlib/v1.12/REPL/src/REPL.jl:453; run\_repl(repl::REPL.AbstractREPL, consumer::Any)
> ╎ ╎ 549 …4-5/julialang/julia-master/usr/share/julia/stdlib/v1.12/REPL/src/REPL.jl:467; run\_repl(repl::REPL.AbstractREPL, consumer::Any; backend\_on\_current\_task::Bool, backend::Any)
> ╎ ╎ 549 …4-5/julialang/julia-master/usr/share/julia/stdlib/v1.12/REPL/src/REPL.jl:308; kwcall(::NamedTuple, ::typeof(REPL.start\_repl\_backend), backend::REPL.REPLBackend, consumer::Any)
> ╎ ╎ 549 …-5/julialang/julia-master/usr/share/julia/stdlib/v1.12/REPL/src/REPL.jl:311; start\_repl\_backend(backend::REPL.REPLBackend, consumer::Any; get\_module::Function)
> ╎ ╎ 549 …-5/julialang/julia-master/usr/share/julia/stdlib/v1.12/REPL/src/REPL.jl:326; repl\_backend\_loop(backend::REPL.REPLBackend, get\_module::Function)
> ╎ ╎ ╎ 549 …-5/julialang/julia-master/usr/share/julia/stdlib/v1.12/REPL/src/REPL.jl:229; eval\_user\_input(ast::Any, backend::REPL.REPLBackend, mod::Module)
> 2╎ ╎ ╎ 549 @Base/boot.jl:428; eval
> 2╎ ╎ ╎ 2 @Base/abstractarray.jl:0; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> 289╎ ╎ ╎ 289 /tmp/j.jl:0; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> ╎ ╎ ╎ 11 /tmp/j.jl:22; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> ╎ ╎ ╎ 11 @Base/array.jl:923; getindex
> 5╎ ╎ ╎ 11 @Base/abstractarray.jl:699; checkbounds
> ╎ ╎ ╎ ╎ 6 @Base/abstractarray.jl:681; checkbounds
> ╎ ╎ ╎ ╎ 6 @Base/abstractarray.jl:725; checkbounds\_indices
> ╎ ╎ ╎ ╎ 6 @Base/abstractarray.jl:754; checkindex
> 6╎ ╎ ╎ ╎ 6 @Base/int.jl:513; \<
> ╎ ╎ ╎ 112 /tmp/j.jl:23; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> 1╎ ╎ ╎ 1 @Base/abstractarray.jl:0; setindex!
> ╎ ╎ ╎ 3 @Base/array.jl:923; getindex
> 3╎ ╎ ╎ 3 @Base/abstractarray.jl:697; checkbounds
> ╎ ╎ ╎ 64 @Base/array.jl:924; getindex
> 64╎ ╎ ╎ 64 @Base/essentials.jl:892; getindex
> ╎ ╎ ╎ 7 @Base/array.jl:987; setindex!
> 3╎ ╎ ╎ 3 @Base/abstractarray.jl:0; checkbounds
> 4╎ ╎ ╎ 4 @Base/abstractarray.jl:699; checkbounds
> 12╎ ╎ ╎ 12 @Base/array.jl:988; setindex!
> 21╎ ╎ ╎ 21 @Base/float.jl:479; -
> ╎ ╎ ╎ 4 @Base/promotion.jl:428; /
> 4╎ ╎ ╎ 4 @Base/float.jl:481; /
> ╎ ╎ ╎ 26 /tmp/j.jl:24; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> 25╎ ╎ ╎ 26 @Base/promotion.jl:635; ==
> 1╎ ╎ ╎ 2 /tmp/j.jl:27; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> ╎ ╎ ╎ 1 @Base/range.jl:908; iterate
> 1╎ ╎ ╎ 1 @Base/promotion.jl:635; ==
> ╎ ╎ ╎ 105 /tmp/j.jl:30; build\_cov!(cov::Matrix{Float64}, μ::Vector{Float64}, cx::Int64, cy::Int64, bimage::Matrix{Float64}, bism::Array{Float64, 4}, Np::Int64, widx::Int64, widy::Int64)
> ╎ ╎ ╎ 105 @Base/broadcast.jl:875; materialize!
> ╎ ╎ ╎ 105 @Base/broadcast.jl:878; materialize!
> ╎ ╎ ╎ ╎ 105 @Base/broadcast.jl:920; copyto!
> ╎ ╎ ╎ ╎ 105 @Base/broadcast.jl:967; copyto!
> ╎ ╎ ╎ ╎ 105 @Base/simdloop.jl:77; macro expansion
> ╎ ╎ ╎ ╎ 105 @Base/broadcast.jl:968; macro expansion
> ╎ ╎ ╎ ╎ 80 @Base/broadcast.jl:605; getindex
> ╎ ╎ ╎ ╎ ╎ 1 @Base/broadcast.jl:645; \_broadcast\_getindex
> ╎ ╎ ╎ ╎ ╎ 1 @Base/broadcast.jl:669; \_getindex
> ╎ ╎ ╎ ╎ ╎ 1 @Base/broadcast.jl:639; \_broadcast\_getindex
> ╎ ╎ ╎ ╎ ╎ 1 @Base/multidimensional.jl:700; getindex
> ╎ ╎ ╎ ╎ ╎ 1 @Base/array.jl:924; getindex
> ╎ ╎ ╎ ╎ ╎ ╎ 1 @Base/abstractarray.jl:1371; \_to\_linear\_index
> ╎ ╎ ╎ ╎ ╎ ╎ 1 @Base/abstractarray.jl:3081; \_sub2ind
> ╎ ╎ ╎ ╎ ╎ ╎ 1 @Base/abstractarray.jl:3097; \_sub2ind
> ╎ ╎ ╎ ╎ ╎ ╎ 1 @Base/abstractarray.jl:3113; \_sub2ind\_recurse
> 1╎ ╎ ╎ ╎ ╎ ╎ 1 @Base/int.jl:87; +
> ╎ ╎ ╎ ╎ ╎ 79 @Base/broadcast.jl:646; \_broadcast\_getindex
> ╎ ╎ ╎ ╎ ╎ 79 @Base/broadcast.jl:673; \_broadcast\_getindex\_evalf
> 79╎ ╎ ╎ ╎ ╎ 79 @Base/float.jl:480; \*
> ╎ ╎ ╎ ╎ 25 @Base/multidimensional.jl:702; setindex!
> 25╎ ╎ ╎ ╎ ╎ 25 @Base/array.jl:988; setindex!
> Total snapshots: 549. Utilization: 100% across all threads and tasks. Use the \`groupby\` kwarg to break down by thread and/or task.
> 
> julia\> versioninfo()
> Julia Version 1.12.0-DEV.162
> Commit 5c7d24493eb (2024-03-09 22:22 UTC)
> Build Info:
> Official https://julialang.org/ release
> Platform Info:
> OS: Linux (x86\_64-linux-gnu)
> CPU: 8 × AMD Ryzen 3 5300U with Radeon Graphics
> WORD\_SIZE: 64
> LLVM: libLLVM-16.0.6 (ORCJIT, znver2)
> Threads: 1 default, 0 interactive, 1 GC (on 8 virtual cores)
> \`\`\`
> 
> Several things in the profiler output seem wrong:
> 
> 1. Some line numbers are zero
> 
> 2. The entry \`549 @Base/boot.jl:428; eval\` has \`2 @Base/abstractarray.jl:0; build\_cov!\` as a (direct) child, seems like an incomplete stack trace, that is, some intermediate entries are missing
> 
> 3. The entry \`2 @Base/abstractarray.jl:0; build\_cov!\` is nonsensical because there is no \`build\_cov!\` in \`abstractarray.jl\`
> 
> Perhaps some of the malformed entries are related to bounds checking?