From 1ca045ccd43b3647487714e7441981ff87c51943 Mon Sep 17 00:00:00 2001 From: Pratik Naik Date: Fri, 10 Apr 2015 11:58:31 -0500 Subject: Tag log entries with the request id --- lib/action_cable/channel/base.rb | 9 ++--- lib/action_cable/channel/redis.rb | 6 +-- lib/action_cable/connection/base.rb | 54 ++++++++++++++++--------- lib/action_cable/connection/internal_channel.rb | 8 ++-- lib/action_cable/worker.rb | 2 +- 5 files changed, 45 insertions(+), 34 deletions(-) (limited to 'lib') diff --git a/lib/action_cable/channel/base.rb b/lib/action_cable/channel/base.rb index 8ee99649f4..37399c8101 100644 --- a/lib/action_cable/channel/base.rb +++ b/lib/action_cable/channel/base.rb @@ -11,6 +11,7 @@ module ActionCable on_unsubscribe :disconnect attr_reader :params, :connection + delegate :log_info, :log_error, to: :connection class_attribute :channel_name @@ -40,7 +41,7 @@ module ActionCable if respond_to?(:receive) receive(data) else - logger.error "[ActionCable] #{self.class.name} received data (#{data}) but #{self.class.name}#receive callback is not defined" + log_error "#{self.class.name} received data (#{data}) but #{self.class.name}#receive callback is not defined" end else unauthorized @@ -66,7 +67,7 @@ module ActionCable end def unauthorized - logger.error "[ActionCable] Unauthorized access to #{self.class.name}" + log_error "Unauthorized access to #{self.class.name}" end def connect @@ -101,10 +102,6 @@ module ActionCable connection.worker_pool end - def logger - connection.logger - end - end end diff --git a/lib/action_cable/channel/redis.rb b/lib/action_cable/channel/redis.rb index fda55ec45d..197cf03c8e 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 ] - logger.info "[ActionCable] Subscribing to the redis channel: #{redis_channel}" + log_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| - logger.info "[ActionCable] Unsubscribing from the redis channel: #{channel}" + log_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 - logger.info "[ActionCable] Received a message over the redis channel: #{channel} (#{message})" + log_info "Received a message over the redis channel: #{channel} (#{message})" broadcast ActiveSupport::JSON.decode(message) end end diff --git a/lib/action_cable/connection/base.rb b/lib/action_cable/connection/base.rb index 655e74ee01..2ab62092af 100644 --- a/lib/action_cable/connection/base.rb +++ b/lib/action_cable/connection/base.rb @@ -13,7 +13,8 @@ module ActionCable end attr_reader :env, :server - delegate :worker_pool, :pubsub, :logger, to: :server + attr_accessor :log_tags + delegate :worker_pool, :pubsub, to: :server def initialize(server, env) @started_at = Time.now @@ -23,10 +24,11 @@ module ActionCable @accept_messages = false @pending_messages = [] @subscriptions = {} + @log_tags = [ 'ActionCable' ] end def process - logger.info "[ActionCable] #{started_request_message}" + log_info started_request_message if websocket? @websocket = Faye::WebSocket.new(@env) @@ -50,7 +52,7 @@ module ActionCable end @websocket.on(:close) do |event| - logger.info "[ActionCable] #{finished_request_message}" + log_info finished_request_message worker_pool.async.invoke(self, :on_connection_closed) EventMachine.cancel_timer(@ping_timer) if @ping_timer @@ -84,16 +86,10 @@ module ActionCable end def broadcast(data) - logger.info "[ActionCable] Sending data: #{data}" + log_info "Sending data: #{data}" @websocket.send data end - def handle_exception - logger.error "[ActionCable] Closing connection" - - @websocket.close - end - def statistics { identifier: connection_identifier, @@ -102,7 +98,21 @@ module ActionCable } end - private + def handle_exception + log_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) @@ -132,13 +142,13 @@ module ActionCable subscription_klass = server.registered_channels.detect { |channel_klass| channel_klass.find_name == id_options[:channel] } if subscription_klass - logger.info "[ActionCable] Subscribing to channel: #{id_key}" + log_info "Subscribing to channel: #{id_key}" @subscriptions[id_key] = subscription_klass.new(self, id_key, id_options) else - logger.error "[ActionCable] Subscription class not found (#{data.inspect})" + log_error "Subscription class not found (#{data.inspect})" end rescue Exception => e - logger.error "[ActionCable] Could not subscribe to channel (#{data.inspect})" + log_error "Could not subscribe to channel (#{data.inspect})" log_exception(e) end @@ -146,21 +156,21 @@ module ActionCable if @subscriptions[message['identifier']] @subscriptions[message['identifier']].receive_data(ActiveSupport::JSON.decode message['data']) else - logger.error "[ActionCable] Unable to process message because no subscription was found (#{message.inspect})" + log_exception "Unable to process message because no subscription was found (#{message.inspect})" end rescue Exception => e - logger.error "[ActionCable] Could not process message (#{message.inspect})" + log_error "Could not process message (#{message.inspect})" log_exception(e) end def unsubscribe_channel(data) - logger.info "[ActionCable] Unsubscribing from channel: #{data['identifier']}" + log_info "Unsubscribing from channel: #{data['identifier']}" @subscriptions[data['identifier']].unsubscribe @subscriptions.delete(data['identifier']) end def invalid_request - logger.info "[ActionCable] #{finished_request_message}" + log_info "#{finished_request_message}" [404, {'Content-Type' => 'text/plain'}, ['Page not found']] end @@ -194,8 +204,12 @@ module ActionCable end def log_exception(e) - logger.error "[ActionCable] There was an exception - #{e.class}(#{e.message})" - logger.error e.backtrace.join("\n") + log_error "There was an exception - #{e.class}(#{e.message})" + log_error e.backtrace.join("\n") + end + + def log(type, message) + server.logger.tagged(*log_tags) { server.logger.send type, message } end end end diff --git a/lib/action_cable/connection/internal_channel.rb b/lib/action_cable/connection/internal_channel.rb index 745fd99b78..5338fc879e 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) - logger.info "[ActionCable] Registered connection (#{connection_identifier})" + log_info "Registered connection (#{connection_identifier})" end end @@ -26,12 +26,12 @@ module ActionCable case message['type'] when 'disconnect' - logger.info "[ActionCable] Removing connection (#{connection_identifier})" + log_info "Removing connection (#{connection_identifier})" @websocket.close end rescue Exception => e - logger.error "[ActionCable] There was an exception - #{e.class}(#{e.message})" - logger.error e.backtrace.join("\n") + log_error "There was an exception - #{e.class}(#{e.message})" + log_error e.backtrace.join("\n") handle_exception end diff --git a/lib/action_cable/worker.rb b/lib/action_cable/worker.rb index 6773535afe..6800a75d1d 100644 --- a/lib/action_cable/worker.rb +++ b/lib/action_cable/worker.rb @@ -10,7 +10,7 @@ module ActionCable receiver.send method, *args end rescue Exception => e - logger.error "[ActionCable] There was an exception - #{e.class}(#{e.message})" + logger.error "There was an exception - #{e.class}(#{e.message})" logger.error e.backtrace.join("\n") receiver.handle_exception if receiver.respond_to?(:handle_exception) -- cgit v1.2.3