From 9f6a79623438f200c8fc8979781f27743d99dec1 Mon Sep 17 00:00:00 2001
From: Viktar Basharymau <viktar.basharymau@thehamon.com>
Date: Thu, 19 Jun 2014 14:29:16 +0300
Subject: [PATCH] Add `logger.debug?` guard to
 `ActionMailer::LogSubscriber#process`
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

*TLDR*: The method is 4 times faster when log level is higher than DEBUG.
Also, the other two methods, `#deliver` and `#receive` have similar guard statements,
so this commit adds some symmetry to the code.

This is probably not the most critical part of ActionMailer in terms
of performance, but here are some benchmarks:

```
require 'benchmark/ips'
require 'action_mailer'

event = ActiveSupport::Notifications::Event.new(
            'process.action_mailer',
            Time.now,
            Time.now,
            'bf4e2b36ce085fd35b24',
            { mailer: "UserMailer", action: :welcome }
        )

ActionMailer::Base.logger = ActiveSupport::Logger.new '/dev/null'

subscriber = ActionMailer::LogSubscriber.new
def subscriber.process_with_guard(event)
  return unless logger.debug?
  mailer = event.payload[:mailer]
  action = event.payload[:action]
  debug("\n#{mailer}##{action}: processed outbound mail in #{event.duration.round(1)}ms")
end

Benchmark.ips do |r|
  ActionMailer::Base.logger.level = ::Logger::Severity::INFO
  r.report('no guard') { subscriber.process(event) }
  r.report('   guard') { subscriber.process_with_guard(event) }
end

__END__
Calculating -------------------------------------
            no guard      9640 i/100ms
               guard     38381 i/100ms
-------------------------------------------------
            no guard   169166.9 (±10.2%) i/s -     838680 in   5.007262s
               guard   728184.9 (±9.6%) i/s -    3607814 in   4.999218s
```

When log level is DEBUG, the _guarded_ method is a bit slower. This is a
good tradeoff for 4x improvement in production mode.

```
Benchmark.ips do |r|
  ActionMailer::Base.logger.level = ::Logger::Severity::DEBUG
  r.report('no guard') { subscriber.process(event) }
  r.report('   guard') { subscriber.process_with_guard(event) }
end

__END__
Calculating -------------------------------------
            no guard      4970 i/100ms
               guard      4564 i/100ms
-------------------------------------------------
            no guard    55617.4 (±3.5%) i/s -     278320 in   5.010523s
               guard    49452.1 (±5.6%) i/s -     251020 in   5.093358s

```
---
 actionmailer/lib/action_mailer/log_subscriber.rb | 1 +
 1 file changed, 1 insertion(+)

diff --git a/actionmailer/lib/action_mailer/log_subscriber.rb b/actionmailer/lib/action_mailer/log_subscriber.rb
index eb6fb11d81..e4aaab34b1 100644
--- a/actionmailer/lib/action_mailer/log_subscriber.rb
+++ b/actionmailer/lib/action_mailer/log_subscriber.rb
@@ -21,6 +21,7 @@ module ActionMailer
 
     # An email was generated.
     def process(event)
+      return unless logger.debug?
       mailer = event.payload[:mailer]
       action = event.payload[:action]
       debug("\n#{mailer}##{action}: processed outbound mail in #{event.duration.round(1)}ms")