aboutsummaryrefslogtreecommitdiffstats
path: root/actionpack/lib/action_controller
diff options
context:
space:
mode:
Diffstat (limited to 'actionpack/lib/action_controller')
-rw-r--r--actionpack/lib/action_controller/base.rb5
-rw-r--r--actionpack/lib/action_controller/caching.rb11
-rw-r--r--actionpack/lib/action_controller/metal/filter_parameter_logging.rb17
-rw-r--r--actionpack/lib/action_controller/metal/instrumentation.rb77
-rw-r--r--actionpack/lib/action_controller/metal/logger.rb93
-rw-r--r--actionpack/lib/action_controller/metal/redirecting.rb2
-rw-r--r--actionpack/lib/action_controller/metal/streaming.rb4
-rw-r--r--actionpack/lib/action_controller/railtie.rb11
-rw-r--r--actionpack/lib/action_controller/railties/subscriber.rb62
9 files changed, 149 insertions, 133 deletions
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