From dab4abd680309c12fec01d2dc0ee3b53e5be6c07 Mon Sep 17 00:00:00 2001 From: Andrew Arrow Date: Thu, 11 Jun 2009 10:06:22 -0700 Subject: [PATCH] added verbose output to rails startup --- railties/lib/initializer.rb | 66 ++++++++++++++++++++++++++++++++-- railties/lib/rails/plugin/loader.rb | 12 ++++++ 2 files changed, 74 insertions(+), 4 deletions(-) diff --git a/railties/lib/initializer.rb b/railties/lib/initializer.rb index 9148bdd..39facc7 100644 --- a/railties/lib/initializer.rb +++ b/railties/lib/initializer.rb @@ -118,43 +118,79 @@ module Rails @loaded_plugins = [] end + def time_it(name, indent=false) + return if not ENV['RAILS_VERBOSE_STARTUP'] + @stat_total ||= 0 + stat = 0.0 + stat = Time.now.to_f - @last_time if @last_time + @stat_total += stat + if indent + puts " #{name.to_s.rjust(31, ' ')} #{format("%.4f",stat)}" + else + puts "#{name.to_s.rjust(31, ' ')} #{format("%.4f",stat)}" + end + @last_time = Time.now.to_f + end + # Sequentially step through all of the available initialization routines, # in order (view execution order in source). def process Rails.configuration = configuration +time_it(:starting) check_ruby_version +time_it(:check_ruby_version) install_gem_spec_stubs +time_it(:install_gem_spec_stubs) set_load_path +time_it(:set_load_path) add_gem_load_paths - +time_it(:add_gem_load_paths) require_frameworks set_autoload_paths +time_it(:set_autoload_paths) add_plugin_load_paths +time_it(:add_plugin_load_paths) load_environment +time_it(:load_environment) preload_frameworks +time_it(:preload_frameworks) initialize_encoding +time_it(:initialize_encoding) initialize_database +time_it(:initialize_database) initialize_cache +time_it(:initialize_cache) initialize_framework_caches +time_it(:initialize_framework_caches) initialize_logger +time_it(:initialize_logger) initialize_framework_logging +time_it(:initialize_framework_logging) initialize_dependency_mechanism +time_it(:initialize_dependency_mechanism) initialize_whiny_nils +time_it(:initialize_whiny_nils) initialize_time_zone +time_it(:initialize_time_zone) initialize_i18n +time_it(:initialize_i18n) initialize_framework_settings +time_it(:initialize_framework_settings) initialize_framework_views +time_it(:initialize_framework_views) initialize_metal +time_it(:initialize_metal) add_support_load_paths +time_it(:add_support_load_paths) check_for_unbuilt_gems @@ -163,41 +199,54 @@ module Rails # pick up any gems that plugins depend on add_gem_load_paths +time_it(:add_gem_load_paths) load_gems check_gem_dependencies +time_it(:check_gem_dependencies) # bail out if gems are missing - note that check_gem_dependencies will have # already called abort() unless $gems_rake_task is set return unless gems_dependencies_loaded load_application_initializers +time_it(:load_application_initializers) # the framework is now fully initialized after_initialize +time_it(:after_initialize) # Setup database middleware after initializers have run initialize_database_middleware +time_it(:initialize_database_middleware) # Prepare dispatcher callbacks and run 'prepare' callbacks prepare_dispatcher +time_it(:prepare_dispatcher) # Routing must be initialized after plugins to allow the former to extend the routes initialize_routing +time_it(:initialize_routing) # Observers are loaded after plugins in case Observers or observed models are modified by plugins. load_observers +time_it(:load_observers) # Load view path cache load_view_paths +time_it(:load_view_paths) # Load application classes load_application_classes +time_it(:load_application_classes) # Disable dependency loading during request cycle disable_dependency_loading +time_it(:disable_dependency_loading) # Flag initialized Rails.initialized = true + +puts "total #{format("%.4f",@stat_total)}" if ENV['RAILS_VERBOSE_STARTUP'] end # Check for valid Ruby version @@ -264,7 +313,11 @@ module Rails # Action Pack, Action Mailer, and Active Resource) are loaded. def require_frameworks require 'active_support/all' - configuration.frameworks.each { |framework| require(framework.to_s) } + puts ' ============== REQUIRE FRAMEWORKS =================' if ENV['RAILS_VERBOSE_STARTUP'] + configuration.frameworks.each do |framework| + require(framework.to_s) + time_it(framework.to_s, true) + end rescue LoadError => e # Re-raise as RuntimeError because Mongrel would swallow LoadError. raise e.to_s @@ -304,8 +357,13 @@ module Rails end def load_gems - unless $gems_rake_task - @configuration.gems.each { |gem| gem.load } + unless $gems_build_rake_task + puts ' ============== GEMS =====================' if @first.nil? and ENV['RAILS_VERBOSE_STARTUP'] + @configuration.gems.each do |gem| + gem.load + time_it(gem.name, true) if @first.nil? + end + @first = :not_nill end end diff --git a/railties/lib/rails/plugin/loader.rb b/railties/lib/rails/plugin/loader.rb index bc22dfc..0d63cb7 100644 --- a/railties/lib/rails/plugin/loader.rb +++ b/railties/lib/rails/plugin/loader.rb @@ -33,10 +33,22 @@ module Rails @all_plugins end + def time_it(name) + return if not ENV['RAILS_VERBOSE_STARTUP'] + @stat_total ||= 0 + stat = 0.0 + stat = Time.now.to_f - @last_time if @last_time + @stat_total += stat + puts " #{name.to_s.rjust(31, ' ')} #{format("%.4f",stat)}" + @last_time = Time.now.to_f + end + def load_plugins + puts ' ============== PLUGINS ==================' if ENV['RAILS_VERBOSE_STARTUP'] plugins.each do |plugin| plugin.load(initializer) register_plugin_as_loaded(plugin) + time_it(plugin.name) end configure_engines -- 1.6.2.3