Modify LogSubscriber for single partial's cache message.

Implement naive partial caching mechanism.

Add test for LogSubscriber

Use ActionView::Base#log_payload to store log_subscriber's payload, so we can pass cache result into it.

Fixed tests

Remove useless settings

Check if #log_payload exists before calling it. Because other classes also includes CacheHelper but don't have is attribute

Use @log_payload_for_partial_reder instead of #log_payload to carry ActionView's payload.

Update test's hash syntax

Add configuration to enable/disable fragment caching logging

Remove unless test and add new test to ensure cache info won't effect next rendering's log

Move :enable_fragment_cache_logging config from ActionView to ActionPack

Apply new config to tests

Update actionview's changelog

Update configuration guide

Improve actionview's changelog

Refactor PartialRenderer#render and log tests

Mute subscriber's log instead of disabling instrumentation.

Fix typo, remove useless comment and use new hash syntax

Improve actionpack's log_subscriber test

Fix rebase mistake

Apply new config to all caching intstrument actions

1 files changed, 53 insertions, 6 deletions

diff --git a/actionview/test/template/log_subscriber_test.rb b/actionview/test/template/log_subscriber_test.rb
index 565eee6628..3884807017 100644
--- a/actionview/test/template/log_subscriber_test.rb
+++ b/actionview/test/template/log_subscriber_test.rb
@@ -30,6 +30,13 @@ class AVLogSubscriberTest < ActiveSupport::TestCase
     ActionView::Base.logger = logger
   end
 
+  def set_cache_controller
+    controller = ActionController::Base.new
+    controller.perform_caching = true
+    controller.cache_store = ActiveSupport::Cache::MemoryStore.new
+    @view.controller = controller
+  end
+
   def test_render_file_template
     Rails.stub(:root, File.expand_path(FIXTURE_LOAD_PATH)) do
       @view.render(file: "test/hello_world")
@@ -63,23 +70,63 @@ class AVLogSubscriberTest < ActiveSupport::TestCase
     end
   end
 
-  def test_render_partial_template
+  def test_render_partial_with_implicit_path
     Rails.stub(:root, File.expand_path(FIXTURE_LOAD_PATH)) do
-      @view.render(partial: "test/customer")
+      @view.render(Customer.new("david"), greeting: "hi")
       wait
 
       assert_equal 1, @logger.logged(:info).size
-      assert_match(/Rendered test\/_customer.erb/, @logger.logged(:info).last)
+      assert_match(/Rendered customers\/_customer\.html\.erb/, @logger.logged(:info).last)
     end
   end
 
-  def test_render_partial_with_implicit_path
+  def test_render_partial_with_cache_missed
     Rails.stub(:root, File.expand_path(FIXTURE_LOAD_PATH)) do
-      @view.render(Customer.new("david"), greeting: "hi")
+      def @view.view_cache_dependencies; []; end
+      def @view.fragment_cache_key(*); 'ahoy `controller` dependency'; end
+      set_cache_controller
+
+      @view.render(partial: "test/cached_customer", locals: { cached_customer: Customer.new("david") })
       wait
 
       assert_equal 1, @logger.logged(:info).size
-      assert_match(/Rendered customers\/_customer\.html\.erb/, @logger.logged(:info).last)
+      assert_match(/Rendered test\/_cached_customer\.erb (.*) \[cache miss\]/, @logger.logged(:info).last)
+    end
+  end
+
+  def test_render_partial_with_cache_hitted
+    Rails.stub(:root, File.expand_path(FIXTURE_LOAD_PATH)) do
+      def @view.view_cache_dependencies; []; end
+      def @view.fragment_cache_key(*); 'ahoy `controller` dependency'; end
+      set_cache_controller
+
+      @view.render(partial: "test/cached_customer", locals: { cached_customer: Customer.new("david") })
+      # Second render should hit cache.
+      @view.render(partial: "test/cached_customer", locals: { cached_customer: Customer.new("david") })
+      wait
+
+      assert_equal 2, @logger.logged(:info).size
+      assert_match(/Rendered test\/_cached_customer\.erb (.*) \[cache hit\]/, @logger.logged(:info).last)
+    end
+  end
+
+  def test_render_partial_with_cache_hitted_and_missed
+    Rails.stub(:root, File.expand_path(FIXTURE_LOAD_PATH)) do
+      def @view.view_cache_dependencies; []; end
+      def @view.fragment_cache_key(*); 'ahoy `controller` dependency'; end
+      set_cache_controller
+
+      @view.render(partial: "test/cached_customer", locals: { cached_customer: Customer.new("david") })
+      wait
+      assert_match(/Rendered test\/_cached_customer\.erb (.*) \[cache miss\]/, @logger.logged(:info).last)
+
+      @view.render(partial: "test/cached_customer", locals: { cached_customer: Customer.new("david") })
+      wait
+      assert_match(/Rendered test\/_cached_customer\.erb (.*) \[cache hit\]/, @logger.logged(:info).last)
+
+      @view.render(partial: "test/cached_customer", locals: { cached_customer: Customer.new("Stan") })
+      wait
+      assert_match(/Rendered test\/_cached_customer\.erb (.*) \[cache miss\]/, @logger.logged(:info).last)
     end
   end