Merge pull request #33190 from JuliaLang/jn/profile-recurflat

Profile.jl improvements
JuliaLang · Sep 17, 2019 · c40a93b · c40a93b
2 parents 9096963 + 0002f0a
commit c40a93b
Show file tree

Hide file tree

Showing 21 changed files with 397 additions and 277 deletions.
diff --git a/base/client.jl b/base/client.jl
@@ -79,8 +79,10 @@ function repl_cmd(cmd, out)
     nothing
 end
 
+# deprecated function--preserved for DocTests.jl
 function ip_matches_func(ip, func::Symbol)
-    for fr in StackTraces.lookup(ip)
+    ip isa InterpreterIP || (ip -= 1)
+    for fr in StackTraces.lookupat(ip)
         if fr === StackTraces.UNKNOWN || fr.from_c
             return false
         end
@@ -90,28 +92,28 @@ function ip_matches_func(ip, func::Symbol)
 end
 
 function scrub_repl_backtrace(bt)
-    if bt !== nothing
+    if bt !== nothing && !(bt isa Vector{Any}) # ignore our sentinel value types
+        bt = stacktrace(bt)
         # remove REPL-related frames from interactive printing
-        eval_ind = findlast(addr->ip_matches_func(addr, :eval), bt)
-        if eval_ind !== nothing
-            return bt[1:eval_ind-1]
-        end
+        eval_ind = findlast(frame -> !frame.from_c && frame.func == :eval, bt)
+        eval_ind === nothing || deleteat!(bt, eval_ind:length(bt))
     end
     return bt
 end
 
 function display_error(io::IO, er, bt)
     printstyled(io, "ERROR: "; bold=true, color=Base.error_color())
-    showerror(IOContext(io, :limit => true), er, scrub_repl_backtrace(bt))
+    bt = scrub_repl_backtrace(bt)
+    showerror(IOContext(io, :limit => true), er, bt, backtrace = bt!==nothing)
     println(io)
 end
 function display_error(io::IO, stack::Vector)
     printstyled(io, "ERROR: "; bold=true, color=Base.error_color())
-    show_exception_stack(IOContext(io, :limit => true), Any[ (x[1], scrub_repl_backtrace(x[2])) for x in stack ])
+    bt = Any[ (x[1], scrub_repl_backtrace(x[2])) for x in stack ]
+    show_exception_stack(IOContext(io, :limit => true), bt)
 end
 display_error(stack::Vector) = display_error(stderr, stack)
-display_error(er, bt) = display_error(stderr, er, bt)
-display_error(er) = display_error(er, [])
+display_error(er, bt=nothing) = display_error(stderr, er, bt)
 
 function eval_user_input(errio, @nospecialize(ast), show_value::Bool)
     errcount = 0

diff --git a/base/deprecated.jl b/base/deprecated.jl
@@ -101,33 +101,29 @@ firstcaller(bt::Vector, funcsym::Symbol) = firstcaller(bt, (funcsym,))
 function firstcaller(bt::Vector, funcsyms)
     # Identify the calling line
     found = false
-    lkup = StackTraces.UNKNOWN
-    found_frame = Ptr{Cvoid}(0)
-    for frame in bt
-        lkups = StackTraces.lookup(frame)
-        for outer lkup in lkups
+    for ip in bt
+        ip isa Base.InterpreterIP || (ip -= 1) # convert from return stack to call stack (for inlining info)
+        lkups = StackTraces.lookupat(ip)
+        for lkup in lkups
             if lkup == StackTraces.UNKNOWN || lkup.from_c
                 continue
             end
             if found
-                found_frame = frame
-                @goto found
+                return ip, lkup
             end
             found = lkup.func in funcsyms
             # look for constructor type name
             if !found && lkup.linfo isa Core.MethodInstance
                 li = lkup.linfo
                 ft = ccall(:jl_first_argument_datatype, Any, (Any,), li.def.sig)
-                if isa(ft,DataType) && ft.name === Type.body.name
+                if isa(ft, DataType) && ft.name === Type.body.name
                     ft = unwrap_unionall(ft.parameters[1])
