Ruby on Rails | Screencasts | Download | Documentation | Weblog | Community | Source

Changeset 1052

Show
Ignore:
Timestamp:
04/02/05 01:09:12 (3 years ago)
Author:
bitsweat
Message:

Make request profiler a singleton (by using class methods rather than making instances.) Handle out-of-order execution and failurely sanely. Introduce test suite.

Files:

Legend:

Unmodified
Added
Removed
Modified
Copied
Moved

  • tools/conductor/lib/request_profiler.rb

    r1040 r1052  
    22  class Base 
    33    # Profile each request and append the results to the response body. 
     4    # Requires the ruby-prof C extension by Shugo Maeda which requires 
     5    # Ruby 1.8 younger than 2005-03-22 (this means CVS.) 
    46    # 
    5     # Requires the ruby-prof C extension which requires Ruby 1.8 younger 
    6     # than 2005-03-22 (this means CVS.) 
     7    # TODO: Prof.started? to test whether profiling has begun 
     8    # and Prof.clock_mode to read clock mode. 
    79    # 
    810    # Timing modes: 
    9     #   :clock          Use clock(3).  Default. 
     11    #   :clock          Use clock(3).  Default for compatibility. 
    1012    #   :gettimeofday   Use gettimeofday(2). 
    1113    #   :cpu            Use the CPU clock counter like RDTSC on Pentium. 
    1214    #                   Available on Pentium and PowerPC only. 
    1315    def self.profile_requests(timing_mode = :clock) 
    14       around_filter(ProfilerFilter.new(timing_mode)) if ProfilerFilter.available? 
     16      if ProfilerFilter.available? 
     17        ProfilerFilter.timing_mode = timing_mode 
     18        around_filter ProfilerFilter 
     19      end 
    1520    end 
    1621  end 
    …… 
    1823 
    1924class ProfilerFilter 
    20   # Check whether this filter can be used.  It requires the ruby-prof 
    21   # C extension and Ruby 1.8 younger than 2005-03-22 (this means CVS.) 
    22   def self.available? 
    23     begin 
    24       require 'prof' 
     25  class << self 
     26    # Check whether this filter can be used.  It requires the ruby-prof 
     27    # C extension and Ruby 1.8 younger than 2005-03-22 (this means CVS.) 
     28    def available? 
     29      load_prof 
    2530      true 
    2631    rescue LoadError 
    2732      false 
    2833    end 
    29   end 
    3034 
    31   # Create a profiling filter to wrap an Action Controller action. 
    32   # TODO: return a singleton and check whether profiling already 
    33   # started. 
    34   # 
    35   # Timing modes: 
    36   #   :clock          Use clock(3).  Default for compatibility. 
    37   #   :gettimeofday   Use gettimeofday(2). 
    38   #   :cpu            Use the CPU clock counter like RDTSC on Pentium. 
    39   def initialize(timing_mode = :clock) 
    40     require 'prof' 
    41     timing_modes = { 
    42       :clock => Prof::CLOCK, 
    43       :gettimeofday => Prof::GETTIMEOFDAY, 
    44       :cpu => Prof::CPU 
    45     } 
    46     raise ArgumentError unless timing_modes.has_key?(timing_mode) 
    47     Prof.clock_mode = timing_modes[timing_mode] 
    48   end 
     35    # Timing modes: 
     36    #   :clock          Use clock(3).  Default for compatibility. 
     37    #   :gettimeofday   Use gettimeofday(2). 
     38    #   :cpu            Use the CPU clock counter like RDTSC on Pentium. 
     39    #                   Available on Pentium and PowerPC only. 
     40    def timing_mode=(timing_mode) 
     41      Prof.clock_mode = TIMING_MODES[timing_mode] 
     42    rescue 
     43      # Ignore if mode set while profiling. 
     44      TIMING_MODES[timing_mode] 
     45    end 
    4946 
    50   def before(controller) 
    51     Prof.start 
    52   end 
     47    # Begin profiling.  Ignore if profiling has already begun. 
     48    def before(controller) 
     49      Prof.start rescue true 
     50    end 
    5351 
    54   def after(controller) 
    55     results = Prof.stop 
    56     controller.response.body << format_results(results) 
    57   end 
     52    # Finish profiling.  Append results to response body. 
     53    def after(controller) 
     54      results = Prof.stop 
     55      controller.response.body << render_results(results) 
     56    end 
    5857 
    59   private 
    60     def format_results(results, percent_limit = 0.95) 
    61       total = results.inject(0.0) { |sum, r| sum + r.self_time } 
    62       if total == 0.0 
    63         total = 0.001 
    64       end 
    65       sum = 0.0 
    66  
    67       str = "<pre>total request time: #{'%8d' % (total * 1000)} ms<br/>" 
    68       str << "  %%   cumulative   self              self     total\n" 
    69       str << " time   seconds   seconds    calls  ms/call  ms/call  name\n" 
    70  
    71       for r in results 
    72         sum += r.self_time 
    73         break if sum/total > percent_limit 
    74         if r.method_class.nil? 
    75           name = r.method_id.to_s 
    76         elsif r.method_class.is_a?(Class) 
    77           name = r.method_class.to_s + "#" + r.method_id.to_s 
    78         else 
    79           name = r.method_class.to_s + "." + r.method_id.to_s 
     58    private 
     59      # Load ruby-prof library and initialize TIMING_MODES according 
     60      # to available clock modes. 
     61      def load_prof 
     62        require 'prof' 
     63        unless const_defined?(:TIMING_MODES) 
     64          const_set :TIMING_MODES, {} 
     65          %w(CLOCK GETTIMEOFDAY CPU).each do |mode| 
     66            if Prof.const_defined?(mode) 
     67              TIMING_MODES[mode.downcase.to_sym] = Prof.const_get(mode) 
     68            end 
     69          end 
    8070        end 
    81         str << sprintf( 
    82           "%6.2f %8.3f  %8.3f %8d %8.2f %8.2f  %s\n", 
    83           r.self_time / total * 100, 
    84           sum, 
    85           r.self_time, 
    86           r.count, 
    87           r.self_time * 1000 / r.count, 
    88           r.total_time * 1000 / r.count, 
    89           name 
    90         ) 
    9171      end 
    9272 
    93       str << "</pre>" 
     73      # Preformatted output based on unprof.rb by Shugo Maeda. 
     74      def render_results(results, percent_limit = 0.95) 
     75        total = results.inject(0.0) { |sum, r| sum + r.self_time } 
     76        total = 0.001 if total < 0.001 
     77 
     78        str = "<pre>total request time: #{'%8d' % (total * 1000)} ms<br/>" 
     79        str << "  %%   cumulative   self              self     total\n" 
     80        str << " time   seconds   seconds    calls  ms/call  ms/call  name\n" 
     81 
     82        sum = 0.0 
     83        for r in results 
     84          sum += r.self_time 
     85          break if sum/total > percent_limit 
     86 
     87          name =  if r.method_class.nil? 
     88                    r.method_id.to_s 
     89                  elsif r.method_class.is_a?(Class) 
     90                    r.method_class.to_s + "#" + r.method_id.to_s 
     91                  else 
     92                    r.method_class.to_s + "." + r.method_id.to_s 
     93                  end 
     94 
     95          str << sprintf( 
     96            "%6.2f %8.3f  %8.3f %8d %8.2f %8.2f  %s\n", 
     97            r.self_time / total * 100, 
     98            sum, 
     99            r.self_time, 
     100            r.count, 
     101            r.self_time * 1000 / r.count, 
     102            r.total_time * 1000 / r.count, 
     103            name 
     104          ) 
     105        end 
     106 
     107        str << "</pre>" 
     108      end 
    94109    end 
    95 end 
     110  end