Added :silence option to BenchmarkHelper#benchmark and turned log_level into a hash parameter and deprecated the old use [DHH]

3 files changed, 77 insertions, 28 deletions

diff --git a/actionpack/CHANGELOG b/actionpack/CHANGELOG
index 44790605b2..26e40e76d5 100644
--- a/actionpack/CHANGELOG
+++ b/actionpack/CHANGELOG
@@ -1,5 +1,7 @@
 *2.3.0 [Edge]*
 
+* Added :silence option to BenchmarkHelper#benchmark and turned log_level into a hash parameter and deprecated the old use [DHH]
+
 * Fixed the AssetTagHelper cache to use the computed asset host as part of the cache key instead of just assuming the its a string #1299 [DHH]
 
 * Make ActionController#render(string) work as a shortcut for render :file/:template/:action => string. [#1435] [Pratik Naik] Examples:
diff --git a/actionpack/lib/action_view/helpers/benchmark_helper.rb b/actionpack/lib/action_view/helpers/benchmark_helper.rb
index 372d24a22e..61c2cecb04 100644
--- a/actionpack/lib/action_view/helpers/benchmark_helper.rb
+++ b/actionpack/lib/action_view/helpers/benchmark_helper.rb
@@ -18,12 +18,33 @@ module ActionView
       # That would add something like "Process data files (345.2ms)" to the log,
       # which you can then use to compare timings when optimizing your code.
       #
-      # You may give an optional logger level as the second argument
+      # You may give an optional logger level as the :level option.
       # (:debug, :info, :warn, :error); the default value is :info.
-      def benchmark(message = "Benchmarking", level = :info)
+      #
+      #  <% benchmark "Low-level files", :level => :debug do %>
+      #    <%= lowlevel_files_operation %>
+      #  <% end %>
+      #
+      # Finally, you can pass true as the third argument to silence all log activity 
+      # inside the block. This is great for boiling down a noisy block to just a single statement:
+      #
+      #  <% benchmark "Process data files", :level => :info, :silence => true do %>
+      #    <%= expensive_and_chatty_files_operation %>
+      #  <% end %>
+      def benchmark(message = "Benchmarking", options = {})
         if controller.logger
-          ms = Benchmark.ms { yield }
-          controller.logger.send(level, '%s (%.1fms)' % [message, ms])
+          if options.is_a?(Symbol)
+            ActiveSupport::Deprecation.warn("use benchmark('#{message}', :level => :#{options}) instead", caller)
+            options = { :level => options, :silence => false }
+          else
+            options.assert_valid_keys(:level, :silence)
+            options[:level] ||= :info
+          end
+          
+          result = nil
+          ms = Benchmark.ms { result = options[:silence] ? controller.logger.silence { yield } : yield }
+          controller.logger.send(options[:level], '%s (%.1fms)' % [ message, ms ])
+          result
         else
           yield
         end
diff --git a/actionpack/test/template/benchmark_helper_test.rb b/actionpack/test/template/benchmark_helper_test.rb
index 08d453c965..5d2af7cdd9 100644
--- a/actionpack/test/template/benchmark_helper_test.rb
+++ b/actionpack/test/template/benchmark_helper_test.rb
@@ -4,32 +4,25 @@ require 'action_view/helpers/benchmark_helper'
 class BenchmarkHelperTest < ActionView::TestCase
   tests ActionView::Helpers::BenchmarkHelper
 
-  class MockLogger
-    attr_reader :logged
-
-    def initialize
-      @logged = []
-    end
-
-    def method_missing(method, *args)
-      @logged << [method, args]
-    end
+  def teardown
+    controller.logger.send(:clear_buffer)
   end
 
   def controller
-    @controller ||= Struct.new(:logger).new(MockLogger.new)
+    logger = ActiveSupport::BufferedLogger.new(StringIO.new)
+    logger.auto_flushing = false
+    @controller ||= Struct.new(:logger).new(logger)
   end
 
   def test_without_block
     assert_raise(LocalJumpError) { benchmark }
-    assert controller.logger.logged.empty?
+    assert buffer.empty?
   end
 
   def test_defaults
     i_was_run = false
     benchmark { i_was_run = true }
     assert i_was_run
-    assert 1, controller.logger.logged.size
     assert_last_logged
   end
 
@@ -37,24 +30,57 @@ class BenchmarkHelperTest < ActionView::TestCase
     i_was_run = false
     benchmark('test_run') { i_was_run = true }
     assert i_was_run
-    assert 1, controller.logger.logged.size
     assert_last_logged 'test_run'
   end
 
-  def test_with_message_and_level
+  def test_with_message_and_deprecated_level
     i_was_run = false
-    benchmark('debug_run', :debug) { i_was_run = true }
+
+    assert_deprecated do
+      benchmark('debug_run', :debug) { i_was_run = true }
+    end
+
     assert i_was_run
-    assert 1, controller.logger.logged.size
-    assert_last_logged 'debug_run', :debug
+    assert_last_logged 'debug_run'
+  end
+
+  def test_within_level
+    controller.logger.level = ActiveSupport::BufferedLogger::DEBUG
+    benchmark('included_debug_run', :level => :debug) { }
+    assert_last_logged 'included_debug_run'
+  end
+
+  def test_outside_level
+    controller.logger.level = ActiveSupport::BufferedLogger::ERROR
+    benchmark('skipped_debug_run', :level => :debug) { }
+    assert_no_match(/skipped_debug_run/, buffer.last)
+  ensure
+    controller.logger.level = ActiveSupport::BufferedLogger::DEBUG
   end
 
+  def test_without_silencing
+    benchmark('debug_run', :silence => false) do
+      controller.logger.info "not silenced!"
+    end
+
+    assert_equal 2, buffer.size
+  end
+
+  def test_with_silencing
+    benchmark('debug_run', :silence => true) do
+      controller.logger.info "silenced!"
+    end
+
+    assert_equal 1, buffer.size
+  end
+
+
   private
-    def assert_last_logged(message = 'Benchmarking', level = :info)
-      last = controller.logger.logged.last
-      assert 2, last.size
-      assert_equal level, last.first
-      assert 1, last[1].size
-      assert last[1][0] =~ /^#{message} \(.*\)$/
+    def buffer
+      controller.logger.send(:buffer)
+    end
+  
+    def assert_last_logged(message = 'Benchmarking')
+      assert_match(/^#{message} \(.*\)$/, buffer.last)
     end
 end