-                    found = (isa(ft,DataType) && ft.name.name in funcsyms)
+                    found = (isa(ft, DataType) && ft.name.name in funcsyms)
                 end
             end
         end
     end
-    return found_frame, StackTraces.UNKNOWN
-    @label found
-    return found_frame, lkup
+    return C_NULL, StackTraces.UNKNOWN
 end
 
 deprecate(m::Module, s::Symbol, flag=1) = ccall(:jl_deprecate_binding, Cvoid, (Any, Any, Cint), m, s, flag)

diff --git a/base/errorshow.jl b/base/errorshow.jl
@@ -522,7 +522,8 @@ function show_reduced_backtrace(io::IO, t::Vector, with_prefix::Bool)
             i = frame_counter
             j = p
             while i < length(t) && t[i] == t[j]
-                i+=1 ; j+=1
+                i += 1
+                j += 1
             end
             if j >= frame_counter-1
                 #= At least one cycle repeated =#
@@ -590,6 +591,7 @@ function show_backtrace(io::IO, t::Vector)
 end
 
 function show_backtrace(io::IO, t::Vector{Any})
+    # t is a pre-processed backtrace (ref #12856)
     if length(t) < BIG_STACKTRACE_SIZE
         try invokelatest(update_stackframes_callback[], t) catch end
         for entry in t
@@ -605,31 +607,42 @@ function process_backtrace(t::Vector, limit::Int=typemax(Int); skipC = true)
     last_frame = StackTraces.UNKNOWN
     count = 0
     ret = Any[]
-    for i = eachindex(t)
-        lkups = StackTraces.lookup(t[i])
+    for i in eachindex(t)
+        lkups = t[i]
+        if lkups isa StackFrame
+            lkups = [lkups]
+        elseif lkups isa Base.InterpreterIP
+            lkups = StackTraces.lookupat(lkups)
+        else
+            lkups = StackTraces.lookupat(lkups - 1)
+        end
         for lkup in lkups
             if lkup === StackTraces.UNKNOWN
                 continue
             end
 
-            if lkup.from_c && skipC; continue; end
-            if i == 1 && lkup.func == :error; continue; end
+            if lkup.from_c && skipC
+                continue
+            end
             count += 1
-            if count > limit; break; end
+            if count > limit
+                break
+            end
 
             if lkup.file != last_frame.file || lkup.line != last_frame.line || lkup.func != last_frame.func || lkup.linfo !== lkup.linfo
                 if n > 0
-                    push!(ret, (last_frame,n))
+                    push!(ret, (last_frame, n))
                 end
                 n = 1
                 last_frame = lkup
             else
                 n += 1
             end
         end
+        count > limit && break
     end
     if n > 0
-        push!(ret, (last_frame,n))
+        push!(ret, (last_frame, n))
     end
     return ret
 end

diff --git a/base/stacktraces.jl b/base/stacktraces.jl
@@ -7,8 +7,6 @@ module StackTraces
 
 
 import Base: hash, ==, show
-using Base.Printf: @printf
-using Base: something
 
 export StackTrace, StackFrame, stacktrace
 
@@ -98,31 +96,28 @@ end
 
 
 """
-    lookup(pointer::Union{Ptr{Cvoid}, UInt}) -> Vector{StackFrame}
+    lookupat(pointer::Union{Ptr{Cvoid}, UInt}) -> Vector{StackFrame}
 
 Given a pointer to an execution context (usually generated by a call to `backtrace`), looks
 up stack frame context information. Returns an array of frame information for all functions
 inlined at that point, innermost function first.
 """
-function lookup(pointer::Ptr{Cvoid})
-    infos = ccall(:jl_lookup_code_address, Any, (Ptr{Cvoid}, Cint), pointer - 1, false)
-    isempty(infos) && return [StackFrame(empty_sym, empty_sym, -1, nothing, true, false, convert(UInt64, pointer))]
+function lookupat(pointer::Ptr{Cvoid})
+    infos = ccall(:jl_lookup_code_address, Any, (Ptr{Cvoid}, Cint), pointer, false)
+    pointer = convert(UInt64, pointer)
+    isempty(infos) && return [StackFrame(empty_sym, empty_sym, -1, nothing, true, false, pointer)] # this is equal to UNKNOWN
     res = Vector{StackFrame}(undef, length(infos))
     for i in 1:length(infos)
         info = infos[i]
