From 426fe543d7b6d6fa42ff18304770a628904f5f4c Mon Sep 17 00:00:00 2001 From: Pratik Naik Date: Fri, 10 Apr 2015 14:23:44 -0500 Subject: [PATCH] Add a tagged proxy logger to handle per connection tags --- lib/action_cable/channel/base.rb | 6 +-- lib/action_cable/channel/redis.rb | 6 +-- lib/action_cable/connection.rb | 1 + lib/action_cable/connection/base.rb | 43 ++++++++----------- .../connection/internal_channel.rb | 8 ++-- .../connection/tagged_logger_proxy.rb | 30 +++++++++++++ 6 files changed, 59 insertions(+), 35 deletions(-) create mode 100644 lib/action_cable/connection/tagged_logger_proxy.rb diff --git a/lib/action_cable/channel/base.rb b/lib/action_cable/channel/base.rb index 37399c8101..fac988ba52 100644 --- a/lib/action_cable/channel/base.rb +++ b/lib/action_cable/channel/base.rb @@ -11,7 +11,7 @@ module ActionCable on_unsubscribe :disconnect attr_reader :params, :connection - delegate :log_info, :log_error, to: :connection + delegate :logger, to: :connection class_attribute :channel_name @@ -41,7 +41,7 @@ module ActionCable if respond_to?(:receive) receive(data) else - log_error "#{self.class.name} received data (#{data}) but #{self.class.name}#receive callback is not defined" + logger.error "#{self.class.name} received data (#{data}) but #{self.class.name}#receive callback is not defined" end else unauthorized @@ -67,7 +67,7 @@ module ActionCable end def unauthorized - log_error "Unauthorized access to #{self.class.name}" + logger.error "Unauthorized access to #{self.class.name}" end def connect diff --git a/lib/action_cable/channel/redis.rb b/lib/action_cable/channel/redis.rb index 197cf03c8e..cbc3512072 100644 --- a/lib/action_cable/channel/redis.rb +++ b/lib/action_cable/channel/redis.rb @@ -14,7 +14,7 @@ module ActionCable @_redis_channels ||= [] @_redis_channels << [ redis_channel, callback ] - log_info "Subscribing to the redis channel: #{redis_channel}" + logger.info "Subscribing to the redis channel: #{redis_channel}" pubsub.subscribe(redis_channel, &callback) end @@ -22,7 +22,7 @@ module ActionCable def unsubscribe_from_redis_channels if @_redis_channels @_redis_channels.each do |channel, callback| - log_info "Unsubscribing from the redis channel: #{channel}" + logger.info "Unsubscribing from the redis channel: #{channel}" pubsub.unsubscribe_proc(channel, callback) end end @@ -30,7 +30,7 @@ module ActionCable def default_subscription_callback(channel) -> (message) do - log_info "Received a message over the redis channel: #{channel} (#{message})" + logger.info "Received a message over the redis channel: #{channel} (#{message})" broadcast ActiveSupport::JSON.decode(message) end end diff --git a/lib/action_cable/connection.rb b/lib/action_cable/connection.rb index 665a851b11..a9048926e4 100644 --- a/lib/action_cable/connection.rb +++ b/lib/action_cable/connection.rb @@ -3,5 +3,6 @@ module ActionCable autoload :Base, 'action_cable/connection/base' autoload :InternalChannel, 'action_cable/connection/internal_channel' autoload :Identifier, 'action_cable/connection/identifier' + autoload :TaggedLoggerProxy, 'action_cable/connection/tagged_logger_proxy' end end diff --git a/lib/action_cable/connection/base.rb b/lib/action_cable/connection/base.rb index 2ab62092af..e8126f3d75 100644 --- a/lib/action_cable/connection/base.rb +++ b/lib/action_cable/connection/base.rb @@ -12,8 +12,7 @@ module ActionCable self.identifiers += identifiers end - attr_reader :env, :server - attr_accessor :log_tags + attr_reader :env, :server, :logger delegate :worker_pool, :pubsub, to: :server def initialize(server, env) @@ -24,11 +23,13 @@ module ActionCable @accept_messages = false @pending_messages = [] @subscriptions = {} - @log_tags = [ 'ActionCable' ] + + @logger = TaggedLoggerProxy.new(server.logger, tags: [ 'ActionCable' ]) + @logger.add_tags(*logger_tags) end def process - log_info started_request_message + logger.info started_request_message if websocket? @websocket = Faye::WebSocket.new(@env) @@ -52,7 +53,7 @@ module ActionCable end @websocket.on(:close) do |event| - log_info finished_request_message + logger.info finished_request_message worker_pool.async.invoke(self, :on_connection_closed) EventMachine.cancel_timer(@ping_timer) if @ping_timer @@ -86,7 +87,7 @@ module ActionCable end def broadcast(data) - log_info "Sending data: #{data}" + logger.info "Sending data: #{data}" @websocket.send data end @@ -99,19 +100,11 @@ module ActionCable end def handle_exception - log_error "Closing connection" + logger.error "Closing connection" @websocket.close end - def log_info(message) - log :info, message - end - - def log_error(message) - log :error, message - end - protected def initialize_connection server.add_connection(self) @@ -142,13 +135,13 @@ module ActionCable subscription_klass = server.registered_channels.detect { |channel_klass| channel_klass.find_name == id_options[:channel] } if subscription_klass - log_info "Subscribing to channel: #{id_key}" + logger.info "Subscribing to channel: #{id_key}" @subscriptions[id_key] = subscription_klass.new(self, id_key, id_options) else - log_error "Subscription class not found (#{data.inspect})" + logger.error "Subscription class not found (#{data.inspect})" end rescue Exception => e - log_error "Could not subscribe to channel (#{data.inspect})" + logger.error "Could not subscribe to channel (#{data.inspect})" log_exception(e) end @@ -159,18 +152,18 @@ module ActionCable log_exception "Unable to process message because no subscription was found (#{message.inspect})" end rescue Exception => e - log_error "Could not process message (#{message.inspect})" + logger.error "Could not process message (#{message.inspect})" log_exception(e) end def unsubscribe_channel(data) - log_info "Unsubscribing from channel: #{data['identifier']}" + logger.info "Unsubscribing from channel: #{data['identifier']}" @subscriptions[data['identifier']].unsubscribe @subscriptions.delete(data['identifier']) end def invalid_request - log_info "#{finished_request_message}" + logger.info "#{finished_request_message}" [404, {'Content-Type' => 'text/plain'}, ['Page not found']] end @@ -204,12 +197,12 @@ module ActionCable end def log_exception(e) - log_error "There was an exception - #{e.class}(#{e.message})" - log_error e.backtrace.join("\n") + logger.error "There was an exception - #{e.class}(#{e.message})" + logger.error e.backtrace.join("\n") end - def log(type, message) - server.logger.tagged(*log_tags) { server.logger.send type, message } + def logger_tags + [] end end end diff --git a/lib/action_cable/connection/internal_channel.rb b/lib/action_cable/connection/internal_channel.rb index 5338fc879e..a7d99f4b14 100644 --- a/lib/action_cable/connection/internal_channel.rb +++ b/lib/action_cable/connection/internal_channel.rb @@ -10,7 +10,7 @@ module ActionCable @_internal_redis_subscriptions << [ internal_redis_channel, callback ] pubsub.subscribe(internal_redis_channel, &callback) - log_info "Registered connection (#{connection_identifier})" + logger.info "Registered connection (#{connection_identifier})" end end @@ -26,12 +26,12 @@ module ActionCable case message['type'] when 'disconnect' - log_info "Removing connection (#{connection_identifier})" + logger.info "Removing connection (#{connection_identifier})" @websocket.close end rescue Exception => e - log_error "There was an exception - #{e.class}(#{e.message})" - log_error e.backtrace.join("\n") + logger.error "There was an exception - #{e.class}(#{e.message})" + logger.error e.backtrace.join("\n") handle_exception end diff --git a/lib/action_cable/connection/tagged_logger_proxy.rb b/lib/action_cable/connection/tagged_logger_proxy.rb new file mode 100644 index 0000000000..04ea331bde --- /dev/null +++ b/lib/action_cable/connection/tagged_logger_proxy.rb @@ -0,0 +1,30 @@ +module ActionCable + module Connection + class TaggedLoggerProxy + + def initialize(logger, tags:) + @logger = logger + @tags = tags.flatten + end + + def info(message) + log :info, message + end + + def error(message) + log :error, message + end + + def add_tags(*tags) + @tags += tags.flatten + @tags = @tags.uniq + end + + protected + def log(type, message) + @logger.tagged(*@tags) { @logger.send type, message } + end + + end + end +end