Emit inlining information to improve line numbers #12544

ihnorton · 2015-08-10T21:03:39Z

Also changes the parser to include file information with every linenode (see #1334 (comment))

function foo()
    @show error("oops")
end

julia> foo3()
ERROR: oops
 in foo3 at /cmn/julia/base/userimg.jl:109

after:

ERROR: oops
 in foo2 at /cmn/julia/base/userimg.jl:4 
    [ from inlined function at ./show.jl:109 ]

over 5 runs rebuilding sysimg I get average times of:

master: 81.328s (max: 82.28)
branch: 81.846s (max: 82.76)

so, +.48s to rebuild sysimg (also +9MB max resident RAM)

yuyichao · 2015-08-10T21:08:55Z

Would be better to construct a backtrace for inline functions as well but this is very nice to have.

Can the profiling system take advantage of this?

carnaval · 2015-08-10T21:17:08Z

Didn't look in details but I'd be glad to have it as well. I don't think there will be much conflict but can this be done on top of the codegen rewrite ? Even if it should not really touch the same parts I think it's good in general. (Might also help in getting it merged ;-))

timholy · 2015-08-10T21:17:26Z

I'm honored that you thought my foo function was worthy of being built into your local julia 😄.

Seriously, this is really nice---a huge gain in terms of usability.

jakebolewski · 2015-08-10T21:19:59Z

🍰

ScottPJones · 2015-08-10T21:21:54Z

👏

ihnorton · 2015-08-10T21:27:19Z

@timholy I forgot to mention, this works with precompile:

isaiah@titan:/cmn/julia/base$ nm ../usr/lib/julia/sys.so | grep foo2
00000000002eac80 t jlcall_foo2_20918
00000000002eab50 t julia_foo2_20918

@carnaval it should be trivial to rebase on the codegen rewrite if needed, there's only about ~10 loc change in codegen.

tkelman · 2015-08-11T01:23:54Z

src/codegen.cpp

