Extract Metric and Performer. Simplify and refactor.

activesupport/lib/active_support/testing/performance.rb

@@ -12,18 +12,22 @@ module Performance
 
       DEFAULTS = {
         :benchmark => benchmark,
-        :runs => benchmark ? 20 : 4,
-        :min_percent => 0.05,
-        :metrics => [:process_time, :memory, :allocations],
+        :runs => benchmark ? 10 : 1,
+        :min_percent => 0.02,
+        :metrics => [:process_time, :wall_time, :cpu_time, :memory, :objects],
         :formats => [:flat, :graph_html, :call_tree],
-        :output => 'tmp/performance' }
+        :output => 'tmp/performance'
+      }
 
       def self.included(base)
-        base.extend ClassMethods
-        base.class_inheritable_accessor :profile_options
+        base.class_inheritable_hash :profile_options
         base.profile_options = DEFAULTS.dup
       end
 
+      def full_test_name
+        "#{self.class.name}##{method_name}"
+      end
+
       def run(result)
         return if method_name =~ /^default_test$/
 
@@ -31,153 +35,122 @@ def run(result)
         @_result = result
 
         run_warmup
-
-        self.class.measure_modes.each do |measure_mode|
-          data = run_profile(measure_mode)
-          self.class.report_profile_total(data, measure_mode)
-          self.class.record_results(full_test_name, data, measure_mode)
-          result.add_run
+        profile_options[:metrics].each do |metric_name|
+          if klass = Metrics[metric_name.to_sym]
+            run_profile(klass.new)
+            result.add_run
+          else
+            $stderr.puts "Skipping unknown metric #{metric_name.inspect}. Expected :process_time, :wall_time, :cpu_time, :memory, or :objects."
+          end
         end
 
         yield(self.class::FINISHED, name)
       end
 
-      protected
-        def full_test_name
-          "#{self.class.name}##{@method_name}"
-        end
-
-        def run_test
-          run_callbacks :setup
-          setup
-          yield
+      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
+        add_error($!)
+      ensure
+        begin
+          teardown
+          run_callbacks :teardown, :enumerator => :reverse_each
         rescue ::Test::Unit::AssertionFailedError => e
           add_failure(e.message, e.backtrace)
         rescue StandardError, ScriptError
           add_error($!)
-        ensure
-          begin
-            teardown
-            run_callbacks :teardown, :enumerator => :reverse_each
-          rescue ::Test::Unit::AssertionFailedError => e
-            add_failure(e.message, e.backtrace)
-          rescue StandardError, ScriptError
-            add_error($!)
-          end
         end
+      end
 
+      protected
         def run_warmup
-          puts
-          print full_test_name
-
-          run_test do
-            bench = Benchmark.realtime do
-              __send__(@method_name)
-            end
-            puts " (%.2fs warmup)" % bench
-          end
+          time = Metrics::Time.new
+          run_test(time, :benchmark)
+          puts "%s (%s warmup)" % [full_test_name, time.format(time.total)]
         end
 
-        def run_profile(measure_mode)
-          RubyProf.benchmarking = profile_options[:benchmark]
-          RubyProf.measure_mode = measure_mode
+        def run_profile(metric)
+          klass = profile_options[:benchmark] ? Benchmarker : Profiler
+          performer = klass.new(self, metric)
 
-          print '  '
-          profile_options[:runs].times do |i|
-            run_test do
-              begin
-                GC.disable
-                RubyProf.resume { __send__(@method_name) }
-                print '.'
-                $stdout.flush
-              ensure
-                GC.enable
-              end
-            end
-          end
-
-          RubyProf.stop
-        end
-
-      module ClassMethods
-        def record_results(test_name, data, measure_mode)
-          if RubyProf.benchmarking?
-            record_benchmark(test_name, data, measure_mode)
-          else
-            record_profile(test_name, data, measure_mode)
-          end
+          performer.run
+          puts performer.report
+          performer.record
         end
 
-        def report_profile_total(data, measure_mode)
-          total_time =
-            if RubyProf.benchmarking?
-              data
-            else
-              data.threads.values.sum(0) do |method_infos|
-                method_infos.sort.last.total_time
-              end
-            end
+      class Performer
+        delegate :profile_options, :full_test_name, :to => :@harness
 
