Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

SnoopCompile investigation #122

Closed
gdalle opened this issue Jun 14, 2024 · 3 comments
Closed

SnoopCompile investigation #122

gdalle opened this issue Jun 14, 2024 · 3 comments

Comments

@gdalle
Copy link
Collaborator

gdalle commented Jun 14, 2024 •
edited
Loading

Since we're having latency trouble in #120, I thought it would be interesting to analyze method invalidations with SnoopCompile.

EDIT: I tried removing most of those myself in the source code, and the britgas Hessian latency remains unchanged.

To reproduce, start a Julia REPL with

julia --startup-file="no"

then run

using Pkg
Pkg.activate(temp=true)
Pkg.add(["SnoopCompileCore", "SnoopCompile", "SparseConnectivityTracer"])
using SnoopCompileCore
invalidations = @snoopr using SparseConnectivityTracer
using SnoopCompile
trees = invalidation_trees(invalidations)

Here are the results, with the most important invalidations printed last (do it in your terminal you'll have colored outputs)

julia> length(invalidations)
2469

julia> trees
13-element Vector{SnoopCompile.MethodInvalidations}:
 inserting ifelse(::SparseConnectivityTracer.AbstractTracer, x, y) @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/overload_ifelse.jl:2 invalidated:
   mt_backedges: 1: signature Tuple{typeof(ifelse), Any, Integer, Integer} triggered MethodInstance for max(::T, ::T) where T<:Integer (0 children)

 inserting similar(a::Vector{D}) where {P, T, D<:Dual{P, T}} @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/conversion.jl:78 invalidated:
   backedges: 1: superseding similar(a::Vector{T}) where T @ Base array.jl:415 with MethodInstance for similar(::Vector{T}) where T (1 children)

 inserting convert(::Type{T}, x::Real) where T<:AbstractTracer @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/conversion.jl:11 invalidated:
   backedges: 1: superseding convert(::Type{T}, x::Number) where T<:Number @ Base number.jl:7 with MethodInstance for convert(::Type{T} where T<:Real, ::Int64) (4 children)

 inserting resize!(x::SparseArrays.ReadOnly, l) @ SparseArrays ~/.julia/juliaup/julia-1.10.4+0.x64.linux.gnu/share/julia/stdlib/v1.10/SparseArrays/src/readonly.jl:33 invalidated:
   mt_backedges: 1: signature Tuple{typeof(resize!), Any, Int64} triggered MethodInstance for Base.remove_linenums!(::Core.CodeInfo) (7 children)

 inserting promote_rule(::Type{N}, ::Type{SparseConnectivityTracer.Dual{P, T}}) where {P, T, N<:Real} @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/conversion.jl:48 invalidated:
   backedges: 1: superseding promote_rule(::Type, ::Type) @ Base promotion.jl:325 with MethodInstance for promote_rule(::Type{Int64}, ::Type{S} where S<:Real) (2 children)
              2: superseding promote_rule(::Type, ::Type) @ Base promotion.jl:325 with MethodInstance for promote_rule(::Type{UInt8}, ::Type) (3 children)
              3: superseding promote_rule(::Type, ::Type) @ Base promotion.jl:325 with MethodInstance for promote_rule(::Type{Int128}, ::Type) (3 children)
              4: superseding promote_rule(::Type, ::Type) @ Base promotion.jl:325 with MethodInstance for promote_rule(::Type{Int64}, ::Type) (6 children)

 inserting _any(f, A::SparseArrays.AbstractSparseMatrixCSC, ::Colon) @ SparseArrays ~/.julia/juliaup/julia-1.10.4+0.x64.linux.gnu/share/julia/stdlib/v1.10/SparseArrays/src/sparsematrix.jl:2375 invalidated:
   backedges:  1: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{ComposedFunction{ComposedFunction{O, I}, typeof(adjoint)}, typeof(transpose)} where {O, I}, ::Any, ::Colon) (1 children)
               2: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{ComposedFunction{O, I}, typeof(adjoint)} where {O, I}, ::Any, ::Colon) (1 children)
               3: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{ComposedFunction{typeof(ismissing), typeof(adjoint)}, typeof(transpose)}, ::Any, ::Colon) (1 children)
               4: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{typeof(ismissing), typeof(adjoint)}, ::Any, ::Colon) (1 children)
               5: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{ComposedFunction{typeof(ismissing), typeof(transpose)}, typeof(adjoint)}, ::Any, ::Colon) (1 children)
               6: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{ComposedFunction{ComposedFunction{O, I}, typeof(transpose)}, typeof(adjoint)} where {O, I}, ::Any, ::Colon) (1 children)
               7: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{typeof(ismissing), typeof(transpose)}, ::Any, ::Colon) (1 children)
               8: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::typeof(ismissing), ::AbstractArray, ::Colon) (1 children)
               9: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::typeof(ismissing), ::Any, ::Colon) (1 children)
              10: superseding _any(f, itr, ::Colon) @ Base reduce.jl:1217 with MethodInstance for Base._any(::ComposedFunction{ComposedFunction{O, I}, typeof(transpose)} where {O, I}, ::Any, ::Colon) (26 children)
   1 mt_cache

 inserting _all(f, A::SparseArrays.AbstractSparseMatrixCSC, ::Colon) @ SparseArrays ~/.julia/juliaup/julia-1.10.4+0.x64.linux.gnu/share/julia/stdlib/v1.10/SparseArrays/src/sparsematrix.jl:2377 invalidated:
   backedges:  1: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{ComposedFunction{ComposedFunction{O, I}, typeof(adjoint)}, typeof(transpose)} where {O, I}, ::Any, ::Colon) (1 children)
               2: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{ComposedFunction{O, I}, typeof(adjoint)} where {O, I}, ::Any, ::Colon) (1 children)
               3: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{ComposedFunction{Base.var"#947#948", typeof(adjoint)}, typeof(transpose)}, ::Any, ::Colon) (1 children)
               4: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{Base.var"#947#948", typeof(adjoint)}, ::Any, ::Colon) (1 children)
               5: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{ComposedFunction{Base.var"#947#948", typeof(transpose)}, typeof(adjoint)}, ::Any, ::Colon) (1 children)
               6: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{ComposedFunction{ComposedFunction{O, I}, typeof(transpose)}, typeof(adjoint)} where {O, I}, ::Any, ::Colon) (1 children)
               7: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{Base.var"#947#948", typeof(transpose)}, ::Any, ::Colon) (1 children)
               8: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::Base.var"#947#948", ::AbstractArray, ::Colon) (1 children)
               9: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::Base.var"#947#948", ::Any, ::Colon) (1 children)
              10: superseding _all(f, itr, ::Colon) @ Base reduce.jl:1285 with MethodInstance for Base._all(::ComposedFunction{ComposedFunction{O, I}, typeof(transpose)} where {O, I}, ::Any, ::Colon) (26 children)

 inserting isnothing(t::T) where T<:AbstractTracer @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/overload_dual.jl:17 invalidated:
   backedges: 1: superseding isnothing(x) @ Base some.jl:69 with MethodInstance for isnothing(::Any) (36 children)

 inserting similar(a::Array, ::Type{SparseConnectivityTracer.Dual{P, T}}, dims::Tuple{Vararg{Int64, N}}) where {P, T, N} @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/conversion.jl:106 invalidated:
   mt_backedges: 1: signature Tuple{typeof(similar), Vector, Any, Tuple{Int64}} triggered MethodInstance for similar(::Vector, ::Tuple{Base.OneTo{Int64}}) (2 children)
   backedges: 1: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector, ::Type, ::Tuple{Int64}) (1 children)
              2: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Int64}, ::DataType, ::Tuple{Int64}) (3 children)
              3: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Pair{DataType, Function}}, ::DataType, ::Tuple{Int64}) (3 children)
              4: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Dict{String, Dates.DateTime}}, ::DataType, ::Tuple{Int64}) (3 children)
              5: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Any}, ::Type, ::Tuple{Int64}) (5 children)
              6: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Int64}, ::Type, ::Tuple{Int64}) (5 children)
              7: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Pair{DataType, Function}}, ::Type, ::Tuple{Int64}) (5 children)
              8: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Dict{String, Dates.DateTime}}, ::Type, ::Tuple{Int64}) (5 children)
              9: superseding similar(a::Array, T::Type, dims::Tuple{Vararg{Int64, N}}) where N @ Base array.jl:420 with MethodInstance for similar(::Vector{Any}, ::DataType, ::Tuple{Int64}) (6 children)
   28 mt_cache

 inserting convert(::Type{N}, d::D) where {N<:Real, P, T, D<:Dual{P, T}} @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/conversion.jl:59 invalidated:
   backedges: 1: superseding convert(::Type{T}, x::T) where T<:Number @ Base number.jl:6 with MethodInstance for convert(::Type{T}, ::Real) where T<:Real (2 children)
              2: superseding convert(::Type{T}, x::Number) where T<:Number @ Base number.jl:7 with MethodInstance for convert(::Type{T} where T<:Real, ::Real) (18 children)
              3: superseding convert(::Type{T}, x::Number) where T<:Number @ Base number.jl:7 with MethodInstance for convert(::Type{Int64}, ::Real) (26 children)

 inserting identity(d::D) where {P, T<:HessianTracer, D<:Dual{P, T}} @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/overload_hessian.jl:43 invalidated:
   backedges: 1: superseding identity(x) @ Base operators.jl:522 with MethodInstance for identity(::Any) (49 children)
   1 mt_cache

 inserting similar(a::Vector{A}, ::Type{D}) where {P, T, D<:Dual{P, T}, A} @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/conversion.jl:86 invalidated:
   backedges: 1: superseding similar(a::Vector{T}, S::Type) where T @ Base array.jl:417 with MethodInstance for similar(::Vector{T} where T<:(NamedTuple{(:exception, :backtrace), <:Tuple{Any, Vector{Any}}}), ::Type) (2 children)
              2: superseding similar(a::Vector{T}, S::Type) where T @ Base array.jl:417 with MethodInstance for similar(::Vector{@NamedTuple{exception::Base.IOError, backtrace::Vector{Any}}}, ::Type) (2 children)
              3: superseding similar(a::Vector{T}, S::Type) where T @ Base array.jl:417 with MethodInstance for similar(::Vector{Dates.DateTime}, ::Type) (2 children)
              4: superseding similar(a::Vector{T}, S::Type) where T @ Base array.jl:417 with MethodInstance for similar(::Vector{T} where T<:(NamedTuple{(:name, :uuid), <:Tuple{Union{Nothing, String}, Union{Nothing, Base.UUID}}}), ::Type) (2 children)
              5: superseding similar(a::Vector{T}, S::Type) where T @ Base array.jl:417 with MethodInstance for similar(::Vector, ::Type) (137 children)
   6 mt_cache

 inserting ismissing(t::T) where T<:AbstractTracer @ SparseConnectivityTracer ~/.julia/packages/SparseConnectivityTracer/QlV0S/src/overload_dual.jl:17 invalidated:
   backedges: 1: superseding ismissing(x) @ Base essentials.jl:1010 with MethodInstance for ismissing(::Any) (677 children)
