diff --git a/README.md b/README.md index c0ff33408..3d9f0f350 100644 --- a/README.md +++ b/README.md @@ -2,84 +2,134 @@ TypeProfiler.jl employs Julia's type inference for bug reports. +!!! note + TypeProfiler.jl needs Julia v1.6, especially [this commit](https://github.com/JuliaLang/julia/commit/d5cf73ffffbab40ae06cc1ec99cac9d8e3d2b6a2); + as such I recommend you give a try on this package with Julia built from source after the commit. + ```julia +julia> using TypeProfiler + julia> fib(n) = n ≤ 2 ? n : fib(n - 1) + fib(n - 2) fib (generic function with 1 method) julia> @profile_call fib(100000) # computation explodes otherwise No errors ! -Int64 + Int64 julia> @profile_call fib(100000.) No errors ! -Float64 + Float64 julia> @profile_call fib("100000") # report errors -1 errors found -┌ @ none:1 within `fib` -│┌ @ operators.jl:317 <=(x, y) = (x < y) | (x == y) -││┌ @ operators.jl:268 <(x, y) = isless(x, y) -│││ no method matching signature: isless(::String, ::Int64) +1 error found +┌ @ none:1 within `fib(n) in Main at none:1` +│┌ @ operators.jl:326 <=(x, y) = (x < y) | (x == y) +││┌ @ operators.jl:277 <(x, y) = isless(x, y) +│││ no matching method found for signature: isless(::String, ::Int64) ││└ -TypeProfiler.Unknown + Union{} + +julia> @profile_call sum("julia") +2 errors found +┌ @ reduce.jl:528 sum(a; kw...) = sum(identity, a; kw...) +│┌ @ reduce.jl:528 sum(a; kw...) = sum(identity, a; kw...) +││┌ @ reduce.jl:501 sum(f, a; kw...) = mapreduce(f, add_sum, a; kw...) +│││┌ @ reduce.jl:501 sum(f, a; kw...) = mapreduce(f, add_sum, a; kw...) +││││┌ @ reduce.jl:287 mapreduce(f, op, itr; kw...) = mapfoldl(f, op, itr; kw...) +│││││┌ @ reduce.jl:287 mapreduce(f, op, itr; kw...) = mapfoldl(f, op, itr; kw...) +││││││┌ @ reduce.jl:160 mapfoldl(f, op, itr; init=_InitialValue()) = mapfoldl_impl(f, op, init, itr) +│││││││┌ @ reduce.jl:160 mapfoldl(f, op, itr; init=_InitialValue()) = mapfoldl_impl(f, op, init, itr) +││││││││┌ @ reduce.jl:42 function mapfoldl_impl(f::F, op::OP, nt, itr) where {F,OP} +│││││││││┌ @ reduce.jl:47 function foldl_impl(op::OP, nt, itr) where {OP} +││││││││││┌ @ reduce.jl:53 function _foldl_impl(op::OP, init, itr) where {OP} +│││││││││││┌ @ reduce.jl:81 @inline (op::BottomRF)(acc, x) = op.rf(acc, x) +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Char, ::Char) +││││││││││││└ +││││││││││┌ @ reduce.jl:354 @inline reduce_empty_iter(op, itr) = reduce_empty_iter(op, itr, IteratorEltype(itr)) +│││││││││││┌ @ reduce.jl:355 @inline reduce_empty_iter(op, itr, ::HasEltype) = reduce_empty(op, eltype(itr)) +││││││││││││┌ @ reduce.jl:328 reduce_empty(op::BottomRF, ::Type{T}) where {T} = reduce_empty(op.rf, T) +│││││││││││││┌ @ reduce.jl:320 reduce_empty(::typeof(add_sum), ::Type{T}) where {T} = reduce_empty(+, T) +││││││││││││││┌ @ reduce.jl:311 reduce_empty(::typeof(+), ::Type{T}) where {T} = zero(T) +│││││││││││││││ no matching method found for signature: zero(::Type{Char}) +││││││││││││││└ + Char + +julia> ary = Union{Symbol,Int}[:one, 1] -julia> @profile_call sum("julia") # can find errors that would happen in "deeper" calls -3 errors found -┌ @ reduce.jl:500 sum(a) = sum(identity, a) -│┌ @ reduce.jl:483 sum(f, a) = mapreduce(f, add_sum, a) -││┌ @ reduce.jl:280 mapreduce(f, op, itr; kw...) = mapfoldl(f, op, itr; kw...) -│││┌ @ reduce.jl:280 mapreduce(f, op, itr; kw...) = mapfoldl(f, op, itr; kw...) -││││┌ @ reduce.jl:157 mapfoldl(f, op, itr; kw...) = mapfoldl_impl(f, op, kw.data, itr) -│││││┌ @ reduce.jl:157 mapfoldl(f, op, itr; kw...) = mapfoldl_impl(f, op, kw.data, itr) -││││││┌ @ reduce.jl:41 return foldl_impl(op′, nt, itr′) -│││││││┌ @ reduce.jl:45 v = _foldl_impl(op, get(nt, :init, _InitialValue()), itr) -││││││││┌ @ namedtuple.jl:271 get(nt::NamedTuple, key::Union{Integer, Symbol}, default) = haskey(nt, key) ? getfield(nt, key) : default -│││││││││ invalid builtin function call: getfield(::NamedTuple{(),Tuple{}}, ::Symbol) -││││││││└ -││││││││┌ @ reduce.jl:59 v = op(v, y[1]) -│││││││││┌ @ reduce.jl:78 @inline (op::BottomRF)(acc, x) = op.rf(acc, x) -││││││││││┌ @ reduce.jl:21 add_sum(x, y) = x + y -│││││││││││ no method matching signature: +(::Char, ::Char) +julia> @profile_call sum(ary) # can profile on abstract-typed inputs +14 errors found +┌ @ reducedim.jl:867 @inline ($fname)(a::AbstractArray; dims=:, kw...) = ($_fname)(a, dims; kw...) +│┌ @ reducedim.jl:867 @inline ($fname)(a::AbstractArray; dims=:, kw...) = ($_fname)(a, dims; kw...) +││┌ @ reducedim.jl:871 ($_fname)(a, ::Colon; kw...) = ($_fname)(identity, a, :; kw...) +│││┌ @ reducedim.jl:871 ($_fname)(a, ::Colon; kw...) = ($_fname)(identity, a, :; kw...) +││││┌ @ reducedim.jl:872 ($_fname)(f, a, ::Colon; kw...) = mapreduce(f, $op, a; kw...) +│││││┌ @ reducedim.jl:872 ($_fname)(f, a, ::Colon; kw...) = mapreduce(f, $op, a; kw...) +││││││┌ @ reducedim.jl:310 mapreduce(f, op, A::AbstractArrayOrBroadcasted; dims=:, init=_InitialValue()) = +│││││││┌ @ reducedim.jl:310 mapreduce(f, op, A::AbstractArrayOrBroadcasted; dims=:, init=_InitialValue()) = +││││││││┌ @ reducedim.jl:318 _mapreduce_dim(f, op, ::_InitialValue, A::AbstractArrayOrBroadcasted, ::Colon) = +│││││││││┌ @ reduce.jl:396 function _mapreduce(f, op, ::IndexLinear, A::AbstractArrayOrBroadcasted) +││││││││││┌ @ reduce.jl:351 mapreduce_empty_iter(f, op, itr, ItrEltype) = +│││││││││││┌ @ reduce.jl:355 @inline reduce_empty_iter(op, itr, ::HasEltype) = reduce_empty(op, eltype(itr)) +││││││││││││┌ @ reduce.jl:329 reduce_empty(op::MappingRF, ::Type{T}) where {T} = mapreduce_empty(op.f, op.rf, T) +│││││││││││││┌ @ reduce.jl:343 mapreduce_empty(::typeof(identity), op, T) = reduce_empty(op, T) +││││││││││││││┌ @ reduce.jl:320 reduce_empty(::typeof(add_sum), ::Type{T}) where {T} = reduce_empty(+, T) +│││││││││││││││┌ @ reduce.jl:311 reduce_empty(::typeof(+), ::Type{T}) where {T} = zero(T) +││││││││││││││││ no matching method found for signature: zero(::Type{Union{Int64, Symbol}}) +│││││││││││││││└ +││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││ no matching method found for signature: +(::Symbol, ::Int64) ││││││││││└ -│││││││┌ @ reduce.jl:46 v isa _InitialValue && return reduce_empty_iter(op, itr) -││││││││┌ @ reduce.jl:343 @inline reduce_empty_iter(op, itr) = reduce_empty_iter(op, itr, IteratorEltype(itr)) -│││││││││┌ @ reduce.jl:344 @inline reduce_empty_iter(op, itr, ::HasEltype) = reduce_empty(op, eltype(itr)) -││││││││││┌ @ reduce.jl:317 reduce_empty(op::BottomRF, T) = reduce_empty(op.rf, T) -│││││││││││┌ @ reduce.jl:310 reduce_empty(::typeof(add_sum), T) = reduce_empty(+, T) -││││││││││││┌ @ reduce.jl:303 reduce_empty(::typeof(+), T) = zero(T) -│││││││││││││ no method matching signature: zero(::Type{Char}) +││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││ no matching method found for signature: +(::Int64, ::Symbol) +││││││││││└ +││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││ no matching method found for signature: +(::Symbol, ::Symbol) +││││││││││└ +││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││ no matching method found for signature: +(::Int64, ::Symbol) +││││││││││└ +││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││ no matching method found for signature: +(::Int64, ::Symbol) +││││││││││└ +││││││││││┌ @ reduce.jl:257 mapreduce_impl(f, op, A::AbstractArrayOrBroadcasted, ifirst::Integer, ilast::Integer) = +│││││││││││┌ @ reduce.jl:233 @noinline function mapreduce_impl(f, op, A::AbstractArrayOrBroadcasted, +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Symbol, ::Int64) +││││││││││││└ +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Int64, ::Symbol) ││││││││││││└ -Char +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Symbol, ::Symbol) +││││││││││││└ +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Int64, ::Symbol) +││││││││││││└ +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Int64, ::Symbol) +││││││││││││└ +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Symbol, ::Int64) +││││││││││││└ +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Int64, ::Symbol) +││││││││││││└ +││││││││││││┌ @ reduce.jl:24 add_sum(x, y) = x + y +│││││││││││││ no matching method found for signature: +(::Symbol, ::Symbol) +││││││││││││└ + Union{Int64, Symbol} ``` ### TODOs in order of priority: - -- [x] show profiled results -- [x] escape recursive calls -- [ ] bug fixes: `TypeVar` etc. can serious errors within the current implementation -- [ ] toplevel executions - - handle untyped IRs while splitting expressions as JuliaIntepreter.jl does - - then, TP will be able to profile a file directly like an usual static linter -- [ ] more reports - - [ ] `UndefVarError` - - [x] report `GlobalRef` for really undefined variable - - report `:throw_undef_if_not` ? (includes lots of false positives as is) - - [ ] method ambiguity error - - more and more ... -- [ ] don't trace into "primitive" functions in `Core` and `Base`: with the similar approach to https://github.com/FluxML/Mjolnir.jl/tree/9435d98673752cec4e222e31a6b9f38edcd7d5e0/src/lib -- [ ] balance between Julia's inference approach and error profiling +- setup a type-level virtual machine and enable profiling on toplevel code +- more reports + * invalid built-in function calls + * report some cases of `throw`, e.g. `rand('1')::ArgumentError("Sampler for this object is not defined")` +- balance between Julia's inference approach and error profiling ? - Julia's type inference allows abstract type (like `Any`) to slip into the inference process by various heuristics, in order to ensure its termination and obtain the performance - - but this is obviously unideal for TP, since our basic stance is _"better safe than sorry"_, meaning ideally we want to find all the possible errors while revealing some uncertainty Julia's inference accepts - - nevertheless, as far as TP relies on the Julia's inference, we need to achieve the conservative error profiling in the existence of abstract types, _somehow_ - - as a consequence, TP will be able to profile, e.g.: - - [ ] `print` - - [ ] `sort` -- [ ] support generated functions -- [ ] replace `Core` types: enables profiling things in `Core.Compiler` module - -### Ideas - -- report performance pitfalls -- somehow profiles possible exceptions ? + - but this is somewhat unideal in the context of bug reports, since the stance would be _"better safe than sorry"_, meaning we ideally want to find all the possible errors while revealing some uncertainty Julia's inference accepts +- maybe we need some additional setup for supporting generated functions +- report performance pitfalls ? diff --git a/src/TypeProfiler.jl b/src/TypeProfiler.jl index 31b8a103f..f47ac8e07 100644 --- a/src/TypeProfiler.jl +++ b/src/TypeProfiler.jl @@ -1,64 +1,24 @@ +@doc read(normpath(dirname(@__DIR__), "README.md"), String) module TypeProfiler -export - # profile_file, profile_text, - @profile_call - -# TODO: using once gets stable -import Core: - SimpleVector, svec, - MethodInstance, CodeInfo, LineInfoNode, - GotoNode, PiNode, PhiNode, PhiCNode, UpsilonNode, SlotNumber -import Core.Compiler: - specialize_method, typeinf_ext, - tmerge, - SSAValue -import Base: - unwrap_unionall, rewrap_unionall -import Base.Meta: isexpr - -const to_tt = Base.to_tuple_type - -include("types.jl") -include("utils.jl") -include("construct.jl") -include("interpret.jl") -include("builtin.jl") -include("profile.jl") -include("print.jl") +include("profiler/profiler.jl") -# for debugging -# ------------- - -# this method is basically only for testing -# TODO: keyword args -function prepare_frame(f, args...) - slottyps = Type[typeof′(f), typeof′.(args)...] - tt = to_tt(slottyps) - mms = matching_methods(tt) - @assert (n = length(mms)) === 1 "$(n === 0 ? "no" : "multiple") methods found: $tt" - tt, sparams::SimpleVector, m::Method = mms[1] - mi = specialize_method(m, tt, sparams) - return prepare_frame(mi, slottyps) -end +using Base: + Meta.isexpr macro profile_call(ex, kwargs...) - @assert isexpr(ex, :call) "function call expression should be given" - f = ex.args[1] - args = ex.args[2:end] - return quote let - maybe_newframe = prepare_frame($(esc(f)), $(map(esc, args)...)) - !isa(maybe_newframe, Frame) && return maybe_newframe - frame = maybe_newframe::Frame - try - evaluate_or_profile!(frame) - print_report(frame; $(map(esc, kwargs)...)) - catch err - rethrow(err) - finally - global $(esc(:frame)) = frame # HACK: assign the erroneous frame into global `frame` variable for debugging - end - end end + @assert isexpr(ex, :call) "function call expression should be given" + f = ex.args[1] + args = ex.args[2:end] + + quote let + interp, frame = Profiler.profile_call($(esc(f)), $(map(esc, args)...)) + Profiler.print_reports(interp; $(map(esc, kwargs)...)) + frame.result.result + end end end +export + @profile_call + end diff --git a/src/abandoned/TypeProfiler.jl b/src/abandoned/TypeProfiler.jl new file mode 100644 index 000000000..31b8a103f --- /dev/null +++ b/src/abandoned/TypeProfiler.jl @@ -0,0 +1,64 @@ +module TypeProfiler + +export + # profile_file, profile_text, + @profile_call + +# TODO: using once gets stable +import Core: + SimpleVector, svec, + MethodInstance, CodeInfo, LineInfoNode, + GotoNode, PiNode, PhiNode, PhiCNode, UpsilonNode, SlotNumber +import Core.Compiler: + specialize_method, typeinf_ext, + tmerge, + SSAValue +import Base: + unwrap_unionall, rewrap_unionall +import Base.Meta: isexpr + +const to_tt = Base.to_tuple_type + +include("types.jl") +include("utils.jl") +include("construct.jl") +include("interpret.jl") +include("builtin.jl") +include("profile.jl") +include("print.jl") + +# for debugging +# ------------- + +# this method is basically only for testing +# TODO: keyword args +function prepare_frame(f, args...) + slottyps = Type[typeof′(f), typeof′.(args)...] + tt = to_tt(slottyps) + mms = matching_methods(tt) + @assert (n = length(mms)) === 1 "$(n === 0 ? "no" : "multiple") methods found: $tt" + tt, sparams::SimpleVector, m::Method = mms[1] + mi = specialize_method(m, tt, sparams) + return prepare_frame(mi, slottyps) +end + +macro profile_call(ex, kwargs...) + @assert isexpr(ex, :call) "function call expression should be given" + f = ex.args[1] + args = ex.args[2:end] + return quote let + maybe_newframe = prepare_frame($(esc(f)), $(map(esc, args)...)) + !isa(maybe_newframe, Frame) && return maybe_newframe + frame = maybe_newframe::Frame + try + evaluate_or_profile!(frame) + print_report(frame; $(map(esc, kwargs)...)) + catch err + rethrow(err) + finally + global $(esc(:frame)) = frame # HACK: assign the erroneous frame into global `frame` variable for debugging + end + end end +end + +end diff --git a/src/builtin.jl b/src/abandoned/builtin.jl similarity index 100% rename from src/builtin.jl rename to src/abandoned/builtin.jl diff --git a/src/construct.jl b/src/abandoned/construct.jl similarity index 100% rename from src/construct.jl rename to src/abandoned/construct.jl diff --git a/src/interpret.jl b/src/abandoned/interpret.jl similarity index 100% rename from src/interpret.jl rename to src/abandoned/interpret.jl diff --git a/src/abandoned/print.jl b/src/abandoned/print.jl new file mode 100644 index 000000000..2b195a156 --- /dev/null +++ b/src/abandoned/print.jl @@ -0,0 +1,153 @@ +# colors +# ------ + +const ERROR_COLOR = :light_red +const NOERROR_COLOR = :light_green +const RAIL_COLORS = [:bold, :light_cyan, :light_green, :light_yellow] + +# entry +# ----- + +print_report(frame::Frame; kwargs...) = print_report(stdout, frame; kwargs...) +function print_report(io::IO, frame::Frame; view = :inline) + reports = frame.reports + + n = length(reports) + if n === 0 + printstyled(io, "No errors !\n"; color = NOERROR_COLOR) + return + end + + if view === :inline + printstyled(io, n, " errors found\n"; color = ERROR_COLOR) + wrote_lins = Set{UInt64}() + for er in reports + depth = + print_calltrace(io, er.lin, er.frame, wrote_lins; duplicate_lines = false) + print_rails(io, depth - 1) + ers = report_string(er) + printstyled(io, "│ ", ers, '\n'; color = ERROR_COLOR) + print_rails(io, depth - 1) + printstyled(io, '└', '\n'; color = ERROR_COLOR) + end + elseif view === :separate + for er in reports + print_report(io, er) + println() + end + else + error("keyword argument view should either of :inline or :separate") + end + return +end + +print_report(er::ErrorReport; kwargs...) = print_report(stdout, er; kwargs...) +function print_report(io::IO, er::ErrorReport) + ers = report_string(er) + print(io, "Error: ") + printstyled(io, ers, '\n'; color = ERROR_COLOR) + + println(io, "Calltrace:") + print_calltrace(io, er.lin, er.frame) + return +end + +# report +# ------ + +report_string(er::ErrorReport) = + return error("report_string(::$(typeof(er))) should be implemented") + +function report_string(er::UndefVarErrorReport) + be = er.maybe ? "may not be" : "is not" + return if isa(er.mod, Module) + "variable $(er.mod).$(er.name) $be defined" + else + "variable $(er.name) $be defined in $(er.mod)" + end +end + +report_string(er::InvalidBuiltinCallErrorReport) = "invalid builtin function call: $(tt_to_signature_str(er.tt))" +report_string(er::NoMethodErrorReport) = "no method matching signature: $(tt_to_signature_str(er.tt))" +report_string(er::ConditionErrorReport) = "non-boolean ($(er.t)) found in boolean context" + +# location +# -------- + +# IDEA: type annotate source lines with profiled types +print_calltrace(io, lin, frame, wrote_lins::Set{UInt64} = Set{UInt64}(); kwargs...) = + return _print_calltrace(io, lin, lin, frame, wrote_lins; kwargs...) + +function _print_calltrace( + io, lin, err_lin, frame, wrote_lins::Set{UInt64} = Set{UInt64}(); + duplicate_lines::Bool = true +) + lin_hash = hash(lin) + should_print = lin_hash ∉ wrote_lins || duplicate_lines + push!(wrote_lins, lin_hash) + + if lin.inlined_at === 0 && is_root(frame) + # reached the initial statement of a root frame + should_print && print_location(io, lin, err_lin, 0) + return 1 + end + + if lin.inlined_at === 0 + # callstack is still remaining in the caller frame, recur into it + prev_lin = frame.caller.lin + prev_frame = frame.caller.frame + else + prev_lin = frame.src.linetable[lin.inlined_at] + prev_frame = frame + end + + # prewalk + depth = _print_calltrace( + io, prev_lin, err_lin, prev_frame, wrote_lins; + duplicate_lines = duplicate_lines + ) + should_print && print_location(io, lin, err_lin, depth) + return depth + 1 +end + +function print_location(io, lin, err_lin, depth) + # rail + print_rails(io, depth) + color = lin == err_lin ? ERROR_COLOR : RAIL_COLORS[(depth+1)%length(RAIL_COLORS)+1] + printstyled(io, "┌ @ ", lin.file, ":", lin.line; color) + + # source + path = fullpath(string(lin.file)) + source_line = if isfile(path) + strip(readlines(path)[lin.line]) + else + string("within `", lin.method, ''') # when the file doesn't exist, e.g. REPL + end + println(io, ' ', source_line) + return +end + +function print_rails(io, depth) + n = length(RAIL_COLORS) + for i = 1:depth + color = RAIL_COLORS[i%n+1] + printstyled(io, '│'; color) + end + return +end + +# path +# ---- + +const SRC_DIR = joinpath(Sys.BINDIR, "..", "..", "base") +const RELEASE_DIR = joinpath(Sys.BINDIR, "..", "share", "julia", "base") +basepath(filename) = + return normpath(joinpath((@static isdir(SRC_DIR) ? SRC_DIR : RELEASE_DIR), filename)) +function fullpath(filename) + path = isabspath(filename) ? filename : basepath(filename) + return try + realpath(path) + catch + path + end +end diff --git a/src/profile.jl b/src/abandoned/profile.jl similarity index 100% rename from src/profile.jl rename to src/abandoned/profile.jl diff --git a/src/types.jl b/src/abandoned/types.jl similarity index 100% rename from src/types.jl rename to src/abandoned/types.jl diff --git a/src/utils.jl b/src/abandoned/utils.jl similarity index 100% rename from src/utils.jl rename to src/abandoned/utils.jl diff --git a/src/print.jl b/src/print.jl deleted file mode 100644 index 6eb55dd3a..000000000 --- a/src/print.jl +++ /dev/null @@ -1,153 +0,0 @@ -# colors -# ------ - -const ERROR_COLOR = :light_red -const NOERROR_COLOR = :light_green -const RAIL_COLORS = [:bold, :light_cyan, :light_green, :light_yellow] - -# entry -# ----- - -print_report(frame::Frame; kwargs...) = print_report(stdout, frame; kwargs...) -function print_report(io::IO, frame::Frame; view = :inline) - reports = frame.reports - - n = length(reports) - if n === 0 - printstyled(io, "No errors !\n"; color = NOERROR_COLOR) - return - end - - if view === :inline - printstyled(io, n, " errors found\n"; color = ERROR_COLOR) - wrote_lins = Set{UInt64}() - for er in reports - depth = print_calltrace(io, er.lin, er.frame, wrote_lins; duplicate_lines = false) - print_rails(io, depth-1) - ers = report_string(er) - printstyled(io, "│ ", ers, '\n'; color = ERROR_COLOR) - print_rails(io, depth-1) - printstyled(io, '└', '\n'; color = ERROR_COLOR) - end - elseif view === :separate - for er in reports - print_report(io, er) - println() - end - else - error("keyword argument view should either of :inline or :separate") - end - return -end - -print_report(er::ErrorReport; kwargs...) = print_report(stdout, er; kwargs...) -function print_report(io::IO, er::ErrorReport) - ers = report_string(er) - print(io, "Error: ") - printstyled(io, ers, '\n'; color = ERROR_COLOR) - - println(io, "Calltrace:") - print_calltrace(io, er.lin, er.frame) - return -end - -# report -# ------ - -function report_string(er::ErrorReport) - error("report_string(::$(typeof(er))) should be implemented") -end - -function report_string(er::UndefVarErrorReport) - be = er.maybe ? "may not be" : "is not" - return if er.mod isa Module - "variable $(er.mod).$(er.name) $be defined" - else - "variable $(er.name) $be defined in $(er.mod)" - end -end - -report_string(er::InvalidBuiltinCallErrorReport) = - "invalid builtin function call: $(tt_to_signature_str(er.tt))" - -report_string(er::NoMethodErrorReport) = - "no method matching signature: $(tt_to_signature_str(er.tt))" - -report_string(er::ConditionErrorReport) = - "non-boolean ($(er.t)) found in boolean context" - -# location -# -------- - -# IDEA: type annotate source lines with profiled types -print_calltrace(io, lin, frame, wrote_lins::Set{UInt64} = Set{UInt64}(); kwargs...) = - _print_calltrace(io, lin, lin, frame, wrote_lins; kwargs...) - -function _print_calltrace(io, lin, err_lin, frame, wrote_lins::Set{UInt64} = Set{UInt64}(); duplicate_lines::Bool = true) - lin_hash = hash(lin) - should_print = lin_hash ∉ wrote_lins || duplicate_lines - push!(wrote_lins, lin_hash) - - if lin.inlined_at === 0 && is_root(frame) - # reached the initial statement of a root frame - should_print && print_location(io, lin, err_lin, 0) - return 1 - end - - if lin.inlined_at === 0 - # callstack is still remaining in the caller frame, recur into it - prev_lin = frame.caller.lin - prev_frame = frame.caller.frame - else - prev_lin = frame.src.linetable[lin.inlined_at] - prev_frame = frame - end - - # prewalk - depth = _print_calltrace(io, prev_lin, err_lin, prev_frame, wrote_lins; duplicate_lines = duplicate_lines) - should_print && print_location(io, lin, err_lin, depth) - return depth + 1 -end - -function print_location(io, lin, err_lin, depth) - # rail - print_rails(io, depth) - if lin == err_lin - printstyled(io, "┌ @ ", lin.file, ":", lin.line; color = ERROR_COLOR) - else - printstyled(io, "┌ @ ", lin.file, ":", lin.line; color = RAIL_COLORS[(depth+1) % length(RAIL_COLORS) + 1]) - end - - # source - path = fullpath(string(lin.file)) - source_line = if isfile(path) - strip(readlines(path)[lin.line]) - else - string("within `", lin.method, ''') # when the file doesn't exist, e.g. REPL - end - println(io, ' ', source_line) -end - -function print_rails(io, depth) - n = length(RAIL_COLORS) - for i in 1:depth - c = RAIL_COLORS[i % n + 1] - printstyled(io, '│'; color = c) - end -end - -# path -# ---- - -const SRC_DIR = joinpath(Sys.BINDIR, "..", "..", "base") -const RELEASE_DIR = joinpath(Sys.BINDIR, "..", "share", "julia", "base") -basepath(filename) = - normpath(joinpath((@static isdir(SRC_DIR) ? SRC_DIR : RELEASE_DIR), filename)) -function fullpath(filename) - path = isabspath(filename) ? filename : basepath(filename) - return try - realpath(path) - catch - path - end -end diff --git a/src/profiler/abstractinterpretation.jl b/src/profiler/abstractinterpretation.jl new file mode 100644 index 000000000..b41fde0e9 --- /dev/null +++ b/src/profiler/abstractinterpretation.jl @@ -0,0 +1,95 @@ +# HACK: +# calls down to `NativeInterpreter`'s abstract interpretation method while passing `TPInterpreter` +# so that its overloaded methods can be called within the sub/recursive method callls. +function invoke_native(f, interp::TPInterpreter, args...; kwargs...) + argtypes = to_tuple_type((AbstractInterpreter, typeof.(args)...)) + return invoke(f, argtypes, interp, args...; kwargs...) +end + +get_cur_stmt(frame::InferenceState) = frame.src.code[frame.currpc] + +# report undef var error +function check_global_ref!(interp::TPInterpreter, sv::InferenceState, m::Module, s::Symbol) + return if !isdefined(m, s) + add_remark!(interp, sv, UndefVarErrorReport(sv, m, s)) + true + else + false + end +end + +# NOTE: +# below is adapted from https://github.com/JuliaLang/julia/blob/1e6e65691254a7fe81f5da8706bb30aa6cb3f8d2/base/compiler/abstractinterpretation.jl +# and ideally the patching here is better to be upstreamed as much as possible + +# TODO: +# - report "too many method matched" +# - maybe "cound not identify method table for call" won't happen since we eagerly propagate bottom for e.g. undef var case, etc. +function abstract_call_gf_by_type(interp::TPInterpreter, @nospecialize(f), argtypes::Vector{Any}, @nospecialize(atype), sv::InferenceState, + max_methods::Int = InferenceParams(interp).MAX_METHODS) + ret = invoke_native(abstract_call_gf_by_type, interp, f, argtypes, atype, sv, max_methods)::CallMeta + + # report no method error, notes: + info = ret.info + if isa(info, UnionSplitInfo) + # if `info` is `UnionSplitInfo`, but there won't be a case where `info.matches` is empty + for info in info.matches + if isa(info.results, MethodLookupResult) && isempty(info.results.matches) + # no method match for this union split + # ret.rt = Bottom # maybe we want to be more strict on error cases ? but such a check will be really against the nature of dynamic typing + add_remark!(interp, sv, NoMethodErrorReport(sv, atype, true)) + end + end + elseif isa(info, MethodMatchInfo) && isa(info.results, MethodLookupResult) && isempty(info.results.matches) + # really no method found + typeassert(ret.rt, TypeofBottom) # return type is initialized as `Bottom`, and should never change in these passes + add_remark!(interp, sv, NoMethodErrorReport(sv, atype, false)) + end + + return ret +end + +function abstract_eval_special_value(interp::TPInterpreter, @nospecialize(e), vtypes::VarTable, sv::InferenceState) + ret = invoke_native(abstract_eval_special_value, interp, e, vtypes, sv) + + # report undef var error + if isa(e, GlobalRef) + check_global_ref!(interp, sv, e.mod, e.name) && (ret = Bottom) # ret here should annotated as `Any` by `NativeInterpreter`, but here I would like to be more conservative and change it to `Bottom` + end + + return ret +end + +function abstract_eval_value(interp::TPInterpreter, @nospecialize(e), vtypes::VarTable, sv::InferenceState) + ret = invoke_native(abstract_eval_value, interp, e, vtypes, sv) + + # report non-boolean condition error + stmt = get_cur_stmt(sv) + if isa(stmt, GotoIfNot) + t = widenconst(ret) + if !⊑(Bool, Bottom) && !⊑(Bool, t) + add_remark!(interp, sv, NonBooleanCondErrorReport(sv, t)) + ret = Bottom + end + end + + return ret +end + +function abstract_eval_statement(interp::TPInterpreter, @nospecialize(e), vtypes::VarTable, sv::InferenceState) + ret = invoke_native(abstract_eval_statement, interp, e, vtypes, sv) + + # report undef var error + if isa(e, Expr) + if e.head === :isdefined + sym = e.args[1] + if isa(sym, Symbol) + check_global_ref!(interp, sv, sv.mod, sym) && (ret = Bottom) + elseif isa(sym, GlobalRef) + check_global_ref!(interp, sv, sym.mod, sym.name) && (ret = Bottom) + end + end + end + + return ret +end diff --git a/src/profiler/abstractinterpreterinterface.jl b/src/profiler/abstractinterpreterinterface.jl new file mode 100644 index 000000000..67f403816 --- /dev/null +++ b/src/profiler/abstractinterpreterinterface.jl @@ -0,0 +1,43 @@ +# define `AbstractInterpreter` API + +struct TPInterpreter <: AbstractInterpreter + native::NativeInterpreter + reports::Vector{ErrorReport} + optimize::Bool + compress::Bool + discard_trees::Bool + + function TPInterpreter(world::UInt = get_world_counter(); + inf_params::InferenceParams = InferenceParams(), + opt_params::OptimizationParams = OptimizationParams(), + optimize::Bool = false, + compress::Bool = false, + discard_trees::Bool = false + ) + native = NativeInterpreter(world; inf_params, opt_params) + return new(native, [], optimize, compress, discard_trees) + end +end + +InferenceParams(interp::TPInterpreter) = InferenceParams(interp.native) +OptimizationParams(interp::TPInterpreter) = OptimizationParams(interp.native) +get_world_counter(interp::TPInterpreter) = get_world_counter(interp.native) +get_inference_cache(interp::TPInterpreter) = get_inference_cache(interp.native) +code_cache(interp::TPInterpreter) = code_cache(interp.native) + +# TP only works for runtime inference +lock_mi_inference(::TPInterpreter, ::MethodInstance) = nothing +unlock_mi_inference(::TPInterpreter, ::MethodInstance) = nothing + +function add_remark!(interp::TPInterpreter, ::InferenceState, report::ErrorReport) + push!(interp.reports, report) + return +end +function add_remark!(interp::TPInterpreter, sv::InferenceState, s::String) + add_remark!(interp, sv, NativeRemark(sv, s)) + return +end + +may_optimize(interp::TPInterpreter) = interp.optimize +may_compress(interp::TPInterpreter) = interp.compress +may_discard_trees(interp::TPInterpreter) = interp.discard_trees diff --git a/src/profiler/errorreport.jl b/src/profiler/errorreport.jl new file mode 100644 index 000000000..08f49e346 --- /dev/null +++ b/src/profiler/errorreport.jl @@ -0,0 +1,115 @@ +# error reports +# ------------- + +""" + abstract type ErrorReport end + +Abstract type of all the error reports that TypeProfiler.jl states. +All `ErrorReport`s are required to: +- have `acs::Vector{MethodInstance}` field -- keeps abstract call stack of this error (from call site to error location) +- provide `report_string` method -- converts this `ErrorReport` into readable text + +!!! note + All concrete `ErrorReport` types are supposed to be declared with `@reportdef` macro. +""" +abstract type ErrorReport end + +const AbstractCallStack = Vector{MethodInstance} + +macro reportdef(structex) + @assert isexpr(structex, :struct, 3) "struct expression should be given" + typedecl, body = structex.args[2:3] + @assert isexpr(typedecl, :<:, 2) && __module__.eval(last(typedecl.args)) <: ErrorReport "error report should be declared as subtype of ErrorReport" + T = first(typedecl.args) + + flds = filter(x->!isa(x, LineNumberNode), body.args) + @assert first(flds) == :(acs::AbstractCallStack) "the first field of error report should be `acs::AbstractCallStack`" + + sigs = map(flds[2:end]) do x + isexpr(x, :(::)) ? first(x.args) : x + end + constructor = :( + function $(T)(sv::InferenceState, $(sigs...)) + @nospecialize $(sigs...) + acs = trace_abstract_call_stack!(sv) + return new(acs, $(sigs...)) + end + ) + push!(body.args, constructor) + + return structex +end + +# traces the current abstract call stack +function trace_abstract_call_stack!(sv, acs = MethodInstance[]) + isnothing(sv.parent) || trace_abstract_call_stack!(sv.parent, acs) # prewalk + push!(acs, sv.linfo) + return acs +end + +@reportdef struct NoMethodErrorReport <: ErrorReport + acs::AbstractCallStack + tt::Type + unionsplit::Bool +end + +@reportdef struct InvalidBuiltinCallErrorReport <: ErrorReport + acs::AbstractCallStack + tt::Type +end + +@reportdef struct UndefVarErrorReport <: ErrorReport + acs::AbstractCallStack + mod::Module + name::Symbol +end + +@reportdef struct NonBooleanCondErrorReport <: ErrorReport + acs::AbstractCallStack + t::Type +end + +""" + NativeRemark <: ErrorReport + +This special `ErrorReport` is just for wrapping remarks from `NativeInterpreter`. +Ideally all of them should be covered by the other "real" `ErrorReport`s. +""" +@reportdef struct NativeRemark <: ErrorReport + acs::AbstractCallStack + s::String +end + +# report string +# ------------- + +report_string(er::ErrorReport) = + error("report_string(::$(typeof(er))) should be implemented") +report_string(er::NoMethodErrorReport) = er.unionsplit ? + "for one of the union split cases, no matching method found for signature: $(tt_to_signature_str(er.tt))" : + "no matching method found for signature: $(tt_to_signature_str(er.tt))" +# report_string(er::InvalidBuiltinCallErrorReport) = +# "invalid builtin function call: $(tt_to_signature_str(er.tt))" +report_string(er::UndefVarErrorReport) = + "variable $(er.mod).$(er.name) is not defined" +report_string(er::NonBooleanCondErrorReport) = + "non-boolean ($(er.t)) used in boolean context" +report_string(r::NativeRemark) = r.s + +# returns a call signature string from tt +function tt_to_signature_str(@nospecialize(tt::Type{<:Tuple})) + fn = ft_to_fname(tt.parameters[1]) + args = join("::" .* string.(tt.parameters[2:end]), ", ") + return string(fn, '(', args, ')') +end + +# returns function name from its type +function ft_to_fname(@nospecialize(ft)) + return if isconstType(ft) + ft.parameters[1] + elseif ft isa DataType && isdefined(ft, :instance) + ft.instance + else + ft + end |> string +end diff --git a/src/profiler/print.jl b/src/profiler/print.jl new file mode 100644 index 000000000..0e4f3d68b --- /dev/null +++ b/src/profiler/print.jl @@ -0,0 +1,135 @@ +# print reports nicely: +# - TODO: maybe we want to show callsites instead of method sigs in a calltrace +# - TODO: method sigs or callsites can be type annotated with profiled types + +# entry methods +# ------------- + +function print_reports(io::IO, interp::TPInterpreter; kwargs...) + print_reports(io, interp.reports; kwargs...) + return +end + +function print_reports(io::IO, reports::Vector{<:ErrorReport}; + view::Symbol = :inline, + filter_native_remarks::Bool = true) + if filter_native_remarks + reports = filter(r->!isa(r, NativeRemark), reports) + end + + if isempty(reports) + printstyled(io, "No errors !\n"; color = NOERROR_COLOR) + return + end + + if view === :inline + s = string(pluralize(length(reports), "error"), " found") + printstyled(io, s, '\n'; color = ERROR_COLOR) + wrote_linfos = Set{UInt64}() + foreach(reports) do report + print_report(io, report, wrote_linfos) + end + elseif view === :separate + foreach(reports) do report + print(io, "Error: ") + s = report_string(report) + printstyled(io, s, '\n'; color = ERROR_COLOR) + println(io, "Calltrace:") + print_report(io, report) + end + else + error("keyword argument `view` should either of :inline or :separate") + end + + return +end + +print_reports(args...; kwargs...) = print_reports(stdout, args...; kwargs...) + +function print_report(io, report, wrote_linfos = Set{UInt64}()) + print_calltrace(io, report.acs, wrote_linfos) + n = length(report.acs) - 1 + print_rails(io, n) + printstyled(io, "│ ", report_string(report), '\n'; color = ERROR_COLOR) + print_rails(io, n) + printstyled(io, '└', '\n'; color = ERROR_COLOR) + return +end + +# traverse backedges, collect locations +# ------------------------------------- + +function print_calltrace(io, linfos, wrote_linfos, depth = 0) + i = depth + 1 + linfo = linfos[i] + + linfo_hash = hash(linfo) + should_print = linfo_hash ∉ wrote_linfos + push!(wrote_linfos, linfo_hash) + + if length(linfos) == i # error here + print_location(io, linfo, depth, true) + return + end + + # print current frame adn go into deeper + should_print && print_location(io, linfo, depth, false) + print_calltrace(io, linfos, wrote_linfos, depth + 1) + return +end + +function print_location(io, linfo, depth, is_err) + file, line = get_file_line(linfo) + + # rail + print_rails(io, depth) + + color = is_err ? ERROR_COLOR : RAIL_COLORS[(depth+1)%length(RAIL_COLORS)+1] + printstyled(io, "┌ @ ", file, ":", line; color) + + # source + path = fullpath(string(file)) + source_line = if isfile(path) + strip(readlines(path)[line]) + else + string("within `", linfo.def, ''') # when the file doesn't exist, e.g. defined in REPL + end + println(io, ' ', source_line) + + return +end + +# utils +# ----- + +const ERROR_COLOR = :light_red +const NOERROR_COLOR = :light_green +const RAIL_COLORS = [:bold, :light_cyan, :light_green, :light_yellow] + +pluralize(n::Integer, one::AbstractString, more::AbstractString = string(one, 's')) = + return string(n, ' ', isone(n) ? one : more) + +function print_rails(io, depth) + n = length(RAIL_COLORS) + for i = 1:depth + color = RAIL_COLORS[i%n+1] + printstyled(io, '│'; color) + end + return +end + +get_file_line(mi::MethodInstance) = get_file_line(mi.def) +get_file_line(m::Method) = (; m.file, m.line) +get_file_line(m::Module) = error("get_file_line(::Module) unimplemented") + +const SRC_DIR = normpath(Sys.BINDIR, "..", "..", "base") +const RELEASE_DIR = normpath(Sys.BINDIR, "..", "share", "julia", "base") +basepath(filename) = normpath((@static isdir(SRC_DIR) ? SRC_DIR : RELEASE_DIR), filename) +function fullpath(filename) + path = isabspath(filename) ? filename : basepath(filename) + return try + realpath(path) + catch + path + end +end diff --git a/src/profiler/profiler.jl b/src/profiler/profiler.jl new file mode 100644 index 000000000..bb52d4708 --- /dev/null +++ b/src/profiler/profiler.jl @@ -0,0 +1,74 @@ +module Profiler + +# overloads +import Core.Compiler: + # `AbstractInterpreter` API defined in abstractinterpreterinterface.jl + InferenceParams, OptimizationParams, get_world_counter, get_inference_cache, code_cache, + lock_mi_inference, unlock_mi_inference, add_remark!, may_optimize, may_compress, + may_discard_trees, + # abstractinterpretation.jl + abstract_call_gf_by_type, abstract_call_known, abstract_call, + abstract_eval_special_value, abstract_eval_value_expr, abstract_eval_value, + abstract_eval_statement + +# TODO: use `using` instead +# loaded symbols +import Core: + MethodInstance, TypeofBottom + +import Core.Compiler: + AbstractInterpreter, NativeInterpreter, InferenceState, InferenceResult, + Bottom, widenconst, ⊑, isconstType, typeintersect, Builtin, CallMeta, argtypes_to_type, + MethodMatchInfo, UnionSplitInfo, MethodLookupResult, + Const, VarTable, SSAValue, abstract_eval_ssavalue, Slot, slot_id, GlobalRef, GotoIfNot, + _methods_by_ftype, specialize_method, typeinf, to_tuple_type + +import Base: + Meta.isexpr, Iterators.flatten + +include("errorreport.jl") +include("abstractinterpreterinterface.jl") +include("abstractinterpretation.jl") +include("tfuncs.jl") +include("print.jl") + + +@nospecialize + +function profile!(interp::TPInterpreter, tt::Type{<:Tuple}) + # `get_world_counter` here will always make the method the newest as in REPL + ms = _methods_by_ftype(tt, -1, get_world_counter()) + (ms === false || length(ms) != 1) && error("Unable to find single applicable method for $tt") + + atypes, sparams, m = ms[1] + + # grab the appropriate method instance for these types + mi = specialize_method(m, atypes, sparams) + + # create an InferenceResult to hold the result + result = InferenceResult(mi) + + # create an InferenceState to begin inference, give it a world that is always newest + world = get_world_counter() + frame = InferenceState(result, #=cached=# true, interp) + + # run type inference on this frame + typeinf(interp, frame) + + return frame # and `interp` now holds traced information +end + +# TODO: keyword arguments +profile_call(f, args...) = profile_call(to_tuple_type(typeof′.([f, args...]))) +function profile_call(tt::Type{<:Tuple}) + interp = TPInterpreter() + frame = profile!(interp, tt) + return interp, frame +end + +typeof′(x) = typeof(x) +typeof′(x::Type{T}) where {T} = Type{T} + +@specialize + +end # module Profiler diff --git a/src/profiler/tfuncs.jl b/src/profiler/tfuncs.jl new file mode 100644 index 000000000..e69de29bb diff --git a/test/runtests.jl b/test/runtests.jl index 9010a3d9e..7aac94fe8 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -1,10 +1,46 @@ using TypeProfiler -# using Test +const CC = Core.Compiler -@profile_call sum("julia") -fib(n) = n <= 2 ? n : fib(n - 1) + fib(n - 2) -@profile_call fib(100) # never ends otherwise +# favorite +# -------- + +# never ends otherwise +fib(n) = n ≤ 2 ? n : fib(n-1) + fib(n-2) +@profile_call fib(100000) # ::Int +@profile_call fib(100000.) # ::Float64 +@profile_call fib(100000 + 100000im) # report ! + + +# undef var +# --------- + +undef1(a) = return foo(a) +@profile_call undef1(0) + +undef2(a) = @isdefined(b) && return a # will be lowered to `Expr(:isdefined)` +@profile_call undef2(0) + + +# non-boolean condition +# --------------------- + +nonbool(a) = a ? a : nothing +nonbool() = (c = rand(Any[1,2,3])) ? c #=c is Any typed=# : nothing + +@profile_call nonbool(1) # report +@profile_call nonbool(true) # not report +@profile_call nonbool() # not report because it's untyped + + +# no matching method +# ------------------ + +# single match +@profile_call sum("julia") +@profile_call sum(Char[]) +@profile_call sum([]) # the actual error (i.e. no method for `zero(Any)`) is buriled in the "Too many methods matched" heuristic -fib′(n) = n <= 2 ? n : fib′′(n - 1) + fib′(n′ - 2) -@profile_call fib′(100) # never ends otherwise +# union splitting +nomethod_partial(a) = sin(a) +TypeProfiler.profile_call(Tuple{typeof(nomethod_partial), Union{Int,Char}})