-          format =
-            case measure_mode
-              when RubyProf::PROCESS_TIME, RubyProf::WALL_TIME
-                "%.2f seconds"
-              when RubyProf::MEMORY
-                "%.2f bytes"
-              when RubyProf::ALLOCATIONS
-                "%d allocations"
-              else
-                "%.2f #{measure_mode}"
-            end
+        def initialize(harness, metric)
+          @harness, @metric = harness, metric
+        end
 
-          total = format % total_time
-          puts "\n  #{ActiveSupport::Testing::Performance::Util.metric_name(measure_mode)}: #{total}\n"
+        def report
+          rate = @total / profile_options[:runs]
+          '%20s: %s/run' % [@metric.name, @metric.format(rate)]
         end
+      end
 
-        def measure_modes
-          ActiveSupport::Testing::Performance::Util.measure_modes(profile_options[:metrics])
+      class Benchmarker < Performer
+        def run
+          profile_options[:runs].times { @harness.run_test(@metric, :benchmark) }
+          @total = @metric.total
         end
 
-        def printer_classes
-          ActiveSupport::Testing::Performance::Util.printer_classes(profile_options[:formats])
+        def record
+          with_output_file do |file|
+            file.puts [full_test_name, @metric.name,
+              @metric.total, profile_options[:runs],
+              @metric.total / profile_options[:runs],
+              Time.now.utc.xmlschema,
+              Rails::VERSION::STRING,
+              defined?(RUBY_ENGINE) ? RUBY_ENGINE : 'ruby',
+              RUBY_VERSION, RUBY_PATCHLEVEL, RUBY_PLATFORM].join(',')
+          end
         end
 
-        private
-          def record_benchmark(test_name, data, measure_mode)
-            bench_filename = "#{profile_options[:output]}/benchmarks.csv"
+        protected
+          HEADER = 'test,metric,measurement,runs,average,created_at,rails_version,ruby_engine,ruby_version,ruby_patchlevel,ruby_platform'
 
-            if new_file = !File.exist?(bench_filename)
-              FileUtils.mkdir_p(File.dirname(bench_filename))
-            end
+          def with_output_file
+            fname = "#{profile_options[:output]}/benchmarks.csv"
 
-            File.open(bench_filename, 'ab') do |file|
-              if new_file
-                file.puts 'test,metric,measurement,runs,average,created_at,rails_version,ruby_engine,ruby_version,ruby_patchlevel,ruby_platform'
-              end
+            if new = !File.exist?(fname)
+              FileUtils.mkdir_p(File.dirname(fname))
+            end
 
-              file.puts [test_name,
-                ActiveSupport::Testing::Performance::Util.metric_name(measure_mode),
-                data, profile_options[:runs], data / profile_options[:runs],
-                Time.now.utc.xmlschema,
-                Rails::VERSION::STRING,
-                defined?(RUBY_ENGINE) ? RUBY_ENGINE : 'ruby',
-                RUBY_VERSION, RUBY_PATCHLEVEL, RUBY_PLATFORM].join(',')
+            File.open(fname, 'ab') do |file|
+              file.puts(HEADER) if new
+              yield file
             end
           end
+      end
+
+      class Profiler < Performer
+        def run
+          @runs.times { @harness.run_test(@metric, :profile) }
+          @data = RubyProf.stop
+          @total = @data.threads.values.sum(0) { |method_infos| method_infos.sort.last.total_time }
+        end
 
-          def record_profile(test_name, data, measure_mode)
-            printer_classes.each do |printer_class|
-              fname = output_filename(test_name, printer_class, measure_mode)
+        def record(path)
+          klasses = profile_options[:formats].map { |f| RubyProf.const_get("#{f.to_s.camelize}Printer") }.compact
 
