50 Line Profiler in Pure Ruby!

In this lightning talk, I step through writing a basic sampling profiler in less than 50 lines of pure Ruby. Video at http://www.justin.tv/confreaks/b/374982906 around 1:07:30.

Transcript

1. Fifty Line Profiler! In Pure Ruby! Jason Clark @jasonrclark (twitter, github) Ruby Agent Engineer
2. What’s a Profiler?
3. How?
4. Take a Sample!
5. Our Stack SQL Model Controller Routing Middleware Server S M C R M S
6. Sampling Time S M C R M S
7. Sampling Time S M C R M S C R M S
8. Sampling Time S M C R M S C R M S S M C R M S
9. Sampling Time S M C R M S C R M S S M C R M S S M C R M S
10. Let’s Build It!
11. Run Profiler, Run! class Profiler @running = false ... Thread.new do while should_run? take_sample sleep(@interval) end end end
12. Run Profiler, Run! class Profiler @running = false ... Thread.new do while should_run? take_sample sleep(@interval) end end end
13. Run Profiler, Run! class Profiler @running = false ... Thread.new do while should_run? take_sample sleep(@interval) end end end
14. Run Profiler, Run! class Profiler @running = false ... Thread.new do while should_run? take_sample sleep(@interval) end end end
15. Take a Sample def take_sample @sample_count += 1 Thread.list.each do |t| next if t.backtrace.nil? t.backtrace.each do |line| count_backtrace_line(line) end end end
16. Take a Sample def take_sample @sample_count += 1 Thread.list.each do |t| next if t.backtrace.nil? t.backtrace.each do |line| count_backtrace_line(line) end end end
17. Take a Sample def take_sample @sample_count += 1 Thread.list.each do |t| next if t.backtrace.nil? t.backtrace.each do |line| count_backtrace_line(line) end end end
18. What’s in a Backtrace? Thread.current.backtrace => ["(irb):1:in `irb_binding'", "/.../irb/workspace.rb:80:in `eval'", "/.../irb/workspace.rb:80:in `evaluate'", "/.../irb/context.rb:254:in `evaluate'", ... "/.../1.9.1/irb.rb:69:in `start'", "/.../1.9.3/bin/irb:12:in `<main>'"]
19. Take a Sample def take_sample @sample_count += 1 Thread.list.each do |t| next if t.backtrace.nil? t.backtrace.each do |line| count_backtrace_line(line) end end end
20. Making Calls Count def initialize(interval = 0.1) @calls = Hash.new(0) end def count_backtrace_line(line) @calls[key(line)] += 1 end
21. Making Calls Count def initialize(interval = 0.1) @calls = Hash.new(0) end def count_backtrace_line(line) @calls[key(line)] += 1 end
22. Breaking in Line BACKTRACE_LINE_REGEX = /(.*)\:(\d+)\:in `(.*)'/ def key(line) BACKTRACE_LINE_REGEX. match(line). captures end
23. What Do We Get?
25. Call Trees
26. MOAR! https://github.com/jasonrclark/diy_profile class Profiler attr_reader :sample_count, :calls def initialize(interval = 0.1) @interval = interval @running = false @sample_count = 0 @calls = Hash.new(0) end def count_backtrace_line(line) @calls[key(line)] += 1 end def should_run? @running end def stop @running = false end def start return if @running @running = true Thread.new do while should_run? take_sample sleep(@interval) end end end def take_sample @sample_count += 1 Thread.list.each do |thread| next if thread.backtrace.nil? thread.backtrace.each do |line| count_backtrace_line(line) end end end def count_backtrace_line(line) @calls[key(line)] += 1 end BACKTRACE_LINE_REGEX = /(.*)\:(\d+)\:in `(.*)'/ def key(line) BACKTRACE_LINE_REGEX.match(line).captures end end http://mtnwestrubyconf.org/ @jasonrclark