2 files changed, 31 insertions, 20 deletions

diff --git a/actionpack/lib/action_controller/benchmarking.rb b/actionpack/lib/action_controller/benchmarking.rb
index b7c7eae8e9..587bc29d42 100644
--- a/actionpack/lib/action_controller/benchmarking.rb
+++ b/actionpack/lib/action_controller/benchmarking.rb
@@ -19,11 +19,15 @@ module ActionController #:nodoc:
     module ClassMethods
       # Log and benchmark the workings of a single block and silence whatever logging that may have happened inside it 
       # (unless <tt>use_silence</tt> is set to false).
-      def benchmark(title, use_silence = true)
-        if logger
+      #
+      # The benchmark is only recorded if the current level of the logger matches the <tt>log_level</tt>, which makes it
+      # easy to include benchmarking statements in production software that will remain inexpensive because the benchmark
+      # will only be conducted if the log level is low enough.
+      def benchmark(title, log_level = Logger::DEBUG, use_silence = true)
+        if logger && logger.level == log_level
           result = nil
           seconds = Benchmark.realtime { result = use_silence ? silence { yield } : yield }
-          logger.info "#{title} (#{sprintf("%f", seconds)})"
+          logger.add(log_level, "#{title} (#{sprintf("%f", seconds)})")
           result
         else
           yield
diff --git a/actionpack/lib/action_controller/caching.rb b/actionpack/lib/action_controller/caching.rb
index 8ca01fa9b0..f866f7bd24 100644
--- a/actionpack/lib/action_controller/caching.rb
+++ b/actionpack/lib/action_controller/caching.rb
@@ -74,17 +74,21 @@ module ActionController #:nodoc:
         #   expire_page "/lists/show"
         def expire_page(path)
           return unless perform_caching
-          File.delete(page_cache_path(path)) if File.exists?(page_cache_path(path))
-          logger.debug "Expired page: #{page_cache_file(path)}" unless logger.nil?
+
+          benchmark "Expired page: #{page_cache_file(path)}" do
+            File.delete(page_cache_path(path)) if File.exists?(page_cache_path(path))
+          end
         end
         
         # Manually cache the +content+ in the key determined by +path+. Example:
         #   cache_page "I'm the cached content", "/lists/show"
         def cache_page(content, path)
           return unless perform_caching
-          FileUtils.makedirs(File.dirname(page_cache_path(path)))
-          File.open(page_cache_path(path), "w+") { |f| f.write(content) }
-          logger.debug "Cached page: #{page_cache_file(path)}" unless logger.nil?
+
+          benchmark "Cached page: #{page_cache_file(path)}" do
+            FileUtils.makedirs(File.dirname(page_cache_path(path)))
+            File.open(page_cache_path(path), "w+") { |f| f.write(content) }
+          end
         end
 
         # Caches the +actions+ using the page-caching approach that'll store the cache in a path within the page_cache_directory that
@@ -279,21 +283,22 @@ module ActionController #:nodoc:
         return unless perform_caching
 
         key = fragment_cache_key(name)
-        fragment_cache_store.write(key, content, options)
-        logger.debug "Cached fragment: #{key}" unless logger.nil?
+        benchmark "Cached fragment: #{key}" do
+          fragment_cache_store.write(key, content, options)
+        end
+
         content
       end
       
       def read_fragment(name, options = {})
         return unless perform_caching
 
-        key = fragment_cache_key(name)
-        if cache = fragment_cache_store.read(key, options)
-          logger.debug "Fragment hit: #{key}" unless logger.nil?
-          cache
-        else
-          false
+        key, cache = fragment_cache_key(name), nil
+        benchmark "Fragment hit: #{key}" do
+          cache = fragment_cache_store.read(key, options)
         end
+
+        cache || false
       end
       
       # Name can take one of three forms:
@@ -306,11 +311,13 @@ module ActionController #:nodoc:
         key = fragment_cache_key(name)
 
         if key.is_a?(Regexp)
-          fragment_cache_store.delete_matched(key, options)
-          logger.debug "Expired fragments matching: #{key.source}" unless logger.nil?
+          benchmark "Expired fragments matching: #{key.source}" do
+            fragment_cache_store.delete_matched(key, options)
+          end
         else
-          fragment_cache_store.delete(key, options)
-          logger.debug "Expired fragment: #{key}" unless logger.nil?
+          benchmark "Expired fragment: #{key}" do
+            fragment_cache_store.delete(key, options)
+          end
         end
       end