-        @assert(length(info) == 7)
-        res[i] = StackFrame(info[1], info[2], info[3], info[4], info[5], info[6], info[7])
+        @assert(length(info) == 6)
+        res[i] = StackFrame(info[1], info[2], info[3], info[4], info[5], info[6], pointer)
     end
     return res
 end
 
-lookup(pointer::UInt) = lookup(convert(Ptr{Cvoid}, pointer))
-
 const top_level_scope_sym = Symbol("top-level scope")
 
-using Base.Meta
-is_loc_meta(expr, kind) = isexpr(expr, :meta) && length(expr.args) >= 1 && expr.args[1] === kind
-function lookup(ip::Base.InterpreterIP)
+function lookupat(ip::Base.InterpreterIP)
     if ip.code isa Core.MethodInstance && ip.code.def isa Method
         codeinfo = ip.code.uninferred
         func = ip.code.def.name
@@ -154,10 +149,6 @@ function lookup(ip::Base.InterpreterIP)
     return scopes
 end
 
-# allow lookup on already-looked-up data for easier handling of pre-processed frames
-lookup(s::StackFrame) = StackFrame[s]
-lookup(s::Tuple{StackFrame,Int}) = StackFrame[s[1]]
-
 """
     backtrace()
 
@@ -195,26 +186,28 @@ doesn't return C functions, but this can be enabled.) When called without specif
 trace, `stacktrace` first calls `backtrace`.
 """
 function stacktrace(trace::Vector{<:Union{Base.InterpreterIP,Ptr{Cvoid}}}, c_funcs::Bool=false)
-    stack = vcat(StackTrace(), map(lookup, trace)...)::StackTrace
-
-    # Remove frames that come from C calls.
-    if !c_funcs
-        filter!(frame -> !frame.from_c, stack)
+    stack = StackTrace()
+    for ip in trace
+        ip isa Base.InterpreterIP || (ip -= 1) # convert from return stack to call stack (for inlining info)
+        for frame in lookupat(ip)
+            # Skip frames that come from C calls.
+            if c_funcs || !frame.from_c
+                push!(stack, frame)
+            end
+        end
     end
+    return stack
+end
 
+function stacktrace(c_funcs::Bool=false)
+    stack = stacktrace(backtrace(), c_funcs)
     # Remove frame for this function (and any functions called by this function).
     remove_frames!(stack, :stacktrace)
-
-    # is there a better way?  the func symbol has a number suffix which changes.
-    # it's possible that no test is needed and we could just popfirst! all the time.
-    # this line was added to PR #16213 because otherwise stacktrace() != stacktrace(false).
-    # not sure why.  possibly b/c of re-ordering of base/sysimg.jl
-    !isempty(stack) && startswith(string(stack[1].func),"jlcall_stacktrace") && popfirst!(stack)
-    stack
+    # also remove all of the non-Julia functions that led up to this point (if that list is non-empty)
+    c_funcs && deleteat!(stack, 1:(something(findfirst(frame -> !frame.from_c, stack), 1) - 1))
+    return stack
 end
 
-stacktrace(c_funcs::Bool=false) = stacktrace(backtrace(), c_funcs)
-
 """
     remove_frames!(stack::StackTrace, name::Symbol)
 
@@ -224,12 +217,12 @@ all frames above the specified function). Primarily used to remove `StackTraces`
 from the `StackTrace` prior to returning it.
 """
 function remove_frames!(stack::StackTrace, name::Symbol)
-    splice!(stack, 1:something(findlast(frame -> frame.func == name, stack), 0))
+    deleteat!(stack, 1:something(findlast(frame -> frame.func == name, stack), 0))
     return stack
 end
 
 function remove_frames!(stack::StackTrace, names::Vector{Symbol})