@@ -4502,6 +4502,7 @@ static Function *emit_function(jl_lambda_info_t *lam)
    int prevlno = -1;
    for(i=0; i < stmtslen; i++) {
        jl_value_t *stmt = jl_cellref(stmts,i);
+        /*


should this block just be deleted, or does it need to be brought back?

Forgot about this. If Jeff approves the parser change then all LineNode-handling code can be deleted.

I don't see what is controversial about the LineNode change.

vtjnash · 2015-08-11T01:51:37Z

since this touches only the debuginfo parts of codegen, i expect it will merge cleanly with my codegen restructuring PR.

carnaval · 2015-08-11T16:57:10Z

@vtjnash shhh don't tell, I thought if we pile up PRs depending on this one it would get merged faster

ihnorton · 2015-08-12T00:26:38Z

Test failures are fixed.

tkelman · 2015-08-12T00:27:43Z

Sweet! Will be good to squash out the failing commits.

ihnorton · 2015-08-14T22:00:35Z

Squashed, rebased, ~~and LineNumberNode excised.~~ (edit: now using LineNumberNode everywhere, see comments below). Unless someone (...@mlubin) wants to fight to get this in 0.4, I'll just let it bide until we branch.

jakebolewski · 2015-08-14T22:09:56Z

You have a whitespace error. Why wouldn't we merge this? 0.4 will probably be at least 8-12 months, so it seems worth it to have better debug info during that time.

mlubin · 2015-08-14T22:12:16Z

Well I (and many other people) would very much appreciate backtraces working with macros in 0.4, but I'm not in a position to judge how risky it is to merge this.
Are there any unit tests we can add for these backtraces?

IainNZ · 2015-08-14T22:23:44Z

Anything to make line numbers better is worth it

timholy · 2015-08-14T23:03:37Z

Since we seem to be taking longer to branch than I expected, then heck, if it's all working there's no reason to have this languish (I'm not really qualified to review it). I recognize touching codegen is risky, but this is a pretty big usability problem (I had someone in my lab ask about this just today).

StefanKarpinski · 2015-08-14T23:38:27Z

I'm in favor of merging if @ihorton thinks it's safe.

ihnorton · 2015-08-20T04:38:26Z

updated based on discussion with @vtjnash and @jakebolewski: now adds file field to LineNumberNode, and uses LineNumberNode everywhere
now handle inlines from the same file
added test for inlining information (edit: looks like this test fails on win32... will investigate tomorrow)

I am comfortable merging this, but would appreciate a once-over/thumbs-up from anyone who can review (especially the changes to ast.c and codegen.cpp).

vtjnash · 2015-08-20T04:50:34Z

test/backtrace.jl

+
+    try
+        testinline()
+    catch err


LoadError("C:\projects\julia\test\backtrace.jl",18,ErrorException("invalid redefinition of constant err"))

looks like CI wants you to pick a different name here (or add err to the let block variable list)

must be an ordering thing because it did pass on several workers. I just added err to the let block, and also mimicked the handling in replutil (skip fromC and :error frames) because I don't think bt[4] is accurate for all platforms (namely win32).

vtjnash · 2015-08-27T03:07:31Z

this looks ready to merge to me. it looks like someone will need to deal with some merge conflict on the command line though to push it to master.

prcastro · 2015-08-27T03:41:02Z

👍

JeffBezanson · 2015-08-27T03:43:36Z

base/cartesian.jl

@@ -222,7 +222,7 @@ function poplinenum(ex::Expr)
    if ex.head == :block
        if length(ex.args) == 1
            return ex.args[1]
-        elseif length(ex.args) == 2 && ex.args[1].head == :line
+        elseif length(ex.args) == 2 && isa(ex.args[1], LineNumberNode)


Doesn't this need to work on surface syntax ASTs? (used from macros)

Fixed (I think). Thanks.

JeffBezanson · 2015-08-27T03:52:10Z

What's the impact on the size of the system image?

JeffBezanson · 2015-08-27T03:59:27Z

base/replutil.jl

+
+    if (inlinedfile != symbol(""))
+        print(io, " at ", inlinedfile, ":", inlinedline)
+        print(io, " \n    [ thrown by inlined function defined at ]\n    ")


I find this output a bit confusing. Since the brackets close before all the info is printed, it looks like the location is simply missing. I would print it something like in inlined function defined at file:line.

how about by code inlined from? could be from macro or inline.

Yes, that makes sense.

Utilizes the DebugLoc "inlinedAt" parameter to remember inlining location in addition to source code origin. When available, we now print both the inlinee origin below the top-level call site. Mostly addresses #1334. (this does not handle nested inlines, which may require deeper changes)

ihnorton · 2015-08-27T04:45:16Z

What's the impact on the size of the system image?

~ 700k

master:
isaiah@titan:/cmn/julia$ ls -la usr/lib/julia/*
-rw-r--r-- 1 isaiah isaiah  1892596 Aug 27 00:34 usr/lib/julia/inference0.ji
-rw-r--r-- 1 isaiah isaiah  1832530 Aug 27 00:35 usr/lib/julia/inference.ji
-rw-rw-r-- 1 isaiah isaiah 30183440 Aug 27 00:36 usr/lib/julia/sys.o
-rwxrwxr-x 1 isaiah isaiah 25856974 Aug 27 00:36 usr/lib/julia/sys.so

this branch:
isaiah@titan:/cmn/julia$ ls -la usr/lib/julia/*
-rw-r--r-- 1 isaiah isaiah  1902264 Aug 27 00:01 usr/lib/julia/inference0.ji
-rw-r--r-- 1 isaiah isaiah  1848958 Aug 27 00:02 usr/lib/julia/inference.ji
-rw-rw-r-- 1 isaiah isaiah 31107296 Aug 27 00:15 usr/lib/julia/sys.o
-rwxrwxr-x 1 isaiah isaiah 26560922 Aug 27 00:15 usr/lib/julia/sys.so

ihnorton · 2015-08-27T05:01:40Z

Rebased.

JeffBezanson · 2015-08-27T05:14:25Z

base/profile.jl

@@ -134,8 +136,8 @@ maxlen_data() = convert(Int, ccall(:jl_profile_maxlen_data, Csize_t, ()))

 function lookup(ip::Ptr{Void})


We should probably make more use of this interface to jl_lookup_code_address.

JeffBezanson · 2015-08-27T05:18:51Z

Hmm, I guess 2-3% isn't so bad. The MODE_AST serializer needs to do a better job compressing symbols.

carnaval · 2015-08-27T05:21:36Z

(quick&dirty test: lz4 shrinks sys.so by 4x and only takes ~50ms to decompress, so it might be easier than spending too much time improving the serializer)

- renamed inlinedfile/line -> inlinedat_file/line - update inlining message - fix poplinenum.

dcjones · 2015-09-02T17:58:01Z

Nothing of substance to add, but I found this branch to be exceedingly useful to profile some macro heavy code that previously reported complete nonsense. I'm unreasonably excited to see it merged.

…-to-linenode Emit inlining information to improve line numbers

timholy · 2015-09-04T06:08:07Z

Woot! Didn't expect this to make it in. But really looking forward to it (building now).

ScottPJones · 2015-09-04T12:24:51Z

👍 💯 👏 🎉

tkelman reviewed Aug 11, 2015
View reviewed changes

ihnorton mentioned this pull request Aug 11, 2015

debug metadata for inlined functions #1189

Closed

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch 3 times, most recently from 8a94a36 to b3d0e4a Compare August 11, 2015 13:23

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch from b3d0e4a to e2d7bfe Compare August 14, 2015 21:58

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch from e2d7bfe to 093d1b2 Compare August 14, 2015 22:29

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch 5 times, most recently from 9ec72c0 to 6d5b7a1 Compare August 20, 2015 04:04

vtjnash reviewed Aug 20, 2015
View reviewed changes

JeffBezanson reviewed Aug 27, 2015
View reviewed changes

ihnorton added 3 commits August 27, 2015 00:00

Include filename with every linenode

543305d

Add missing GC roots in ast.c

eb867a9

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch from 7aa2dd3 to 013f906 Compare August 27, 2015 05:01

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch from 013f906 to c1ded2e Compare August 27, 2015 05:04

JeffBezanson reviewed Aug 27, 2015
View reviewed changes

Address review comments

19e765e

- renamed inlinedfile/line -> inlinedat_file/line - update inlining message - fix poplinenum.

ihnorton force-pushed the all-your-filename-are-belong-to-linenode branch from c1ded2e to 19e765e Compare August 27, 2015 20:39

yuyichao mentioned this pull request Sep 2, 2015

Loose signature of push! fallback (results in confusing MethodError) #12919

Open

jakebolewski added a commit that referenced this pull request Sep 4, 2015

Merge pull request #12544 from JuliaLang/all-your-filename-are-belong…

a07d5ee

…-to-linenode Emit inlining information to improve line numbers

jakebolewski merged commit a07d5ee into master Sep 4, 2015

vtjnash deleted the all-your-filename-are-belong-to-linenode branch September 4, 2015 05:01

JeffBezanson added a commit that referenced this pull request Sep 4, 2015

fix extra newline at end of stack traces after #12544

aaf771e

mlubin mentioned this pull request Sep 4, 2015

errors inside macros give incorrect line numbers jump-dev/JuMP.jl#7

Closed

MichaelHatherly mentioned this pull request Sep 6, 2015

Linenumber info regression. #12977

Closed

This was referenced Sep 29, 2015

RFC: pass macro call location to macro-function #13339

Closed

Fix inlinedAt debug locations #13431

Merged

		@@ -134,8 +136,8 @@ maxlen_data() = convert(Int, ccall(:jl_profile_maxlen_data, Csize_t, ()))

		function lookup(ip::Ptr{Void})

Emit inlining information to improve line numbers #12544

Emit inlining information to improve line numbers #12544

Conversation

ihnorton commented Aug 10, 2015

yuyichao commented Aug 10, 2015

carnaval commented Aug 10, 2015

timholy commented Aug 10, 2015

jakebolewski commented Aug 10, 2015

ScottPJones commented Aug 10, 2015

ihnorton commented Aug 10, 2015

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vtjnash commented Aug 11, 2015

carnaval commented Aug 11, 2015

ihnorton commented Aug 12, 2015

tkelman commented Aug 12, 2015

ihnorton commented Aug 14, 2015

jakebolewski commented Aug 14, 2015

mlubin commented Aug 14, 2015

IainNZ commented Aug 14, 2015

timholy commented Aug 14, 2015

StefanKarpinski commented Aug 14, 2015

ihnorton commented Aug 20, 2015

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vtjnash commented Aug 27, 2015

prcastro commented Aug 27, 2015

Choose a reason for hiding this comment

Choose a reason for hiding this comment

JeffBezanson commented Aug 27, 2015

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ihnorton commented Aug 27, 2015

ihnorton commented Aug 27, 2015

Choose a reason for hiding this comment

JeffBezanson commented Aug 27, 2015

carnaval commented Aug 27, 2015

dcjones commented Sep 2, 2015

timholy commented Sep 4, 2015

ScottPJones commented Sep 4, 2015