Presentations are a work in progress. The content is here, but "flattened", so it lacks progressive disclosure.

TracePoint

Examining the execution flow of your code

1 / 36

TODO: image of a recording device

Speaker notes:

Reports execution events in your code

2 / 36

Create your tracer

1methods = Set.new
2trace = TracePoint.new(:call, :c_call) do |tp|
3  methods << tp.method_id
4end
3 / 36

:call, :return

Call / return from a Ruby function Even if an exception is raised, you still get the :return event

4 / 36

:c_call, :c_return

Call / return from a C function

5 / 36

:b_call, :b_return

Call / return from a block

6 / 36

:class, :end

Start / end a class/module definition

7 / 36

:raise

Raise an exception

8 / 36

:line

Execute a line of Ruby code

9 / 36

TODO: Drake image as background

You used to call me on my cellphone, but now I use Tracepoint and it really makes that hotline bling — Drake*

* Not an actual Drake quote

10 / 36

Tracepoint#event

Name of the tracepoint event

11 / 36

Tracepoint#method_id

Underlying method name

Speaker notes:

Also, callee_id, which would be the alias if the method was called via an aliased name

12 / 36

Tracepoint#defined_class

Class that defined the method

Speaker notes:

Sometimes nil

13 / 36

Tracepoint#self

The class at runtime

14 / 36

Tracepoint#path

Path of source file of execution point

Speaker notes:

Also, #lineno for the line number

15 / 36

Tracepoint#return_value

Value returned from functions/blocks

Speaker notes:

Also

  • #raised_exception for :raise event
  • #binding to evaluate arbitrary expressions in the binding at the execution point
16 / 36

TODO: some fun image, from original presentation I used snoop dogg dancing

Speaker notes:

Niiiiiiiiice

17 / 36

Trace your code

1methods = Set.new
2trace = TracePoint.new(:call, :c_call) do |tp|
3  methods << tp.method_id
4end
5
6trace.enable { func2 }
7puts methods
18 / 36

Trace your code

1def foo
2  puts “test”
3end
4
5def func1
6  foo
7end
8
9def bar
10  func1
11end
1def func2
2  func1
3  bar
4end
5
6func2
func2 func1 foo puts write bar
19 / 36

TODO: oprah image

Speaker notes:

You get a tracepoint, and you get a tracepoint. Everybody gets a tracepoint.

20 / 36

Call graphs

1def foo
2  sleep 0.1
3end
4
5def func1
6  foo
7end
8
9def bar
10  func1
11end
12
13def func2
14  func1
15  bar
16end

=>

call graph

21 / 36

TracePoint doesn’t track your call stack

22 / 36

TODO: Psyduck at computer image

Speaker notes:

Ugh, okay

23 / 36

TODO: good news everyone professor farnsworth

Speaker notes:

It shouldn’t be that hard to do!

24 / 36
1def foo
2  sleep 0.1
3end
4
5def func1
6  foo
7end
8
9def bar
10  func1
11end
12
13def func2
14  func1
15  bar
16end
17
18func2
stack = [] callgraph = {} trace = TracePoint.new(:call, :return) do |tp| case tp.event when :call stack << tp.method_id if stack.length >= 2 callgraph[stack[-2]] ||= Set.new callgraph[stack[-2]] << tp.method_id end when :return stack.pop end end
:call:func2[:func2]
:call:func1[:func2, :func1]
:call:foo[:func2, :func1, :foo]
:return:foo[:func2, :func1]
:return:func1[:func2]
:call:bar[:func2, :bar]
:call:func1[:func2, :bar, :func1]
:call:foo[:func2, :bar, :func1, :foo]
:return:foo[:func2, :bar, :func1]
:return:func1[:func2, :bar]
:return:bar[:func2]
:return:func2[]

TODO progressive disclosure of above

25 / 36
1{
2  func1: #<Set: {:foo}>,
3  bar: #<Set: {:func1}>,
4  func2: #<Set: {:func1, :bar}>,
5}

call graph

26 / 36

TODO: excited image, originally used excited minions

Speaker notes:

We did it!

27 / 36

There’s still more to do...

Speaker notes:

Previous example was greatly simplified, so we have a lot more to do to really make a useful callgraph

28 / 36

Include self

Speaker notes:

Same method could exist on many classes

Can get tangly with singleton classes

29 / 36

Filter gems

Speaker notes:

We don’t care too much about what happens outside of our own codebases

But maybe we could keep it to understand where gems are being used?

30 / 36

Compute the transitive closure

TODO: take previous call graph and show transitive closure

Speaker notes:

Unnecessary, but good for efficient ancestor/descendant queries

31 / 36
1TracePoint.trace(:raise) do |tp|
2  exception = tp.raised_exception.inspect
3  location = "#{tp.path}:#{tp.lineno}"
4  puts "Raised #{exception} at #{location}"
5end

Speaker notes:

Log all exceptions raised

32 / 36
1coverage = {}
2trace = TracePoint.new(:line) do |tp|
3  coverage[tp.path] ||= Set.new
4  coverage[tp.path] << tp.lineno
5end

Speaker notes:

Code coverage

  • Detecting dead code

Note that there’s a builtin coverage library

  • Exact same data structure as above
  • Entirely in C, so will be much faster if you just want simple coverage
  • #result disables the system though (quantum entanglement?), but you have #peek_result
33 / 36
1stack = []
2profile = Hash.new(0)
3trace = TracePoint.new(:call, :return) do |tp|
4  case tp.event
5  when :call
6    stack << [tp.method_id, Time.now]
7  when :return
8    method, start_time = stack.pop
9    profile[method] += Time.now - start_time
10  end
11end

Speaker notes:

Custom runtime profiling

  • 🔥🔥🔥 Flamegraphs 🔥🔥🔥
  • Dynamic analysis
  • Detecting native extension use (moving to JRuby?)
34 / 36
1stack = []
2tests_to_run = {}
3trace = TracePoint.new(:call, :return) do |tp|
4  case tp.event
5  when :call
6    stack << [tp.method_id, tp.path]
7  when :return
8    _, path = stack.pop
9    tests_to_run[path] ||= Set.new
10    tests_to_run[path] << stack.first unless stack.empty?
11  end
12end

Speaker notes:

Detecting tests to run

  • Assumes very first call is the test function
35 / 36

Thanks!

Twitter: @thegedge

GitHub: @thegedge

36 / 36