Skip to content

Instantly share code, notes, and snippets.

Embed
What would you like to do?
All the code for the Paperless Profiler
require 'rblineprof'
module Rblineprof
module ConsoleHelpers
include Rblineprof::Helpers
def lineprof_block(options = {}, &block)
profile = lineprof(rblineprof_profiler_regex(options[:lineprofiler])) do
ret = yield
end
profile_text(profile, options)
end
def profile_text(profile, options)
sort = options[:lineprofiler_sort]
mode = options[:lineprofiler_mode] || 'cpu'
min = (options[:lineprofiler_min] || 10).to_i * 1000
summary = options[:lineprofiler_summary]
# Sort each file by the longest calculated time
per_file = profile.map do |file, lines|
total, child, excl, total_cpu, child_cpu, excl_cpu = lines[0]
wall = summary == 'exclusive' ? excl : total
cpu = summary == 'exclusive' ? excl_cpu : total_cpu
idle = summary == 'exclusive' ? (excl - excl_cpu) : (total - total_cpu)
[
file, lines,
wall, cpu, idle,
sort == 'idle' ? idle : sort == 'cpu' ? cpu : wall
]
end.sort_by{ |a,b,c,d,e,f| -f }
div = "\n#{"-" * 80}\n"
output = []
per_file.each do |file_name, lines, file_wall, file_cpu, file_idle, file_sort|
show_src = file_sort > min
output << div
subed_name = file_name.sub(Rails.root.to_s + '/', '')
if mode == 'cpu'
output << sprintf("% 8.1fms + % 8.1fms (% 5d) | #{subed_name}", file_cpu / 1000.0, file_idle / 1000.0, 1)
else
output << sprintf("% 8.1fms | #{subed_name}", file_wall/1000.0)
end
next unless show_src
output << div
times = []
File.readlines(file_name).each_with_index do |line, i|
wall, cpu, calls = lines[i + 1]
if calls && calls > 0
if mode == 'cpu'
idle = wall - cpu
times << sprintf("% 8.1fms + % 8.1fms (% 5d) | %5d | ", cpu / 1000.0, idle / 1000.0, calls, i) + line
else
times << sprintf("% 8.1fms (% 5d) | %5d | ", wall / 1000.0, calls, i) + line
end
end
end
output << times
end
output.flatten.join
end
end
end
require 'rblineprof'
module Rblineprof
module Helpers
def rblineprof_profiler_regex(which)
escaped_rails_root = Regexp.escape(Rails.root.to_s)
case which
when 'app'
%r{^#{escaped_rails_root}/(app|lib)}
when 'views'
%r{^#{escaped_rails_root}/app/view}
when 'gems'
%r|^#{escaped_rails_root}/vendor/gems|
when 'all'
%r|^#{escaped_rails_root}|
when 'stdlib'
%r|^#{Regexp.escape RbConfig::CONFIG['rubylibdir']}|
else
%r{^#{escaped_rails_root}/(app|config|lib|vendor/plugin)}
end
end
end
end
#!/usr/bin/env ruby
require File.dirname(__FILE__) + '/../config/environment'
Paperless::Profiler.new(ARGV[0], ARGV[1].try(:to_i)).run
require 'benchmark'
require 'rblineprof'
require 'rblineprof/console_helpers'
module Paperless
class Profiler
include Rblineprof::ConsoleHelpers
BENCHMARK_FORMAT = "User %u | System %y | Total %t | Wall %r"
def initialize(profilee, n)
@profilee = profilee
@cache_enabled = Paperless::Content::Cacheable.enabled
@benchmark_times = n || 100
instance_eval <<-EOT
def wrapped_profilee
Rails.logger.debug "==================="
#{@profilee}
Rails.logger.debug "==================="
end
EOT
end
def run_subscriber
@counts ||= {}
GC.start
start = ObjectSpace.count_objects[:TOTAL] - ObjectSpace.count_objects[:FREE]
counts = {}
counts[:sql] = subscribe_and_count('sql.active_record') do
counts[:redis] = subscribe_and_count('execute_command.redis') do
counts[:cache_read] = subscribe_and_count('cache_read.active_support') do
counts[:cache_write] = subscribe_and_count('cache_write.active_support') do
wrapped_profilee
end
end
end
end
finish = ObjectSpace.count_objects[:TOTAL] - ObjectSpace.count_objects[:FREE]
counts[:objects] = [finish - start, 0]
@counts[@cache_enabled] = counts
end
def run_benchmark
@benchmark ||= {}
@benchmark[@cache_enabled] = Benchmark.measure { @benchmark_times.times { wrapped_profilee } }
end
def run_lineprof
@lineprof_output ||= {}
@lineprof_output[@cache_enabled] = lineprof_block do
wrapped_profilee
end
end
def run
output_header
# prime
toggle_caching
run_subscriber
toggle_caching
run_subscriber
toggle_caching
run_benchmark
toggle_caching
run_benchmark
toggle_caching
run_lineprof
toggle_caching
run_lineprof
output_to_console
end
def hr
puts "\n#{"=" * 80}\n\n"
end
def output_header
hr
puts "#### Running `#{@profilee}`"
puts
puts "#### Revision #{CURRENT_REVISION}"
puts
puts "[#{Time.now}] Running the profile"
end
def output_to_console
puts "[#{Time.now}] Done"
hr
puts "## Basic Stats: "
puts
puts "### Cache on"
puts
puts format_benchmark(@benchmark[true])
puts
puts "### Cache off"
puts
puts format_benchmark(@benchmark[false])
puts
hr
puts "## Events"
puts
puts "### Cache on"
puts
puts format_counts(@counts[true])
puts
puts "### Cache off"
puts
puts format_counts(@counts[false])
hr
puts "## Lineprof"
puts
puts "### Cache on"
puts
puts "```ruby"
puts @lineprof_output[true]
puts "```"
puts
puts "### Cache off"
puts
puts "```ruby"
puts @lineprof_output[false]
puts "```"
end
private
def format_counts(counts)
output = []
counts.each do |name, (count, time)|
output << "- #{name.to_s.humanize} #{count} in #{'%0.2f' % time}ms"
end
output.join("\n")
end
def format_benchmark(benchmark)
out = ""
out << "- #{@benchmark_times} | #{benchmark.format(BENCHMARK_FORMAT)}\n"
out << "- 1 | #{(benchmark / @benchmark_times).format(BENCHMARK_FORMAT)}\n"
out
end
def subscribe_and_count(to, &block)
count = 0
duration = 0
subscriber = ActiveSupport::Notifications.subscribe(to) do |*args|
e = ActiveSupport::Notifications::Event.new(*args)
count += 1
duration += e.duration
end
yield
ActiveSupport::Notifications.unsubscribe(subscriber)
[count, duration]
end
def toggle_caching
@cache_enabled = !@cache_enabled
Rails.cache.clear if @cache_enabled
Paperless::Content::Cacheable.enabled = @cache_enabled
ActionController::Base.perform_caching = @cache_enabled
wrapped_profilee
end
end
end
@marcamillion

This comment has been minimized.

Copy link

commented Jan 11, 2015

This looks awesome. Out of curiosity....y not bundle this as a gem?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.