diff options
34 files changed, 382 insertions, 316 deletions
diff --git a/actionpack/lib/abstract_controller/logger.rb b/actionpack/lib/abstract_controller/logger.rb index e3bcd28da7..a23a13e1d6 100644 --- a/actionpack/lib/abstract_controller/logger.rb +++ b/actionpack/lib/abstract_controller/logger.rb @@ -9,25 +9,5 @@ module AbstractController cattr_accessor :logger extend ActiveSupport::Benchmarkable 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 - # entire processed String to the logger, which might - # just discard the String if the log level is too low. - # - # TODO: Require that Rails loggers accept a block. - class DelayedLog < ActiveSupport::BasicObject - def initialize(&block) - @str, @block = nil, block - end - - def method_missing(*args, &block) - unless @str - @str, @block = @block.call, nil - end - @str.send(*args, &block) - end - end end end diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb index dbba69f637..67656110c4 100644 --- a/actionpack/lib/action_controller/base.rb +++ b/actionpack/lib/action_controller/base.rb @@ -15,7 +15,6 @@ module ActionController include ActionController::ConditionalGet include ActionController::RackDelegation include ActionController::Logger - include ActionController::Benchmarking include ActionController::Configuration # Legacy modules diff --git a/actionpack/lib/action_controller/caching.rb b/actionpack/lib/action_controller/caching.rb index d784138ebe..69ed84da95 100644 --- a/actionpack/lib/action_controller/caching.rb +++ b/actionpack/lib/action_controller/caching.rb @@ -60,6 +60,17 @@ module ActionController #:nodoc: def cache_configured? perform_caching && cache_store end + + def log_event(name, before, after, instrumenter_id, payload) + if name.to_s =~ /(read|write|cache|expire|exist)_(fragment|page)\??/ + key_or_path = payload[:key] || payload[:path] + human_name = name.to_s.humanize + duration = (after - before) * 1000 + logger.info("#{human_name} #{key_or_path.inspect} (%.1fms)" % duration) + else + super + end + end end def caching_allowed? diff --git a/actionpack/lib/action_controller/caching/fragments.rb b/actionpack/lib/action_controller/caching/fragments.rb index 8c1167d526..f569d0dd8b 100644 --- a/actionpack/lib/action_controller/caching/fragments.rb +++ b/actionpack/lib/action_controller/caching/fragments.rb @@ -74,7 +74,7 @@ module ActionController #:nodoc: return unless cache_configured? key = fragment_cache_key(key) - ActiveSupport::Notifications.instrument(:fragment_exist?, :key => key) do + ActiveSupport::Notifications.instrument(:exist_fragment?, :key => key) do cache_store.exist?(key, options) end end diff --git a/actionpack/lib/action_controller/metal/benchmarking.rb b/actionpack/lib/action_controller/metal/benchmarking.rb deleted file mode 100644 index f73f635b0d..0000000000 --- a/actionpack/lib/action_controller/metal/benchmarking.rb +++ /dev/null @@ -1,72 +0,0 @@ -require 'active_support/core_ext/benchmark' - -module ActionController #:nodoc: - # The benchmarking module times the performance of actions and reports to the logger. If the Active Record - # package has been included, a separate timing section for database calls will be added as well. - module Benchmarking #:nodoc: - extend ActiveSupport::Concern - - protected - def render(*args, &block) - if logger - if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - db_runtime = ActiveRecord::Base.connection.reset_runtime - end - - render_output = nil - @view_runtime = Benchmark.ms { render_output = super } - - if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - @db_rt_before_render = db_runtime - @db_rt_after_render = ActiveRecord::Base.connection.reset_runtime - @view_runtime -= @db_rt_after_render - end - - render_output - else - super - end - end - - private - def process_action(*args) - if logger - ms = [Benchmark.ms { super }, 0.01].max - logging_view = defined?(@view_runtime) - logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - - log_message = 'Completed in %.0fms' % ms - - if logging_view || logging_active_record - log_message << " (" - log_message << view_runtime if logging_view - - if logging_active_record - log_message << ", " if logging_view - log_message << active_record_runtime + ")" - else - ")" - end - end - - log_message << " | #{response.status}" - log_message << " [#{complete_request_uri rescue "unknown"}]" - - logger.info(log_message) - else - super - end - end - - def view_runtime - "View: %.0f" % @view_runtime - end - - def active_record_runtime - db_runtime = ActiveRecord::Base.connection.reset_runtime - db_runtime += @db_rt_before_render if @db_rt_before_render - db_runtime += @db_rt_after_render if @db_rt_after_render - "DB: %.0f" % db_runtime - end - end -end diff --git a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb index a53c052075..59e200396a 100644 --- a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb +++ b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb @@ -2,8 +2,6 @@ module ActionController module FilterParameterLogging extend ActiveSupport::Concern - include AbstractController::Logger - module ClassMethods # Replace sensitive parameter data from the request log. # Filters parameters that have any of the arguments as a substring. @@ -54,23 +52,25 @@ module ActionController end protected :filter_parameters end - end - INTERNAL_PARAMS = [:controller, :action, :format, :_method, :only_path] + protected - def process(*) - response = super - if logger - parameters = filter_parameters(params).except!(*INTERNAL_PARAMS) - logger.info { " Parameters: #{parameters.inspect}" } unless parameters.empty? + # Overwrite log_process_action to include parameters information. + # If this method is invoked, it means logger is defined, so don't + # worry with such scenario here. + def log_process_action(controller) #:nodoc: + params = controller.send(:filter_parameters, controller.request.params) + logger.info " Parameters: #{params.inspect}" unless params.empty? + super end - response end + INTERNAL_PARAMS = [:controller, :action, :format, :_method, :only_path] + protected def filter_parameters(params) - params.dup + params.dup.except!(*INTERNAL_PARAMS) end end diff --git a/actionpack/lib/action_controller/metal/logger.rb b/actionpack/lib/action_controller/metal/logger.rb index 956d7dd371..e71f77fbb2 100644 --- a/actionpack/lib/action_controller/metal/logger.rb +++ b/actionpack/lib/action_controller/metal/logger.rb @@ -1,34 +1,85 @@ require 'abstract_controller/logger' module ActionController + # Adds instrumentation to <tt>process_action</tt> and a <tt>log_event</tt> method + # responsible to log events from ActiveSupport::Notifications. This module handles + # :process_action and :render_template events but allows any other module to hook + # into log_event and provide its own logging facilities (as in ActionController::Caching). module Logger - # Override process_action in the AbstractController::Base - # to log details about the method. + extend ActiveSupport::Concern + + attr_internal :view_runtime + def process_action(action) - result = ActiveSupport::Notifications.instrument(:process_action, - :controller => self, :action => action) do + ActiveSupport::Notifications.instrument(:process_action, :controller => self, :action => action) do super end + end + def render(*args, &block) if logger - log = AbstractController::Logger::DelayedLog.new do - "\n\nProcessing #{self.class.name}\##{action_name} " \ - "to #{request.formats} (for #{request_origin}) " \ - "[#{request.method.to_s.upcase}]" + render_output = nil + + self.view_runtime = cleanup_view_runtime do + Benchmark.ms { render_output = super } end - logger.info(log) + render_output + else + super end + end - result + # If you want to remove any time taken into account in :view_runtime + # wrongly, you can do it here: + # + # def cleanup_view_runtime + # super - time_taken_in_something_expensive + # end + # + # :api: plugin + def cleanup_view_runtime #:nodoc: + yield end - private + module ClassMethods + # This is the hook invoked by ActiveSupport::Notifications.subscribe. + # If you need to log any event, overwrite the method and do it here. + def log_event(name, before, after, instrumenter_id, payload) #:nodoc: + if name == :process_action + duration = [(after - before) * 1000, 0.01].max + controller = payload[:controller] + request = controller.request + + logger.info "\n\nProcessed #{controller.class.name}##{payload[:action]} " \ + "to #{request.formats} (for #{request.remote_ip} at #{before.to_s(:db)}) " \ + "[#{request.method.to_s.upcase}]" - # 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 - @request_origin ||= "#{request.remote_ip} at #{Time.now.to_s(:db)}" + log_process_action(controller) + + message = "Completed in %.0fms" % duration + message << " | #{controller.response.status}" + message << " [#{request.request_uri rescue "unknown"}]" + + logger.info(message) + elsif name == :render_template + # TODO Make render_template logging work if you are using just ActionView + duration = (after - before) * 1000 + message = "Rendered #{payload[:identifier]}" + message << " within #{payload[:layout]}" if payload[:layout] + message << (" (%.1fms)" % duration) + logger.info(message) + end + end + + protected + + # A hook which allows logging what happened during controller process action. + # :api: plugin + def log_process_action(controller) #:nodoc: + view_runtime = controller.send :view_runtime + logger.info(" View runtime: %.1fms" % view_runtime.to_f) if view_runtime + end end end -end +end
\ No newline at end of file diff --git a/actionpack/lib/action_controller/rails.rb b/actionpack/lib/action_controller/rails.rb index 36a52b3149..6ebb50887b 100644 --- a/actionpack/lib/action_controller/rails.rb +++ b/actionpack/lib/action_controller/rails.rb @@ -1,6 +1,7 @@ module ActionController class Plugin < Rails::Plugin plugin_name :action_controller + include_modules_in "ActionController::Base" initializer "action_controller.set_configs" do |app| app.config.action_controller.each do |k,v| @@ -14,10 +15,6 @@ module ActionController end # Routing must be initialized after plugins to allow the former to extend the routes - # --- - # If Action Controller is not one of the loaded frameworks (Configuration#frameworks) - # this does nothing. Otherwise, it loads the routing definitions and sets up - # loading module used to lazily load controllers (Configuration#controller_paths). initializer "action_controller.initialize_routing" do |app| app.route_configuration_files << app.config.routes_configuration_file app.route_configuration_files << app.config.builtin_routes_configuration_file @@ -88,13 +85,8 @@ module ActionController initializer "action_controller.notifications" do |app| require 'active_support/notifications' - ActiveSupport::Notifications.subscribe(/(read|write|cache|expire|exist)_(fragment|page)\??/) do |*args| - event = ActiveSupport::Notifications::Event.new(*args) - - if logger = ActionController::Base.logger - human_name = event.name.to_s.humanize - logger.info("#{human_name} (%.1fms)" % event.duration) - end + ActiveSupport::Notifications.subscribe do |*args| + ActionController::Base.log_event(*args) if ActionController::Base.logger end end diff --git a/actionpack/lib/action_view/render/partials.rb b/actionpack/lib/action_view/render/partials.rb index aeaf1ee4ff..5158415c20 100644 --- a/actionpack/lib/action_view/render/partials.rb +++ b/actionpack/lib/action_view/render/partials.rb @@ -191,45 +191,60 @@ module ActionView def setup(options, block) partial = options[:partial] - @options = options - @locals = options[:locals] || {} - @block = block + @options = options + @locals = options[:locals] || {} + @block = block if String === partial - @object = options[:object] - @path = partial + @object = options[:object] + @path = partial + @collection = collection else @object = partial - @path = partial_path(partial) + + if @collection = collection + paths = @collection_paths = @collection.map { |o| partial_path(o) } + @path = paths.uniq.size == 1 ? paths.first : nil + else + @path = partial_path + end end end def render - if @collection = collection - render_collection + options = @options + + if @collection + ActiveSupport::Notifications.instrument(:render_collection, :path => @path, + :count => @collection.size) do + render_collection + end else - @template = template = find_template - render_template(template, @object || @locals[template.variable_name]) + content = ActiveSupport::Notifications.instrument(:render_partial, :path => @path) do + render_partial + end + + if !@block && options[:layout] + content = @view._render_layout(find_template(options[:layout]), @locals){ content } + end + content end end def render_collection @template = template = find_template - return nil if @collection.blank? if @options.key?(:spacer_template) spacer = find_template(@options[:spacer_template]).render(@view, @locals) end - result = template ? collection_with_template(template) : collection_without_template + result = template ? collection_with_template : collection_without_template result.join(spacer).html_safe! end - def collection_with_template(template) - options = @options - - segments, locals, as = [], @locals, options[:as] || template.variable_name + def collection_with_template(template = @template) + segments, locals, as = [], @locals, @options[:as] || template.variable_name counter_name = template.counter_name locals[counter_name] = -1 @@ -245,16 +260,14 @@ module ActionView segments end - def collection_without_template - options = @options - - segments, locals, as = [], @locals, options[:as] + def collection_without_template(collection_paths = @collection_paths) + segments, locals, as = [], @locals, @options[:as] index, template = -1, nil - @collection.each do |object| - template = find_template(partial_path(object)) + @collection.each_with_index do |object, i| + template = find_template(collection_paths[i]) locals[template.counter_name] = (index += 1) - locals[template.variable_name] = object + locals[as || template.variable_name] = object segments << template.render(@view, locals) end @@ -263,18 +276,15 @@ module ActionView segments end - def render_template(template, object = @object) - options, locals, view = @options, @locals, @view - locals[options[:as] || template.variable_name] = object + def render_partial(object = @object) + @template = template = find_template + locals, view = @locals, @view - content = template.render(view, locals) do |*name| - @view._layout_for(*name, &@block) - end + object ||= locals[template.variable_name] + locals[@options[:as] || template.variable_name] = object - if @block || !options[:layout] - content - else - find_template(options[:layout]).render(@view, @locals) { content } + template.render(view, locals) do |*name| + view._layout_for(*name, &@block) end end @@ -305,9 +315,9 @@ module ActionView def partial_path(object = @object) @partial_names[object.class] ||= begin - return nil unless object.respond_to?(:to_model) + object = object.to_model if object.respond_to?(:to_model) - object.to_model.class.model_name.partial_path.dup.tap do |partial| + object.class.model_name.partial_path.dup.tap do |partial| path = @view.controller_path partial.insert(0, "#{File.dirname(path)}/") if path.include?(?/) end diff --git a/actionpack/lib/action_view/render/rendering.rb b/actionpack/lib/action_view/render/rendering.rb index d4d16b4d98..0302e44b4e 100644 --- a/actionpack/lib/action_view/render/rendering.rb +++ b/actionpack/lib/action_view/render/rendering.rb @@ -73,25 +73,24 @@ module ActionView # would be <html>Hello David</html>. def _layout_for(name = nil, &block) return @_content_for[name || :layout] if !block_given? || name - capture(&block) end def _render_inline(inline, layout, options) - handler = Template.handler_class_for_extension(options[:type] || "erb") - template = Template.new(options[:inline], "inline template", handler, {}) + locals = options[:locals] - locals = options[:locals] - content = template.render(self, locals) + content = ActiveSupport::Notifications.instrument(:render_inline) do + handler = Template.handler_class_for_extension(options[:type] || "erb") + template = Template.new(options[:inline], "inline template", handler, {}) + template.render(self, locals) + end _render_text(content, layout, locals) end def _render_text(content, layout, locals) - content = layout.render(self, locals) do |*name| - _layout_for(*name) { content } - end if layout - + ActiveSupport::Notifications.instrument(:render_text) + content = _render_layout(layout, locals){ content } if layout content end @@ -108,23 +107,27 @@ module ActionView end def _render_template(template, layout = nil, options = {}, partial = nil) - logger && logger.info do - msg = "Rendering #{template.inspect}" - msg << " (#{options[:status]})" if options[:status] - msg + locals = options[:locals] || {} + + content = ActiveSupport::Notifications.instrument(:render_template, + :identifier => template.identifier, :layout => (layout ? layout.identifier : nil)) do + partial ? _render_partial_object(template, options) : template.render(self, locals) end - locals = options[:locals] || {} - content = partial ? _render_partial_object(template, options) : template.render(self, locals) @_content_for[:layout] = content if layout @_layout = layout.identifier - logger.info("Rendering template within #{layout.inspect}") if logger - content = layout.render(self, locals) { |*name| _layout_for(*name) } + content = _render_layout(layout, locals) end content end + + def _render_layout(layout, locals, &block) + ActiveSupport::Notifications.instrument(:render_layout, :identifier => layout.identifier) do + layout.render(self, locals){ |*name| _layout_for(*name, &block) } + end + end end end diff --git a/actionpack/lib/action_view/template.rb b/actionpack/lib/action_view/template.rb index d46c989d11..adaf6544a7 100644 --- a/actionpack/lib/action_view/template.rb +++ b/actionpack/lib/action_view/template.rb @@ -36,10 +36,8 @@ module ActionView end def render(view, locals, &block) - ActiveSupport::Notifications.instrument(:render_template, :identifier => identifier) do - method_name = compile(locals, view) - view.send(method_name, locals, &block) - end + method_name = compile(locals, view) + view.send(method_name, locals, &block) rescue Exception => e if e.is_a?(Template::Error) e.sub_template_of(self) diff --git a/actionpack/test/abstract_unit.rb b/actionpack/test/abstract_unit.rb index a9341b60df..8c65087898 100644 --- a/actionpack/test/abstract_unit.rb +++ b/actionpack/test/abstract_unit.rb @@ -50,6 +50,14 @@ ORIGINAL_LOCALES = I18n.available_locales.map {|locale| locale.to_s }.sort FIXTURE_LOAD_PATH = File.join(File.dirname(__FILE__), 'fixtures') FIXTURES = Pathname.new(FIXTURE_LOAD_PATH) +# Turn on notifications +require 'active_support/notifications' +Thread.abort_on_exception = true + +ActiveSupport::Notifications.subscribe do |*args| + ActionController::Base.log_event(*args) if ActionController::Base.logger +end + module SetupOnce extend ActiveSupport::Concern @@ -87,6 +95,21 @@ class ActiveSupport::TestCase end end +class MockLogger + attr_reader :logged + attr_accessor :level + + def initialize + @level = Logger::DEBUG + @logged = [] + end + + def method_missing(method, *args, &blk) + @logged << args.first + @logged << blk.call if block_given? + end +end + class ActionController::IntegrationTest < ActiveSupport::TestCase def self.build_app(routes = nil) ActionDispatch::MiddlewareStack.new { |middleware| diff --git a/actionpack/test/controller/base_test.rb b/actionpack/test/controller/base_test.rb index 8f8ada8d8c..65118f9bc9 100644 --- a/actionpack/test/controller/base_test.rb +++ b/actionpack/test/controller/base_test.rb @@ -158,13 +158,6 @@ class PerformActionTest < ActionController::TestCase assert_raise(ActionController::UnknownAction) { get :hidden_action } assert_raise(ActionController::UnknownAction) { get :another_hidden_action } end - - def test_namespaced_action_should_log_module_name - use_controller Submodule::ContainedNonEmptyController - @controller.logger = MockLogger.new - get :public_action - assert_match /Processing\sSubmodule::ContainedNonEmptyController#public_action/, @controller.logger.logged[1] - end end class DefaultUrlOptionsTest < ActionController::TestCase diff --git a/actionpack/test/controller/benchmark_test.rb b/actionpack/test/controller/benchmark_test.rb deleted file mode 100644 index 66ebfcf20a..0000000000 --- a/actionpack/test/controller/benchmark_test.rb +++ /dev/null @@ -1,33 +0,0 @@ -require 'abstract_unit' - -# Provide some static controllers. -class BenchmarkedController < ActionController::Base - def public_action - render :nothing => true - end - - def rescue_action(e) - raise e - end -end - -class BenchmarkTest < ActionController::TestCase - tests BenchmarkedController - - class MockLogger - def method_missing(*args) - end - end - - def setup - super - # benchmark doesn't do anything unless a logger is set - @controller.logger = MockLogger.new - @request.host = "test.actioncontroller.i" - end - - def test_with_http_1_0_request - @request.host = nil - assert_nothing_raised { get :public_action } - end -end diff --git a/actionpack/test/controller/caching_test.rb b/actionpack/test/controller/caching_test.rb index 4ea2e57741..679eaf7b38 100644 --- a/actionpack/test/controller/caching_test.rb +++ b/actionpack/test/controller/caching_test.rb @@ -640,7 +640,7 @@ class FragmentCachingTest < ActionController::TestCase assert fragment_computed assert_equal 'generated till now -> ', buffer ActiveSupport::Notifications.notifier.wait - assert_equal [:fragment_exist?, :write_fragment], events.map(&:first) + assert_equal [:exist_fragment?, :write_fragment], events.map(&:first) end end diff --git a/actionpack/test/controller/filter_params_test.rb b/actionpack/test/controller/filter_params_test.rb index 43bef34885..420ebeacf4 100644 --- a/actionpack/test/controller/filter_params_test.rb +++ b/actionpack/test/controller/filter_params_test.rb @@ -70,9 +70,9 @@ class FilterParamTest < ActionController::TestCase FilterParamController.filter_parameter_logging(:lifo, :amount) get :payment, :lifo => 'Pratik', :amount => '420', :step => '1' + ActiveSupport::Notifications.notifier.wait filtered_params_logs = logs.detect {|l| l =~ /\AParameters/ } - assert filtered_params_logs.index('"amount"=>"[FILTERED]"') assert filtered_params_logs.index('"lifo"=>"[FILTERED]"') assert filtered_params_logs.index('"step"=>"1"') diff --git a/actionpack/test/controller/logging_test.rb b/actionpack/test/controller/logging_test.rb index 2b5e8d8bde..4206dffa7e 100644 --- a/actionpack/test/controller/logging_test.rb +++ b/actionpack/test/controller/logging_test.rb @@ -1,48 +1,74 @@ require 'abstract_unit' -class LoggingController < ActionController::Base - def show - render :nothing => true - end -end - -class LoggingTest < ActionController::TestCase - tests LoggingController - - class MockLogger - attr_reader :logged - attr_accessor :level +module Another + class LoggingController < ActionController::Base + layout "layouts/standard" - def initialize - @level = Logger::DEBUG + def show + render :nothing => true end - def method_missing(method, *args, &blk) - @logged ||= [] - @logged << args.first - @logged << blk.call if block_given? + def with_layout + render :template => "test/hello_world", :layout => true end end +end + +class LoggingTest < ActionController::TestCase + tests Another::LoggingController def setup super set_logger end + def get(*args) + super + wait + end + + def wait + ActiveSupport::Notifications.notifier.wait + end + def test_logging_without_parameters get :show - assert_equal 3, logs.size + assert_equal 4, logs.size assert_nil logs.detect {|l| l =~ /Parameters/ } end def test_logging_with_parameters get :show, :id => '10' - assert_equal 4, logs.size + assert_equal 5, logs.size params = logs.detect {|l| l =~ /Parameters/ } assert_equal 'Parameters: {"id"=>"10"}', params end + def test_log_controller_with_namespace_and_action + get :show + assert_match /Processed\sAnother::LoggingController#show/, logs[1] + end + + def test_log_view_runtime + get :show + assert_match /View runtime/, logs[2] + end + + def test_log_completed_status_and_request_uri + get :show + last = logs.last + assert_match /Completed/, last + assert_match /200/, last + assert_match /another\/logging\/show/, last + end + + def test_logger_prints_layout_and_template_rendering_info + get :with_layout + logged = logs.find {|l| l =~ /render/i } + assert_match /Rendered (.*)test\/hello_world.erb within (.*)layouts\/standard.html.erb/, logged + end + private def set_logger @controller.logger = MockLogger.new diff --git a/actionpack/test/controller/render_test.rb b/actionpack/test/controller/render_test.rb index 54f2739d38..2c3dc2a72d 100644 --- a/actionpack/test/controller/render_test.rb +++ b/actionpack/test/controller/render_test.rb @@ -10,19 +10,6 @@ module Fun end end -class MockLogger - attr_reader :logged - - def initialize - @logged = [] - end - - def method_missing(method, *args, &blk) - @logged << args.first - @logged << blk.call if block_given? - end -end - class TestController < ActionController::Base protect_from_forgery @@ -1500,21 +1487,4 @@ class LastModifiedRenderTest < ActionController::TestCase get :conditional_hello_with_bangs assert_response :success end -end - -class RenderingLoggingTest < ActionController::TestCase - tests TestController - - def setup - super - @request.host = "www.nextangle.com" - end - - def test_logger_prints_layout_and_template_rendering_info - @controller.logger = MockLogger.new - get :layout_test - logged = @controller.logger.logged.find_all {|l| l =~ /render/i } - assert logged[0] =~ %r{Rendering.*test/hello_world} - assert logged[1] =~ %r{Rendering template within.*layouts/standard} - end -end +end
\ No newline at end of file diff --git a/activerecord/CHANGELOG b/activerecord/CHANGELOG index 4daeb6a302..3f4d77979b 100644 --- a/activerecord/CHANGELOG +++ b/activerecord/CHANGELOG @@ -1,5 +1,10 @@ *Edge* +* Add Model.from and association_collection#from finder methods [Pratik Naik] + + user = User.scoped + user.select('*').from('users, items') + * Add relation.destroy_all [Pratik Naik] old_items = Item.where("age > 100") diff --git a/activerecord/lib/active_record.rb b/activerecord/lib/active_record.rb index 196b87c0ac..2cfd528f2c 100644 --- a/activerecord/lib/active_record.rb +++ b/activerecord/lib/active_record.rb @@ -52,6 +52,7 @@ module ActiveRecord autoload :Batches autoload :Calculations autoload :Callbacks + autoload :ControllerRuntime autoload :DynamicFinderMatch autoload :DynamicScopeMatch autoload :Migration diff --git a/activerecord/lib/active_record/associations.rb b/activerecord/lib/active_record/associations.rb index 2735bc5141..c23c9f63f1 100755 --- a/activerecord/lib/active_record/associations.rb +++ b/activerecord/lib/active_record/associations.rb @@ -1707,7 +1707,7 @@ module ActiveRecord def construct_finder_arel_with_included_associations(options, join_dependency) scope = scope(:find) - relation = arel_table((scope && scope[:from]) || options[:from]) + relation = arel_table for association in join_dependency.join_associations relation = association.join_relation(relation) @@ -1717,7 +1717,8 @@ module ActiveRecord select(column_aliases(join_dependency)). group(construct_group(options[:group], options[:having], scope)). order(construct_order(options[:order], scope)). - where(construct_conditions(options[:conditions], scope)) + where(construct_conditions(options[:conditions], scope)). + from((scope && scope[:from]) || options[:from]) relation = relation.where(construct_arel_limited_ids_condition(options, join_dependency)) if !using_limitable_reflections?(join_dependency.reflections) && ((scope && scope[:limit]) || options[:limit]) relation = relation.limit(construct_limit(options[:limit], scope)) if using_limitable_reflections?(join_dependency.reflections) diff --git a/activerecord/lib/active_record/associations/association_collection.rb b/activerecord/lib/active_record/associations/association_collection.rb index ac970f02b1..d2c61cdc78 100644 --- a/activerecord/lib/active_record/associations/association_collection.rb +++ b/activerecord/lib/active_record/associations/association_collection.rb @@ -21,7 +21,7 @@ module ActiveRecord construct_sql end - delegate :group, :order, :limit, :joins, :where, :preload, :eager_load, :to => :scoped + delegate :group, :order, :limit, :joins, :where, :preload, :eager_load, :from, :to => :scoped def select(select = nil, &block) if block_given? diff --git a/activerecord/lib/active_record/base.rb b/activerecord/lib/active_record/base.rb index cad75f80e5..3b880ce17f 100755 --- a/activerecord/lib/active_record/base.rb +++ b/activerecord/lib/active_record/base.rb @@ -652,7 +652,7 @@ module ActiveRecord #:nodoc: end end - delegate :select, :group, :order, :limit, :joins, :where, :preload, :eager_load, :to => :scoped + delegate :select, :group, :order, :limit, :joins, :where, :preload, :eager_load, :from, :to => :scoped # A convenience wrapper for <tt>find(:first, *args)</tt>. You can pass in all the # same arguments to this method as you can to <tt>find(:first)</tt>. @@ -1563,7 +1563,7 @@ module ActiveRecord #:nodoc: # TODO add lock to Arel validate_find_options(options) - relation = arel_table(options[:from]). + relation = arel_table. joins(construct_join(options[:joins], scope)). where(construct_conditions(options[:conditions], scope)). select(options[:select] || (scope && scope[:select]) || default_select(options[:joins] || (scope && scope[:joins]))). diff --git a/activerecord/lib/active_record/controller_runtime.rb b/activerecord/lib/active_record/controller_runtime.rb new file mode 100644 index 0000000000..1281901ae8 --- /dev/null +++ b/activerecord/lib/active_record/controller_runtime.rb @@ -0,0 +1,27 @@ +module ActiveRecord + module ControllerRuntime + extend ActiveSupport::Concern + + attr_internal :db_runtime + + def cleanup_view_runtime + if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? + db_rt_before_render = ActiveRecord::Base.connection.reset_runtime + runtime = super + db_rt_after_render = ActiveRecord::Base.connection.reset_runtime + self.db_runtime = db_rt_before_render + db_rt_after_render + runtime - db_rt_after_render + else + super + end + end + + module ClassMethods + def process_log_action(controller) + super + db_runtime = controller.send :db_runtime + logger.info(" ActiveRecord runtime: %.1fms" % db_runtime.to_f) if db_runtime + end + end + end +end
\ No newline at end of file diff --git a/activerecord/lib/active_record/rails.rb b/activerecord/lib/active_record/rails.rb index ddbc555113..8b22f869bc 100644 --- a/activerecord/lib/active_record/rails.rb +++ b/activerecord/lib/active_record/rails.rb @@ -7,6 +7,9 @@ require "action_controller/rails" module ActiveRecord class Plugin < Rails::Plugin plugin_name :active_record + include_modules_in "ActiveRecord::Base" + + config.action_controller.include "ActiveRecord::ControllerRuntime" initializer "active_record.set_configs" do |app| app.config.active_record.each do |k,v| @@ -50,8 +53,8 @@ module ActiveRecord initializer "active_record.notifications" do require 'active_support/notifications' - ActiveSupport::Notifications.subscribe("sql") do |name, before, after, result, instrumenter_id, payload| - ActiveRecord::Base.connection.log_info(payload[:sql], name, after - before) + ActiveSupport::Notifications.subscribe("sql") do |name, before, after, instrumenter_id, payload| + ActiveRecord::Base.connection.log_info(payload[:sql], payload[:name], (after - before) * 1000) end end diff --git a/activerecord/test/cases/associations/eager_test.rb b/activerecord/test/cases/associations/eager_test.rb index d5a4d9007b..7fa5557b96 100644 --- a/activerecord/test/cases/associations/eager_test.rb +++ b/activerecord/test/cases/associations/eager_test.rb @@ -61,14 +61,7 @@ class EagerAssociationTest < ActiveRecord::TestCase end def test_with_two_tables_in_from_without_getting_double_quoted - posts = Post.find(:all, - :select => "posts.*", - :from => "authors, posts", - :include => :comments, - :conditions => "posts.author_id = authors.id", - :order => "posts.id" - ) - + posts = Post.select("posts.*").from("authors, posts").eager_load(:comments).where("posts.author_id = authors.id").order("posts.id").to_a assert_equal 2, posts.first.comments.size end diff --git a/activerecord/test/cases/finder_test.rb b/activerecord/test/cases/finder_test.rb index c531a2dec1..87a9630978 100644 --- a/activerecord/test/cases/finder_test.rb +++ b/activerecord/test/cases/finder_test.rb @@ -1023,7 +1023,7 @@ class FinderTest < ActiveRecord::TestCase all_topics = Topic.find(:all) Topic.with_scope(:find => { :from => 'fake_topics' }) do - assert_equal all_topics, Topic.all(:from => 'topics').to_a + assert_equal all_topics, Topic.from('topics').to_a end end diff --git a/activesupport/lib/active_support/core_ext/string/output_safety.rb b/activesupport/lib/active_support/core_ext/string/output_safety.rb index 3e6ab0ebd2..ceed90ce79 100644 --- a/activesupport/lib/active_support/core_ext/string/output_safety.rb +++ b/activesupport/lib/active_support/core_ext/string/output_safety.rb @@ -1,3 +1,15 @@ +class Object + def html_safe? + false + end +end + +class Fixnum + def html_safe? + true + end +end + class String attr_accessor :_rails_html_safe alias html_safe? _rails_html_safe diff --git a/activesupport/lib/active_support/notifications/instrumenter.rb b/activesupport/lib/active_support/notifications/instrumenter.rb index fb95422af2..0655dd0cb6 100644 --- a/activesupport/lib/active_support/notifications/instrumenter.rb +++ b/activesupport/lib/active_support/notifications/instrumenter.rb @@ -10,10 +10,10 @@ module ActiveSupport end def instrument(name, payload={}) - time = Time.now - result = yield if block_given? + time = Time.now + yield if block_given? ensure - @notifier.publish(name, time, Time.now, result, @id, payload) + @notifier.publish(name, time, Time.now, @id, payload) end private @@ -23,15 +23,14 @@ module ActiveSupport end class Event - attr_reader :name, :time, :end, :transaction_id, :result, :payload + attr_reader :name, :time, :end, :transaction_id, :payload - def initialize(name, start, ending, result, transaction_id, payload) + def initialize(name, start, ending, transaction_id, payload) @name = name @payload = payload.dup @time = start @transaction_id = transaction_id @end = ending - @result = result end def duration diff --git a/activesupport/test/core_ext/string_ext_test.rb b/activesupport/test/core_ext/string_ext_test.rb index 56ed296dac..6ed209f724 100644 --- a/activesupport/test/core_ext/string_ext_test.rb +++ b/activesupport/test/core_ext/string_ext_test.rb @@ -350,6 +350,24 @@ class OutputSafetyTest < ActiveSupport::TestCase assert_equal @string, @string.html_safe! end + test "A fixnum is safe by default" do + assert 5.html_safe? + end + + test "An object is unsafe by default" do + klass = Class.new(Object) do + def to_str + "other" + end + end + + @string.html_safe! + @string << klass.new + + assert_equal "helloother", @string + assert !@string.html_safe? + end + test "Adding a safe string to another safe string returns a safe string" do @other_string = "other".html_safe! @string.html_safe! @@ -416,4 +434,10 @@ class OutputSafetyTest < ActiveSupport::TestCase @other_string << @string assert @other_string.html_safe? end + + test "Concatting a fixnum to safe always yields safe" do + @string.html_safe! + @string.concat(13) + assert @string.html_safe? + end end diff --git a/activesupport/test/notifications_test.rb b/activesupport/test/notifications_test.rb index 4f880d0db7..3ba77ae135 100644 --- a/activesupport/test/notifications_test.rb +++ b/activesupport/test/notifications_test.rb @@ -134,27 +134,25 @@ module Notifications class EventTest < TestCase def test_events_are_initialized_with_details - event = event(:foo, Time.now, Time.now + 1, 1, random_id, :payload => :bar) - assert_equal :foo, event.name - assert_equal Hash[:payload => :bar], event.payload - end - - def test_events_consumes_information_given_as_payload time = Time.now - event = event(:foo, time, time + 0.01, 1, random_id, {}) + event = event(:foo, time, time + 0.01, random_id, {}) - assert_equal Hash.new, event.payload + assert_equal :foo, event.name assert_equal time, event.time - assert_equal 1, event.result assert_equal 10.0, event.duration end + def test_events_consumes_information_given_as_payload + event = event(:foo, Time.now, Time.now + 1, random_id, :payload => :bar) + assert_equal Hash[:payload => :bar], event.payload + end + def test_event_is_parent_based_on_time_frame time = Time.utc(2009, 01, 01, 0, 0, 1) - parent = event(:foo, Time.utc(2009), Time.utc(2009) + 100, nil, random_id, {}) - child = event(:foo, time, time + 10, nil, random_id, {}) - not_child = event(:foo, time, time + 100, nil, random_id, {}) + parent = event(:foo, Time.utc(2009), Time.utc(2009) + 100, random_id, {}) + child = event(:foo, time, time + 10, random_id, {}) + not_child = event(:foo, time, time + 100, random_id, {}) assert parent.parent_of?(child) assert !child.parent_of?(parent) diff --git a/railties/lib/rails/configuration.rb b/railties/lib/rails/configuration.rb index 086f67a419..cb321536d2 100644 --- a/railties/lib/rails/configuration.rb +++ b/railties/lib/rails/configuration.rb @@ -1,6 +1,24 @@ require 'active_support/ordered_options' module Rails + # Create a Plugin::Options from ActiveSuppot::OrderedOptions, + # which support the following syntax: + # + # controller.action_controller.include FooBar + # + class Plugin::Options < ActiveSupport::OrderedOptions #:nodoc: + attr_reader :includes + + def initialize(*args) + @includes = [] + super + end + + def include(*args) + @includes.concat(args) + end + end + # Temporarily separate the plugin configuration class from the main # configuration class while this bit is being cleaned up. class Plugin::Configuration @@ -16,7 +34,7 @@ module Rails @options = base.options.dup @middleware = base.middleware.dup else - @options = Hash.new { |h,k| h[k] = ActiveSupport::OrderedOptions.new } + @options = Hash.new { |h,k| h[k] = Rails::Plugin::Options.new } @middleware = ActionDispatch::MiddlewareStack.new end end diff --git a/railties/lib/rails/plugin.rb b/railties/lib/rails/plugin.rb index 0699affea7..aa325c6f76 100644 --- a/railties/lib/rails/plugin.rb +++ b/railties/lib/rails/plugin.rb @@ -25,6 +25,24 @@ module Rails Configuration.default end + # Creates an initializer which includes all given modules to the given class. + # + # module Rails + # class ActionController < Rails::Plugin + # plugin_name :action_controller + # include_modules_in "ActionController::Base" + # end + # end + # + def self.include_modules_in(klass, from=plugin_name) + self.initializer :"#{from}.include_modules" do |app| + klass = klass.constantize if klass.is_a?(String) + app.config.send(from).includes.each do |mod| + klass.send(:include, mod.is_a?(String) ? mod.constantize : mod) + end + end + end + class Vendored < Plugin def self.all(list, paths) plugins = [] diff --git a/railties/test/plugins/configuration_test.rb b/railties/test/plugins/configuration_test.rb index 5786316d1d..0843d05577 100644 --- a/railties/test/plugins/configuration_test.rb +++ b/railties/test/plugins/configuration_test.rb @@ -8,6 +8,10 @@ module PluginsTest require "rails" end + module Bar; end + module Baz; end + module All; end + test "config is available to plugins" do class Foo < Rails::Plugin ; end assert_nil Foo.config.action_controller.foo @@ -24,6 +28,18 @@ module PluginsTest assert_equal "hello", AppTemplate::Application.config.foo.greetings end + test "plugin configurations allow modules to be given" do + class Foo < Rails::Plugin ; config.foo.include(Bar, Baz) ; end + assert_equal [Bar, Baz], Foo.config.foo.includes + end + + test "plugin includes given modules in given class" do + class Foo < Rails::Plugin ; config.foo.include(Bar, "PluginsTest::ConfigurationTest::Baz") ; include_modules_in All ; end + Foo.new.run_initializers(Foo) + assert All.ancestors.include?(Bar) + assert All.ancestors.include?(Baz) + end + test "plugin config merges are deep" do class Foo < Rails::Plugin ; config.foo.greetings = 'hello' ; end class MyApp < Rails::Application |