-    splice!(stack, 1:something(findlast(frame -> frame.func in names, stack), 0))
+    deleteat!(stack, 1:something(findlast(frame -> frame.func in names, stack), 0))
     return stack
 end
 
@@ -248,7 +241,7 @@ is_top_level_frame(f::StackFrame) = f.linfo isa Core.CodeInfo || (f.linfo === no
 function show_spec_linfo(io::IO, frame::StackFrame)
     if frame.linfo === nothing
         if frame.func === empty_sym
-            @printf(io, "ip:%#x", frame.pointer)
+            print(io, "ip:0x", string(frame.pointer, base=16))
         elseif frame.func === top_level_scope_sym
             print(io, "top-level scope")
         else

diff --git a/doc/src/base/stacktraces.md b/doc/src/base/stacktraces.md
@@ -7,9 +7,9 @@ Base.StackTraces.stacktrace
 ```
 
 The following methods and types in `Base.StackTraces` are not exported and need to be called e.g.
-as `StackTraces.lookup(ptr)`.
+as `StackTraces.lookupat(ptr)`.
 
 ```@docs
-Base.StackTraces.lookup
+Base.StackTraces.lookupat
 Base.StackTraces.remove_frames!
 ```
diff --git a/doc/src/manual/stacktraces.md b/doc/src/manual/stacktraces.md
@@ -300,16 +300,15 @@ julia> stacktrace(trace, true)
 ```
 
 Individual pointers returned by [`backtrace`](@ref) can be translated into [`StackTraces.StackFrame`](@ref)
-s by passing them into [`StackTraces.lookup`](@ref):
+s by passing them into [`StackTraces.lookupat`](@ref):
 
 ```julia-repl
 julia> pointer = backtrace()[1];
 
-julia> frame = StackTraces.lookup(pointer)
+julia> frame = StackTraces.lookupat(pointer - 1)
 1-element Array{Base.StackTraces.StackFrame,1}:
  jl_apply_generic at gf.c:2167
 
 julia> println("The top frame is from $(frame[1].func)!")
 The top frame is from jl_apply_generic!
 ```
-
diff --git a/src/julia_internal.h b/src/julia_internal.h
@@ -637,9 +637,9 @@ typedef int bt_cursor_t;
 // Special marker in backtrace data for encoding interpreter frames
 #define JL_BT_INTERP_FRAME (((uintptr_t)0)-1)
 size_t rec_backtrace(uintptr_t *data, size_t maxsize) JL_NOTSAFEPOINT;
-size_t rec_backtrace_ctx(uintptr_t *data, size_t maxsize, bt_context_t *ctx) JL_NOTSAFEPOINT;
+size_t rec_backtrace_ctx(uintptr_t *data, size_t maxsize, bt_context_t *ctx, int add_interp_frames) JL_NOTSAFEPOINT;
 #ifdef LIBOSXUNWIND
-size_t rec_backtrace_ctx_dwarf(uintptr_t *data, size_t maxsize, bt_context_t *ctx);
+size_t rec_backtrace_ctx_dwarf(uintptr_t *data, size_t maxsize, bt_context_t *ctx, int add_interp_frames) JL_NOTSAFEPOINT;
 #endif
 JL_DLLEXPORT void jl_get_backtrace(jl_array_t **bt, jl_array_t **bt2);
 void jl_critical_error(int sig, bt_context_t *context, uintptr_t *bt_data, size_t *bt_size);

diff --git a/src/signal-handling.c b/src/signal-handling.c
@@ -231,7 +231,7 @@ void jl_critical_error(int sig, bt_context_t *context, uintptr_t *bt_data, size_
         jl_safe_printf("\nsignal (%d): %s\n", sig, strsignal(sig));
     jl_safe_printf("in expression starting at %s:%d\n", jl_filename, jl_lineno);
     if (context)
-        *bt_size = n = rec_backtrace_ctx(bt_data, JL_MAX_BT_SIZE, context);
+        *bt_size = n = rec_backtrace_ctx(bt_data, JL_MAX_BT_SIZE, context, 0);
     for (i = 0; i < n; i++)
         jl_gdblookup(bt_data[i] - 1);
     gc_debug_print_status();