Skip to content

Instantly share code, notes, and snippets.

Embed
What would you like to do?
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
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.