From 5ff777bc6d519e966326793f06e39a412540d926 Mon Sep 17 00:00:00 2001 From: Tim Holy Date: Fri, 6 Aug 2021 11:56:14 -0500 Subject: [PATCH] JET integration --- Project.toml | 2 + docs/make.jl | 4 +- docs/src/index.md | 4 ++ docs/src/jet.md | 133 ++++++++++++++++++++++++++++++++++++++ docs/src/reference.md | 3 + src/SnoopCompile.jl | 1 + src/parcel_snoopi_deep.jl | 72 +++++++++++++++++++++ test/snoopi_deep.jl | 15 +++++ 8 files changed, 232 insertions(+), 2 deletions(-) create mode 100644 docs/src/jet.md diff --git a/Project.toml b/Project.toml index 25f2e7934..9dbf396c7 100644 --- a/Project.toml +++ b/Project.toml @@ -7,6 +7,7 @@ version = "2.8.1" Cthulhu = "f68482b8-f384-11e8-15f7-abe071a5a75f" FlameGraphs = "08572546-2f56-4bcf-ba4e-bab62c3a3f89" InteractiveUtils = "b77e0a4c-d291-57a0-90e8-8db25a27a240" +JET = "c3a54625-cd67-489e-a8e7-0a5a0ff4e31b" OrderedCollections = "bac558e1-5e72-5ebc-8fee-abe8a469f55d" Pkg = "44cfe95a-1eb2-52ea-b672-e2afdf69b78f" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" @@ -19,6 +20,7 @@ YAML = "ddb6d928-2868-570f-bddf-ab3f9cf99eb6" [compat] Cthulhu = "1.5, 2" FlameGraphs = "0.2" +JET = "0.0, 0.4, 0.5" OrderedCollections = "1" Requires = "1" SnoopCompileCore = "~2.8.0" diff --git a/docs/make.jl b/docs/make.jl index 4a839f327..3569fe859 100644 --- a/docs/make.jl +++ b/docs/make.jl @@ -11,10 +11,10 @@ makedocs( linkcheck = true, pages = ["index.md", "tutorial.md", - "Modern tools" => ["snoopr.md", "snoopi_deep.md", "pgdsgui.md", "snoopi_deep_analysis.md", "snoopi_deep_parcel.md"], + "Modern tools" => ["snoopr.md", "snoopi_deep.md", "pgdsgui.md", "snoopi_deep_analysis.md", "snoopi_deep_parcel.md", "jet.md"], "Older tools" => ["snoopi.md", "snoopc.md"], "userimg.md", - "reference.md"] + "reference.md"], ) deploydocs( diff --git a/docs/src/index.md b/docs/src/index.md index 47f6545ef..6c6fa11fd 100644 --- a/docs/src/index.md +++ b/docs/src/index.md @@ -12,6 +12,10 @@ Invalidation can trigger a domino effect, in which all users of invalidated code When a source of invalidation can be identified and either eliminated or mitigated, you can reduce the amount of work that the compiler needs to repeat and take better advantage of precompilation. +Finally, SnoopCompile interacts with other important diagnostics and debugging tools in the Julia ecosystem. +For example, the combination of SnoopCompile and [JET](https://github.com/aviatesk/JET.jl) allows you to analyze an entire call-chain for +potential errors; see the page on [JET integration](@ref JET) for more information. + ## Background Julia uses diff --git a/docs/src/jet.md b/docs/src/jet.md new file mode 100644 index 000000000..156f367f4 --- /dev/null +++ b/docs/src/jet.md @@ -0,0 +1,133 @@ +# [JET integration](@id JET) + +[JET](https://github.com/aviatesk/JET.jl) is a powerful tool for analyzing call graphs. +While some of its functionality overlaps that of SnoopCompile's, JET also provides mechanisms to detect potential errors. +Conversely, JET is a purely static-analysis tool and lacks SnoopCompile's ability to "bridge" across runtime dispatch. +For this reason, the combination of the tools--using SnoopCompile to collect data on the callgraph, and JET +to perform the error-analysis--provides capabilities that neither package has on its own. + +The integration between the two packages is bundled into SnoopCompile, specifically [`report_callee`](@ref), +[`report_callees`](@ref), and [`report_caller`](@ref). These take [`InferenceTrigger`](@ref) (see the page on [inference failures](@ref inferrability)) and use them to generate JET reports. + +We can demonstrate both the need and use of these tools with a simple extended example. + +## JET usage + +JET provides a useful report for the following call: + +```jldoctest jet; filter=r"@ reduce.*" +julia> using JET + +julia> list = Any[1,2,3]; + +julia> sum(list) +6 + +julia> @report_call sum(list) +═════ 1 possible error found ═════ +┌ @ reducedim.jl:889 Base.#sum#732(Base.:, Base.pairs(Core.NamedTuple()), #self#, a) +│┌ @ reducedim.jl:889 Base._sum(a, dims) +││┌ @ reducedim.jl:893 Base.#_sum#734(Base.pairs(Core.NamedTuple()), #self#, a, _3) +│││┌ @ reducedim.jl:893 Base._sum(Base.identity, a, Base.:) +││││┌ @ reducedim.jl:894 Base.#_sum#735(Base.pairs(Core.NamedTuple()), #self#, f, a, _4) +│││││┌ @ reducedim.jl:894 Base.mapreduce(f, Base.add_sum, a) +││││││┌ @ reducedim.jl:322 Base.#mapreduce#725(Base.:, Base._InitialValue(), #self#, f, op, A) +│││││││┌ @ reducedim.jl:322 Base._mapreduce_dim(f, op, init, A, dims) +││││││││┌ @ reducedim.jl:330 Base._mapreduce(f, op, Base.IndexStyle(A), A) +│││││││││┌ @ reduce.jl:402 Base.mapreduce_empty_iter(f, op, A, Base.IteratorEltype(A)) +││││││││││┌ @ reduce.jl:353 Base.reduce_empty_iter(Base.MappingRF(f, op), itr, ItrEltype) +│││││││││││┌ @ reduce.jl:357 Base.reduce_empty(op, Base.eltype(itr)) +││││││││││││┌ @ reduce.jl:331 Base.mapreduce_empty(Base.getproperty(op, :f), Base.getproperty(op, :rf), _) +│││││││││││││┌ @ reduce.jl:345 Base.reduce_empty(op, T) +││││││││││││││┌ @ reduce.jl:322 Base.reduce_empty(Base.+, _) +│││││││││││││││┌ @ reduce.jl:313 Base.zero(_) +││││││││││││││││┌ @ missing.jl:106 Base.throw(Base.MethodError(Base.zero, Core.tuple(Base.Any))) +│││││││││││││││││ MethodError: no method matching zero(::Type{Any}) +││││││││││││││││└────────────────── +``` + +The final line reveals that while `sum` happened to work for the specific `list` we provided, it nevertheless has a "gotcha" for the types we supplied: if `list` happens to be empty, `sum` depends on the ability to generate `zero(T)` for the element-type `T` of `list`, but because we constructed `list` to have an element-type of `Any`, there is no such method and `sum(Any[])` throws an error: + +```jldoctest +julia> sum(Int[]) +0 + +julia> sum(Any[]) +ERROR: MethodError: no method matching zero(::Type{Any}) +[...] +``` + +(This can be circumvented with `sum(Any[]; init=0)`.) + +This is the kind of bug that can "lurk" undetected for a long time, and JET excels at exposing them. + +## JET limitations + +JET is a *static* analyzer, meaning that it works from the argument types provided, and that has an important consequence: if a particular callee can't be inferred, JET can't analyze it. We can illustrate that quite easily: + +```jldoctest jet +julia> callsum(listcontainer) = sum(listcontainer[1]) +callsum (generic function with 1 method) + +julia> lc = Any[list]; # "hide" `list` inside a Vector{Any} + +julia> callsum(lc) +6 + +julia> @report_call callsum(lc) +No errors ! +``` + +Because we "hid" the type of `list` from inference, JET couldn't tell what specific instance of `sum` was going to be called, so it was unable to detect any errors. + +## JET/SnoopCompile integration + +The resolution to this problem is to use SnoopCompile to do the "data collection" and JET to do the analysis. +The key reason is that SnoopCompile is a dynamic analyzer, and is capable of bridging across runtime dispatch. +As always, you need to do the data collection in a fresh session where the calls have not previously been inferred. +After restarting Julia, we can do this: + +``` +julia> using SnoopCompile + +julia> list = Any[1,2,3]; + +julia> lc = Any[list]; # "hide" `list` inside a Vector{Any} + +julia> callsum(listcontainer) = sum(listcontainer[1]) +callsum (generic function with 1 method) + +julia> tinf = @snoopi_deep callsum(lc) +InferenceTimingNode: 0.039239/0.046793 on Core.Compiler.Timings.ROOT() with 2 direct children + +julia> tinf.children +2-element Vector{SnoopCompileCore.InferenceTimingNode}: + InferenceTimingNode: 0.000869/0.000869 on callsum(::Vector{Any}) with 0 direct children + InferenceTimingNode: 0.000196/0.006685 on sum(::Vector{Any}) with 1 direct children + +julia> report_callees(inference_triggers(tinf)) +1-element Vector{Pair{InferenceTrigger, JET.JETCallResult{JET.JETAnalyzer{JET.BasicPass{typeof(JET.basic_function_filter)}}, Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}}}}}: + Inference triggered to call sum(::Vector{Any}) from callsum (./REPL[5]:1) with specialization callsum(::Vector{Any}) => ═════ 1 possible error found ═════ +┌ @ reducedim.jl:889 Base.#sum#732(Base.:, Base.pairs(Core.NamedTuple()), #self#, a) +│┌ @ reducedim.jl:889 Base._sum(a, dims) +││┌ @ reducedim.jl:893 Base.#_sum#734(Base.pairs(Core.NamedTuple()), #self#, a, _3) +│││┌ @ reducedim.jl:893 Base._sum(Base.identity, a, Base.:) +││││┌ @ reducedim.jl:894 Base.#_sum#735(Base.pairs(Core.NamedTuple()), #self#, f, a, _4) +│││││┌ @ reducedim.jl:894 Base.mapreduce(f, Base.add_sum, a) +││││││┌ @ reducedim.jl:322 Base.#mapreduce#725(Base.:, Base._InitialValue(), #self#, f, op, A) +│││││││┌ @ reducedim.jl:322 Base._mapreduce_dim(f, op, init, A, dims) +││││││││┌ @ reducedim.jl:330 Base._mapreduce(f, op, Base.IndexStyle(A), A) +│││││││││┌ @ reduce.jl:402 Base.mapreduce_empty_iter(f, op, A, Base.IteratorEltype(A)) +││││││││││┌ @ reduce.jl:353 Base.reduce_empty_iter(Base.MappingRF(f, op), itr, ItrEltype) +│││││││││││┌ @ reduce.jl:357 Base.reduce_empty(op, Base.eltype(itr)) +││││││││││││┌ @ reduce.jl:331 Base.mapreduce_empty(Base.getproperty(op, :f), Base.getproperty(op, :rf), _) +│││││││││││││┌ @ reduce.jl:345 Base.reduce_empty(op, T) +││││││││││││││┌ @ reduce.jl:322 Base.reduce_empty(Base.+, _) +│││││││││││││││┌ @ reduce.jl:313 Base.zero(_) +││││││││││││││││┌ @ missing.jl:106 Base.throw(Base.MethodError(Base.zero, Core.tuple(Base.Any))) +│││││││││││││││││ MethodError: no method matching zero(::Type{Any}) +││││││││││││││││└────────────────── +``` + +Because SnoopCompile collected the runtime-dispatched `sum` call, we can pass it to JET. +`report_callees` filters those calls which generate JET reports, allowing you to focus on potential errors. diff --git a/docs/src/reference.md b/docs/src/reference.md index ae6264e5b..4d5cabd2c 100644 --- a/docs/src/reference.md +++ b/docs/src/reference.md @@ -47,6 +47,9 @@ InferenceTrigger runtime_inferencetime SnoopCompile.parcel SnoopCompile.write +report_callee +report_callees +report_caller ``` ## Other utilities diff --git a/src/SnoopCompile.jl b/src/SnoopCompile.jl index 8b73be52e..1df1079bd 100644 --- a/src/SnoopCompile.jl +++ b/src/SnoopCompile.jl @@ -92,6 +92,7 @@ if isdefined(SnoopCompileCore, Symbol("@snoopi_deep")) include("deep_demos.jl") export @snoopi_deep, exclusive, inclusive, flamegraph, flatten, accumulate_by_source, collect_for, runtime_inferencetime, staleinstances export InferenceTrigger, inference_triggers, callerinstance, callingframe, skiphigherorder, trigger_tree, suggest, isignorable + export report_callee, report_caller, report_callees end if isdefined(SnoopCompileCore, Symbol("@snoopl")) diff --git a/src/parcel_snoopi_deep.jl b/src/parcel_snoopi_deep.jl index 02cb431f0..359cd65d8 100644 --- a/src/parcel_snoopi_deep.jl +++ b/src/parcel_snoopi_deep.jl @@ -7,6 +7,7 @@ using Core.Compiler.Timings: InferenceFrameInfo using SnoopCompileCore: InferenceTiming, InferenceTimingNode, inclusive, exclusive using Profile using Cthulhu +using JET const InferenceNode = Union{InferenceFrameInfo,InferenceTiming,InferenceTimingNode} @@ -896,6 +897,77 @@ Cthulhu.specTypes(itrig::InferenceTrigger) = Cthulhu.specTypes(Cthulhu.instance( Cthulhu.backedges(itrig::InferenceTrigger) = (itrig.callerframes,) Cthulhu.nextnode(itrig::InferenceTrigger, edge) = (ret = callingframe(itrig); return isempty(ret.callerframes) ? nothing : ret) +""" + report_callee(itrig::InferenceTrigger) + +Return the `JET.report_call` for the callee in `itrig`. +""" +report_callee(itrig::InferenceTrigger; jetconfigs...) = report_call(Cthulhu.specTypes(itrig); jetconfigs...) + +""" + report_caller(itrig::InferenceTrigger) + +Return the `JET.report_call` for the caller in `itrig`. +""" +report_caller(itrig::InferenceTrigger; jetconfigs...) = report_call(Cthulhu.specTypes(callerinstance(itrig)); jetconfigs...) + +""" + report_callees(itrigs) + +Filter `itrigs` for those with a non-passing `JET` report, returning the list of `itrig => report` pairs. + +# Examples + +```jldoctest jetfib; setup=(using SnoopCompile, JET), filter=r"[0-9]*\\.?[0-9]+([eE][-+]?[0-9]+)?/[0-9]*\\.?[0-9]+([eE][-+]?[0-9]+)?" +julia> fib(n::Integer) = n ≤ 2 ? n : fib(n-1) + fib(n-2); + +julia> function fib(str::String) + n = length(str) + return fib(m) # error is here + end +fib (generic function with 2 methods) + +julia> fib(::Dict) = 0; fib(::Vector) = 0; + +julia> list = [5, "hello"]; + +julia> mapfib(list) = map(fib, list) +mapfib (generic function with 1 method) + +julia> tinf = @snoopi_deep try mapfib(list) catch end +InferenceTimingNode: 0.049825/0.071476 on Core.Compiler.Timings.ROOT() with 5 direct children + +julia> @report_call mapfib(list) +No errors ! +``` + +JET did not catch the error because the call to `fib` is hidden behind runtime dispatch. +However, when captured by `@snoopi_deep`, we get + +```jldoctest jetfib; filter=[r"@ .*", r"REPL\\[\\d+\\]|none"] +julia> report_callees(inference_triggers(tinf)) +1-element Vector{Pair{InferenceTrigger, JET.JETCallResult{JET.JETAnalyzer{JET.BasicPass{typeof(JET.basic_function_filter)}}, Base.Pairs{Symbol, Union{}, Tuple{}, NamedTuple{(), Tuple{}}}}}}: + Inference triggered to call fib(::String) from iterate (./generator.jl:47) inlined into Base.collect_to!(::Vector{Int64}, ::Base.Generator{Vector{Any}, typeof(fib)}, ::Int64, ::Int64) (./array.jl:782) => ═════ 1 possible error found ═════ +┌ @ none:3 fib(m) +│ variable m is not defined: fib(m) +└────────── +``` +""" +function report_callees(itrigs; jetconfigs...) + function rr(itrig) + rpt = try + report_callee(itrig; jetconfigs...) + catch err + @warn "skipping $itrig due to report_callee error" exception=err + nothing + end + return itrig => rpt + end + hasreport((itrig, report)) = report !== nothing && !isempty(JET.get_reports(report)) + + return [itrigrpt for itrigrpt in map(rr, itrigs) if hasreport(itrigrpt)] +end + filtermod(mod::Module, itrigs::AbstractVector{InferenceTrigger}) = filter(==(mod) ∘ callermodule, itrigs) ### inference trigger trees diff --git a/test/snoopi_deep.jl b/test/snoopi_deep.jl index 39c618ff9..2219b3d78 100644 --- a/test/snoopi_deep.jl +++ b/test/snoopi_deep.jl @@ -894,3 +894,18 @@ end end Pkg.activate(cproj) end + +if Base.VERSION >= v"1.7" + @testset "JET integration" begin + f(c) = sum(c[1]) + c = Any[Any[1,2,3]] + tinf = @snoopi_deep f(c) + rpt = SnoopCompile.JET.@report_call f(c) + @test isempty(SnoopCompile.JET.get_reports(rpt)) + itrigs = inference_triggers(tinf) + irpts = report_callees(itrigs) + @test only(irpts).first == last(itrigs) + @test !isempty(SnoopCompile.JET.get_reports(only(irpts).second)) + @test isempty(SnoopCompile.JET.get_reports(report_caller(itrigs[end]))) + end +end