diff options
Diffstat (limited to 'actionpack')
| -rw-r--r-- | actionpack/lib/abstract_controller.rb | 1 | ||||
| -rw-r--r-- | actionpack/lib/abstract_controller/benchmarker.rb | 38 | ||||
| -rw-r--r-- | actionpack/lib/abstract_controller/logger.rb | 39 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/base.rb | 1 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/caching/fragments.rb | 32 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/caching/pages.rb | 20 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/dispatch/dispatcher.rb | 2 | ||||
| -rw-r--r-- | actionpack/lib/action_dispatch/middleware/callbacks.rb | 61 | ||||
| -rw-r--r-- | actionpack/lib/action_view/template/template.rb | 6 | ||||
| -rw-r--r-- | actionpack/test/controller/caching_test.rb | 11 | ||||
| -rw-r--r-- | actionpack/test/controller/dispatcher_test.rb | 18 |
11 files changed, 124 insertions, 105 deletions
diff --git a/actionpack/lib/abstract_controller.rb b/actionpack/lib/abstract_controller.rb index cdeb55b915..76c5845f5b 100644 --- a/actionpack/lib/abstract_controller.rb +++ b/actionpack/lib/abstract_controller.rb @@ -3,7 +3,6 @@ require "active_support/core_ext/module/delegation" module AbstractController autoload :Base, "abstract_controller/base" - autoload :Benchmarker, "abstract_controller/benchmarker" autoload :Callbacks, "abstract_controller/callbacks" autoload :Helpers, "abstract_controller/helpers" autoload :Layouts, "abstract_controller/layouts" diff --git a/actionpack/lib/abstract_controller/benchmarker.rb b/actionpack/lib/abstract_controller/benchmarker.rb deleted file mode 100644 index 58e9564c2f..0000000000 --- a/actionpack/lib/abstract_controller/benchmarker.rb +++ /dev/null @@ -1,38 +0,0 @@ -module AbstractController - module Benchmarker - extend ActiveSupport::Concern - - include Logger - - module ClassMethods - # Execute the passed in block, timing the duration of the block in ms. - # - # ==== Parameters - # title<#to_s>:: The title of block to benchmark - # log_level<Integer>:: A valid log level. Defaults to Logger::DEBUG - # use_silence<TrueClass, FalseClass>:: Whether or not to silence the - # logger for the duration of the block. - # - # ==== Returns - # Object:: The result of the block - def benchmark(title, log_level = ::Logger::DEBUG, use_silence = true) - if logger && logger.level >= log_level - result = nil - ms = Benchmark.ms { result = use_silence ? silence { yield } : yield } - logger.add(log_level, "#{title} (#{('%.1f' % ms)}ms)") - result - else - yield - end - end - - # Silences the logger for the duration of the block. - def silence - old_logger_level, logger.level = logger.level, ::Logger::ERROR if logger - yield - ensure - logger.level = old_logger_level if logger - end - end - end -end diff --git a/actionpack/lib/abstract_controller/logger.rb b/actionpack/lib/abstract_controller/logger.rb index 06b64d5cb2..f4d017b8e5 100644 --- a/actionpack/lib/abstract_controller/logger.rb +++ b/actionpack/lib/abstract_controller/logger.rb @@ -4,6 +4,26 @@ module AbstractController module Logger extend ActiveSupport::Concern + included do + cattr_accessor :logger + end + + module ClassMethods #:nodoc: + # Logs a message appending the value measured. + def log_with_time(message, time, log_level=::Logger::DEBUG) + return unless logger && logger.level >= log_level + logger.add(log_level, "#{message} (%.1fms)" % time) + end + + # Silences the logger for the duration of the block. + def silence + old_logger_level, logger.level = logger.level, ::Logger::ERROR if logge + yield + ensure + logger.level = old_logger_level if logger + end + end + # A class that allows you to defer expensive processing # until the logger actually tries to log. Otherwise, you are # forced to do the processing in advance, and send the @@ -24,32 +44,31 @@ module AbstractController end end - included do - cattr_accessor :logger - end - # Override process_action in the AbstractController::Base # to log details about the method. def process_action(action) - retval = super + event = ActiveSupport::Orchestra.instrument(:process_action, + :controller => self, :action => action) do + super + end if logger log = DelayedLog.new do "\n\nProcessing #{self.class.name}\##{action_name} " \ - "to #{request.formats} " \ - "(for #{request_origin}) [#{request.method.to_s.upcase}]" + "to #{request.formats} (for #{request_origin}) " \ + "(%.1fms) [#{request.method.to_s.upcase}]" % event.duration end logger.info(log) end - retval + event.result end private + # Returns the request origin with the IP and time. This needs to be cached, + # otherwise we would get different results for each time it calls. def request_origin - # this *needs* to be cached! - # otherwise you'd get different results if calling it more than once @request_origin ||= "#{request.remote_ip} at #{Time.now.to_s(:db)}" end end diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb index 0dae68c7b7..f5bd0a00a1 100644 --- a/actionpack/lib/action_controller/base.rb +++ b/actionpack/lib/action_controller/base.rb @@ -2,7 +2,6 @@ module ActionController class Base < Metal abstract! - include AbstractController::Benchmarker include AbstractController::Callbacks include AbstractController::Logger diff --git a/actionpack/lib/action_controller/caching/fragments.rb b/actionpack/lib/action_controller/caching/fragments.rb index 4ef600bea0..59e24619e3 100644 --- a/actionpack/lib/action_controller/caching/fragments.rb +++ b/actionpack/lib/action_controller/caching/fragments.rb @@ -53,11 +53,11 @@ module ActionController #:nodoc: return content unless cache_configured? key = fragment_cache_key(key) - - self.class.benchmark "Cached fragment miss: #{key}" do + event = ActiveSupport::Orchestra.instrument(:write_fragment, :key => key) do cache_store.write(key, content, options) end + self.class.log_with_time("Cached fragment miss: #{key}", event.duration) content end @@ -66,10 +66,12 @@ module ActionController #:nodoc: return unless cache_configured? key = fragment_cache_key(key) - - self.class.benchmark "Cached fragment hit: #{key}" do + event = ActiveSupport::Orchestra.instrument(:read_fragment, :key => key) do cache_store.read(key, options) end + + self.class.log_with_time("Cached fragment hit: #{key}", event.duration) + event.result end # Check if a cached fragment from the location signified by <tt>key</tt> exists (see <tt>expire_fragment</tt> for acceptable formats) @@ -77,10 +79,12 @@ module ActionController #:nodoc: return unless cache_configured? key = fragment_cache_key(key) - - self.class.benchmark "Cached fragment exists?: #{key}" do + event = ActiveSupport::Orchestra.instrument(:fragment_exist?, :key => key) do cache_store.exist?(key, options) end + + self.class.log_with_time("Cached fragment exists?: #{key}", event.duration) + event.result end # Removes fragments from the cache. @@ -103,17 +107,21 @@ module ActionController #:nodoc: def expire_fragment(key, options = nil) return unless cache_configured? - key = key.is_a?(Regexp) ? key : fragment_cache_key(key) + key = fragment_cache_key(key) unless key.is_a?(Regexp) + message = nil - if key.is_a?(Regexp) - self.class.benchmark "Expired fragments matching: #{key.source}" do + event = ActiveSupport::Orchestra.instrument(:expire_fragment, :key => key) do + if key.is_a?(Regexp) + message = "Expired fragments matching: #{key.source}" cache_store.delete_matched(key, options) - end - else - self.class.benchmark "Expired fragment: #{key}" do + else + message = "Expired fragment: #{key}" cache_store.delete(key, options) end end + + self.class.log_with_time(message, event.duration) + event.result end end end diff --git a/actionpack/lib/action_controller/caching/pages.rb b/actionpack/lib/action_controller/caching/pages.rb index bd3b5a5875..4fb154470f 100644 --- a/actionpack/lib/action_controller/caching/pages.rb +++ b/actionpack/lib/action_controller/caching/pages.rb @@ -62,21 +62,29 @@ module ActionController #:nodoc: # expire_page "/lists/show" def expire_page(path) return unless perform_caching + path = page_cache_path(path) - benchmark "Expired page: #{page_cache_file(path)}" do - File.delete(page_cache_path(path)) if File.exist?(page_cache_path(path)) + event = ActiveSupport::Orchestra.instrument(:expire_page, :path => path) do + File.delete(path) if File.exist?(path) end + + log_with_time("Expired page: #{path}", event.duration) + event.result end # Manually cache the +content+ in the key determined by +path+. Example: # cache_page "I'm the cached content", "/lists/show" def cache_page(content, path) return unless perform_caching + path = page_cache_path(path) - benchmark "Cached page: #{page_cache_file(path)}" do - FileUtils.makedirs(File.dirname(page_cache_path(path))) - File.open(page_cache_path(path), "wb+") { |f| f.write(content) } + event = ActiveSupport::Orchestra.instrument(:cache_page, :path => path) do + FileUtils.makedirs(File.dirname(path)) + File.open(path, "wb+") { |f| f.write(content) } end + + log_with_time("Cached page: #{path}", event.duration) + event.result end # Caches the +actions+ using the page-caching approach that'll store the cache in a path within the page_cache_directory that @@ -149,4 +157,4 @@ module ActionController #:nodoc: end end end -end
\ No newline at end of file +end diff --git a/actionpack/lib/action_controller/dispatch/dispatcher.rb b/actionpack/lib/action_controller/dispatch/dispatcher.rb index 9ad1cadfd3..ba316b9e63 100644 --- a/actionpack/lib/action_controller/dispatch/dispatcher.rb +++ b/actionpack/lib/action_controller/dispatch/dispatcher.rb @@ -54,7 +54,7 @@ module ActionController end end - delegate :to_prepare, :prepare_dispatch, :before_dispatch, :after_dispatch, + delegate :to_prepare, :before_dispatch, :around_dispatch, :after_dispatch, :to => ActionDispatch::Callbacks def new diff --git a/actionpack/lib/action_dispatch/middleware/callbacks.rb b/actionpack/lib/action_dispatch/middleware/callbacks.rb index 0a2b4cf5f7..2f86a382c2 100644 --- a/actionpack/lib/action_dispatch/middleware/callbacks.rb +++ b/actionpack/lib/action_dispatch/middleware/callbacks.rb @@ -1,40 +1,55 @@ module ActionDispatch class Callbacks - include ActiveSupport::Callbacks - define_callbacks :prepare, :before, :after + include ActiveSupport::NewCallbacks + + define_callbacks :call, :terminator => "result == false", :scope => :kind + define_callbacks :prepare, :scope => :name + + # Add a preparation callback. Preparation callbacks are run before every + # request in development mode, and before the first request in production mode. + # + # If a symbol with a block is given, the symbol is used as an identifier. + # That allows to_prepare to be called again with the same identifier to + # replace the existing callback. Passing an identifier is a suggested + # practice if the code adding a preparation block may be reloaded. + def self.to_prepare(*args, &block) + if args.first.is_a?(Symbol) && block_given? + define_method :"__#{args.first}", &block + set_callback(:prepare, :"__#{args.first}") + else + set_callback(:prepare, *args, &block) + end + end + + def self.before(*args, &block) + set_callback(:call, :before, *args, &block) + end + + def self.around(*args, &block) + set_callback(:call, :around, *args, &block) + end + + def self.after(*args, &block) + set_callback(:call, :after, *args, &block) + end class << self # DEPRECATED - alias_method :prepare_dispatch, :prepare alias_method :before_dispatch, :before + alias_method :around_dispatch, :around alias_method :after_dispatch, :after end - # Add a preparation callback. Preparation callbacks are run before every - # request in development mode, and before the first request in production - # mode. - # - # An optional identifier may be supplied for the callback. If provided, - # to_prepare may be called again with the same identifier to replace the - # existing callback. Passing an identifier is a suggested practice if the - # code adding a preparation block may be reloaded. - def self.to_prepare(identifier = nil, &block) - @prepare_callbacks ||= ActiveSupport::Callbacks::CallbackChain.new - callback = ActiveSupport::Callbacks::Callback.new(:prepare, block, :identifier => identifier) - @prepare_callbacks.replace_or_append!(callback) - end - def initialize(app, prepare_each_request = false) @app, @prepare_each_request = app, prepare_each_request - run_callbacks :prepare + _run_prepare_callbacks end def call(env) - run_callbacks :before - run_callbacks :prepare if @prepare_each_request - @app.call(env) - ensure - run_callbacks :after, :enumerator => :reverse_each + _run_call_callbacks do + _run_prepare_callbacks if @prepare_each_request + @app.call(env) + end end end end diff --git a/actionpack/lib/action_view/template/template.rb b/actionpack/lib/action_view/template/template.rb index 7d6964e3e3..80c1bab7d5 100644 --- a/actionpack/lib/action_view/template/template.rb +++ b/actionpack/lib/action_view/template/template.rb @@ -27,8 +27,10 @@ module ActionView end def render(view, locals, &block) - method_name = compile(locals, view) - view.send(method_name, locals, &block) + ActiveSupport::Orchestra.instrument(:render_template, :identifier => identifier) do + method_name = compile(locals, view) + view.send(method_name, locals, &block) + end.result rescue Exception => e if e.is_a?(TemplateError) e.sub_template_of(self) diff --git a/actionpack/test/controller/caching_test.rb b/actionpack/test/controller/caching_test.rb index 25e035cb49..bd17df73c7 100644 --- a/actionpack/test/controller/caching_test.rb +++ b/actionpack/test/controller/caching_test.rb @@ -625,15 +625,20 @@ class FragmentCachingTest < ActionController::TestCase def test_fragment_for_logging fragment_computed = false - @controller.class.expects(:benchmark).with('Cached fragment exists?: views/expensive') - @controller.class.expects(:benchmark).with('Cached fragment miss: views/expensive') - @controller.class.expects(:benchmark).with('Cached fragment hit: views/expensive').never + listener = [] + ActiveSupport::Orchestra.register listener buffer = 'generated till now -> ' @controller.fragment_for(buffer, 'expensive') { fragment_computed = true } + assert_equal 2, listener.size + assert_equal :fragment_exist?, listener[0].name + assert_equal :write_fragment, listener[1].name + assert fragment_computed assert_equal 'generated till now -> ', buffer + ensure + ActiveSupport::Orchestra.unregister listener end end diff --git a/actionpack/test/controller/dispatcher_test.rb b/actionpack/test/controller/dispatcher_test.rb index 9fae1fcf63..150fc83cde 100644 --- a/actionpack/test/controller/dispatcher_test.rb +++ b/actionpack/test/controller/dispatcher_test.rb @@ -3,13 +3,16 @@ require 'abstract_unit' class DispatcherTest < Test::Unit::TestCase Dispatcher = ActionController::Dispatcher + class Foo + cattr_accessor :a, :b + end + def setup ENV['REQUEST_METHOD'] = 'GET' # Clear callbacks as they are redefined by Dispatcher#define_dispatcher_callbacks - ActionDispatch::Callbacks.instance_variable_set("@prepare_callbacks", ActiveSupport::Callbacks::CallbackChain.new) - ActionDispatch::Callbacks.instance_variable_set("@before_callbacks", ActiveSupport::Callbacks::CallbackChain.new) - ActionDispatch::Callbacks.instance_variable_set("@after_callbacks", ActiveSupport::Callbacks::CallbackChain.new) + ActionDispatch::Callbacks.reset_callbacks(:prepare) + ActionDispatch::Callbacks.reset_callbacks(:call) @old_router, Dispatcher.router = Dispatcher.router, mock() Dispatcher.router.stubs(:call).returns([200, {}, 'response']) @@ -68,13 +71,12 @@ class DispatcherTest < Test::Unit::TestCase end def test_to_prepare_with_identifier_replaces - a = b = nil - Dispatcher.to_prepare(:unique_id) { |*args| a = b = 1 } - Dispatcher.to_prepare(:unique_id) { |*args| a = 2 } + Dispatcher.to_prepare(:unique_id) { |*args| Foo.a, Foo.b = 1, 1 } + Dispatcher.to_prepare(:unique_id) { |*args| Foo.a = 2 } dispatch - assert_equal 2, a - assert_equal nil, b + assert_equal 2, Foo.a + assert_equal nil, Foo.b end private |