cstjean / TraceCalls.jl

A debugging and profiling tool for Julia
Other
46 stars 4 forks source link

Tracing imported functions #50

Closed mkborregaard closed 7 years ago

mkborregaard commented 7 years ago

If I have a function in MyModule that imports a function and defines a new method , e.g. Base.getindex(x::MyType, idx), it appears that @trace MyModule somefun will skip any calls to that method, viewing it as a Base function. The issue is that MyModule's getindex method may call other functions in MyModule that are then not visible to the trace.

Again, this comes from my experiments using Plots, where like half the functionality is in a function that is called by a method for Base.display so there's a real-world application.

cstjean commented 7 years ago

it appears that @trace MyModule somefun will skip any calls to that method, viewing it as a Base function

That shouldn't happen. Can you provide an example?

The issue is that MyModule's getindex method may call other functions in MyModule that are then not visible to the trace.

That shouldn't happen either. Every call to a function in a traced module should show up in the trace (unless it's defined behind a macro like @inline), even if it was called by a non-traced function.

Again, this comes from my experiments using Plots, where like half the functionality is in a function that is called by a method for Base.display so there's a real-world application.

That's likely a different problem. If I call @trace fun(), the displaying of the return value of fun() doesn't happen within the scope of @trace. If you want to trace show/display, you have to call @trace Plots display(plot(...)) (or show). Is that what you did?

# Dummy2.jl
module Dummy2

struct MyType
    x
end

Base.getindex(m::MyType, i) = m.x+i

foo(a) = a + MyType(1)[2] + 2

end

---

julia> using Revise, TraceCalls

julia> using Dummy2

julia> @trace Dummy2 foo(1)
- #1() => UndefVarError(:foo)

julia> @trace Dummy2 Dummy2.foo(1)
- #3() => 6
   - Dummy2.foo(1) => 6
      - getindex(Dummy2.MyType(1), 2) => 3
mkborregaard commented 7 years ago

Huh, you're right about display 🤦‍♂️ . I'd forgotten that about 50% of all the functionality is called hiddenly when the object is returned to the console.

The issue that made me assume that imported functions weren't shown is that some functions don't show up in the trace. In the case of Plots, it turns out it's not the imported ones - it's all the backend-specific ones. I've looked it over, and the issue is that these functions are all in files that get included by a macro call. I'm guessing that, like with @eval, this means that the functions aren't visible to TraceCalls. When those functions again call normally defined functions they show up in place of the macroderived function in the trace, i.e. as shown in this pseudocode

@makefunction b
a -> b -> c #call
a -> c      #trace

I'm assuming this isn't anything you have a fix for at the moment (ever?).

cstjean commented 7 years ago

it's all the backend-specific ones. I've looked it over, and the issue is that these functions are all in files that get included by a macro call.

Yeah, it's this issue. TraceCalls is built on top of Revise. It seems fixable, but it's not a top-priority for me at the moment.

FYI, I want to start macroexpanding the code to trace functions hidden behind macros (@inline, @traitfn, etc.), probably in the next few weeks, and for some packages (eg. LightGraphs.jl) this is going to add a lot of functions to your call graphs.

mkborregaard commented 7 years ago

Ah. But few packages need TraceCalls more than Plots :-) It's a pretty daunting package for new contributors to get an overview of, so passing people a call graph would be pretty darn useful. We plan to reorganize so the backend code gets relayed to individual packages, so maybe that could resolve this (?).

cstjean commented 7 years ago

We plan to reorganize so the backend code gets relayed to individual packages, so maybe that could resolve this

I think it does! FWIW, there might be some trick you could use in Plots right now. Maybe something like

@require Revise begin
Revise.track(Plots, "included_file.jl")  # or @__FILE__ ?
end

inside of the missing included files?

mkborregaard commented 7 years ago

Awesome, I'll try that!

mkborregaard commented 7 years ago

It works! Holy moly:

using TraceGraphs, Plots, PlotRecipes
pyplot(size = (2400, 3600))
x = randn(10000)
trace = @trace Plots display(histogram(x));
plot(trace)

full_histogram

cstjean commented 7 years ago

I love it! Looking forward to the PR/package. The layout is really tight.