Permalink
Browse files

Add `logger.debug?` guard to `ActionMailer::LogSubscriber#process`

*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

```
  • Loading branch information...
1 parent 96f28b6 commit 9f6a79623438f200c8fc8979781f27743d99dec1 @DNNX DNNX committed Jun 19, 2014
Showing with 1 addition and 0 deletions.
  1. +1 −0 actionmailer/lib/action_mailer/log_subscriber.rb
View
1 actionmailer/lib/action_mailer/log_subscriber.rb
@@ -21,6 +21,7 @@ def receive(event)
# 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")

0 comments on commit 9f6a796

Please sign in to comment.