From 9ce59c858a47057cdab9890932eabd9fe8c62377 Mon Sep 17 00:00:00 2001 From: Jameson Nash Date: Tue, 26 Jan 2016 21:38:12 -0500 Subject: [PATCH 1/3] track the exact lambda associated with a fptr 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) --- base/deprecated.jl | 2 +- base/profile.jl | 70 +++++++++++++++------- base/replutil.jl | 42 +++++++++---- base/task.jl | 4 +- src/anticodegen.c | 3 +- src/codegen.cpp | 16 +++++ src/debuginfo.cpp | 140 +++++++++++++++++++++++++++++-------------- src/disasm.cpp | 3 +- src/dump.c | 36 +++++++---- src/julia_internal.h | 2 +- src/task.c | 22 ++++--- test/backtrace.jl | 6 +- 12 files changed, 237 insertions(+), 109 deletions(-) diff --git a/base/deprecated.jl b/base/deprecated.jl index a8c0be7558f23..90aa6c942d271 100644 --- a/base/deprecated.jl +++ b/base/deprecated.jl @@ -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 diff --git a/base/profile.jl b/base/profile.jl index 4703046e4ab86..561e733325633 100644 --- a/base/profile.jl +++ b/base/profile.jl @@ -2,7 +2,7 @@ module Profile -import Base: hash, == +import Base: hash, ==, show_spec_linfo export @profile @@ -122,7 +122,7 @@ end # TODO update signature in docstring. """ - callers(funcname, [data, lidict], [filename=], [linerange=]) -> Vector{Tuple{count, linfo}} + callers(funcname, [data, lidict], [filename=], [linerange=]) -> 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 @@ -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 @@ -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 @@ -326,8 +335,8 @@ 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)) @@ -335,17 +344,26 @@ function print_flat(io::IO, lilist::Vector{LineInfo}, n::Vector{Int}, combine::B 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 @@ -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] = "" @@ -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}) diff --git a/base/replutil.jl b/base/replutil.jl index ace8b400c2d36..e986b5bb12ab1 100644 --- a/base/replutil.jl +++ b/base/replutil.jl @@ -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 @@ -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) @@ -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 @@ -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 @@ -447,7 +463,7 @@ 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) @@ -455,7 +471,7 @@ function process_backtrace(process_func::Function, top_function::Symbol, t, set; 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 @@ -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 diff --git a/base/task.jl b/base/task.jl index facc6ef891d20..f18a7548ad0d7 100644 --- a/base/task.jl +++ b/base/task.jl @@ -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) diff --git a/src/anticodegen.c b/src/anticodegen.c index 4d5ea3c8569ad..3dcdceb53af7b 100644 --- a/src/anticodegen.c +++ b/src/anticodegen.c @@ -28,7 +28,7 @@ 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; @@ -36,6 +36,7 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, *filename = NULL; *inlinedat_file = NULL; *inlinedat_line = -1; + *outer_linfo = NULL; *fromC = 0; } diff --git a/src/codegen.cpp b/src/codegen.cpp index fcc2f3b81342a..ac1e9ce456d07 100644 --- a/src/codegen.cpp +++ b/src/codegen.cpp @@ -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) { @@ -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) || diff --git a/src/debuginfo.cpp b/src/debuginfo.cpp index e5620014d91f3..3b785cdcc1f72 100644 --- a/src/debuginfo.cpp +++ b/src/debuginfo.cpp @@ -13,12 +13,15 @@ #include #include #include +#include #ifdef LLVM35 #include #else #include #endif -#ifdef USE_MCJIT +#if defined(USE_MCJIT) || defined(USE_ORCJIT) +#include +#include #ifndef LLVM36 #include #endif @@ -74,9 +77,8 @@ extern "C" void jl_init_debuginfo() struct FuncInfo { const Function *func; size_t lengthAdr; - std::string name; - std::string filename; std::vector lines; + jl_lambda_info_t *linfo; }; #else struct ObjectInfo { @@ -90,9 +92,31 @@ struct ObjectInfo { #if defined(_OS_DARWIN_) && !defined(LLVM37) const char *name; #endif + jl_lambda_info_t *linfo; }; #endif +// Maintain a mapping of unrealized function names -> linfo objects +// so that when we see it get emitted, we can add a link back to the linfo +// that it came from (providing name, type signature, file info, etc.) +static StringMap linfo_in_flight; +static std::string mangle(const std::string &Name, const DataLayout &DL) { +#if defined(USE_MCJIT) || defined(USE_ORCJIT) + std::string MangledName; + { + raw_string_ostream MangledNameStream(MangledName); + Mangler::getNameWithPrefix(MangledNameStream, Name, DL); + } + return MangledName; +#else + return Name; +#endif +} +void jl_add_linfo_in_flight(StringRef name, jl_lambda_info_t *linfo, const DataLayout &DL) +{ + linfo_in_flight[mangle(name, DL)] = linfo; +} + #if defined(_OS_WINDOWS_) #if defined(_CPU_X86_64_) extern "C" EXCEPTION_DISPOSITION _seh_exception_handler(PEXCEPTION_RECORD ExceptionRecord,void *EstablisherFrame, PCONTEXT ContextRecord, void *DispatcherContext); @@ -197,10 +221,16 @@ class JuliaJITEventListener: public JITEventListener int8_t gc_state = jl_gc_safe_enter(); uv_rwlock_wrlock(&threadsafe); jl_gc_safe_leave(gc_state); + StringMap::iterator linfo_it = linfo_in_flight.find(F.getName()); + jl_lambda_info_t *linfo = NULL; + if (linfo_it != linfo_in_flight.end()) { + linfo = linfo_it->second; + linfo_in_flight.erase(linfo_it); + } #if defined(_OS_WINDOWS_) create_PRUNTIME_FUNCTION((uint8_t*)Code, Size, F.getName(), (uint8_t*)Code, Size, NULL); #endif - FuncInfo tmp = {&F, Size, F.getName().str(), std::string(), Details.LineStarts}; + FuncInfo tmp = {&F, Size, Details.LineStarts, linfo}; info[(size_t)(Code)] = tmp; uv_rwlock_wrunlock(&threadsafe); } @@ -338,12 +368,9 @@ class JuliaJITEventListener: public JITEventListener uint64_t SectionAddr = L.getSectionLoadAddress(secName); #endif Addr += SectionAddr; + StringRef sName = sym_iter.getName().get(); #if defined(_OS_WINDOWS_) uint64_t SectionSize = Section->getSize(); - StringRef sName = sym_iter.getName().get(); -# ifdef _CPU_X86_ - if (sName[0] == '_') sName = sName.substr(1); -# endif if (SectionAddrCheck) assert(SectionAddrCheck == SectionAddr); else @@ -352,7 +379,13 @@ class JuliaJITEventListener: public JITEventListener (uint8_t*)(intptr_t)Addr, (size_t)Size, sName, (uint8_t*)(intptr_t)SectionAddr, (size_t)SectionSize, UnwindData); #endif - ObjectInfo tmp = {&debugObj, (size_t)Size, L.clone().release()}; + StringMap::iterator linfo_it = linfo_in_flight.find(sName); + jl_lambda_info_t *linfo = NULL; + if (linfo_it != linfo_in_flight.end()) { + linfo = linfo_it->second; + linfo_in_flight.erase(linfo_it); + } + ObjectInfo tmp = {&debugObj, (size_t)Size, L.clone().release(), linfo}; objectmap[Addr] = tmp; } @@ -360,14 +393,11 @@ class JuliaJITEventListener: public JITEventListener uint64_t Addr; uint64_t Size; object::SymbolRef::Type SymbolType; + StringRef sName; #ifdef LLVM36 uint64_t SectionAddr = 0; - StringRef sName; #else bool isText; -#ifndef _OS_LINUX_ - StringRef sName; -#endif #ifdef _OS_WINDOWS_ uint64_t SectionAddr = 0; #endif @@ -389,17 +419,12 @@ class JuliaJITEventListener: public JITEventListener #else if (Section->isText(isText) || !isText) continue; #endif -#ifdef _OS_DARWIN_ sym_iter.getName(sName); -# if defined(LLVM36) - if (sName[0] == '_') { - sName = sName.substr(1); - } -# else +#ifdef _OS_DARWIN_ +# if !defined(LLVM36) Addr = ((MCJIT*)jl_ExecutionEngine)->getSymbolAddress(sName, true); if (!Addr && sName[0] == '_') { - sName = sName.substr(1); - Addr = ((MCJIT*)jl_ExecutionEngine)->getSymbolAddress(sName, true); + Addr = ((MCJIT*)jl_ExecutionEngine)->getSymbolAddress(sName.substr(1), true); } if (!Addr) continue; # endif @@ -410,10 +435,6 @@ class JuliaJITEventListener: public JITEventListener # else Section->getAddress(SectionAddr); Section->getSize(SectionSize); -# endif - sym_iter.getName(sName); -# ifdef _CPU_X86_ - if (sName[0] == '_') sName = sName.substr(1); # endif if (SectionAddrCheck) assert(SectionAddrCheck == SectionAddr); @@ -423,21 +444,28 @@ class JuliaJITEventListener: public JITEventListener (uint8_t*)(intptr_t)Addr, (size_t)Size, sName, (uint8_t*)(intptr_t)SectionAddr, (size_t)SectionSize, UnwindData); #endif + StringMap::iterator linfo_it = linfo_in_flight.find(sName); + jl_lambda_info_t *linfo = NULL; + if (linfo_it != linfo_in_flight.end()) { + linfo = linfo_it->second; + linfo_in_flight.erase(linfo_it); + } const object::ObjectFile *objfile = #ifdef LLVM36 &obj; #else obj.getObjectFile(); #endif - ObjectInfo tmp = {objfile, (size_t)Size + ObjectInfo tmp = {objfile, (size_t)Size, #ifdef LLVM37 - ,L.clone().release() + L.clone().release(), #elif defined(LLVM36) - ,(size_t)SectionAddr + (size_t)SectionAddr, #endif #ifdef _OS_DARWIN_ - ,strndup(sName.data(), sName.size()) + strndup(sName.data(), sName.size()), #endif + linfo }; objectmap[Addr] = tmp; } @@ -577,8 +605,8 @@ static void lookup_pointer(DIContext *context, char **name, size_t *line, #endif done: - // If this is a jlcall wrapper, set fromC to match JIT behavior - if (*name == NULL || ((strlen(*name) > 7) && (memcmp(*name, "jlcall_",7) == 0))) { + // If this is a jlcall or jlcapi wrapper, set fromC to match JIT behavior + if (*name == NULL || !strncmp(*name, "jlcall_", 7) || !strncmp(*name, "jlcapi_", 7)) { *fromC = true; } } @@ -634,13 +662,22 @@ static bool getObjUUID(llvm::object::MachOObjectFile *obj, uint8_t uuid[16]) } #endif -extern "C" uint64_t jl_sysimage_base; +static uint64_t jl_sysimage_base; +static void **sysimg_fvars; +static jl_lambda_info_t **sysimg_fvars_linfo; +static size_t sysimg_fvars_n; +extern "C" void jl_register_fptrs(uint64_t sysimage_base, void **fptrs, jl_lambda_info_t **linfos, size_t n) +{ + jl_sysimage_base = sysimage_base; + sysimg_fvars = fptrs; + sysimg_fvars_linfo = linfos; + sysimg_fvars_n = n; +} // *name and *filename should be either NULL or malloc'd pointer static void jl_getDylibFunctionInfo(char **name, char **filename, size_t *line, - char **inlinedat_file, - size_t *inlinedat_line, size_t pointer, - int *fromC, int skipC, int skipInline) + char **inlinedat_file, size_t *inlinedat_line, jl_lambda_info_t **outer_linfo, + size_t pointer, int *fromC, int skipC, int skipInline) { // This function is not allowed to reference any TLS variables since // it can be called from an unmanaged thread on OSX. @@ -669,6 +706,7 @@ static void jl_getDylibFunctionInfo(char **name, char **filename, size_t *line, DWORD dwDisplacement = 0; DWORD64 dwDisplacement64 = 0; DWORD64 dwAddress = pointer; + void *saddr = NULL; PSYMBOL_INFO pSymbol = (PSYMBOL_INFO)frame_info_func; pSymbol->SizeOfStruct = sizeof(SYMBOL_INFO); pSymbol->MaxNameLen = MAX_SYM_NAME; @@ -677,6 +715,7 @@ static void jl_getDylibFunctionInfo(char **name, char **filename, size_t *line, pSymbol)) { // SymFromAddr returned success jl_copy_str(name, pSymbol->Name); + saddr = (void*)(uintptr_t)pSymbol->Address; } else { // SymFromAddr failed @@ -701,6 +740,7 @@ static void jl_getDylibFunctionInfo(char **name, char **filename, size_t *line, if ((dladdr((void*)pointer, &dlinfo) != 0) && dlinfo.dli_fname) { const char *fname; uint64_t fbase = (uint64_t)dlinfo.dli_fbase; + void *saddr = dlinfo.dli_saddr; #if defined(_OS_DARWIN_) size_t msize = (size_t)(((uint64_t)-1)-fbase); #endif @@ -841,6 +881,14 @@ static void jl_getDylibFunctionInfo(char **name, char **filename, size_t *line, #endif lookup_pointer(context, name, line, filename, inlinedat_line, inlinedat_file, pointer+slide, fbase == jl_sysimage_base, fromC); + if (jl_sysimage_base == fbase && sysimg_fvars && saddr) { + for (size_t i = 0; i < sysimg_fvars_n; i++) { + if (saddr == sysimg_fvars[i]) { + *outer_linfo = sysimg_fvars_linfo[i]; + break; + } + } + } } else { *fromC = 1; @@ -849,7 +897,7 @@ static void jl_getDylibFunctionInfo(char **name, char **filename, size_t *line, // Set *name and *filename to either NULL or malloc'd string 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) { // This function is not allowed to reference any TLS variables since @@ -859,6 +907,7 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, *filename = NULL; *inlinedat_file = NULL; *inlinedat_line = -1; + *outer_linfo = NULL; *fromC = 0; #ifdef USE_MCJIT @@ -869,6 +918,7 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, if (it != objmap.end() && (intptr_t)(*it).first + (*it).second.size > pointer) { + *outer_linfo = (*it).second.linfo; #if defined(_OS_DARWIN_) && !defined(LLVM37) *name = jl_demangle((*it).second.name); DIContext *context = NULL; // versions of MCJIT < 3.7 can't handle MachO relocations @@ -886,8 +936,6 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, #endif lookup_pointer(context, name, line, filename, inlinedat_line, inlinedat_file, pointer, 1, fromC); delete context; - uv_rwlock_rdunlock(&threadsafe); - return; } #else // !USE_MCJIT @@ -905,8 +953,8 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, return; } - jl_copy_str(name, (*it).second.name.c_str()); - jl_copy_str(filename, (*it).second.filename.c_str()); + jl_copy_str(name, (*it).second.func->getName().str().c_str()); + jl_copy_str(filename, ""); if ((*it).second.lines.empty()) { *fromC = 1; @@ -914,6 +962,7 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, return; } + *outer_linfo = (*it).second.linfo; std::vector::iterator vit = (*it).second.lines.begin(); JITEvent_EmittedFunctionDetails::LineStart prev = *vit; @@ -959,12 +1008,13 @@ void jl_getFunctionInfo(char **name, char **filename, size_t *line, jl_copy_str(inlinedat_file, inlinescope.getFilename().str().c_str()); *inlinedat_line = inlineloc.getLine(); } - - uv_rwlock_rdunlock(&threadsafe); - return; } #endif // USE_MCJIT - jl_getDylibFunctionInfo(name, filename, line, inlinedat_file, inlinedat_line, pointer, fromC, skipC, skipInline); + + else { + jl_getDylibFunctionInfo(name, filename, line, inlinedat_file, inlinedat_line, outer_linfo, pointer, fromC, skipC, skipInline); + } + uv_rwlock_rdunlock(&threadsafe); } @@ -1104,7 +1154,7 @@ DWORD64 jl_getUnwindInfo(ULONG64 dwAddr) ipstart = (DWORD64)(intptr_t)(*it).first; } uv_rwlock_rdunlock(&threadsafe); - return 0; + return ipstart; } #else //ifdef USE_MCJIT diff --git a/src/disasm.cpp b/src/disasm.cpp index 6801a0a0d5850..5e06dfcf4a1c1 100644 --- a/src/disasm.cpp +++ b/src/disasm.cpp @@ -232,8 +232,9 @@ static int OpInfoLookup(void *DisInfo, uint64_t PC, uint64_t Offset, uint64_t Si size_t line; char *inlinedat_file; size_t inlinedat_line; + jl_lambda_info_t *outer_linfo; int fromC; - jl_getFunctionInfo(&name, &filename, &line, &inlinedat_file, &inlinedat_line, pointer, &fromC, skipC, 1); + jl_getFunctionInfo(&name, &filename, &line, &inlinedat_file, &inlinedat_line, &outer_linfo, pointer, &fromC, skipC, 1); free(filename); free(inlinedat_file); if (!name) diff --git a/src/dump.c b/src/dump.c index 1f9db1116ae8e..10bf2b359a2fe 100644 --- a/src/dump.c +++ b/src/dump.c @@ -200,16 +200,16 @@ static void write_float64(ios_t *s, double x) #define jl_serialize_value(s, v) jl_serialize_value_(s,(jl_value_t*)(v)) static void jl_serialize_value_(ios_t *s, jl_value_t *v); static jl_value_t *jl_deserialize_value(ios_t *s, jl_value_t **loc); -jl_value_t ***sysimg_gvars = NULL; -void **sysimg_fvars = NULL; +static jl_value_t ***sysimg_gvars = NULL; +static void **sysimg_fvars = NULL; #ifdef HAVE_CPUID extern void jl_cpuid(int32_t CPUInfo[4], int32_t InfoType); #endif extern int globalUnique; -void *jl_sysimg_handle = NULL; -uint64_t jl_sysimage_base = 0; +static void *jl_sysimg_handle = NULL; +static uint64_t sysimage_base = 0; #ifdef _OS_WINDOWS_ #include #endif @@ -263,13 +263,13 @@ static int jl_load_sysimg_so(void) #endif #ifdef _OS_WINDOWS_ - jl_sysimage_base = (intptr_t)jl_sysimg_handle; + sysimage_base = (intptr_t)jl_sysimg_handle; #else if (dladdr((void*)sysimg_gvars, &dlinfo) != 0) { - jl_sysimage_base = (intptr_t)dlinfo.dli_fbase; + sysimage_base = (intptr_t)dlinfo.dli_fbase; } else { - jl_sysimage_base = 0; + sysimage_base = 0; } #endif } @@ -384,13 +384,14 @@ static void jl_deserialize_gv_others(ios_t *s) } } -struct delayed_fptrs_t { +static struct delayed_fptrs_t { jl_lambda_info_t *li; int32_t func; int32_t cfunc; } *delayed_fptrs = NULL; static size_t delayed_fptrs_n = 0; static size_t delayed_fptrs_max = 0; +static size_t sysimg_fvars_max = 0; static void jl_delayed_fptrs(jl_lambda_info_t *li, int32_t func, int32_t cfunc) { @@ -399,8 +400,8 @@ static void jl_delayed_fptrs(jl_lambda_info_t *li, int32_t func, int32_t cfunc) if (cfunc || func) { if (delayed_fptrs_max < delayed_fptrs_n + 1) { if (delayed_fptrs_max == 0) - // current measurements put the number of functions at 1130 - delayed_fptrs_max = 2048; + // current measurements put the number of functions at 4508 + delayed_fptrs_max = 4096; else delayed_fptrs_max *= 2; delayed_fptrs = (struct delayed_fptrs_t*)realloc(delayed_fptrs, delayed_fptrs_max*sizeof(delayed_fptrs[0])); //assumes sizeof==alignof @@ -409,9 +410,15 @@ static void jl_delayed_fptrs(jl_lambda_info_t *li, int32_t func, int32_t cfunc) delayed_fptrs[delayed_fptrs_n].func = func; delayed_fptrs[delayed_fptrs_n].cfunc = cfunc; delayed_fptrs_n++; + if (func > sysimg_fvars_max) + sysimg_fvars_max = func; + if (cfunc > sysimg_fvars_max) + sysimg_fvars_max = cfunc; } } +void jl_register_fptrs(uint64_t sysimage_base, void **fptrs, jl_lambda_info_t **linfos, size_t n); + static void jl_update_all_fptrs(void) { //jl_printf(JL_STDOUT, "delayed_fptrs_n: %d\n", delayed_fptrs_n); @@ -422,19 +429,24 @@ static void jl_update_all_fptrs(void) sysimg_gvars = NULL; sysimg_fvars = NULL; size_t i; + jl_lambda_info_t **linfos = (jl_lambda_info_t**)malloc(sizeof(jl_lambda_info_t*) * sysimg_fvars_max); for (i = 0; i < delayed_fptrs_n; i++) { jl_lambda_info_t *li = delayed_fptrs[i].li; - int32_t func = delayed_fptrs[i].func-1; + int32_t func = delayed_fptrs[i].func - 1; if (func >= 0) { jl_fptr_to_llvm(fvars[func], li, 0); + linfos[func] = li; } - int32_t cfunc = delayed_fptrs[i].cfunc-1; + int32_t cfunc = delayed_fptrs[i].cfunc - 1; if (cfunc >= 0) { jl_fptr_to_llvm(fvars[cfunc], li, 1); + linfos[cfunc] = li; } } + jl_register_fptrs(sysimage_base, fvars, linfos, delayed_fptrs_n); delayed_fptrs_n = 0; delayed_fptrs_max = 0; + sysimg_fvars_max = 0; free(delayed_fptrs); delayed_fptrs = NULL; } diff --git a/src/julia_internal.h b/src/julia_internal.h index e3e2cedf25d08..a33ca1b2d7ec0 100644 --- a/src/julia_internal.h +++ b/src/julia_internal.h @@ -288,7 +288,7 @@ size_t rec_backtrace_ctx_dwarf(ptrint_t *data, size_t maxsize, bt_context_t ctx) JL_DLLEXPORT void jl_raise_debugger(void); // Set *name and *filename to either NULL or malloc'd string 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, uintptr_t pointer, int *fromC, int skipC, int skipInline); JL_DLLEXPORT void jl_gdblookup(ptrint_t ip); diff --git a/src/task.c b/src/task.c index d73f9b9cce176..5b1d1c7b1511a 100644 --- a/src/task.c +++ b/src/task.c @@ -491,6 +491,7 @@ static void init_task(jl_task_t *t, char *stack) static int frame_info_from_ip(char **func_name, char **file_name, size_t *line_num, char **inlinedat_file, size_t *inlinedat_line, + jl_lambda_info_t **outer_linfo, size_t ip, int skipC, int skipInline) { // This function is not allowed to reference any TLS variables since @@ -498,8 +499,8 @@ static int frame_info_from_ip(char **func_name, static const char *name_unknown = "???"; int fromC = 0; - jl_getFunctionInfo(func_name, file_name, line_num, inlinedat_file, inlinedat_line, ip, &fromC, - skipC, skipInline); + jl_getFunctionInfo(func_name, file_name, line_num, inlinedat_file, inlinedat_line, outer_linfo, + ip, &fromC, skipC, skipInline); if (!*func_name) { *func_name = strdup(name_unknown); *line_num = ip; @@ -736,17 +737,20 @@ JL_DLLEXPORT jl_value_t *jl_lookup_code_address(void *ip, int skipC) char *file_name; size_t inlinedat_line; char *inlinedat_file; + jl_lambda_info_t *outer_linfo; int fromC = frame_info_from_ip(&func_name, &file_name, &line_num, - &inlinedat_file, &inlinedat_line, (size_t)ip, skipC, 0); - jl_value_t *r = (jl_value_t*)jl_alloc_svec(7); + &inlinedat_file, &inlinedat_line, &outer_linfo, + (size_t)ip, skipC, 0); + jl_value_t *r = (jl_value_t*)jl_alloc_svec(8); JL_GC_PUSH1(&r); jl_svecset(r, 0, jl_symbol(func_name)); jl_svecset(r, 1, jl_symbol(file_name)); jl_svecset(r, 2, jl_box_long(line_num)); jl_svecset(r, 3, jl_symbol(inlinedat_file ? inlinedat_file : "")); jl_svecset(r, 4, jl_box_long(inlinedat_file ? inlinedat_line : -1)); - jl_svecset(r, 5, jl_box_bool(fromC)); - jl_svecset(r, 6, jl_box_long((intptr_t)ip)); + jl_svecset(r, 5, outer_linfo != NULL ? (jl_value_t*)outer_linfo : jl_nothing); + jl_svecset(r, 6, jl_box_bool(fromC)); + jl_svecset(r, 7, jl_box_long((intptr_t)ip)); free(func_name); free(file_name); free(inlinedat_file); @@ -779,8 +783,10 @@ JL_DLLEXPORT void jl_gdblookup(ptrint_t ip) char *file_name; size_t inlinedat_line; char *inlinedat_file; - frame_info_from_ip(&func_name, &file_name, &line_num, &inlinedat_file, &inlinedat_line, ip, - /* skipC */ 0, /* skipInline */ 0); + jl_lambda_info_t *outer_linfo; + frame_info_from_ip(&func_name, &file_name, &line_num, + &inlinedat_file, &inlinedat_line, &outer_linfo, ip, + /* skipC */ 0, /* skipInline */ 0); if (line_num == ip) { jl_safe_printf("unknown function (ip: %p)\n", (void*)ip); } diff --git a/test/backtrace.jl b/test/backtrace.jl index 3c569460e58be..3dec42bf6b39f 100644 --- a/test/backtrace.jl +++ b/test/backtrace.jl @@ -5,7 +5,7 @@ have_backtrace = false for l in bt lkup = ccall(:jl_lookup_code_address, Any, (Ptr{Void},), l) if lkup[1] == :backtrace - @test lkup[6] == false # fromC + @test lkup[7] == false # fromC have_backtrace = true break end @@ -46,7 +46,7 @@ catch err lkup = get_bt_frame(:test_inline_1, catch_backtrace()) @test lkup !== nothing || "Missing backtrace in inlining test" - fname, file, line, inlinedfile, inlinedline, fromC = lkup + fname, file, line, inlinedfile, inlinedline, linfo, fromC = lkup @test endswith(string(inlinedfile), "backtrace.jl") @test inlinedline == 42 end @@ -57,7 +57,7 @@ catch err lkup = get_bt_frame(:test_inline_2, catch_backtrace()) @test lkup !== nothing || "Missing backtrace in inlining test" - fname, file, line, inlinedfile, inlinedline, fromC = lkup + fname, file, line, inlinedfile, inlinedline, linfo, fromC = lkup @test string(file) == absfilepath @test line == 111 @test endswith(string(inlinedfile), "backtrace.jl") From adce3569b31d29e8bf45c3b8f66fdf2dbd2ec947 Mon Sep 17 00:00:00 2001 From: Gem Newman Date: Fri, 11 Dec 2015 09:39:30 -0600 Subject: [PATCH 2/3] Incorporating StackTraces into Base. Tests and documentation for stacktraces. Updated NEWS.md with stacktraces functionality. Refactored, doctests, show_stacktrace is now show. Added doctests to the manual. Removed show_stacktrace in favour of show(x::StackFrame). Removed format_stacktrace and format_stackframe. Additional test cases (which currently fail due to difficult to track down line number issues) Test for invalid frame. Removed failing Win32 test. Reintroduced UNKNOWN constant stack frame from profile.jl. Added test case for looking up an invalid stack frame. Selectively removed some tests that consistently fail in Appveyor's 32-bit Windows LVM. --- NEWS.md | 3 + base/exports.jl | 7 + base/profile.jl | 90 ++++--------- base/stacktraces.jl | 154 ++++++++++++++++++++++ base/sysimg.jl | 4 + doc/index.rst | 2 + doc/manual/index.rst | 1 + doc/manual/stacktraces.rst | 254 +++++++++++++++++++++++++++++++++++++ doc/stdlib/stacktraces.rst | 68 ++++++++++ test/choosetests.jl | 4 +- test/meta.jl | 6 +- test/stacktraces.jl | 79 ++++++++++++ 12 files changed, 600 insertions(+), 72 deletions(-) create mode 100644 base/stacktraces.jl create mode 100644 doc/manual/stacktraces.rst create mode 100644 doc/stdlib/stacktraces.rst create mode 100644 test/stacktraces.jl diff --git a/NEWS.md b/NEWS.md index 54dc861184f30..71bbe3fd1681d 100644 --- a/NEWS.md +++ b/NEWS.md @@ -99,6 +99,8 @@ Library improvements * Improve performance of `quantile` ([#14413]). + * The new `Base.StackTraces` module makes stack traces easier to use programmatically. ([#14469]) + Deprecated or removed --------------------- @@ -1779,3 +1781,4 @@ Too numerous to mention. [#14424]: https://github.com/JuliaLang/julia/issues/14424 [#14759]: https://github.com/JuliaLang/julia/issues/14759 [#14114]: https://github.com/JuliaLang/julia/issues/14114 +[#14469]: https://github.com/JuliaLang/julia/issues/14469 diff --git a/base/exports.jl b/base/exports.jl index cb31ce2376357..e440bdbc47108 100644 --- a/base/exports.jl +++ b/base/exports.jl @@ -9,6 +9,7 @@ export Pkg, Git, LibGit2, + StackTraces, Profile, Dates, Sys, @@ -1046,6 +1047,12 @@ export rethrow, systemerror, +# stack traces + StackTrace, + StackFrame, + stacktrace, + catch_stacktrace, + # types convert, fieldoffset, diff --git a/base/profile.jl b/base/profile.jl index 561e733325633..f308e8aec6dc6 100644 --- a/base/profile.jl +++ b/base/profile.jl @@ -2,7 +2,8 @@ module Profile -import Base: hash, ==, show_spec_linfo +import Base: show_spec_linfo +import Base.StackTraces: lookup, UNKNOWN export @profile @@ -117,7 +118,7 @@ end function getdict(data::Vector{UInt}) uip = unique(data) - Dict{UInt, LineInfo}([ip=>lookup(ip) for ip in uip]) + Dict{UInt, StackFrame}([ip=>lookup(ip) for ip in uip]) end # TODO update signature in docstring. @@ -165,37 +166,6 @@ Julia, and examine the resulting `*.mem` files. """ clear_malloc_data() = ccall(:jl_clear_malloc_data, Void, ()) - -#### -#### Internal interface -#### -immutable LineInfo - func::ByteString - 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, Nullable{LambdaStaticData}(), true, 0) - -# -# If the LineInfo has function and line information, we consider two of them the same -# if they share the same function/line information. For unknown functions, line==ip -# so we never actually need to consider the .ip field. -# -==(a::LineInfo, b::LineInfo) = a.line == b.line && a.fromC == b.fromC && a.func == b.func && a.file == b.file - -function hash(li::LineInfo, h::UInt) - h += 0xf4fbda67fe20ce88 % UInt - h = hash(li.line, h) - h = hash(li.file, h) - h = hash(li.func, h) -end - # C wrappers start_timer() = ccall(:jl_profile_start_timer, Cint, ()) @@ -209,24 +179,6 @@ 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) == 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 -end -lookup(ip::UInt) = lookup(convert(Ptr{Void},ip)) - error_codes = Dict{Int,ASCIIString}( -1=>"cannot specify signal action for profiling", -2=>"cannot create the timer for profiling", @@ -291,7 +243,7 @@ function parse_flat(iplist, n, lidict, C::Bool) # The ones with no line number might appear multiple times in a single # backtrace, giving the wrong impression about the total number of backtraces. # Delete them too. - keep = !Bool[x == UNKNOWN || x.line == 0 || (x.fromC && !C) for x in lilist] + keep = !Bool[x == UNKNOWN || x.line == 0 || (x.from_c && !C) for x in lilist] n = n[keep] lilist = lilist[keep] lilist, n @@ -310,7 +262,7 @@ function flat{T<:Unsigned}(io::IO, data::Vector{T}, lidict::Dict, C::Bool, combi print_flat(io, lilist, n, combine, cols, sortedby) end -function print_flat(io::IO, lilist::Vector{LineInfo}, n::Vector{Int}, combine::Bool, cols::Integer, sortedby) +function print_flat(io::IO, lilist::Vector{StackFrame}, n::Vector{Int}, combine::Bool, cols::Integer, sortedby) p = liperm(lilist) lilist = lilist[p] n = n[p] @@ -339,8 +291,8 @@ function print_flat(io::IO, lilist::Vector{LineInfo}, n::Vector{Int}, combine::B maxfunc = 10 for li in lilist maxline = max(maxline, li.line) - maxfile = max(maxfile, length(li.file)) - maxfunc = max(maxfunc, length(li.func)) + maxfile = max(maxfile, length(string(li.file))) + maxfunc = max(maxfunc, length(string(li.func))) end wline = max(5, ndigits(maxline)) ntext = cols - wcounts - wline - 3 @@ -389,9 +341,9 @@ function tree_aggregate{T<:Unsigned}(data::Vector{T}) bt, counts end -tree_format_linewidth(x::LineInfo) = ndigits(x.line)+6 +tree_format_linewidth(x::StackFrame) = ndigits(x.line)+6 -function tree_format(lilist::Vector{LineInfo}, counts::Vector{Int}, level::Int, cols::Integer) +function tree_format(lilist::Vector{StackFrame}, counts::Vector{Int}, level::Int, cols::Integer) nindent = min(cols>>1, level) ndigcounts = ndigits(maximum(counts)) ndigline = maximum([tree_format_linewidth(x) for x in lilist]) @@ -412,20 +364,22 @@ function tree_format(lilist::Vector{LineInfo}, counts::Vector{Int}, level::Int, if showextra base = string(base, "+", nextra, " ") end - if li.line == li.ip + if li.line == li.pointer strs[i] = string(base, rpad(string(counts[i]), ndigcounts, " "), - " ","unknown function (ip: 0x",hex(li.ip,2*sizeof(Ptr{Void})), + " ", + "unknown function (pointer: 0x", + hex(li.pointer,2*sizeof(Ptr{Void})), ")") else - fname = li.func + fname = string(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, " "), " ", - rtruncto(li.file, widthfile), + rtruncto(string(li.file), widthfile), ":", li.line == -1 ? "?" : string(li.line), "; ", @@ -446,7 +400,7 @@ function tree{T<:Unsigned}(io::IO, bt::Vector{Vector{T}}, counts::Vector{Int}, l # Organize backtraces into groups that are identical up to this level if combine # Combine based on the line information - d = Dict{LineInfo,Vector{Int}}() + d = Dict{StackFrame,Vector{Int}}() for i = 1:length(bt) ip = bt[i][level+1] key = lidict[ip] @@ -459,7 +413,7 @@ function tree{T<:Unsigned}(io::IO, bt::Vector{Vector{T}}, counts::Vector{Int}, l end # Generate counts dlen = length(d) - lilist = Array(LineInfo, dlen) + lilist = Array(StackFrame, dlen) group = Array(Vector{Int}, dlen) n = Array(Int, dlen) i = 1 @@ -483,7 +437,7 @@ function tree{T<:Unsigned}(io::IO, bt::Vector{Vector{T}}, counts::Vector{Int}, l end # Generate counts, and do the code lookup dlen = length(d) - lilist = Array(LineInfo, dlen) + lilist = Array(StackFrame, dlen) group = Array(Vector{Int}, dlen) n = Array(Int, dlen) i = 1 @@ -534,7 +488,7 @@ function tree{T<:Unsigned}(io::IO, data::Vector{T}, lidict::Dict, C::Bool, combi end function callersf(matchfunc::Function, bt::Vector{UInt}, lidict) - counts = Dict{LineInfo, Int}() + counts = Dict{StackFrame, Int}() lastmatched = false for id in bt if id == 0 @@ -574,8 +528,10 @@ function ltruncto(str::ByteString, w::Int) end +truncto(str::Symbol, w::Int) = truncto(string(str), w) + # Order alphabetically (file, function) and then by line number -function liperm(lilist::Vector{LineInfo}) +function liperm(lilist::Vector{StackFrame}) comb = Array(ByteString, length(lilist)) for i = 1:length(lilist) li = lilist[i] @@ -594,7 +550,7 @@ warning_empty() = warn(""" Profile.init().""") function purgeC(data, lidict) - keep = Bool[d == 0 || lidict[d].fromC == false for d in data] + keep = Bool[d == 0 || lidict[d].from_c == false for d in data] data[keep] end diff --git a/base/stacktraces.jl b/base/stacktraces.jl new file mode 100644 index 0000000000000..e370eebd175c3 --- /dev/null +++ b/base/stacktraces.jl @@ -0,0 +1,154 @@ +# This file is a part of Julia. License is MIT: http://julialang.org/license + +module StackTraces + + +import Base: hash, ==, show + +export StackTrace, StackFrame, stacktrace, catch_stacktrace + +""" + StackFrame + +Stack information representing execution context. +""" +immutable StackFrame + "the name of the function containing the execution context" + func::Symbol + "the LambdaStaticData for the the execution context" + outer_linfo::Nullable{LambdaStaticData} + "the path to the file containing the execution context" + file::Symbol + "the line number in the file containing the execution context" + line::Int + "the path to the file containing the context for code inlined into the execution context" + inlined_file::Symbol + "the line number in the file containing the context for code inlined into the execution context" + inlined_line::Int + "true if the code is from C" + from_c::Bool + "representation of the pointer to the execution context as returned by `backtrace`" + pointer::Int64 # Large enough to be read losslessly on 32- and 64-bit machines. +end + +StackFrame(func, file, line) = StackFrame(func, file, line, symbol(""), -1, false, 0) + +""" + StackTrace + +An alias for `Vector{StackFrame}` provided for convenience; returned by calls to +`stacktrace` and `catch_stacktrace`. +""" +typealias StackTrace Vector{StackFrame} + +const empty_symbol = symbol("") +const unk_symbol = symbol("???") +const UNKNOWN = StackFrame(unk_symbol, Nullable{LambdaStaticData}(), unk_symbol, 0, empty_symbol, -1, true, 0) + + +#= +If the StackFrame has function and line information, we consider two of them the same if +they share the same function/line information. For unknown functions, line == pointer, so we +never actually need to consider the pointer field. +=# +function ==(a::StackFrame, b::StackFrame) + a.line == b.line && a.from_c == b.from_c && a.func == b.func && a.file == b.file +end + +function hash(frame::StackFrame, h::UInt) + h += 0xf4fbda67fe20ce88 % UInt + h = hash(frame.line, h) + h = hash(frame.file, h) + h = hash(frame.func, h) +end + + +""" + lookup(pointer::Union{Ptr{Void}, UInt}) -> StackFrame + +Given a pointer to an execution context (usually generated by a call to `backtrace`), looks +up stack frame context information. +""" +function lookup(pointer::Ptr{Void}) + info = ccall(:jl_lookup_code_address, Any, (Ptr{Void}, Cint), ip, false) + if length(info) == 8 + is_inlined = (info[4] !== empty_sym) + return LineInfo(string(info[1]), + info[6] === nothing ? Nullable{LambdaStaticData}() : Nullable{LambdaStaticData}(info[6]), + is_inlined ? info[4] : info[2], + Int(is_inlined ? info[5] : info[3]), + is_inlined ? info[2] : "", + is_inlined ? Int(info[3]) : -1, + info[7], Int64(info[8])) + else + return UNKNOWN + end +end + +lookup(pointer::UInt) = lookup(convert(Ptr{Void}, pointer)) + +""" + stacktrace([trace::Vector{Ptr{Void}},] [c_funcs::Bool=false]) -> StackTrace + +Returns a stack trace in the form of a vector of `StackFrame`s. (By default stacktrace +doesn't return C functions, but this can be enabled.) When called without specifying a +trace, `stacktrace` first calls `backtrace`. +""" +function stacktrace(trace::Vector{Ptr{Void}}, c_funcs::Bool=false) + stack = map(lookup, trace)::StackTrace + + # Remove frames that come from C calls. + if !c_funcs + filter!(frame -> !frame.from_c, stack) + end + + # Remove frame for this function (and any functions called by this function). + remove_frames!(stack, :stacktrace) +end + +stacktrace(c_funcs::Bool=false) = stacktrace(backtrace(), c_funcs) + +""" + catch_stacktrace([c_funcs::Bool=false]) -> StackTrace + +Returns the stack trace for the most recent error thrown, rather than the current execution +context. +""" +catch_stacktrace(c_funcs::Bool=false) = stacktrace(catch_backtrace(), c_funcs) + +""" + remove_frames!(stack::StackTrace, name::Symbol) + +Takes a `StackTrace` (a vector of `StackFrames`) and a function name (a `Symbol`) and +removes the `StackFrame` specified by the function name from the `StackTrace` (also removing +all frames above the specified function). Primarily used to remove `StackTraces` functions +from the `StackTrace` prior to returning it. +""" +function remove_frames!(stack::StackTrace, name::Symbol) + splice!(stack, 1:findlast(frame -> frame.func == name, stack)) + return stack +end + +function remove_frames!(stack::StackTrace, names::Vector{Symbol}) + splice!(stack, 1:findlast(frame -> frame.func in names, stack)) + return stack +end + +function show(io::IO, frame::StackFrame; full_path::Bool=false) + file_info = "$(full_path ? frame.file : basename(string(frame.file))):$(frame.line)" + + if frame.inlined_file != Symbol("") + inline_info = string("[inlined code from ", file_info, "] ") + file_info = string( + full_path ? frame.inlined_file : basename(string(frame.inlined_file)), + ":", frame.inlined_line + ) + else + inline_info = "" + end + + print(io, string(inline_info, frame.func != "" ? frame.func : "?", " at ", file_info)) +end + + +end diff --git a/base/sysimg.jl b/base/sysimg.jl index 5a03a87ae0e18..a26eecb7c23fd 100644 --- a/base/sysimg.jl +++ b/base/sysimg.jl @@ -296,6 +296,10 @@ include("libgit2.jl") include("pkg.jl") const Git = Pkg.Git +# Stack frames and traces +include("stacktraces.jl") +importall .StackTraces + # profiler include("profile.jl") importall .Profile diff --git a/doc/index.rst b/doc/index.rst index 7a62aeb794287..b1ef5c7781112 100644 --- a/doc/index.rst +++ b/doc/index.rst @@ -45,6 +45,7 @@ manual/embedding manual/packages manual/profile + manual/stacktraces manual/performance-tips manual/workflow-tips manual/style-guide @@ -79,6 +80,7 @@ stdlib/test stdlib/c stdlib/profile + stdlib/stacktraces .. _devdocs: diff --git a/doc/manual/index.rst b/doc/manual/index.rst index 960ee6f387d65..d601ce5606550 100644 --- a/doc/manual/index.rst +++ b/doc/manual/index.rst @@ -35,6 +35,7 @@ embedding packages profile + stacktraces performance-tips style-guide faq diff --git a/doc/manual/stacktraces.rst b/doc/manual/stacktraces.rst new file mode 100644 index 0000000000000..878b2a40af5ac --- /dev/null +++ b/doc/manual/stacktraces.rst @@ -0,0 +1,254 @@ +.. _man-stacktraces: + +.. currentmodule:: Base + +************ +Stack Traces +************ + +The :mod:`StackTraces` module provides simple stack traces that are both human readable and +easy to use programmatically. + +Viewing a stack trace +--------------------- + +The primary function used to obtain a stack trace is :func:`stacktrace`:: + + julia> stacktrace() + 3-element Array{StackFrame,1}: + eval at boot.jl:265 + [inlined code from REPL.jl:3] eval_user_input at REPL.jl:62 + [inlined code from REPL.jl:92] anonymous at task.jl:63 + +Calling :func:`stacktrace` returns a vector of :obj:`StackFrame` s. For ease of use, the +alias :obj:`StackTrace` can be used in place of ``Vector{StackFrame}``. (Examples with +``...`` indicate that output may vary depending on how the code is run.) + +.. doctest:: + + julia> example() = stacktrace() + example (generic function with 1 method) + + julia> example() + ...-element Array{StackFrame,1}: + example at none:1 + eval at boot.jl:265 + ... + + julia> @noinline child() = stacktrace() + child (generic function with 1 method) + + julia> @noinline parent() = child() + parent (generic function with 1 method) + + julia> grandparent() = parent() + grandparent (generic function with 1 method) + + julia> grandparent() + ...-element Array{StackFrame,1}: + child at none:1 + parent at none:1 + grandparent at none:1 + eval at boot.jl:265 + ... + +Note that when calling :func:`stacktrace` you'll typically see a frame with +``eval at boot.jl``. When calling :func:`stacktrace` from the REPL you'll also have a few +extra frames in the stack from ``REPL.jl``, usually looking something like this:: + + julia> example() = stacktrace() + example (generic function with 1 method) + + julia> example() + 4-element Array{StackFrame,1}: + example at none:1 + eval at boot.jl:265 + [inlined code from REPL.jl:3] eval_user_input at REPL.jl:62 + [inlined code from REPL.jl:92] anonymous at task.jl:63 + +Extracting useful information +----------------------------- + +Each :obj:`StackFrame` contains the function name, file name, line number, file and line +information for inlined functions, a flag indicating whether it is a C function (by default +C functions do not appear in the stack trace), and an integer representation of the pointer +returned by :func:`backtrace`: + +.. doctest:: + + julia> top_frame = stacktrace()[1] + eval at boot.jl:265 + + julia> top_frame.func + :eval + + julia> top_frame.file + symbol("./boot.jl") + + julia> top_frame.line + 265 + + julia> top_frame.inlined_file + symbol("") + + julia> top_frame.inlined_line + -1 + + julia> top_frame.from_c + false + +:: + + julia> top_frame.pointer + 13203085684 + +This makes stack trace information available programmatically for logging, error handling, +and more. + +Error handling +-------------- + +While having easy access to information about the current state of the callstack can be +helpful in many places, the most obvious application is in error handling and debugging. + +.. doctest:: + + julia> @noinline bad_function() = undeclared_variable + bad_function (generic function with 1 method) + + julia> @noinline example() = try + bad_function() + catch + stacktrace() + end + example (generic function with 1 method) + + julia> example() + ...-element Array{StackFrame,1}: + example at none:4 + eval at boot.jl:265 + ... + +You may notice that in the example above the first stack frame points points at line 4, +where :func:`stacktrace` is called, rather than line 2, where `bad_function` is called, and +``bad_function``'s frame is missing entirely. This is understandable, given that +:func:`stacktrace` is called from the context of the `catch`. While in this example it's +fairly easy to find the actual source of the error, in complex cases tracking down the +source of the error becomes nontrivial. + +This can be remedied by calling :func:`catch_stacktrace` instead of :func:`stacktrace`. +Instead of returning callstack information for the current context, :func:`catch_stacktrace` +returns stack information for the context of the most recent exception: + +.. doctest:: + + julia> @noinline bad_function() = undeclared_variable + bad_function (generic function with 1 method) + + julia> @noinline example() = try + bad_function() + catch + catch_stacktrace() + end + example (generic function with 1 method) + + julia> example() + ...-element Array{StackFrame,1}: + bad_function at none:1 + example at none:2 + eval at boot.jl:265 + ... + +Notice that the stack trace now indicates the appropriate line number and the missing frame. + +.. doctest:: + + julia> @noinline child() = error("Whoops!") + child (generic function with 1 method) + + julia> @noinline parent() = child() + parent (generic function with 1 method) + + julia> @noinline function grandparent() + try + parent() + catch err + println("ERROR: ", err.msg) + catch_stacktrace() + end + end + grandparent (generic function with 1 method) + + julia> grandparent() + ERROR: Whoops! + ...-element Array{StackFrame,1}: + child at none:1 + parent at none:1 + grandparent at none:3 + eval at boot.jl:265 + ... + +Comparison with :func:`backtrace` +--------------------------------- + +A call to :func:`backtrace` returns a vector of ``Ptr{Void}``, which may then be passed into +:func:`stacktrace` for translation:: + + julia> trace = backtrace() + 15-element Array{Ptr{Void},1}: + Ptr{Void} @0x000000010527895e + Ptr{Void} @0x0000000309bf6220 + Ptr{Void} @0x0000000309bf61a0 + Ptr{Void} @0x00000001052733b4 + Ptr{Void} @0x0000000105271a0e + Ptr{Void} @0x000000010527189d + Ptr{Void} @0x0000000105272e6d + Ptr{Void} @0x0000000105272cef + Ptr{Void} @0x0000000105285b88 + Ptr{Void} @0x000000010526b50e + Ptr{Void} @0x000000010663cc28 + Ptr{Void} @0x0000000309bbc20f + Ptr{Void} @0x0000000309bbbde7 + Ptr{Void} @0x0000000309bb0262 + Ptr{Void} @0x000000010527980e + + julia> stacktrace(trace) + 4-element Array{StackFrame,1}: + backtrace at error.jl:26 + eval at boot.jl:265 + [inlined code from REPL.jl:3] eval_user_input at REPL.jl:62 + [inlined code from REPL.jl:92] anonymous at task.jl:63 + +Notice that the vector returned by :func:`backtrace` had 15 pointers, while the vector returned by :func:`stacktrace` only has 3. This is because, by default, :func:`stacktrace` removes any lower-level C functions from the stack. If you want to include stack frames from C calls, you can do it like this:: + + julia> stacktrace(stack, true) + 15-element Array{StackFrame,1}: + [inlined code from task.c:651] rec_backtrace at task.c:711 + backtrace at error.jl:26 + jlcall_backtrace_23146 at :-1 + [inlined code from interpreter.c:55] jl_apply at interpreter.c:65 + eval at interpreter.c:214 + eval at interpreter.c:220 + eval_body at interpreter.c:601 + jl_toplevel_eval_body at interpreter.c:534 + jl_toplevel_eval_flex at toplevel.c:525 + jl_toplevel_eval_in_warn at builtins.c:590 + eval at boot.jl:265 + [inlined code from REPL.jl:3] eval_user_input at REPL.jl:62 + jlcall_eval_user_input_22658 at :-1 + [inlined code from REPL.jl:92] anonymous at task.jl:63 + [inlined code from julia.h:1352] jl_apply at task.c:246 + +Individual pointers returned by :func:`backtrace` can be translated into :obj:`StackFrame` s +by passing them into :func:`StackTraces.lookup`: + +.. doctest:: + + julia> pointer = backtrace()[1] + Ptr{Void} @0x... + + julia> frame = StackTraces.lookup(pointer) + [inlined code from task.c:663] rec_backtrace at task.c:723 + + julia> println("The top frame is from $(frame.func)!") + The top frame is from rec_backtrace! diff --git a/doc/stdlib/stacktraces.rst b/doc/stdlib/stacktraces.rst new file mode 100644 index 0000000000000..3a48958abae7f --- /dev/null +++ b/doc/stdlib/stacktraces.rst @@ -0,0 +1,68 @@ +.. module:: StackTraces + +.. _stdlib-stacktraces: + +************* + StackTraces +************* + +.. currentmodule:: Base + +.. data:: StackFrame + + Stack information representing execution context, with the following fields: + + ``func::Symbol`` + the name of the function containing the execution context + + ``file::Symbol`` + the path to the file containing the execution context + + ``line::Int`` + the line number in the file containing the execution context + + ``inlined_file::Symbol`` + the path to the file containing the context for inlined code + + ``inlined_line::Int`` + the line number in the file containing the context for inlined code + + ``from_c::Bool`` + true if the code is from C + + ``pointer::Int64`` + representation of the pointer to the execution context as returned by ``backtrace`` + +.. data:: StackTrace + + An alias for ``Vector{StackFrame}`` provided for convenience; returned by calls to + ``stacktrace`` and ``catch_stacktrace``. + +.. function:: stacktrace([trace::Vector{Ptr{Void}},] [c_funcs::Bool=false]) -> StackTrace + + .. Docstring generated from Julia source + + Returns a stack trace in the form of a vector of ``StackFrame``\ s. (By default stacktrace doesn't return C functions, but this can be enabled.) When called without specifying a trace, ``stacktrace`` first calls ``backtrace``\ . + +.. function:: catch_stacktrace([c_funcs::Bool=false]) -> StackTrace + + .. Docstring generated from Julia source + + Returns the stack trace for the most recent error thrown, rather than the current execution context. + +.. currentmodule:: Base.StackTraces + +The following methods and types in :mod:`Base.StackTraces` are not exported and need to be called e.g. as ``StackTraces.lookup(ptr)``. + +.. function:: lookup(pointer::Union{Ptr{Void}, UInt}) -> StackFrame + + .. Docstring generated from Julia source + + Given a pointer to an execution context (usually generated by a call to ``backtrace``\ ), looks up stack frame context information. + +.. function:: remove_frames!(stack::StackTrace, name::Symbol) + + .. Docstring generated from Julia source + + Takes a ``StackTrace`` (a vector of ``StackFrames``\ ) and a function name (a ``Symbol``\ ) and removes the ``StackFrame`` specified by the function name from the ``StackTrace`` (also removing all frames above the specified function). Primarily used to remove ``StackTraces`` functions from the ``StackTrace`` prior to returning it. + diff --git a/test/choosetests.jl b/test/choosetests.jl index aa6fd49205707..0b59ac73e70f9 100644 --- a/test/choosetests.jl +++ b/test/choosetests.jl @@ -29,8 +29,8 @@ function choosetests(choices = []) "combinatorics", "sysinfo", "rounding", "ranges", "mod2pi", "euler", "show", "lineedit", "replcompletions", "repl", "replutil", "sets", "test", "goto", "llvmcall", "grisu", - "nullable", "meta", "profile", "libgit2", "docs", "markdown", - "base64", "serialize", "functors", "misc", "threads", + "nullable", "meta", "stacktraces", "profile", "libgit2", "docs", + "markdown", "base64", "serialize", "functors", "misc", "threads", "enums", "cmdlineargs", "i18n", "workspace", "libdl", "int", "checked", "intset", "floatfuncs", "compile", "parallel", "inline", "boundscheck" diff --git a/test/meta.jl b/test/meta.jl index 51cf1239aa134..e1e076aec6cac 100644 --- a/test/meta.jl +++ b/test/meta.jl @@ -34,15 +34,15 @@ h_noinlined() = g_noinlined() function foundfunc(bt, funcname) for b in bt - lkup = Profile.lookup(b) + lkup = StackTraces.lookup(b) if lkup.func == funcname return true end end false end -@test !foundfunc(h_inlined(), "g_inlined") -@test foundfunc(h_noinlined(), "g_noinlined") +@test !foundfunc(h_inlined(), :g_inlined) +@test foundfunc(h_noinlined(), :g_noinlined) using Base.pushmeta!, Base.popmeta! diff --git a/test/stacktraces.jl b/test/stacktraces.jl new file mode 100644 index 0000000000000..96c32cd303cfa --- /dev/null +++ b/test/stacktraces.jl @@ -0,0 +1,79 @@ +# This file is a part of Julia. License is MIT: http://julialang.org/license + +# Tests for /base/stacktraces.jl + +# Some tests don't currently work for Appveyor 32-bit Windows +const APPVEYOR_WIN32 = ( + OS_NAME == :Windows && WORD_SIZE == 32 && get(ENV, "APPVEYOR", "False") == "True" +) + +if !APPVEYOR_WIN32 + let + @noinline child() = stacktrace() + @noinline parent() = child() + @noinline grandparent() = parent() + line_numbers = @__LINE__ - [3, 2, 1] + + # Basic tests. + stack = grandparent() + @assert length(stack) >= 3 "Compiler has unexpectedly inlined functions" + @test [:child, :parent, :grandparent] == [f.func for f in stack[1:3]] + for (line, frame) in zip(line_numbers, stack[1:3]) + @test [Symbol(@__FILE__), line] in + ([frame.file, frame.line], [frame.inlined_file, frame.inlined_line]) + end + @test [false, false, false] == [f.from_c for f in stack[1:3]] + + # Test remove_frames! + stack = StackTraces.remove_frames!(grandparent(), :parent) + @test stack[1] == StackFrame(:grandparent, @__FILE__, line_numbers[3]) + + stack = StackTraces.remove_frames!(grandparent(), [:child, :something_nonexistent]) + @test stack[1:2] == [ + StackFrame(:parent, @__FILE__, line_numbers[2]), + StackFrame(:grandparent, @__FILE__, line_numbers[3]) + ] + end +end + +let + # Test from_c + default, with_c, without_c = stacktrace(), stacktrace(true), stacktrace(false) + @test default == without_c + @test length(with_c) > length(without_c) + @test !isempty(filter(frame -> frame.from_c, with_c)) + @test isempty(filter(frame -> frame.from_c, without_c)) +end + +@test StackTraces.lookup(C_NULL) == StackTraces.UNKNOWN + +let + # No errors should mean nothing in catch_backtrace + @test catch_backtrace() == StackFrame[] + + @noinline bad_function() = throw(UndefVarError(:nonexistent)) + @noinline function try_stacktrace() + try + bad_function() + catch + return stacktrace() + end + end + @noinline function try_catch() + try + bad_function() + catch + return catch_stacktrace() + end + end + line_numbers = @__LINE__ .- [15, 10, 5] + + # Test try...catch with stacktrace + @test try_stacktrace()[1] == StackFrame(:try_stacktrace, @__FILE__, line_numbers[2]) + + # Test try...catch with catch_stacktrace + @test try_catch()[1:2] == [ + StackFrame(:bad_function, @__FILE__, line_numbers[1]), + StackFrame(:try_catch, @__FILE__, line_numbers[3]) + ] +end From 8a0a7d69cd4891757844be52d39a0d39d0b92669 Mon Sep 17 00:00:00 2001 From: Jameson Nash Date: Thu, 28 Jan 2016 17:24:21 -0500 Subject: [PATCH 3/3] fix StackTraces and DRY some of the code --- base/deprecated.jl | 7 ++- base/profile.jl | 15 +++--- base/replutil.jl | 94 ++++++++++---------------------------- base/stacktraces.jl | 50 ++++++++++++-------- base/task.jl | 3 +- doc/stdlib/stacktraces.rst | 3 ++ test/stacktraces.jl | 54 ++++++++++------------ 7 files changed, 93 insertions(+), 133 deletions(-) diff --git a/base/deprecated.jl b/base/deprecated.jl index 90aa6c942d271..ca5054e346755 100644 --- a/base/deprecated.jl +++ b/base/deprecated.jl @@ -76,13 +76,12 @@ function firstcaller(bt::Array{Ptr{Void},1}, funcsym::Symbol) # Identify the calling line i = 1 while i <= length(bt) - lkup = ccall(:jl_lookup_code_address, Any, (Ptr{Void},Cint), bt[i], true) + lkup = StackTraces.lookup(bt[i]) i += 1 - if lkup === () + if lkup === StackTraces.UNKNOWN continue end - fname, file, line, inlinedat_file, inlinedat_line, linfo, fromC = lkup - if fname == funcsym + if lkup.func == funcsym break end end diff --git a/base/profile.jl b/base/profile.jl index f308e8aec6dc6..a15be2f755891 100644 --- a/base/profile.jl +++ b/base/profile.jl @@ -2,8 +2,7 @@ module Profile -import Base: show_spec_linfo -import Base.StackTraces: lookup, UNKNOWN +import Base.StackTraces: lookup, UNKNOWN, show_spec_linfo export @profile @@ -308,11 +307,11 @@ function print_flat(io::IO, lilist::Vector{StackFrame}, n::Vector{Int}, combine: for i = 1:length(n) li = lilist[i] Base.print(io, lpad(string(n[i]), wcounts, " "), " ") - Base.print(io, rpad(rtruncto(li.file, wfile), wfile, " "), " ") + Base.print(io, rpad(rtruncto(string(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)) + fname = string(li.func) + if !li.from_c && !isnull(li.outer_linfo) + fname = sprint(show_spec_linfo, li) end Base.print(io, rpad(ltruncto(fname, wfunc), wfunc, " ")) println(io) @@ -373,8 +372,8 @@ function tree_format(lilist::Vector{StackFrame}, counts::Vector{Int}, level::Int ")") else fname = string(li.func) - if !li.fromC && !isnull(li.outer_linfo) - fname = sprint(show_spec_linfo, Symbol(li.func), get(li.outer_linfo)) + if !li.from_c && !isnull(li.outer_linfo) + fname = sprint(show_spec_linfo, li) end strs[i] = string(base, rpad(string(counts[i]), ndigcounts, " "), diff --git a/base/replutil.jl b/base/replutil.jl index e986b5bb12ab1..c8827b40d6385 100644 --- a/base/replutil.jl +++ b/base/replutil.jl @@ -119,13 +119,13 @@ showerror(io::IO, ex::InitError) = showerror(io, ex, []) 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) == 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 + code = StackTraces.lookup(b) + if code !== lookup && code.from_c + if code.func in (:log, :log2, :log10, :sqrt) # TODO add :besselj, :besseli, :bessely, :besselk + print(io,"\n$(code.func) will only return a complex result if called with a complex argument. Try $(code[1])(complex(x)).") + elseif (code.func == :^ && code.file == symbol("intfuncs.jl")) || code.func == :power_by_squaring #3024 print(io, "\nCannot raise an integer x to a negative power -n. \nMake x a float by adding a zero decimal (e.g. 2.0^-n instead of 2^-n), or write 1/x^n, float(x)^-n, or (x//1)^-n.") - elseif code[1] == :^ && (code[2] == symbol("promotion.jl") || code[2] == symbol("math.jl")) + elseif code.func == :^ && (code.file == symbol("promotion.jl") || code.file == symbol("math.jl")) print(io, "\nExponentiation yielding a complex result requires a complex argument.\nReplace x^y with (x+0im)^y, Complex(x)^y, or similar.") end break @@ -387,52 +387,10 @@ function show_method_candidates(io::IO, ex::MethodError) end end -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) +function show_trace_entry(io, frame, 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 !== empty_symbol - # align the location text - print(io, " [inlined code] from ") - else - print(io, " in ") - show_spec_linfo(io, fname, outer_linfo) - print(io, " at ") - end - - print(io, file) - - if line >= 1 - try - print(io, ":", line) - catch - print(io, '?') #for when dec is not yet defined - end - end - - if n > 1 - print(io, " (repeats ", n, " times)") - end - - 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 + show(io, frame, full_path=true) + n > 1 && print(io, " (repeats ", n, " times)") end function show_backtrace(io::IO, t, set=1:typemax(Int)) @@ -448,8 +406,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, outer_linfo, n) = - show_trace_entry(io, lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, outer_linfo, n) + process_entry(last_frame, n) = + show_trace_entry(io, last_frame, n) process_backtrace(process_entry, top_function, t, set) end @@ -461,36 +419,32 @@ end # process the backtrace, up to (but not including) top_function 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_outer_linfo = nothing - local fname, file, line + n = 0 + last_frame = StackTraces.UNKNOWN count = 0 for i = 1:length(t) - lkup = ccall(:jl_lookup_code_address, Any, (Ptr{Void}, Cint), t[i]-1, skipC) - if lkup === nothing + lkup = StackTraces.lookup(t[i]) + if lkup === StackTraces.UNKNOWN continue end - fname, file, line, inlinedat_file, inlinedat_line, outer_linfo, fromC = lkup - if fromC && skipC; continue; end - if i == 1 && fname == :error; continue; end - if fname == top_function; break; end + if lkup.from_c && skipC; continue; end + if i == 1 && lkup.func == :error; continue; end + if lkup.func == top_function; break; end count += 1 if !in(count, set); continue; end - if file != lastfile || line != lastline || fname != lastname - if lastline != -11 - process_func(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, last_outer_linfo, n) + if lkup.file != last_frame.file || lkup.line != last_frame.line || lkup.func != last_frame.func + if n > 0 + process_func(last_frame, n) end n = 1 - lastfile = file; lastline = line; lastname = fname; - last_inlinedat_file = inlinedat_file; last_inlinedat_line = inlinedat_line; last_outer_linfo = outer_linfo + last_frame = lkup else n += 1 end end - if n > 1 || lastline != -11 - process_func(lastname, lastfile, lastline, last_inlinedat_file, last_inlinedat_line, last_outer_linfo, n) + if n > 0 + process_func(last_frame, n) end end diff --git a/base/stacktraces.jl b/base/stacktraces.jl index e370eebd175c3..979a496bc2df3 100644 --- a/base/stacktraces.jl +++ b/base/stacktraces.jl @@ -15,7 +15,7 @@ Stack information representing execution context. immutable StackFrame "the name of the function containing the execution context" func::Symbol - "the LambdaStaticData for the the execution context" + "the LambdaStaticData containing the execution context (if it could be found)" outer_linfo::Nullable{LambdaStaticData} "the path to the file containing the execution context" file::Symbol @@ -31,7 +31,7 @@ immutable StackFrame pointer::Int64 # Large enough to be read losslessly on 32- and 64-bit machines. end -StackFrame(func, file, line) = StackFrame(func, file, line, symbol(""), -1, false, 0) +StackFrame(func, file, line) = StackFrame(func, Nullable{LambdaStaticData}(), file, line, empty_sym, -1, false, 0) """ StackTrace @@ -41,9 +41,9 @@ An alias for `Vector{StackFrame}` provided for convenience; returned by calls to """ typealias StackTrace Vector{StackFrame} -const empty_symbol = symbol("") -const unk_symbol = symbol("???") -const UNKNOWN = StackFrame(unk_symbol, Nullable{LambdaStaticData}(), unk_symbol, 0, empty_symbol, -1, true, 0) +const empty_sym = symbol("") +const unk_sym = symbol("???") +const UNKNOWN = StackFrame(unk_sym, Nullable{LambdaStaticData}(), unk_sym, -1, empty_sym, -1, true, 0) # === lookup(C_NULL) #= @@ -70,10 +70,10 @@ Given a pointer to an execution context (usually generated by a call to `backtra up stack frame context information. """ function lookup(pointer::Ptr{Void}) - info = ccall(:jl_lookup_code_address, Any, (Ptr{Void}, Cint), ip, false) + info = ccall(:jl_lookup_code_address, Any, (Ptr{Void}, Cint), pointer - 1, false) if length(info) == 8 is_inlined = (info[4] !== empty_sym) - return LineInfo(string(info[1]), + return StackFrame(string(info[1]), info[6] === nothing ? Nullable{LambdaStaticData}() : Nullable{LambdaStaticData}(info[6]), is_inlined ? info[4] : info[2], Int(is_inlined ? info[5] : info[3]), @@ -134,21 +134,33 @@ function remove_frames!(stack::StackTrace, names::Vector{Symbol}) return stack end -function show(io::IO, frame::StackFrame; full_path::Bool=false) - file_info = "$(full_path ? frame.file : basename(string(frame.file))):$(frame.line)" - - if frame.inlined_file != Symbol("") - inline_info = string("[inlined code from ", file_info, "] ") - file_info = string( - full_path ? frame.inlined_file : basename(string(frame.inlined_file)), - ":", frame.inlined_line - ) +function show_spec_linfo(io::IO, frame::StackFrame) + if isnull(frame.outer_linfo) + print(io, frame.func !== empty_sym ? frame.func : "?") else - inline_info = "" + linfo = get(frame.outer_linfo) + print(io, linfo.name) + if isdefined(linfo, 8) + Base.show_delim_array(io, linfo.(#=specTypes=#8).parameters, "(", ", ", ")", false) + end end - - print(io, string(inline_info, frame.func != "" ? frame.func : "?", " at ", file_info)) end +function show(io::IO, frame::StackFrame; full_path::Bool=false) + if frame.inlined_file !== empty_sym + # if we have inlining information, print it first + inline_info = full_path ? string(frame.inlined_file) : basename(string(frame.inlined_file)) + print(io, " [inlined code] from ", inline_info) + if frame.inlined_line > 0 + print(io, ":", frame.inlined_line) + end + println(io) + end + + print(io, " in ") + show_spec_linfo(io, frame) + file_info = full_path ? string(frame.file) : basename(string(frame.file)) + print(io, " at ", file_info, ":", frame.line) +end end diff --git a/base/task.jl b/base/task.jl index f18a7548ad0d7..a0e2422f84d01 100644 --- a/base/task.jl +++ b/base/task.jl @@ -17,8 +17,7 @@ type CapturedException # Process bt_raw so that it can be safely serialized bt_lines = Any[] - 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_func(args...) = push!(bt_lines, args) process_backtrace(process_func, :(:), bt_raw, 1:100) # Limiting this to 100 lines. new(ex, bt_lines) diff --git a/doc/stdlib/stacktraces.rst b/doc/stdlib/stacktraces.rst index 3a48958abae7f..e6940c8c9f5b9 100644 --- a/doc/stdlib/stacktraces.rst +++ b/doc/stdlib/stacktraces.rst @@ -15,6 +15,9 @@ ``func::Symbol`` the name of the function containing the execution context + ``outer_linfo::Nullable{LambdaStaticData}`` + the LambdaStaticData containing the execution context (if it could be found) + ``file::Symbol`` the path to the file containing the execution context diff --git a/test/stacktraces.jl b/test/stacktraces.jl index 96c32cd303cfa..f1ffe36048f0f 100644 --- a/test/stacktraces.jl +++ b/test/stacktraces.jl @@ -2,38 +2,31 @@ # Tests for /base/stacktraces.jl -# Some tests don't currently work for Appveyor 32-bit Windows -const APPVEYOR_WIN32 = ( - OS_NAME == :Windows && WORD_SIZE == 32 && get(ENV, "APPVEYOR", "False") == "True" -) - -if !APPVEYOR_WIN32 - let - @noinline child() = stacktrace() - @noinline parent() = child() - @noinline grandparent() = parent() - line_numbers = @__LINE__ - [3, 2, 1] +let + @noinline child() = stacktrace() + @noinline parent() = child() + @noinline grandparent() = parent() + line_numbers = @__LINE__ - [3, 2, 1] + stack = grandparent() - # Basic tests. - stack = grandparent() - @assert length(stack) >= 3 "Compiler has unexpectedly inlined functions" - @test [:child, :parent, :grandparent] == [f.func for f in stack[1:3]] - for (line, frame) in zip(line_numbers, stack[1:3]) - @test [Symbol(@__FILE__), line] in - ([frame.file, frame.line], [frame.inlined_file, frame.inlined_line]) - end - @test [false, false, false] == [f.from_c for f in stack[1:3]] + # Basic tests. + @assert length(stack) >= 3 "Compiler has unexpectedly inlined functions" + @test [:child, :parent, :grandparent] == [f.func for f in stack[1:3]] + for (line, frame) in zip(line_numbers, stack[1:3]) + @test [Symbol(@__FILE__), line] in + ([frame.file, frame.line], [frame.inlined_file, frame.inlined_line]) + end + @test [false, false, false] == [f.from_c for f in stack[1:3]] - # Test remove_frames! - stack = StackTraces.remove_frames!(grandparent(), :parent) - @test stack[1] == StackFrame(:grandparent, @__FILE__, line_numbers[3]) + # Test remove_frames! + stack = StackTraces.remove_frames!(grandparent(), :parent) + @test stack[1] == StackFrame(:grandparent, @__FILE__, line_numbers[3]) - stack = StackTraces.remove_frames!(grandparent(), [:child, :something_nonexistent]) - @test stack[1:2] == [ - StackFrame(:parent, @__FILE__, line_numbers[2]), - StackFrame(:grandparent, @__FILE__, line_numbers[3]) - ] - end + stack = StackTraces.remove_frames!(grandparent(), [:child, :something_nonexistent]) + @test stack[1:2] == [ + StackFrame(:parent, @__FILE__, line_numbers[2]), + StackFrame(:grandparent, @__FILE__, line_numbers[3]) + ] end let @@ -56,6 +49,7 @@ let try bad_function() catch + i_need_a_line_number_julia_bug = true # julia lowering doesn't emit a proper line number for catch return stacktrace() end end @@ -66,7 +60,7 @@ let return catch_stacktrace() end end - line_numbers = @__LINE__ .- [15, 10, 5] + line_numbers = @__LINE__ .- [16, 10, 5] # Test try...catch with stacktrace @test try_stacktrace()[1] == StackFrame(:try_stacktrace, @__FILE__, line_numbers[2])