diff options
| -rw-r--r-- | actionpack/lib/action_dispatch/testing/performance_test.rb | 22 | ||||
| -rw-r--r-- | activesupport/lib/active_support/testing/performance.rb | 618 |
2 files changed, 319 insertions, 321 deletions
diff --git a/actionpack/lib/action_dispatch/testing/performance_test.rb b/actionpack/lib/action_dispatch/testing/performance_test.rb index e7aeb45fb3..465bf40568 100644 --- a/actionpack/lib/action_dispatch/testing/performance_test.rb +++ b/actionpack/lib/action_dispatch/testing/performance_test.rb @@ -1,17 +1,13 @@ require 'active_support/testing/performance' -begin - module ActionDispatch - # An integration test that runs a code profiler on your test methods. - # Profiling output for combinations of each test method, measurement, and - # output format are written to your tmp/performance directory. - # - # By default, process_time is measured and both flat and graph_html output - # formats are written, so you'll have two output files per test method. - class PerformanceTest < ActionDispatch::IntegrationTest - include ActiveSupport::Testing::Performance - end +module ActionDispatch + # An integration test that runs a code profiler on your test methods. + # Profiling output for combinations of each test method, measurement, and + # output format are written to your tmp/performance directory. + # + # By default, process_time is measured and both flat and graph_html output + # formats are written, so you'll have two output files per test method. + class PerformanceTest < ActionDispatch::IntegrationTest + include ActiveSupport::Testing::Performance end -rescue NameError - $stderr.puts "Specify ruby-prof as application's dependency in Gemfile to run benchmarks." end diff --git a/activesupport/lib/active_support/testing/performance.rb b/activesupport/lib/active_support/testing/performance.rb index 42b58c4f25..9e46e5963e 100644 --- a/activesupport/lib/active_support/testing/performance.rb +++ b/activesupport/lib/active_support/testing/performance.rb @@ -1,425 +1,427 @@ +require 'fileutils' +require 'rails/version' +require 'active_support/core_ext/class/delegating_attributes' +require 'active_support/core_ext/string/inflections' + begin require 'ruby-prof' +rescue LoadError + $stderr.puts "Specify ruby-prof as application's dependency in Gemfile to run benchmarks." + exit +end - require 'fileutils' - require 'rails/version' - require 'active_support/core_ext/class/delegating_attributes' - require 'active_support/core_ext/string/inflections' - - module ActiveSupport - module Testing - module Performance - DEFAULTS = - if benchmark = ARGV.include?('--benchmark') # HAX for rake test - { :benchmark => true, - :runs => 4, - :metrics => [:wall_time, :memory, :objects, :gc_runs, :gc_time], - :output => 'tmp/performance' } - else - { :benchmark => false, - :runs => 1, - :min_percent => 0.01, - :metrics => [:process_time, :memory, :objects], - :formats => [:flat, :graph_html, :call_tree], - :output => 'tmp/performance' } - end.freeze - - def self.included(base) - base.superclass_delegating_accessor :profile_options - base.profile_options = DEFAULTS - end +module ActiveSupport + module Testing + module Performance + DEFAULTS = + if benchmark = ARGV.include?('--benchmark') # HAX for rake test + { :benchmark => true, + :runs => 4, + :metrics => [:wall_time, :memory, :objects, :gc_runs, :gc_time], + :output => 'tmp/performance' } + else + { :benchmark => false, + :runs => 1, + :min_percent => 0.01, + :metrics => [:process_time, :memory, :objects], + :formats => [:flat, :graph_html, :call_tree], + :output => 'tmp/performance' } + end.freeze + + def self.included(base) + base.superclass_delegating_accessor :profile_options + base.profile_options = DEFAULTS + end - def full_test_name - "#{self.class.name}##{method_name}" - end + def full_test_name + "#{self.class.name}##{method_name}" + end - def run(result) - return if method_name =~ /^default_test$/ + def run(result) + return if method_name =~ /^default_test$/ - yield(self.class::STARTED, name) - @_result = result + yield(self.class::STARTED, name) + @_result = result - run_warmup - if profile_options && metrics = profile_options[:metrics] - metrics.each do |metric_name| - if klass = Metrics[metric_name.to_sym] - run_profile(klass.new) - result.add_run - end + run_warmup + if profile_options && metrics = profile_options[:metrics] + metrics.each do |metric_name| + if klass = Metrics[metric_name.to_sym] + run_profile(klass.new) + result.add_run end end - - yield(self.class::FINISHED, name) end - def run_test(metric, mode) - run_callbacks :setup - setup - metric.send(mode) { __send__ @method_name } + yield(self.class::FINISHED, name) + end + + def run_test(metric, mode) + run_callbacks :setup + setup + metric.send(mode) { __send__ @method_name } + rescue ::Test::Unit::AssertionFailedError => e + add_failure(e.message, e.backtrace) + rescue StandardError, ScriptError => e + add_error(e) + ensure + begin + teardown + run_callbacks :teardown, :enumerator => :reverse_each rescue ::Test::Unit::AssertionFailedError => e add_failure(e.message, e.backtrace) rescue StandardError, ScriptError => e add_error(e) - ensure - begin - teardown - run_callbacks :teardown, :enumerator => :reverse_each - rescue ::Test::Unit::AssertionFailedError => e - add_failure(e.message, e.backtrace) - rescue StandardError, ScriptError => e - add_error(e) - end end + end - protected - def run_warmup - GC.start + protected + def run_warmup + GC.start - time = Metrics::Time.new - run_test(time, :benchmark) - puts "%s (%s warmup)" % [full_test_name, time.format(time.total)] + time = Metrics::Time.new + run_test(time, :benchmark) + puts "%s (%s warmup)" % [full_test_name, time.format(time.total)] - GC.start - end + GC.start + end - def run_profile(metric) - klass = profile_options[:benchmark] ? Benchmarker : Profiler - performer = klass.new(self, metric) + def run_profile(metric) + klass = profile_options[:benchmark] ? Benchmarker : Profiler + performer = klass.new(self, metric) - performer.run - puts performer.report - performer.record - end + performer.run + puts performer.report + performer.record + end - class Performer - delegate :run_test, :profile_options, :full_test_name, :to => :@harness + class Performer + delegate :run_test, :profile_options, :full_test_name, :to => :@harness - def initialize(harness, metric) - @harness, @metric = harness, metric - end + def initialize(harness, metric) + @harness, @metric = harness, metric + end - def report - rate = @total / profile_options[:runs] - '%20s: %s' % [@metric.name, @metric.format(rate)] + def report + rate = @total / profile_options[:runs] + '%20s: %s' % [@metric.name, @metric.format(rate)] + end + + protected + def output_filename + "#{profile_options[:output]}/#{full_test_name}_#{@metric.name}" end + end - protected - def output_filename - "#{profile_options[:output]}/#{full_test_name}_#{@metric.name}" - end + class Benchmarker < Performer + def run + profile_options[:runs].to_i.times { run_test(@metric, :benchmark) } + @total = @metric.total end - class Benchmarker < Performer - def run - profile_options[:runs].to_i.times { run_test(@metric, :benchmark) } - @total = @metric.total + def record + avg = @metric.total / profile_options[:runs].to_i + now = Time.now.utc.xmlschema + with_output_file do |file| + file.puts "#{avg},#{now},#{environment}" end + end + + def environment + unless defined? @env + app = "#{$1}.#{$2}" if File.directory?('.git') && `git branch -v` =~ /^\* (\S+)\s+(\S+)/ - def record - avg = @metric.total / profile_options[:runs].to_i - now = Time.now.utc.xmlschema - with_output_file do |file| - file.puts "#{avg},#{now},#{environment}" + rails = Rails::VERSION::STRING + if File.directory?('vendor/rails/.git') + Dir.chdir('vendor/rails') do + rails += ".#{$1}.#{$2}" if `git branch -v` =~ /^\* (\S+)\s+(\S+)/ + end end + + ruby = defined?(RUBY_ENGINE) ? RUBY_ENGINE : 'ruby' + ruby += "-#{RUBY_VERSION}.#{RUBY_PATCHLEVEL}" + + @env = [app, rails, ruby, RUBY_PLATFORM] * ',' end - def environment - unless defined? @env - app = "#{$1}.#{$2}" if File.directory?('.git') && `git branch -v` =~ /^\* (\S+)\s+(\S+)/ + @env + end - rails = Rails::VERSION::STRING - if File.directory?('vendor/rails/.git') - Dir.chdir('vendor/rails') do - rails += ".#{$1}.#{$2}" if `git branch -v` =~ /^\* (\S+)\s+(\S+)/ - end - end + protected + HEADER = 'measurement,created_at,app,rails,ruby,platform' - ruby = defined?(RUBY_ENGINE) ? RUBY_ENGINE : 'ruby' - ruby += "-#{RUBY_VERSION}.#{RUBY_PATCHLEVEL}" + def with_output_file + fname = output_filename - @env = [app, rails, ruby, RUBY_PLATFORM] * ',' + if new = !File.exist?(fname) + FileUtils.mkdir_p(File.dirname(fname)) end - @env + File.open(fname, 'ab') do |file| + file.puts(HEADER) if new + yield file + end end - protected - HEADER = 'measurement,created_at,app,rails,ruby,platform' - - def with_output_file - fname = output_filename + def output_filename + "#{super}.csv" + end + end - if new = !File.exist?(fname) - FileUtils.mkdir_p(File.dirname(fname)) - end + class Profiler < Performer + def initialize(*args) + super + @supported = @metric.measure_mode rescue false + end - File.open(fname, 'ab') do |file| - file.puts(HEADER) if new - yield file - end - end + def run + return unless @supported - def output_filename - "#{super}.csv" - end + RubyProf.measure_mode = @metric.measure_mode + RubyProf.start + RubyProf.pause + profile_options[:runs].to_i.times { run_test(@metric, :profile) } + @data = RubyProf.stop + @total = @data.threads.values.sum(0) { |method_infos| method_infos.max.total_time } end - class Profiler < Performer - def initialize(*args) + def report + if @supported super - @supported = @metric.measure_mode rescue false + else + '%20s: unsupported' % @metric.name end + end - def run - return unless @supported + def record + return unless @supported - RubyProf.measure_mode = @metric.measure_mode - RubyProf.start - RubyProf.pause - profile_options[:runs].to_i.times { run_test(@metric, :profile) } - @data = RubyProf.stop - @total = @data.threads.values.sum(0) { |method_infos| method_infos.max.total_time } - end + klasses = profile_options[:formats].map { |f| RubyProf.const_get("#{f.to_s.camelize}Printer") }.compact - def report - if @supported - super - else - '%20s: unsupported' % @metric.name + klasses.each do |klass| + fname = output_filename(klass) + FileUtils.mkdir_p(File.dirname(fname)) + File.open(fname, 'wb') do |file| + klass.new(@data).print(file, profile_options.slice(:min_percent)) end end + end - def record - return unless @supported - - klasses = profile_options[:formats].map { |f| RubyProf.const_get("#{f.to_s.camelize}Printer") }.compact - - klasses.each do |klass| - fname = output_filename(klass) - FileUtils.mkdir_p(File.dirname(fname)) - File.open(fname, 'wb') do |file| - klass.new(@data).print(file, profile_options.slice(:min_percent)) + protected + def output_filename(printer_class) + suffix = + case printer_class.name.demodulize + when 'FlatPrinter'; 'flat.txt' + when 'FlatPrinterWithLineNumbers'; 'flat_line_numbers.txt' + when 'GraphPrinter'; 'graph.txt' + when 'GraphHtmlPrinter'; 'graph.html' + when 'GraphYamlPrinter'; 'graph.yml' + when 'CallTreePrinter'; 'tree.txt' + when 'CallStackPrinter'; 'stack.html' + when 'DotPrinter'; 'graph.dot' + else printer_class.name.sub(/Printer$/, '').underscore end - end + + "#{super()}_#{suffix}" end + end - protected - def output_filename(printer_class) - suffix = - case printer_class.name.demodulize - when 'FlatPrinter'; 'flat.txt' - when 'FlatPrinterWithLineNumbers'; 'flat_line_numbers.txt' - when 'GraphPrinter'; 'graph.txt' - when 'GraphHtmlPrinter'; 'graph.html' - when 'GraphYamlPrinter'; 'graph.yml' - when 'CallTreePrinter'; 'tree.txt' - when 'CallStackPrinter'; 'stack.html' - when 'DotPrinter'; 'graph.dot' - else printer_class.name.sub(/Printer$/, '').underscore - end - - "#{super()}_#{suffix}" - end + module Metrics + def self.[](name) + const_get(name.to_s.camelize) + rescue NameError + nil end - module Metrics - def self.[](name) - const_get(name.to_s.camelize) - rescue NameError - nil + class Base + attr_reader :total + + def initialize + @total = 0 end - class Base - attr_reader :total + def name + @name ||= self.class.name.demodulize.underscore + end - def initialize - @total = 0 - end + def measure_mode + self.class::Mode + end - def name - @name ||= self.class.name.demodulize.underscore - end + def measure + 0 + end - def measure_mode - self.class::Mode + def benchmark + with_gc_stats do + before = measure + yield + @total += (measure - before) end + end - def measure - 0 - end + def profile + RubyProf.resume + yield + ensure + RubyProf.pause + end - def benchmark - with_gc_stats do - before = measure + protected + # Ruby 1.9 with GC::Profiler + if defined?(GC::Profiler) + def with_gc_stats + GC::Profiler.enable + GC.start yield - @total += (measure - before) + ensure + GC::Profiler.disable end - end - - def profile - RubyProf.resume - yield - ensure - RubyProf.pause - end - protected - # Ruby 1.9 with GC::Profiler - if defined?(GC::Profiler) - def with_gc_stats - GC::Profiler.enable - GC.start - yield - ensure - GC::Profiler.disable - end - - # Ruby 1.8 + ruby-prof wrapper (enable/disable stats for Benchmarker) - elsif GC.respond_to?(:enable_stats) - def with_gc_stats - GC.enable_stats - yield - ensure - GC.disable_stats - end - - else - def with_gc_stats - yield - end + # Ruby 1.8 + ruby-prof wrapper (enable/disable stats for Benchmarker) + elsif GC.respond_to?(:enable_stats) + def with_gc_stats + GC.enable_stats + yield + ensure + GC.disable_stats end - end - class Time < Base - def measure - ::Time.now.to_f - end - - def format(measurement) - if measurement < 1 - '%d ms' % (measurement * 1000) - else - '%.2f sec' % measurement + else + def with_gc_stats + yield end end - end + end - class ProcessTime < Time - Mode = RubyProf::PROCESS_TIME if RubyProf.const_defined?(:PROCESS_TIME) + class Time < Base + def measure + ::Time.now.to_f + end - def measure - RubyProf.measure_process_time + def format(measurement) + if measurement < 1 + '%d ms' % (measurement * 1000) + else + '%.2f sec' % measurement end end + end - class WallTime < Time - Mode = RubyProf::WALL_TIME if RubyProf.const_defined?(:WALL_TIME) + class ProcessTime < Time + Mode = RubyProf::PROCESS_TIME if RubyProf.const_defined?(:PROCESS_TIME) - def measure - RubyProf.measure_wall_time - end + def measure + RubyProf.measure_process_time end + end - class CpuTime < Time - Mode = RubyProf::CPU_TIME if RubyProf.const_defined?(:CPU_TIME) + class WallTime < Time + Mode = RubyProf::WALL_TIME if RubyProf.const_defined?(:WALL_TIME) - def initialize(*args) - # FIXME: yeah my CPU is 2.33 GHz - RubyProf.cpu_frequency = 2.33e9 unless RubyProf.cpu_frequency > 0 - super - end + def measure + RubyProf.measure_wall_time + end + end - def measure - RubyProf.measure_cpu_time - end + class CpuTime < Time + Mode = RubyProf::CPU_TIME if RubyProf.const_defined?(:CPU_TIME) + + def initialize(*args) + # FIXME: yeah my CPU is 2.33 GHz + RubyProf.cpu_frequency = 2.33e9 unless RubyProf.cpu_frequency > 0 + super end - class Memory < Base - Mode = RubyProf::MEMORY if RubyProf.const_defined?(:MEMORY) + def measure + RubyProf.measure_cpu_time + end + end - # Ruby 1.9 + GCdata patch - if GC.respond_to?(:malloc_allocated_size) - def measure - GC.malloc_allocated_size / 1024.0 - end + class Memory < Base + Mode = RubyProf::MEMORY if RubyProf.const_defined?(:MEMORY) - # Ruby 1.8 + ruby-prof wrapper - elsif RubyProf.respond_to?(:measure_memory) - def measure - RubyProf.measure_memory / 1024.0 - end + # Ruby 1.9 + GCdata patch + if GC.respond_to?(:malloc_allocated_size) + def measure + GC.malloc_allocated_size / 1024.0 end - def format(measurement) - '%.2f KB' % measurement + # Ruby 1.8 + ruby-prof wrapper + elsif RubyProf.respond_to?(:measure_memory) + def measure + RubyProf.measure_memory / 1024.0 end end - class Objects < Base - Mode = RubyProf::ALLOCATIONS if RubyProf.const_defined?(:ALLOCATIONS) + def format(measurement) + '%.2f KB' % measurement + end + end - # Ruby 1.9 + GCdata patch - if GC.respond_to?(:malloc_allocations) - def measure - GC.malloc_allocations - end + class Objects < Base + Mode = RubyProf::ALLOCATIONS if RubyProf.const_defined?(:ALLOCATIONS) - # Ruby 1.8 + ruby-prof wrapper - elsif RubyProf.respond_to?(:measure_allocations) - def measure - RubyProf.measure_allocations - end + # Ruby 1.9 + GCdata patch + if GC.respond_to?(:malloc_allocations) + def measure + GC.malloc_allocations end - def format(measurement) - measurement.to_i.to_s + # Ruby 1.8 + ruby-prof wrapper + elsif RubyProf.respond_to?(:measure_allocations) + def measure + RubyProf.measure_allocations end end - class GcRuns < Base - Mode = RubyProf::GC_RUNS if RubyProf.const_defined?(:GC_RUNS) + def format(measurement) + measurement.to_i.to_s + end + end - # Ruby 1.9 - if GC.respond_to?(:count) - def measure - GC.count - end + class GcRuns < Base + Mode = RubyProf::GC_RUNS if RubyProf.const_defined?(:GC_RUNS) - # Ruby 1.8 + ruby-prof wrapper - elsif RubyProf.respond_to?(:measure_gc_runs) - def measure - RubyProf.measure_gc_runs - end + # Ruby 1.9 + if GC.respond_to?(:count) + def measure + GC.count end - def format(measurement) - measurement.to_i.to_s + # Ruby 1.8 + ruby-prof wrapper + elsif RubyProf.respond_to?(:measure_gc_runs) + def measure + RubyProf.measure_gc_runs end end - class GcTime < Base - Mode = RubyProf::GC_TIME if RubyProf.const_defined?(:GC_TIME) + def format(measurement) + measurement.to_i.to_s + end + end - # Ruby 1.9 with GC::Profiler - if defined?(GC::Profiler) && GC::Profiler.respond_to?(:total_time) - def measure - GC::Profiler.total_time - end + class GcTime < Base + Mode = RubyProf::GC_TIME if RubyProf.const_defined?(:GC_TIME) - # Ruby 1.8 + ruby-prof wrapper - elsif RubyProf.respond_to?(:measure_gc_time) - def measure - RubyProf.measure_gc_time / 1000 - end + # Ruby 1.9 with GC::Profiler + if defined?(GC::Profiler) && GC::Profiler.respond_to?(:total_time) + def measure + GC::Profiler.total_time end - def format(measurement) - '%.2f ms' % measurement + # Ruby 1.8 + ruby-prof wrapper + elsif RubyProf.respond_to?(:measure_gc_time) + def measure + RubyProf.measure_gc_time / 1000 end end + + def format(measurement) + '%.2f ms' % measurement + end end end end end -rescue LoadError end |