TracePoint

Examining the execution flow of your code

Jason Gedge

Senior Developer

Gadget

an old recording device with the tape wheels spinning

Create your tracer

Create your tracer


trace = TracePoint.new(:call, :c_call) do |tp|

end

Create your tracer

methods = Set.new
trace = TracePoint.new(:call, :c_call) do |tp|
  methods << tp.method_id
end

:call,:return

Call / return from a Ruby function

:c_call,:c_return

Call / return from a C function

:b_call,:b_return

Call / return from a block

:class,:end

Start / end a class/module definition

:raise

Raise an exception

:line

Execute a line of Ruby code

a clip of Drake from his song Hotline Bling

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

Tracepoint#event

Name of the tracepoint event

Tracepoint#method_id

Underlying method name

Tracepoint#defined_class

Class that defined the method

Tracepoint#self

The class at runtime

Tracepoint#path

Path of source file of execution point

Tracepoint#return_value

Value returned from functions/blocks

snoop dogg dancing

Trace your code

methods = Set.new
trace = TracePoint.new(:call, :c_call) do |tp|
  methods << tp.method_id
end


Trace your code

methods = Set.new
trace = TracePoint.new(:call, :c_call) do |tp|
  methods << tp.method_id
end
trace.enable { func2 }
puts methods

Trace your code

def foo
  putstest
end

def func1
  foo
end

def bar
  func1
end
def func2
  func1
  bar
end

func2
func2
func1
foo
puts
write
bar
Oprah Winfrey pointing at everyone (you get a prize!)
def foo
  sleep 0.1
end

def func1
  foo
end

def bar
  func1
end

def func2
  func1
  bar
end

func2

bar

func1

foo

Call graphs

TracePoint doesn't track your call stack

Psyduck from Pokémon in its confused pose, looking at a computer screen
Dr. Farnsworth from Futurama, entering the room and saying "Good news, Everyone!"
def foo
  sleep 0.1
end

def func1
  foo
end

def bar
  func1
end

def func2
  func1
  bar
end

func2


trace = TracePoint.new(:call, :return) do |tp|
  case tp.event






  when :return

  end
end
def foo
  sleep 0.1
end

def func1
  foo
end

def bar
  func1
end

def func2
  func1
  bar
end

func2
:call:func2
:call:func1
:call:foo
:return:foo
:return:func1
:call:bar
:call:func1
:call:foo
:return:foo
:return:func1
:return:bar
:return:func2
stack = []

trace = TracePoint.new(:call, :return) do |tp|
  case tp.event
  when :call
    stack << tp.method_id




  when :return
    stack.pop
  end
end
def foo
  sleep 0.1
end

def func1
  foo
end

def bar
  func1
end

def func2
  func1
  bar
end

func2
: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[]
def foo
  sleep 0.1
end

def func1
  foo
end

def bar
  func1
end

def func2
  func1
  bar
end

func2
: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[]
a baby bringing its hand towards it's face with a look of realization on its face
stack = []

trace = TracePoint.new(:call, :return) do |tp|
  case tp.event
  when :call
    stack << tp.method_id




  when :return
    stack.pop
  end
end
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
{
  func1: #<Set: {:foo}>,
  bar:   #<Set: {:func1}>,
  func2: #<Set: {:func1, :bar}>,
}

func2

bar

func1

foo

Excited minions from Despicable Me

There's still more to do...

Include self

Bill Hader as Stefon on Saturday Night Live's weekend update, with the caption "selfie"

Filter gems

a pink diamond, spinning on its point

Compute the transitive closure

func2

bar

func1

foo

Will Ferrell and John C. Reilly from Step Brothers, excited about the space in their shared room, with the caption "So much room for activities!"
TracePoint.trace(:raise) do |tp|
  exception = tp.raised_exception.inspect
  location = "#{tp.path}:#{tp.lineno}"
  puts "Raised #{exception} at #{location}"
end
coverage = {}
trace = TracePoint.new(:line) do |tp|
  coverage[tp.path] ||= Set.new
  coverage[tp.path] << tp.lineno
end
stack = []
profile = Hash.new(0)
trace = TracePoint.new(:call, :return) do |tp|
  case tp.event
  when :call
    stack << [tp.method_id, Time.now]
  when :return
    method, start_time = stack.pop
    profile[method] += Time.now - start_time
  end
end
stack = []
tests_to_run = {}
trace = TracePoint.new(:call, :return) do |tp|
  case tp.event
  when :call
    stack << [tp.method_id, tp.path]
  when :return
    _, path = stack.pop
    tests_to_run[path] ||= Set.new
    tests_to_run[path] << stack.first unless stack.empty?
  end
end

Thanks for listening!

❤️ ❤️ ❤️ ❤️ ❤️ ❤️