Last active
April 3, 2017 18:28
-
-
Save palkan/875e90fd085e214ce3b0f76e2b27208f to your computer and use it in GitHub Desktop.
RSpec Events Profiler
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
module RSpec | |
class EventProfiler # :nodoc: | |
# Add #duration method to floats | |
module FloatDuration | |
refine Float do | |
def duration | |
t = self | |
format("%02d:%02d.%03d", t / 60, t % 60, t.modulo(1) * 1000) | |
end | |
end | |
end | |
using FloatDuration | |
NOTIFICATIONS = [:example_group_started, :example_group_finished, :example_started].freeze | |
def initialize | |
@time = 0.0 | |
@count = 0 | |
@total_time = 0.0 | |
@total_count = 0 | |
@example_groups = Hash.new { |h, k| h[k] = { count: 0 } } | |
@event = ENV['PROF_EVENT'] != '1' ? ENV['PROF_EVENT'] : 'sql.active_record' | |
@take = (ENV['PROF_NUM'] || 5).to_i | |
ActiveSupport::Notifications.subscribe(@event) do |*args| | |
track(*args) | |
end | |
end | |
def track(_event, start, finish, _id, _data) | |
spent = finish - start | |
@time += spent | |
@total_time += spent | |
@count += 1 | |
@total_count += 1 | |
end | |
attr_reader :example_groups | |
def example_group_started(notification) | |
return unless notification.group.top_level? | |
@time = 0.0 | |
@count = 0 | |
@example_groups[notification.group][:description] = notification.group.top_level_description.to_s | |
end | |
def example_group_finished(notification) | |
return unless notification.group.top_level? | |
@example_groups[notification.group][:total_time] = @time | |
@example_groups[notification.group][:total_count] = @count | |
end | |
def example_started(notification) | |
group = notification.example.example_group.parent_groups.last | |
@example_groups[group][:count] += 1 | |
end | |
def print | |
puts "\n" | |
puts "Profiling #{@event}\n\n" | |
puts "Total time: #{@total_time.duration}\n" | |
puts "Total events: #{@total_count}\n" | |
slowest = @example_groups.values.sort_by { |g| -g[:total_time] }.take(@take) | |
puts "Top #{@take} slowest suites:\n\n" | |
slowest.each do |group| | |
puts "\n" | |
puts "#{group[:description]} – #{group[:total_time].duration} "\ | |
"(#{group[:total_count]} / #{group[:count]} – #{(group[:total_count].to_f / group[:count]).round(2)})" | |
end | |
puts "\n" | |
end | |
end | |
end | |
if ENV['PROF_EVENT'] | |
RSpec.configure do |config| | |
listener = RSpec::EventProfiler.new | |
config.reporter.register_listener(listener, *RSpec::EventProfiler::NOTIFICATIONS) | |
config.after(:suite) do | |
listener.print | |
end | |
end | |
end |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment