打印需要启动时间

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