3 files changed, 32 insertions, 2 deletions
diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb
index 1f3ffe2933..f527b131d8 100644
--- a/actionpack/lib/action_controller/base.rb
+++ b/actionpack/lib/action_controller/base.rb
@@ -871,6 +871,7 @@ module ActionController #:nodoc:
         end
 
         response.layout = layout = pick_layout(options)
+        logger.info("Rendering template within #{layout}") if logger && layout
 
         if content_type = options[:content_type]
           response.content_type = content_type.to_s
@@ -1122,6 +1123,7 @@ module ActionController #:nodoc:
 
     private
       def render_for_file(template_path, status = nil, layout = nil, locals = {}) #:nodoc:
+        logger.info("Rendering #{template_path}" + (status ? " (#{status})" : '')) if logger
         render_for_text @template.render(:file => template_path, :locals => locals, :layout => layout), status
       end
 
diff --git a/actionpack/lib/action_view/base.rb b/actionpack/lib/action_view/base.rb
index 9a2b667005..e9087560a1 100644
--- a/actionpack/lib/action_view/base.rb
+++ b/actionpack/lib/action_view/base.rb
@@ -253,7 +253,6 @@ module ActionView #:nodoc:
             ActiveSupport::Deprecation.warn("use_full_path option has been deprecated and has no affect.", caller)
           end
 
-          logger.info("Rendering #{options[:file]}") if logger
           pick_template(options[:file]).render_template(self, options[:locals])
         elsif options[:partial]
           render_partial(options)
@@ -353,7 +352,6 @@ module ActionView #:nodoc:
 
       def render_with_layout(options, local_assigns, &block)
         partial_layout = options.delete(:layout)
-        logger.info("Rendering template within #{partial_layout}") if logger
 
         if block_given?
           begin
diff --git a/actionpack/test/controller/render_test.rb b/actionpack/test/controller/render_test.rb
index 8d15aa2da4..c4a2bf3db3 100644
--- a/actionpack/test/controller/render_test.rb
+++ b/actionpack/test/controller/render_test.rb
@@ -8,6 +8,18 @@ module Fun
   end
 end
 
+class MockLogger
+  attr_reader :logged
+
+  def initialize
+    @logged = []
+  end
+
+  def method_missing(method, *args)
+    @logged << args.first
+  end
+end
+
 class TestController < ActionController::Base
   class LabellingFormBuilder < ActionView::Helpers::FormBuilder
   end
@@ -1385,3 +1397,21 @@ class LastModifiedRenderTest < Test::Unit::TestCase
     assert_equal @last_modified, @response.headers['Last-Modified']
   end
 end
+
+class RenderingLoggingTest < Test::Unit::TestCase
+  def setup
+    @request    = ActionController::TestRequest.new
+    @response   = ActionController::TestResponse.new
+    @controller = TestController.new
+
+    @request.host = "www.nextangle.com"
+  end
+
+  def test_logger_prints_layout_and_template_rendering_info
+    @controller.logger = MockLogger.new
+    get :layout_test
+    logged = @controller.logger.logged.find_all {|l| l =~ /render/i }
+    assert_equal "Rendering template within layouts/standard", logged[0]
+    assert_equal "Rendering test/hello_world", logged[1]
+  end
+end