From 37852726c93541aa1adc014cfb862659c9bcf349 Mon Sep 17 00:00:00 2001 From: Brian Durand Date: Wed, 19 Sep 2012 16:00:28 -0700 Subject: Optimize log subscribers to check if the log level is sufficient before performing an operations. --- actionmailer/lib/action_mailer/log_subscriber.rb | 6 ++++-- actionpack/lib/action_controller/log_subscriber.rb | 17 +++++++++++------ actionpack/lib/action_view/log_subscriber.rb | 7 +++++-- activerecord/lib/active_record/log_subscriber.rb | 10 ++++++---- activesupport/CHANGELOG.md | 2 ++ 5 files changed, 28 insertions(+), 14 deletions(-) diff --git a/actionmailer/lib/action_mailer/log_subscriber.rb b/actionmailer/lib/action_mailer/log_subscriber.rb index a6c163832e..3fe64759ac 100644 --- a/actionmailer/lib/action_mailer/log_subscriber.rb +++ b/actionmailer/lib/action_mailer/log_subscriber.rb @@ -1,13 +1,15 @@ module ActionMailer class LogSubscriber < ActiveSupport::LogSubscriber def deliver(event) + return unless logger.info? recipients = Array(event.payload[:to]).join(', ') - info("\nSent mail to #{recipients} (%1.fms)" % event.duration) + info("\nSent mail to #{recipients} (#{event.duration.round(1)}ms)") debug(event.payload[:mail]) end def receive(event) - info("\nReceived mail (%.1fms)" % event.duration) + return unless logger.info? + info("\nReceived mail (#{event.duration.round(1)}ms)") debug(event.payload[:mail]) end diff --git a/actionpack/lib/action_controller/log_subscriber.rb b/actionpack/lib/action_controller/log_subscriber.rb index f41d1bb4b9..3d274e7dd7 100644 --- a/actionpack/lib/action_controller/log_subscriber.rb +++ b/actionpack/lib/action_controller/log_subscriber.rb @@ -4,6 +4,8 @@ module ActionController INTERNAL_PARAMS = %w(controller action format _method only_path) def start_processing(event) + return unless logger.info? + payload = event.payload params = payload[:params].except(*INTERNAL_PARAMS) format = payload[:format] @@ -14,6 +16,8 @@ module ActionController end def process_action(event) + return unless logger.info? + payload = event.payload additions = ActionController::Base.log_process_action(payload) @@ -22,35 +26,36 @@ module ActionController exception_class_name = payload[:exception].first status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name) end - message = "Completed #{status} #{Rack::Utils::HTTP_STATUS_CODES[status]} in %.0fms" % event.duration + message = "Completed #{status} #{Rack::Utils::HTTP_STATUS_CODES[status]} in #{event.duration.round}ms" message << " (#{additions.join(" | ")})" unless additions.blank? info(message) end def halted_callback(event) - info "Filter chain halted as #{event.payload[:filter]} rendered or redirected" + info("Filter chain halted as #{event.payload[:filter]} rendered or redirected") end def send_file(event) - info("Sent file %s (%.1fms)" % [event.payload[:path], event.duration]) + info("Sent file #{event.payload[:path]} (#{event.duration.round(1)}ms)") end def redirect_to(event) - info "Redirected to #{event.payload[:location]}" + info("Redirected to #{event.payload[:location]}") end def send_data(event) - info("Sent data %s (%.1fms)" % [event.payload[:filename], event.duration]) + info("Sent data #{event.payload[:filename]} (#{event.duration.round(1)}ms)") 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) + return unless logger.info? key_or_path = event.payload[:key] || event.payload[:path] human_name = #{method.to_s.humanize.inspect} - info("\#{human_name} \#{key_or_path} \#{"(%.1fms)" % event.duration}") + info("\#{human_name} \#{key_or_path} (\#{event.duration.round(1)}ms)") end METHOD end diff --git a/actionpack/lib/action_view/log_subscriber.rb b/actionpack/lib/action_view/log_subscriber.rb index cc3a871576..fd9a543e0a 100644 --- a/actionpack/lib/action_view/log_subscriber.rb +++ b/actionpack/lib/action_view/log_subscriber.rb @@ -3,10 +3,13 @@ module ActionView # # Provides functionality so that Rails can output logs from Action View. class LogSubscriber < ActiveSupport::LogSubscriber + VIEWS_PATTERN = /^app\/views\//.freeze + def render_template(event) + return unless logger.info? message = " Rendered #{from_rails_root(event.payload[:identifier])}" message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] - message << (" (%.1fms)" % event.duration) + message << " (#{event.duration.round(1)}ms)" info(message) end alias :render_partial :render_template @@ -19,7 +22,7 @@ module ActionView protected def from_rails_root(string) - string.sub("#{Rails.root}/", "").sub(/^app\/views\//, "") + string.sub("#{Rails.root}/", "").sub(VIEWS_PATTERN, "") end end end diff --git a/activerecord/lib/active_record/log_subscriber.rb b/activerecord/lib/active_record/log_subscriber.rb index a25f2c7bca..ca79950049 100644 --- a/activerecord/lib/active_record/log_subscriber.rb +++ b/activerecord/lib/active_record/log_subscriber.rb @@ -1,11 +1,13 @@ module ActiveRecord class LogSubscriber < ActiveSupport::LogSubscriber + IGNORE_PAYLOAD_NAMES = ["SCHEMA", "EXPLAIN"] + def self.runtime=(value) - Thread.current["active_record_sql_runtime"] = value + Thread.current[:active_record_sql_runtime] = value end def self.runtime - Thread.current["active_record_sql_runtime"] ||= 0 + Thread.current[:active_record_sql_runtime] ||= 0 end def self.reset_runtime @@ -24,9 +26,9 @@ module ActiveRecord payload = event.payload - return if 'SCHEMA' == payload[:name] + return if IGNORE_PAYLOAD_NAMES.include?(payload[:name]) - name = '%s (%.1fms)' % [payload[:name], event.duration] + name = "#{payload[:name]} (#{event.duration.round(1)}ms)" sql = payload[:sql].squeeze(' ') binds = nil diff --git a/activesupport/CHANGELOG.md b/activesupport/CHANGELOG.md index 47f1c8458e..36296451a1 100644 --- a/activesupport/CHANGELOG.md +++ b/activesupport/CHANGELOG.md @@ -197,4 +197,6 @@ * Remove deprecated ActiveSupport::JSON::Variable. *Erich Menge* +* Optimize log subscribers to check log level before doing any processing. *Brian Durand* + Please check [3-2-stable](https://github.com/rails/rails/blob/3-2-stable/activesupport/CHANGELOG.md) for previous changes. -- cgit v1.2.3