aboutsummaryrefslogtreecommitdiffstats
path: root/actionpack/lib/action_controller/metal/logger.rb
diff options
context:
space:
mode:
Diffstat (limited to 'actionpack/lib/action_controller/metal/logger.rb')
-rw-r--r--actionpack/lib/action_controller/metal/logger.rb89
1 files changed, 89 insertions, 0 deletions
diff --git a/actionpack/lib/action_controller/metal/logger.rb b/actionpack/lib/action_controller/metal/logger.rb
new file mode 100644
index 0000000000..4f4370e5f0
--- /dev/null
+++ b/actionpack/lib/action_controller/metal/logger.rb
@@ -0,0 +1,89 @@
+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(: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 == :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}]"
+
+ 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 \ No newline at end of file