diff options
Diffstat (limited to 'actionpack/lib')
| -rw-r--r-- | actionpack/lib/action_controller.rb | 2 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/base.rb | 5 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/caching.rb | 11 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/metal/filter_parameter_logging.rb | 17 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/metal/instrumentation.rb | 77 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/metal/logger.rb | 93 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/metal/redirecting.rb | 2 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/metal/streaming.rb | 4 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/railtie.rb | 11 | ||||
| -rw-r--r-- | actionpack/lib/action_controller/railties/subscriber.rb | 62 | ||||
| -rw-r--r-- | actionpack/lib/action_view/railtie.rb | 11 | ||||
| -rw-r--r-- | actionpack/lib/action_view/railties/subscriber.rb | 24 | ||||
| -rw-r--r-- | actionpack/lib/action_view/template/text.rb | 2 |
13 files changed, 185 insertions, 136 deletions
diff --git a/actionpack/lib/action_controller.rb b/actionpack/lib/action_controller.rb index 8271f6f3e7..42582c4525 100644 --- a/actionpack/lib/action_controller.rb +++ b/actionpack/lib/action_controller.rb @@ -23,7 +23,7 @@ module ActionController autoload :Helpers autoload :HideActions autoload :HttpAuthentication - autoload :Logger + autoload :Instrumentation autoload :MimeResponds autoload :RackDelegation autoload :Redirecting diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb index 746ab3e6db..4f564a6377 100644 --- a/actionpack/lib/action_controller/base.rb +++ b/actionpack/lib/action_controller/base.rb @@ -15,7 +15,6 @@ module ActionController include ActionController::Renderers::All include ActionController::ConditionalGet include ActionController::RackDelegation - include ActionController::Logger include ActionController::Configuration # Legacy modules @@ -36,6 +35,10 @@ module ActionController include ActionController::FilterParameterLogging include ActionController::Translation + # Add instrumentations hooks at the bottom, to ensure they instrument + # all the methods properly. + include ActionController::Instrumentation + # TODO: Extract into its own module # This should be moved together with other normalizing behavior module ImplicitRender diff --git a/actionpack/lib/action_controller/caching.rb b/actionpack/lib/action_controller/caching.rb index 5c0d754ad6..d784138ebe 100644 --- a/actionpack/lib/action_controller/caching.rb +++ b/actionpack/lib/action_controller/caching.rb @@ -60,17 +60,6 @@ module ActionController #:nodoc: def cache_configured? perform_caching && cache_store end - - def log_event(name, before, after, instrumenter_id, payload) - if name.to_s =~ /action_controller\.((read|write|expire|exist)_(fragment|page)\??)/ - key_or_path = payload[:key] || payload[:path] - human_name = $1.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/metal/filter_parameter_logging.rb b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb index 59e200396a..9e03f50759 100644 --- a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb +++ b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb @@ -2,6 +2,8 @@ module ActionController module FilterParameterLogging extend ActiveSupport::Concern + INTERNAL_PARAMS = %w(controller action format _method only_path) + module ClassMethods # Replace sensitive parameter data from the request log. # Filters parameters that have any of the arguments as a substring. @@ -48,25 +50,12 @@ module ActionController filtered_params[key] = value end - filtered_params + filtered_params.except!(*INTERNAL_PARAMS) end protected :filter_parameters end - - protected - - # 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 end - INTERNAL_PARAMS = [:controller, :action, :format, :_method, :only_path] - protected def filter_parameters(params) diff --git a/actionpack/lib/action_controller/metal/instrumentation.rb b/actionpack/lib/action_controller/metal/instrumentation.rb new file mode 100644 index 0000000000..91d454f0c3 --- /dev/null +++ b/actionpack/lib/action_controller/metal/instrumentation.rb @@ -0,0 +1,77 @@ +require 'abstract_controller/logger' + +module ActionController + # Adds instrumentation to several ends in ActionController::Base. It also provides + # some hooks related with process_action logging and view runtime. + module Instrumentation + extend ActiveSupport::Concern + + included do + include AbstractController::Logger + end + + attr_internal :view_runtime + + def process_action(action, *args) + ActiveSupport::Notifications.instrument("action_controller.process_action", + :controller => self, :action => action) do + super + end + end + + def render(*args, &block) + if logger + render_output = nil + + self.view_runtime = cleanup_view_runtime do + Benchmark.ms { render_output = super } + end + + render_output + else + super + end + end + + def send_file(path, options={}) + ActiveSupport::Notifications.instrument("action_controller.send_file", + options.merge(:path => path)) do + super + end + end + + def send_data(data, options = {}) + ActiveSupport::Notifications.instrument("action_controller.send_data", options) do + super + end + end + + def redirect_to(*args) + super + ActiveSupport::Notifications.instrument("action_controller.redirect_to", + :status => self.status, :location => self.location) + end + + # A hook which allows you to clean up any time taken into account in + # views wrongly, like database querying time. + # + # def cleanup_view_runtime + # super - time_taken_in_something_expensive + # end + # + # :api: plugin + def cleanup_view_runtime #:nodoc: + yield + end + + module ClassMethods + # A hook which allows other frameworks to log 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
\ No newline at end of file diff --git a/actionpack/lib/action_controller/metal/logger.rb b/actionpack/lib/action_controller/metal/logger.rb deleted file mode 100644 index e995d6bcea..0000000000 --- a/actionpack/lib/action_controller/metal/logger.rb +++ /dev/null @@ -1,93 +0,0 @@ -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 - extend ActiveSupport::Concern - - included do - include AbstractController::Logger - end - - attr_internal :view_runtime - - def process_action(action) - ActiveSupport::Notifications.instrument("action_controller.process_action", - :controller => self, :action => action) do - super - end - end - - def render(*args, &block) - if logger - render_output = nil - - self.view_runtime = cleanup_view_runtime do - Benchmark.ms { render_output = super } - end - - render_output - else - super - end - end - - # 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 - - 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 == "action_controller.process_action" - duration = [(after - before) * 1000, 0.01].max - controller = payload[:controller] - request = controller.request - - logger.info "\nProcessed #{controller.class.name}##{payload[:action]} " \ - "to #{request.formats} (for #{request.remote_ip} at #{before.to_s(:db)}) " \ - "[#{request.method.to_s.upcase}]" - - log_process_action(controller) - - message = "Completed in %.0fms" % duration - message << " | #{controller.response.status}" - message << " [#{request.request_uri rescue "unknown"}]\n\n" - - logger.info(message) - elsif name == "action_view.render_template" - duration = (after - before) * 1000 - message = "Rendered #{from_rails_root(payload[:identifier])}" - message << " within #{from_rails_root(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 - - def from_rails_root(string) - defined?(Rails.root) ? string.sub("#{Rails.root}/app/views/", "") : string - end - end - end -end
\ No newline at end of file diff --git a/actionpack/lib/action_controller/metal/redirecting.rb b/actionpack/lib/action_controller/metal/redirecting.rb index 7b277c0ae0..faf0589fd2 100644 --- a/actionpack/lib/action_controller/metal/redirecting.rb +++ b/actionpack/lib/action_controller/metal/redirecting.rb @@ -57,8 +57,6 @@ module ActionController self.status = _extract_redirect_to_status(options, response_status) self.location = _compute_redirect_to_location(options) self.response_body = "<html><body>You are being <a href=\"#{ERB::Util.h(location)}\">redirected</a>.</body></html>" - - logger.info("Redirected to #{location}") if logger && logger.info? end private diff --git a/actionpack/lib/action_controller/metal/streaming.rb b/actionpack/lib/action_controller/metal/streaming.rb index 288b5d7c99..8f03b8bb17 100644 --- a/actionpack/lib/action_controller/metal/streaming.rb +++ b/actionpack/lib/action_controller/metal/streaming.rb @@ -88,13 +88,11 @@ module ActionController #:nodoc: @performed_render = false if options[:x_sendfile] - logger.info "Sending #{X_SENDFILE_HEADER} header #{path}" if logger head options[:status], X_SENDFILE_HEADER => path else if options[:stream] # TODO : Make render :text => proc {} work with the new base render :status => options[:status], :text => Proc.new { |response, output| - logger.info "Streaming file #{path}" unless logger.nil? len = options[:buffer_size] || 4096 File.open(path, 'rb') do |file| while buf = file.read(len) @@ -103,7 +101,6 @@ module ActionController #:nodoc: end } else - logger.info "Sending file #{path}" unless logger.nil? File.open(path, 'rb') { |file| render :status => options[:status], :text => file.read } end end @@ -141,7 +138,6 @@ module ActionController #:nodoc: # data to the browser, then use <tt>render :text => proc { ... }</tt> # instead. See ActionController::Base#render for more information. def send_data(data, options = {}) #:doc: - logger.info "Sending data #{options[:filename]}" if logger send_file_headers! options.merge(:length => data.bytesize) render :status => options[:status], :text => data end diff --git a/actionpack/lib/action_controller/railtie.rb b/actionpack/lib/action_controller/railtie.rb index 42257f9400..d4886ecefd 100644 --- a/actionpack/lib/action_controller/railtie.rb +++ b/actionpack/lib/action_controller/railtie.rb @@ -5,6 +5,9 @@ module ActionController class Railtie < Rails::Railtie plugin_name :action_controller + require "action_controller/railties/subscriber" + subscriber ActionController::Railties::Subscriber.new + initializer "action_controller.set_configs" do |app| app.config.action_controller.each do |k,v| ActionController::Base.send "#{k}=", v @@ -86,13 +89,5 @@ module ActionController end end - initializer "action_controller.notifications" do |app| - require 'active_support/notifications' - - ActiveSupport::Notifications.subscribe do |*args| - ActionController::Base.log_event(*args) if ActionController::Base.logger - end - end - end end diff --git a/actionpack/lib/action_controller/railties/subscriber.rb b/actionpack/lib/action_controller/railties/subscriber.rb new file mode 100644 index 0000000000..d9d77304ee --- /dev/null +++ b/actionpack/lib/action_controller/railties/subscriber.rb @@ -0,0 +1,62 @@ +module ActionController + module Railties + class Subscriber < Rails::Subscriber + def process_action(event) + controller = event.payload[:controller] + request = controller.request + + info "\nProcessed #{controller.class.name}##{event.payload[:action]} " \ + "to #{request.formats} (for #{request.remote_ip} at #{event.time.to_s(:db)}) " \ + "[#{request.method.to_s.upcase}]" + + params = controller.send(:filter_parameters, request.params) + info " Parameters: #{params.inspect}" unless params.empty? + + ActionController::Base.log_process_action(controller) + + message = "Completed in %.0fms" % event.duration + message << " | #{controller.response.status}" + message << " [#{request.request_uri rescue "unknown"}]\n\n" + + info(message) + end + + def send_file(event) + message = if event.payload[:x_sendfile] + header = ActionController::Streaming::X_SENDFILE_HEADER + "Sending #{header} header %s" + elsif event.payload[:stream] + "Streaming file %s" + else + "Sending file %s" + end + + message << " (%.1fms)" + info(message % [event.payload[:path], event.duration]) + end + + def redirect_to(event) + info "Redirected to #{event.payload[:location]} with status #{event.payload[:status]}" + end + + def send_data(event) + info("Sending data %s (%.1fms)" % [event.payload[:filename], event.duration]) + end + + %w(write_fragment read_fragment exist_fragment? + expire_fragment expire_page write_page).each do |method| + class_eval <<-METHOD, __FILE__, __LINE__ + 1 + def #{method}(event) + key_or_path = event.payload[:key] || event.payload[:path] + human_name = #{method.to_s.humanize.inspect} + info("\#{human_name} \#{key_or_path.inspect} (%.1fms)" % event.duration) + end + METHOD + end + + def logger + ActionController::Base.logger + end + end + end +end
\ No newline at end of file diff --git a/actionpack/lib/action_view/railtie.rb b/actionpack/lib/action_view/railtie.rb index a90e0636b9..e368aab825 100644 --- a/actionpack/lib/action_view/railtie.rb +++ b/actionpack/lib/action_view/railtie.rb @@ -1,2 +1,11 @@ require "action_view" -require "rails"
\ No newline at end of file +require "rails" + +module ActionView + class Railtie < Rails::Railtie + plugin_name :action_view + + require "action_view/railties/subscriber" + subscriber ActionView::Railties::Subscriber.new + end +end
\ No newline at end of file diff --git a/actionpack/lib/action_view/railties/subscriber.rb b/actionpack/lib/action_view/railties/subscriber.rb new file mode 100644 index 0000000000..803f19379c --- /dev/null +++ b/actionpack/lib/action_view/railties/subscriber.rb @@ -0,0 +1,24 @@ +module ActionView + module Railties + class Subscriber < Rails::Subscriber + def render_template(event) + message = "Rendered #{from_rails_root(event.payload[:identifier])}" + message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] + message << (" (%.1fms)" % event.duration) + info(message) + end + alias :render_partial :render_template + alias :render_collection :render_template + + def logger + ActionController::Base.logger + end + + protected + + def from_rails_root(string) + string.sub("#{Rails.root}/", "").sub(/^app\/views\//, "") + end + end + end +end
\ No newline at end of file diff --git a/actionpack/lib/action_view/template/text.rb b/actionpack/lib/action_view/template/text.rb index 67e086d8bd..2abb352d4e 100644 --- a/actionpack/lib/action_view/template/text.rb +++ b/actionpack/lib/action_view/template/text.rb @@ -13,7 +13,7 @@ module ActionView #:nodoc: end def identifier - self + 'text template' end def inspect |