Add ActionDispatch::Railties::Subscriber and finish tidying up the logging.

2 files changed, 112 insertions, 69 deletions

diff --git a/actionpack/test/dispatch/notifications_test.rb b/actionpack/test/dispatch/notifications_test.rb
deleted file mode 100644
index d834a734ef..0000000000
--- a/actionpack/test/dispatch/notifications_test.rb
+++ /dev/null
@@ -1,69 +0,0 @@
-require 'abstract_unit'
-
-class NotificationsMiddlewareTest < ActionController::IntegrationTest
-  Boomer = lambda do |env|
-    req = ActionDispatch::Request.new(env)
-    case req.path
-    when "/"
-      [200, {}, []]
-    else
-      raise "puke!"
-    end
-  end
-
-  App = ActionDispatch::Notifications.new(Boomer)
-
-  def setup
-    @queue    = ActiveSupport::Notifications::Fanout.new
-    @notifier = ActiveSupport::Notifications::Notifier.new(@queue)
-    ActiveSupport::Notifications.notifier = @notifier
-
-    @events = []
-    ActiveSupport::Notifications.subscribe do |*args|
-      @events << args
-    end
-
-    @app = App
-  end
-
-  test "publishes notifications" do
-    get "/"
-    ActiveSupport::Notifications.notifier.wait
-
-    assert_equal 2, @events.size
-    before, after = @events
-
-    assert_equal 'action_dispatch.before_dispatch', before[0]
-    assert_kind_of Hash, before[4][:env]
-    assert_equal 'GET',  before[4][:env]["REQUEST_METHOD"]
-
-    assert_equal 'action_dispatch.after_dispatch', after[0]
-    assert_kind_of Hash, after[4][:env]
-    assert_equal 'GET',  after[4][:env]["REQUEST_METHOD"]
-  end
-
-  test "publishes notifications on failure" do
-    begin
-      get "/puke"
-    rescue
-    end
-
-    ActiveSupport::Notifications.notifier.wait
-
-    assert_equal 3, @events.size
-    before, after, exception = @events
-
-    assert_equal 'action_dispatch.before_dispatch', before[0]
-    assert_kind_of Hash, before[4][:env]
-    assert_equal 'GET',  before[4][:env]["REQUEST_METHOD"]
-
-    assert_equal 'action_dispatch.after_dispatch', after[0]
-    assert_kind_of Hash, after[4][:env]
-    assert_equal 'GET',  after[4][:env]["REQUEST_METHOD"]  
-
-    assert_equal 'action_dispatch.exception', exception[0]
-    assert_kind_of Hash, exception[4][:env]
-    assert_equal 'GET',  exception[4][:env]["REQUEST_METHOD"]  
-    assert_kind_of RuntimeError, exception[4][:exception]
-  end
-end
\ No newline at end of file
diff --git a/actionpack/test/dispatch/subscriber_test.rb b/actionpack/test/dispatch/subscriber_test.rb
new file mode 100644
index 0000000000..a7f1a2659a
--- /dev/null
+++ b/actionpack/test/dispatch/subscriber_test.rb
@@ -0,0 +1,112 @@
+require "abstract_unit"
+require "rails/subscriber/test_helper"
+require "action_dispatch/railties/subscriber"
+
+module DispatcherSubscriberTest
+  Boomer = lambda do |env|
+    req = ActionDispatch::Request.new(env)
+    case req.path
+    when "/"
+      [200, {}, []]
+    else
+      raise "puke!"
+    end
+  end
+
+  App = ActionDispatch::Notifications.new(Boomer)
+
+  def setup
+    Rails::Subscriber.add(:action_dispatch, ActionDispatch::Railties::Subscriber.new)
+    @app = App
+    super
+
+    @events = []
+    ActiveSupport::Notifications.subscribe do |*args|
+      @events << args
+    end
+  end
+
+  def set_logger(logger)
+    ActionController::Base.logger = logger
+  end
+
+  def test_publishes_notifications
+    get "/"
+    wait
+
+    assert_equal 2, @events.size
+    before, after = @events
+
+    assert_equal 'action_dispatch.before_dispatch', before[0]
+    assert_kind_of Hash, before[4][:env]
+    assert_equal 'GET',  before[4][:env]["REQUEST_METHOD"]
+
+    assert_equal 'action_dispatch.after_dispatch', after[0]
+    assert_kind_of Hash, after[4][:env]
+    assert_equal 'GET',  after[4][:env]["REQUEST_METHOD"]
+  end
+
+  def test_publishes_notifications_even_on_failures
+    begin
+      get "/puke"
+    rescue
+    end
+
+    wait
+
+    assert_equal 3, @events.size
+    before, after, exception = @events
+
+    assert_equal 'action_dispatch.before_dispatch', before[0]
+    assert_kind_of Hash, before[4][:env]
+    assert_equal 'GET',  before[4][:env]["REQUEST_METHOD"]
+
+    assert_equal 'action_dispatch.after_dispatch', after[0]
+    assert_kind_of Hash, after[4][:env]
+    assert_equal 'GET',  after[4][:env]["REQUEST_METHOD"]
+
+    assert_equal 'action_dispatch.exception', exception[0]
+    assert_kind_of Hash, exception[4][:env]
+    assert_equal 'GET',  exception[4][:env]["REQUEST_METHOD"]
+    assert_kind_of RuntimeError, exception[4][:exception]
+  end
+
+  def test_subscriber_logs_notifications
+    get "/"
+    wait
+
+    log = @logger.logged(:info).first
+    assert_equal 1, @logger.logged(:info).size
+
+    assert_match %r{^Processing "/" to text/html}, log
+    assert_match %r{\(for 127\.0\.0\.1}, log
+    assert_match %r{\[GET\]}, log
+  end
+
+  def test_subscriber_has_its_logged_flushed_after_request
+    assert_equal 0, @logger.flush_count
+    get "/"
+    wait
+    assert_equal 1, @logger.flush_count
+  end
+
+  def test_subscriber_has_its_logged_flushed_even_after_busted_requests
+    assert_equal 0, @logger.flush_count
+    begin
+      get "/puke"
+    rescue
+    end
+    wait
+    assert_equal 1, @logger.flush_count
+  end
+
+  class SyncSubscriberTest < ActionController::IntegrationTest
+    include Rails::Subscriber::SyncTestHelper
+    include DispatcherSubscriberTest
+  end
+
+  class AsyncSubscriberTest < ActionController::IntegrationTest
+    include Rails::Subscriber::AsyncTestHelper
+    include DispatcherSubscriberTest
+  end
+end
\ No newline at end of file