Keep logging in the ActionCable::Channel::Base

To move Action Cable logging to a LoggingSubscriber we need to pass the
log tags in the notification payload since Action Cable logging use the
Channel instance to tag the logs.

3 files changed, 6 insertions, 110 deletions

diff --git a/actioncable/lib/action_cable/channel/base.rb b/actioncable/lib/action_cable/channel/base.rb
index a0319eb522..464d0581dd 100644
--- a/actioncable/lib/action_cable/channel/base.rb
+++ b/actioncable/lib/action_cable/channel/base.rb
@@ -1,4 +1,3 @@
-require 'action_cable/channel/log_subscriber'
 require 'set'
 
 module ActionCable
@@ -195,6 +194,8 @@ module ActionCable
         # Transmit a hash of data to the subscriber. The hash will automatically be wrapped in a JSON envelope with
         # the proper channel identifier marked as the recipient.
         def transmit(data, via: nil)
+          logger.info "#{self.class.name} transmitting #{data.inspect.truncate(300)}".tap { |m| m << " (via #{via})" if via }
+
           payload = { channel_class: self.class.name, data: data, via: via }
           ActiveSupport::Notifications.instrument("transmit.action_cable", payload) do
             connection.transmit ActiveSupport::JSON.encode(identifier: @identifier, message: data)
@@ -270,6 +271,8 @@ module ActionCable
 
         def transmit_subscription_confirmation
           unless subscription_confirmation_sent?
+            logger.info "#{self.class.name} is transmitting the subscription confirmation"
+
             ActiveSupport::Notifications.instrument("transmit_subscription_confirmation.action_cable", channel_class: self.class.name) do
               connection.transmit ActiveSupport::JSON.encode(identifier: @identifier, type: ActionCable::INTERNAL[:message_types][:confirmation])
               @subscription_confirmation_sent = true
@@ -283,6 +286,8 @@ module ActionCable
         end
 
         def transmit_subscription_rejection
+          logger.info "#{self.class.name} is transmitting the subscription rejection"
+
           ActiveSupport::Notifications.instrument("transmit_subscription_rejection.action_cable", channel_class: self.class.name) do
             connection.transmit ActiveSupport::JSON.encode(identifier: @identifier, type: ActionCable::INTERNAL[:message_types][:rejection])
           end
diff --git a/actioncable/lib/action_cable/channel/log_subscriber.rb b/actioncable/lib/action_cable/channel/log_subscriber.rb
deleted file mode 100644
index d58b017e0e..0000000000
--- a/actioncable/lib/action_cable/channel/log_subscriber.rb
+++ /dev/null
@@ -1,40 +0,0 @@
-require 'active_support/log_subscriber'
-
-module ActionCable
-  module Channel
-    class LogSubscriber < ActiveSupport::LogSubscriber
-      def perform_action(event)
-        info do
-          channel_class = event.payload[:channel_class]
-          action = event.payload[:action]
-          "Completed #{channel_class}##{action} in #{event.duration.round}ms"
-        end
-      end
-
-      def transmit(event)
-        info do
-          channel_class = event.payload[:channel_class]
-          data = event.payload[:data]
-          via = event.payload[:via]
-          "#{channel_class} transmitting #{data.inspect.truncate(300)}".tap { |m| m << " (via #{via})" if via }
-        end
-      end
-
-      def transmit_subscription_confirmation(event)
-        info do
-          channel_class = event.payload[:channel_class]
-          "#{channel_class} is transmitting the subscription confirmation"
-        end
-      end
-
-      def transmit_subscription_rejection(event)
-        info do
-          channel_class = event.payload[:channel_class]
-          "#{channel_class} is transmitting the subscription rejection"
-        end
-      end
-    end
-  end
-end
-
-ActionCable::Channel::LogSubscriber.attach_to :action_cable
diff --git a/actioncable/test/channel/log_subscriber_test.rb b/actioncable/test/channel/log_subscriber_test.rb
deleted file mode 100644
index 18acdc9fbd..0000000000
--- a/actioncable/test/channel/log_subscriber_test.rb
+++ /dev/null
@@ -1,69 +0,0 @@
-require 'test_helper'
-require 'stubs/test_connection'
-require 'active_support/log_subscriber/test_helper'
-require 'action_cable/channel/log_subscriber'
-
-class ActionCable::Channel::LogSubscriberTest < ActiveSupport::TestCase
-  include ActiveSupport::LogSubscriber::TestHelper
-
-  class ChatChannel < ActionCable::Channel::Base
-    attr_reader :last_action
-
-    def speak(data)
-      @last_action = [ :speak, data ]
-    end
-
-    def get_latest
-      transmit data: 'latest'
-    end
-  end
-
-  def setup
-    super
-    @connection = TestConnection.new
-    @channel = ChatChannel.new @connection, "{id: 1}", { id: 1 }
-    ActionCable::Channel::LogSubscriber.attach_to :action_cable
-  end
-
-  def test_perform_action
-    data = {'action' => :speak, 'content' => 'hello'}
-    @channel.perform_action(data)
-    wait
-
-    assert_equal(1, logs.size)
-    assert_match(/Completed #{channel_class}#speak in \d+ms/, logs.first)
-  end
-
-  def test_transmit
-    @channel.perform_action('action' => :get_latest)
-    wait
-
-    assert_equal(2, logs.size)
-    assert_match(/^#{channel_class} transmitting/, logs.first)
-  end
-
-  def test_transmit_subscription_confirmation
-    @channel.stubs(:subscription_confirmation_sent?).returns(false)
-    @channel.send(:transmit_subscription_confirmation)
-    wait
-
-    assert_equal(1, logs.size)
-    assert_equal("#{channel_class} is transmitting the subscription confirmation", logs.first)
-  end
-
-  def test_transmit_subscription_rejection
-    @channel.send(:transmit_subscription_rejection)
-    wait
-
-    assert_equal(1, logs.size)
-    assert_equal("#{channel_class} is transmitting the subscription rejection", logs.first)
-  end
-
-  def channel_class
-    "ActionCable::Channel::LogSubscriberTest::ChatChannel"
-  end
-
-  def logs
-    @logs ||= @logger.logged(:info)
-  end
-end