ruby-on-rails - 印刷には起動に時間がかかります

Question

遅いアプリケーションの起動時間をデバッグできるように、ファイルの所要時間を印刷するにはどうすればよいですか。

私はこのようなものを想像しています：

$ rails s
$ app/models/user.rb took 300 milliseconds
$ ...
$ lib/connect.rb took 5000 milliseconds

オーバーライドする必要がKernel#requireありますか？もしそうなら、どのように？

Answer 1

# ACK:
# modified from
# http://gist.github.com/264496 by github.com/eric
# http://gist.github.com/465293 by github.com/alexyoung

# USAGE:
# 1) > ruby -rrequire_tracking -e "require 'active_support'"
# 2) put in config/preinitializer.rb

# WHAT: Provides a simple overview of memory allocation occuring
# during a require.
#
# For a longer explanation, see post at:
# http://bitmonkey.net/post/308322913/tracking-initial-memory-usage-by-file-in-ruby
#
# NOTE: The numbers provided are of self + children, meaning the same will
# be attributed to multiple files at once.
#
# Also, memory that is no longer referenced (and would be freed) is
# still taken into account.
#
# It is intended to give a simple overview of allocations to track
# down gross offenders, not give an exact view of your memory usage.

require 'benchmark'

if GC.respond_to?(:enable_stats)
  module RequireTracking
    def require(*args)
      start_allocated_size = GC.allocated_size

      output = nil
      benchmark = Benchmark.realtime do #Benchmark.measure
        output = super
      end
      benchmark = (benchmark * 100000).to_i

      first_caller = caller[0][40..-1].split(':')[0]
      $my_require_stats << [args[0], benchmark, first_caller, (GC.allocated_size - start_allocated_size)]
    end #def
  end #module
else
  module RequireTracking
    def require(*args)
      output = nil
      benchmark = Benchmark.realtime do #Benchmark.measure
        output = super
      end
      benchmark = (benchmark * 1000_00).to_i

      first_caller = caller[0][40..-1].split(':')[0]
      $my_require_stats << [path, benchmark, first_caller, 'NA']
    end #def
  end #module
  puts "Warning: Not running with an interpreter with GC statistics"
end #if

module RequireTracking
  $my_require_stats ||= []
  $require_stats_top ||= 20

  def numeric_thousands_indicators(number)
    number.to_s.gsub(/(\d)(?=\d{3}+(?:\.|$))(\d{3}\..*)?/,'\1,\2')
  end

  def dump_require_benchmark_stats
    File.open('require_trace.log.csv', 'w') do |out|
      out << "\"path\",\"benchmark\",\"caller\",\"mem\"\n"
      $my_require_stats.each do |path, benchmark, caller, mem|
        out << "\"#{path}\",\"#{benchmark}\",\"#{caller}\",\"#{mem}\"\n"
      end
    end
  end

  def print_require_benchmark_stats_by_memory
    puts " %40s %5s %5s " % [ 'File', 'KB', 'NanoSec' ]
    puts " %40s %s" % [ '-------------', '--------' ]
    $my_require_stats.sort_by {|v| v[3] }.slice(0, $require_stats_top).each do |path, benchmark, caller, mem|
      puts "%40s %5s %5s " % [ path, numeric_thousands_indicators(mem / 1024), benchmark ]
    end
  end

  def print_require_benchmark_stats_by_time
    puts " %40s %5s %5s " % [ 'File', 'KB', 'NanoSec' ]
    puts " %40s %s" % [ '-------------', '--------' ]
    $my_require_stats.sort_by {|v| v[1] }.slice(0, $require_stats_top).each do |path, benchmark, caller, mem|
      puts "%40s %5s %5s " % [ path, numeric_thousands_indicators(mem / 1024), benchmark ]
    end
  end
end #module

Object.send(:include, RequireTracking)
Kernel.send(:include, RequireTracking)

if GC.respond_to?(:enable_stats)
  GC.enable_stats
  GC.clear_stats
end

at_exit do
  dump_require_benchmark_stats
  puts "Memory used by file:"
  print_require_benchmark_stats_by_memory
  puts "Time required by file:"
  print_require_benchmark_stats_by_time
end