-              FileUtils.mkdir_p(File.dirname(fname))
-              File.open(fname, 'wb') do |file|
-                printer_class.new(data).print(file, profile_printer_options)
-              end
+          klasses.each do |klass|
+            fname = output_filename(metric, 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
 
-          # The report filename is test_name + measure_mode + report_type
-          def output_filename(test_name, printer_class, measure_mode)
+        protected
+          def output_filename(metric, printer_class)
             suffix =
               case printer_class.name.demodulize
                 when 'FlatPrinter'; 'flat.txt'
@@ -187,39 +160,140 @@ def output_filename(test_name, printer_class, measure_mode)
                 else printer_class.name.sub(/Printer$/, '').underscore
               end
 
-            "#{profile_options[:output]}/#{test_name}_#{ActiveSupport::Testing::Performance::Util.metric_name(measure_mode)}_#{suffix}"
+            "#{profile_options[:output]}/#{full_test_name}_#{metric.name}_#{suffix}"
           end
+      end
+
+      module Metrics
+        def self.[](name)
+          klass = const_get(name.to_s.camelize)
+          klass if klass::Mode
+        rescue
+          nil
+        end
+
+        class Base
+          attr_reader :total
 
-          def profile_printer_options
-            profile_options.slice(:min_percent)
+          def initialize
+            @total = 0
+          end
+
+          def name
+            @name ||= self.class.name.demodulize.underscore
           end
-      end
 
-      module Util
-        extend self
+          def benchmark
+            with_gc_stats do
+              before = measure
+              yield
+              @total += (measure - before)
+            end
+          end
 
-        def metric_name(measure_mode)
-          case measure_mode
-            when RubyProf::PROCESS_TIME; 'process_time'
-            when RubyProf::WALL_TIME; 'wall_time'
-            when RubyProf::MEMORY; 'memory'
-            when RubyProf::ALLOCATIONS; 'allocations'
-            else "measure#{measure_mode}"
+          def profile
+            RubyProf.measure_mode = MODE
+            RubyProf.resume { yield }
           end
+
+          protected
+            if 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
+            end
         end
 
-        def measure_modes(metrics)
-          ruby_prof_consts(metrics.map { |m| m.to_s.upcase })
+        class Time < Base
+          def measure
+            ::Time.now.to_f
+          end
+
+          def format(measurement)
+            if measurement < 2
+              '%d ms' % (measurement * 1000)
+            else
+              '%.2f sec' % measurement
+            end
+          end
         end
 
-        def printer_classes(formats)
-          ruby_prof_consts(formats.map { |f| "#{f.to_s.camelize}Printer" })
+        class ProcessTime < Time
+          Mode = RubyProf::PROCESS_TIME
+
+          def measure
+            RubyProf.measure_process_time
+          end
         end
 
-        private
-          def ruby_prof_consts(names)
-            names.map { |name| RubyProf.const_get(name) rescue nil }.compact
+        class WallTime < Time
+          Mode = RubyProf::WALL_TIME
+
+          def measure
+            RubyProf.measure_wall_time
           end
+        end
+
+        class CpuTime < Time
+          Mode = RubyProf::CPU_TIME
+
+          def initialize(*args)
+            # FIXME: yeah my CPU is 2.33 GHz
+            RubyProf.cpu_frequency = 2.33e9
+            super
+          end
+
+          def measure
+            RubyProf.measure_cpu_time
+          end
+        end
+
+        class Memory < Base
+          Mode = RubyProf::MEMORY
+
+          if RubyProf.respond_to?(:measure_memory)
+            def measure
+              RubyProf.measure_memory
+            end
+          elsif GC.respond_to?(:allocated_size)
+            def measure
+              GC.allocated_size
+            end
+          elsif GC.respond_to?(:malloc_allocated_size)
+            def measure
+              GC.malloc_allocated_size
+            end
+          end
+
+          def format(measurement)
+            '%.2f KB' % (measurement / 1024.0)
+          end
+        end
+
+        class Objects < Base
+          Mode = RubyProf::ALLOCATIONS
+
+          if RubyProf.respond_to?(:measure_allocations)
+            def measure
+              RubyProf.measure_allocations
+            end
+          elsif ObjectSpace.respond_to?(:allocated_objects)
+            def measure
+              ObjectSpace.allocated_objects
+            end
+          end
+
+          def format(measurement)
+            measurement.to_s
+          end
+        end
       end
     end
   end