Skip to content

Commit

Permalink
track the exact lambda associated with a fptr
Browse files Browse the repository at this point in the history
this allows printing the actual method signature of the function in the call stack

both profiling and backtrace printing have been extended to show this
full linfo signature (when available)
  • Loading branch information
vtjnash committed Jan 30, 2016
1 parent 4d1bf92 commit 9ce59c8
Show file tree
Hide file tree
Showing 12 changed files with 237 additions and 109 deletions.
2 changes: 1 addition & 1 deletion base/deprecated.jl
Original file line number Diff line number Diff line change
Expand Up @@ -81,7 +81,7 @@ function firstcaller(bt::Array{Ptr{Void},1}, funcsym::Symbol)
if lkup === ()
continue
end
fname, file, line, inlinedat_file, inlinedat_line, fromC = lkup
fname, file, line, inlinedat_file, inlinedat_line, linfo, fromC = lkup
if fname == funcsym
break
end
Expand Down
70 changes: 48 additions & 22 deletions base/profile.jl
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@

module Profile

import Base: hash, ==
import Base: hash, ==, show_spec_linfo

export @profile

Expand Down Expand Up @@ -122,7 +122,7 @@ end

# TODO update signature in docstring.
"""
callers(funcname, [data, lidict], [filename=<filename>], [linerange=<start:stop>]) -> Vector{Tuple{count, linfo}}
callers(funcname, [data, lidict], [filename=<filename>], [linerange=<start:stop>]) -> Vector{Tuple{count, lineinfo}}
Given a previous profiling run, determine who called a particular function. Supplying the
filename (and optionally, range of line numbers over which the function is defined) allows
Expand Down Expand Up @@ -171,15 +171,16 @@ clear_malloc_data() = ccall(:jl_clear_malloc_data, Void, ())
####
immutable LineInfo
func::ByteString
file::ByteString
line::Int
inlined_file::ByteString
inlined_line::Int
file::ByteString
line::Int
outer_linfo::Nullable{LambdaStaticData}
fromC::Bool
ip::Int64 # large enough that this struct can be losslessly read on any machine (32 or 64 bit)
end

const UNKNOWN = LineInfo("?", "?", -1, "?", -1, true, 0)
const UNKNOWN = LineInfo("?", "?", -1, "?", -1, Nullable{LambdaStaticData}(), true, 0)

#
# If the LineInfo has function and line information, we consider two of them the same
Expand Down Expand Up @@ -208,10 +209,18 @@ len_data() = convert(Int, ccall(:jl_profile_len_data, Csize_t, ()))

maxlen_data() = convert(Int, ccall(:jl_profile_maxlen_data, Csize_t, ()))

const empty_sym = Symbol("")
function lookup(ip::Ptr{Void})
info = ccall(:jl_lookup_code_address, Any, (Ptr{Void},Cint), ip, false)
if length(info) == 7
return LineInfo(string(info[1]), string(info[2]), Int(info[3]), string(info[4]), Int(info[5]), info[6], Int64(info[7]))
if length(info) == 8
is_inlined = (info[4] !== empty_sym)
return LineInfo(string(info[1]),
is_inlined ? string(info[2]) : "",
is_inlined ? Int(info[3]) : -1,
string(is_inlined ? info[4] : info[2]),
Int(is_inlined ? info[5] : info[3]),
info[6] === nothing ? Nullable{LambdaStaticData}() : Nullable{LambdaStaticData}(info[6]),
info[7], Int64(info[8]))
else
return UNKNOWN
end
Expand Down Expand Up @@ -326,26 +335,35 @@ function print_flat(io::IO, lilist::Vector{LineInfo}, n::Vector{Int}, combine::B
end
wcounts = max(6, ndigits(maximum(n)))
maxline = 0
maxfile = 0
maxfunc = 0
maxfile = 6
maxfunc = 10
for li in lilist
maxline = max(maxline, li.line)
maxfile = max(maxfile, length(li.file))
maxfunc = max(maxfunc, length(li.func))
end
wline = max(5, ndigits(maxline))
ntext = cols - wcounts - wline - 3
if maxfile+maxfunc <= ntext
maxfunc += 25
if maxfile + maxfunc <= ntext
wfile = maxfile
wfunc = maxfunc
else
wfile = floor(Integer,2*ntext/5)
wfunc = floor(Integer,3*ntext/5)
end
println(io, lpad("Count", wcounts, " "), " ", rpad("File", wfile, " "), " ", rpad("Function", wfunc, " "), " ", lpad("Line", wline, " "))
println(io, lpad("Count", wcounts, " "), " ", rpad("File", wfile, " "), " ", lpad("Line", wline, " "), " ", rpad("Function", wfunc, " "))
for i = 1:length(n)
li = lilist[i]
println(io, lpad(string(n[i]), wcounts, " "), " ", rpad(truncto(li.file, wfile), wfile, " "), " ", rpad(truncto(li.func, wfunc), wfunc, " "), " ", lpad(string(li.line), wline, " "))
Base.print(io, lpad(string(n[i]), wcounts, " "), " ")
Base.print(io, rpad(rtruncto(li.file, wfile), wfile, " "), " ")
Base.print(io, lpad(string(li.line), wline, " "), " ")
fname = li.func
if !li.fromC && !isnull(li.outer_linfo)
fname = sprint(show_spec_linfo, Symbol(li.func), get(li.outer_linfo))
end
Base.print(io, rpad(ltruncto(fname, wfunc), wfunc, " "))
println(io)
end
end

Expand Down Expand Up @@ -400,18 +418,18 @@ function tree_format(lilist::Vector{LineInfo}, counts::Vector{Int}, level::Int,
" ","unknown function (ip: 0x",hex(li.ip,2*sizeof(Ptr{Void})),
")")
else
base = string(base,
fname = li.func
if !li.fromC && !isnull(li.outer_linfo)
fname = sprint(show_spec_linfo, Symbol(li.func), get(li.outer_linfo))
end
strs[i] = string(base,
rpad(string(counts[i]), ndigcounts, " "),
" ",
truncto(string(li.file), widthfile),
rtruncto(li.file, widthfile),
":",
li.line == -1 ? "?" : string(li.line),
"; ",
truncto(string(li.func), widthfunc),
"; ")
if li.line == -1
strs[i] = string(base, "(unknown line)")
else
strs[i] = string(base, "line: ", li.line)
end
ltruncto(fname, widthfunc))
end
else
strs[i] = ""
Expand Down Expand Up @@ -540,13 +558,21 @@ function callersf(matchfunc::Function, bt::Vector{UInt}, lidict)
end

# Utilities
function truncto(str::ByteString, w::Int)
function rtruncto(str::ByteString, w::Int)
ret = str;
if length(str) > w
ret = string("...", str[end-w+4:end])
end
ret
end
function ltruncto(str::ByteString, w::Int)
ret = str;
if length(str) > w
ret = string(str[1:w-4], "...")
end
ret
end


# Order alphabetically (file, function) and then by line number
function liperm(lilist::Vector{LineInfo})
Expand Down
42 changes: 29 additions & 13 deletions base/replutil.jl
Original file line number Diff line number Diff line change
Expand Up @@ -120,7 +120,7 @@ function showerror(io::IO, ex::DomainError, bt; backtrace=true)
print(io, "DomainError:")
for b in bt
code = ccall(:jl_lookup_code_address, Any, (Ptr{Void}, Cint), b-1, true)
if length(code) == 7 && !code[6] # code[6] == fromC
if length(code) == 8 && !code[7] # code[7] == fromC
if code[1] in (:log, :log2, :log10, :sqrt) # TODO add :besselj, :besseli, :bessely, :besselk
print(io,"\n$(code[1]) will only return a complex result if called with a complex argument. Try $(code[1])(complex(x)).")
elseif (code[1] == :^ && code[2] == symbol("intfuncs.jl")) || code[1] == :power_by_squaring #3024
Expand Down Expand Up @@ -387,16 +387,30 @@ function show_method_candidates(io::IO, ex::MethodError)
end
end

function show_trace_entry(io, fname, file, line, inlinedat_file, inlinedat_line, n)
function show_spec_linfo(io::IO, fname::Symbol, linfo::Union{LambdaStaticData, Void})
if linfo === nothing
print(io, fname)
else
print(io, linfo.name)
Base.show_delim_array(io, linfo.(#=specTypes=#8).parameters, "(", ", ", ")", false)
end
end

const empty_symbol = symbol("")
show_trace_entry(io, fname, file, line, inlinedat_file, inlinedat_line, n) =
show_trace_entry(io, fname, file, line, inlinedat_file, inlinedat_line, nothing, n)
function show_trace_entry(io, fname, file, line, inlinedat_file, inlinedat_line, outer_linfo, n)
print(io, "\n")
# if we have inlining information, we print the `file`:`line` first,
# then show the inlining info, because the inlining location
# corresponds to `fname`.
if (inlinedat_file != symbol(""))
if inlinedat_file !== empty_symbol
# align the location text
print(io, " [inlined code] from ")
else
print(io, " in ", fname, " at ")
print(io, " in ")
show_spec_linfo(io, fname, outer_linfo)
print(io, " at ")
end

print(io, file)
Expand All @@ -413,8 +427,10 @@ function show_trace_entry(io, fname, file, line, inlinedat_file, inlinedat_line,
print(io, " (repeats ", n, " times)")
end

if (inlinedat_file != symbol(""))
print(io, "\n in ", fname, " at ")
if inlinedat_file !== empty_symbol
print(io, "\n in ")
show_spec_linfo(io, fname, outer_linfo)
print(io, " at ")
print(io, inlinedat_file, ":", inlinedat_line)
end
end
Expand All @@ -432,8 +448,8 @@ function show_backtrace(io::IO, t, set=1:typemax(Int))
end

function show_backtrace(io::IO, top_function::Symbol, t, set)
process_entry(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, n) =
show_trace_entry(io, lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, n)
process_entry(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, outer_linfo, n) =
show_trace_entry(io, lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, outer_linfo, n)
process_backtrace(process_entry, top_function, t, set)
end

Expand All @@ -447,15 +463,15 @@ end
function process_backtrace(process_func::Function, top_function::Symbol, t, set; skipC = true)
n = 1
lastfile = ""; lastline = -11; lastname = symbol("#");
last_inlinedat_file = ""; last_inlinedat_line = -1
last_inlinedat_file = ""; last_inlinedat_line = -1; last_outer_linfo = nothing
local fname, file, line
count = 0
for i = 1:length(t)
lkup = ccall(:jl_lookup_code_address, Any, (Ptr{Void}, Cint), t[i]-1, skipC)
if lkup === nothing
continue
end
fname, file, line, inlinedat_file, inlinedat_line, fromC = lkup
fname, file, line, inlinedat_file, inlinedat_line, outer_linfo, fromC = lkup

if fromC && skipC; continue; end
if i == 1 && fname == :error; continue; end
Expand All @@ -465,16 +481,16 @@ function process_backtrace(process_func::Function, top_function::Symbol, t, set;

if file != lastfile || line != lastline || fname != lastname
if lastline != -11
process_func(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, n)
process_func(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, last_outer_linfo, n)
end
n = 1
lastfile = file; lastline = line; lastname = fname;
last_inlinedat_file = inlinedat_file; last_inlinedat_line = inlinedat_line;
last_inlinedat_file = inlinedat_file; last_inlinedat_line = inlinedat_line; last_outer_linfo = outer_linfo
else
n += 1
end
end
if n > 1 || lastline != -11
process_func(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, n)
process_func(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, last_outer_linfo, n)
end
end
4 changes: 2 additions & 2 deletions base/task.jl
Original file line number Diff line number Diff line change
Expand Up @@ -17,8 +17,8 @@ type CapturedException

# Process bt_raw so that it can be safely serialized
bt_lines = Any[]
process_func(name, file, line, inlined_file, inlined_line, n) =
push!(bt_lines, (name, file, line, inlined_file, inlined_line, n))
process_func(name, file, line, inlined_file, inlined_line, outer_linfo, n) =
push!(bt_lines, (name, file, line, inlined_file, inlined_line, nothing, n))
process_backtrace(process_func, :(:), bt_raw, 1:100) # Limiting this to 100 lines.

new(ex, bt_lines)
Expand Down
3 changes: 2 additions & 1 deletion src/anticodegen.c
Original file line number Diff line number Diff line change
Expand Up @@ -28,14 +28,15 @@ void jl_fptr_to_llvm(void *fptr, jl_lambda_info_t *lam, int specsig)
lam->fptr = (jl_fptr_t)fptr;
}
void jl_getFunctionInfo(char **name, char **filename, size_t *line,
char **inlinedat_file, size_t *inlinedat_line,
char **inlinedat_file, size_t *inlinedat_line, jl_lambda_info_t **outer_linfo,
size_t pointer, int *fromC, int skipC, int skipInline)
{
*name = NULL;
*line = -1;
*filename = NULL;
*inlinedat_file = NULL;
*inlinedat_line = -1;
*outer_linfo = NULL;
*fromC = 0;
}

Expand Down
16 changes: 16 additions & 0 deletions src/codegen.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -821,6 +821,8 @@ void jl_dump_compiles(void *s)
static void emit_function(jl_lambda_info_t *lam, jl_llvm_functions_t *declarations,
jl_llvm_functions_t *definitions, jl_cyclectx_t *cyclectx);
static void jl_finalize_module(Module *m);
void jl_add_linfo_in_flight(StringRef name, jl_lambda_info_t *linfo, const DataLayout &DL);

//static int n_compile=0;
static Function *to_function(jl_lambda_info_t *li, jl_cyclectx_t *cyclectx)
{
Expand Down Expand Up @@ -874,6 +876,20 @@ static Function *to_function(jl_lambda_info_t *li, jl_cyclectx_t *cyclectx)
jl_rethrow_with_add("error compiling %s", jl_symbol_name(li->name));
}
assert(f != NULL);
const DataLayout &DL =
#ifdef LLVM35
f->getParent()->getDataLayout();
#else
*jl_data_layout;
#endif
// record that this function name came from this linfo,
// so we can build a reverse mapping for debug-info.
if (li->name != anonymous_sym) {
// but don't remember anonymous symbols because
// they may not be rooted in the gc for the life of the program,
// and the runtime doesn't notify us when the code becomes unreachable :(
jl_add_linfo_in_flight((specf ? specf : f)->getName(), li, DL);
}
#if !defined(USE_MCJIT) && !defined(USE_ORCJIT)
#ifdef JL_DEBUG_BUILD
if (verifyFunction(*f, PrintMessageAction) ||
Expand Down
Loading

0 comments on commit 9ce59c8

Please sign in to comment.