@gdalle
Copy link
Collaborator Author

gdalle commented Jun 14, 2024

Moving on to analyzing inference with @snoopi_deep:

InferenceTimingNode: 28.898476/29.122585 on Core.Compiler.Timings.ROOT() with 3 direct children
├─ InferenceTimingNode: 0.000201/0.000292 on Base.MainInclude.include(::String) with 1 direct children
│  └─ InferenceTimingNode: 0.000091/0.000091 on getproperty(Base::Module, _include::Symbol) with 0 direct children
├─ InferenceTimingNode: 0.000073/0.000251 on TracerSparsityDetector() with 1 direct children
│  └─ InferenceTimingNode: 0.000045/0.000179 on SparseConnectivityTracer.var"#TracerSparsityDetector#22"(::Type{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}}, ::Type{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}, ::Type{TracerSparsityDetector}) with 1 direct children
│     └─ InferenceTimingNode: 0.000073/0.000134 on TracerSparsityDetector(::Type{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}}, ::Type{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}) with 1 direct children
│        └─ InferenceTimingNode: 0.000062/0.000062 on TracerSparsityDetector{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}() with 0 direct children
└─ InferenceTimingNode: 0.000104/0.223566 on ADTypes.hessian_sparsity(sum_britgas_cons::typeof(sum_britgas_cons), ::Vector{Float64}, TracerSparsityDetector{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}()::TracerSparsityDetector{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}) with 1 direct children
   └─ InferenceTimingNode: 0.000324/0.223462 on SparseConnectivityTracer.hessian_pattern(sum_britgas_cons::typeof(sum_britgas_cons), ::Vector{Float64}, ::Type{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}) with 6 direct children
      ├─ InferenceTimingNode: 0.000135/0.196236 on SparseConnectivityTracer.trace_function(::Type{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, sum_britgas_cons::typeof(sum_britgas_cons), ::Vector{Float64}) with 2 direct children
      │  ├─ InferenceTimingNode: 0.000078/0.024021 on SparseConnectivityTracer.trace_input(::Type{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, ::Vector{Float64}) with 1 direct children
      │  │  └─ InferenceTimingNode: 0.001155/0.023943 on SparseConnectivityTracer.trace_input(::Type{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, ::Vector{Float64}, ::Int64) with 6 direct children
      │  │     ⋮
      │  │     
      │  └─ InferenceTimingNode: 0.001732/0.172080 on sum_britgas_cons(::Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}) with 2 direct children
      │     ├─ InferenceTimingNode: 0.074998/0.162375 on britgas_cons(::Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}) with 22 direct children
      │     │  ⋮
      │     │  
      │     └─ InferenceTimingNode: 0.000117/0.007973 on sum(::Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}) with 1 direct children
      │        ⋮
      │        
      ├─ InferenceTimingNode: 0.000098/0.000263 on Base.indexed_iterate(::Tuple{Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, ::Int64) with 2 direct children
      │  ├─ InferenceTimingNode: 0.000164/0.000164 on Base.indexed_iterate(::Tuple{Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, ::Int64, ::Int64) with 0 direct children
      │  └─ InferenceTimingNode: 0.000001/0.000001 on Base.indexed_iterate(::Tuple{Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, ::Int64, 1::Int64) with 0 direct children
      ├─ InferenceTimingNode: 0.000016/0.000016 on Base.indexed_iterate(::Tuple{Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, 1::Int64) with 0 direct children
      ├─ InferenceTimingNode: 0.000008/0.000008 on Base.indexed_iterate(::Tuple{Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, 2::Int64, 2::Int64) with 0 direct children
      ├─ InferenceTimingNode: 0.000024/0.000024 on SparseConnectivityTracer.to_array(::Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}) with 0 direct children
      └─ InferenceTimingNode: 0.001054/0.026590 on SparseConnectivityTracer.hessian_pattern_to_mat(::Vector{SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}}, ::SparseConnectivityTracer.HessianTracer{SparseConnectivityTracer.CombinedPattern{SparseConnectivityTracer.IndexSetVectorPattern{Int64, BitSet}, SparseConnectivityTracer.IndexSetMatrixPattern{Int64, Set{Tuple{Int64, Int64}}}}}) with 10 direct children

Judging by the documentation:

Each node in this tree is accompanied by a pair of numbers. The first number is the exclusive inference time (in seconds), meaning the time spent inferring the particular MethodInstance, not including the time spent inferring its callees. The second number is the inclusive time, which is the exclusive time plus the time spent on the callees. Therefore, the inclusive time is always at least as large as the exclusive time.

The ROOT node is a bit different: its exclusive time measures the time spent on all operations except inference. In this case, we see that the entire call took approximately 10ms, of which 9.3ms was spent on activities besides inference. Almost all of that was code-generation, but it also includes the time needed to run the code. Just 0.76ms was needed to run type-inference on this entire series of calls. As you will quickly discover, inference takes much more time on more complicated code.

In other words we spent most of the time doing stuff that is not inference (which is not very surprising since the code is type-stable).

@gdalle
Copy link
Collaborator Author

gdalle commented Jun 14, 2024

Most promising avenue: https://timholy.github.io/SnoopCompile.jl/dev/pgdsgui/#pgds

@gdalle gdalle changed the title Fixing (some) invalidations SnoopCompile investigation Jun 14, 2024
@adrhill
Copy link
Owner

adrhill commented Jun 14, 2024

Closing this, since the cause of the compile time problem in #120 has been found and fixes. The solution is described here:
#120 (comment)

Invalidations on similar tracked in #123.

@adrhill adrhill closed this as completed Jun 14, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@adrhill @gdalle