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.

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

Invalidations and problems with stack traces #409

Closed
ranocha opened this issue Mar 8, 2023 · 4 comments
Closed

Invalidations and problems with stack traces #409

ranocha opened this issue Mar 8, 2023 · 4 comments

Comments

@ranocha
Copy link
Member

ranocha commented Mar 8, 2023

I don't really know where to report this, so please move it somewhere else.

I had a brief look at load times using Julia v1.9.0-rc1:

julia> @time_imports using OrdinaryDiffEq
[...]
    416.1 ms  TruncatedStacktraces 93.53% compilation time (63% recompilation)
[...]
    237.7 ms  SciMLBase 4.98% compilation time (100% recompilation)
[...]

This made me suspicious. Thus, I wanted to check whether invalidations are the reason but ran into some problems:

julia> using Pkg; Pkg.activate(temp=true); Pkg.add("SciMLBase")
[...]
  [0bca4576] + SciMLBase v1.89.0
[...]
  [781d530d] + TruncatedStacktraces v1.1.0
[...]

julia> using SnoopCompileCore; invalidations = @snoopr(using SciMLBase); using SnoopCompile

julia> length(uinvalidated(invalidations))
2113

julia> trees = invalidation_trees(invalidations)
5-element Vector{SnoopCompile.MethodInvalidations}:
Error showing value of type Vector{SnoopCompile.MethodInvalidations}:
ERROR: UndefVarError: `isinplace` not defined

Some of the types have been truncated in the stacktrace for improved reading. To emit complete information
in the stack trace, evaluate `TruncatedStacktraces.VERBOSE[] = true` and re-run the code.

Stacktrace:
  [1] show(io::IOContext{IOBuffer}, t::
SYSTEM (REPL): showing an error caused an error
ERROR: UndefVarError: `isinplace` not defined

Some of the types have been truncated in the stacktrace for improved reading. To emit complete information
in the stack trace, evaluate `TruncatedStacktraces.VERBOSE[] = true` and re-run the code.

Stacktrace:
  [1] show(io::IOContext{IOBuffer}, t::
SYSTEM (REPL): caught exception of type UndefVarError while trying to handle a nested exception; giving up

So there are indeed quite a lot of invalidations. However, it's hard to see the full report since something fails. Verbose printing doesn't help:

julia> Pkg.add("TruncatedStacktraces"); using TruncatedStacktraces; TruncatedStacktraces.VERBOSE[] = true

julia> trees[5]
inserting Error showing value of type SnoopCompile.MethodInvalidations:
ERROR: UndefVarError: `uType` not defined
Stacktrace:
  [1] show(io::IOContext{IOBuffer}, t::
SYSTEM (REPL): showing an error caused an error
ERROR: UndefVarError: `uType` not defined
Stacktrace:
  [1] show(io::IOContext{IOBuffer}, t::
SYSTEM (REPL): caught exception of type UndefVarError while trying to handle a nested exception; giving up

I suspect TruncatedStacktraces.jl to play a role here, though:

julia> trees[5].method.name
:show

julia> trees[5].backedges
2-element Vector{SnoopCompile.InstanceNode}:
 MethodInstance for show(::IOContext{IOBuffer}, ::Type) at depth 0 with 107 children
 MethodInstance for show(::IOBuffer, ::Type) at depth 0 with 3064 children

The first four methods do not have many invalidations and can be displayed without problems:

julia> trees[1]
inserting unique(x::FillArrays.AbstractFill{T}) where T @ FillArrays ~/.julia/packages/FillArrays/xqile/src/FillArrays.jl:555 invalidated:
   backedges: 1: superseding unique(A::AbstractArray; dims) @ Base multidimensional.jl:1640 with MethodInstance for unique(::AbstractArray) (1 children)


julia> trees[2]
inserting Base.IteratorSize(::Type{<:FillArrays.AbstractFill{T, N, Axes}}) where {T, N, Axes} @ FillArrays ~/.julia/packages/FillArrays/xqile/src/FillArrays.jl:64 invalidated:
   backedges: 1: superseding Base.IteratorSize(::Type) @ Base generator.jl:94 with MethodInstance for Base.IteratorSize(::Type{<:AbstractString}) (5 children)
   87 mt_cache


julia> trees[3]
inserting print_matrix_row(io::IO, X::Union{FillArrays.AbstractFill{<:Any, 1}, FillArrays.AbstractFill{<:Any, 2}, FillArrays.RectDiagonal, LinearAlgebra.AbstractTriangular{<:Any, <:FillArrays.AbstractFill{<:Any, 2}}, LinearAlgebra.Diagonal{<:Any, <:FillArrays.AbstractFill{<:Any, 1}}}, A::Vector, i::Integer, cols::AbstractVector, sep::AbstractString, idxlast::Integer) @ FillArrays ~/.julia/packages/FillArrays/xqile/src/FillArrays.jl:688 invalidated:
   backedges: 1: superseding print_matrix_row(io::IO, X::AbstractVecOrMat, A::Vector, i::Integer, cols::AbstractVector, sep::AbstractString, idxlast::Integer) @ Base arrayshow.jl:97 with MethodInstance for Base.print_matrix_row(::IOContext{Base.TTY}, ::AbstractVecOrMat, ::Vector{Tuple{Int64, Int64}}, ::Int64, ::Vector{Int64}, ::String, ::Int64) (9 children)


julia> trees[4]
inserting broadcasted(::Base.Broadcast.DefaultArrayStyle{N}, op, r::FillArrays.AbstractFill{T, N}) where {T, N} @ FillArrays ~/.julia/packages/FillArrays/xqile/src/fillbroadcast.jl:78 invalidated:
   mt_backedges: 1: signature broadcasted(::S, f, args...) where S<:BroadcastStyle @ Base.Broadcast broadcast.jl:1319 (formerly broadcasted(::S, f, args...) where S<:BroadcastStyle @ Base.Broadcast broadcast.jl:1319) triggered MethodInstance for Base.Broadcast.broadcasted(::typeof(esc), ::Any) (20 children)
   66 mt_cache
@devmotion
Copy link
Member

Could it be that these invalidations are caused by the definitions of show(::IO, ::Type) that are required when using TruncatedStacktraces? At least such definitions tend to cause invalidations in other places, e.g., FluxML/Zygote.jl#1356 PainterQubits/Unitful.jl#321 JuliaGeometry/GeometryBasics.jl#67 SciML/RuntimeGeneratedFunctions.jl#16

@ranocha
Copy link
Member Author

ranocha commented Mar 8, 2023

Yes, I suspect so.

@KristofferC
Copy link

julia> struct Foo end

julia> Base.show(io::IO, t::Type{Foo}) = @invoke show(io::IO, t::Type)

julia> @time using Random
  0.402905 seconds (576.12 k allocations: 39.977 MiB, 1.94% gc time, 99.02% compilation time: 100% of which was recompilation)

@ChrisRackauckas
Copy link
Member

Fixed by making stacktraces huge.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants