Merge pull request #210 from quixoten/logging

Make logging a pluggable component of Protobuf

Author: abrandoned

lib/protobuf/cli.rb

@@ -1,12 +1,13 @@
 require 'thor'
 require 'protobuf/version'
-require 'protobuf/logger'
+require 'protobuf/logging'
 require 'protobuf/rpc/servers/socket_runner'
 require 'protobuf/rpc/servers/zmq_runner'
 
 module Protobuf
   class CLI < ::Thor
     include ::Thor::Actions
+    include ::Protobuf::Logging
 
     attr_accessor :runner, :mode
 
@@ -21,7 +22,7 @@ class CLI < ::Thor
     option :threshold,                  :type => :numeric, :default => 100, :aliases => %w(-t), :desc => 'Multi-threaded Socket Server cleanup threshold.'
     option :threads,                    :type => :numeric, :default => 5, :aliases => %w(-r), :desc => 'Number of worker threads to run. Only applicable in --zmq mode.'
 
-    option :log,                        :type => :string, :aliases => %w(-l), :desc => 'Log file or device. Default is STDOUT.'
+    option :log,                        :type => :string, :default => STDOUT, :aliases => %w(-l), :desc => 'Log file or device. Default is STDOUT.'
     option :level,                      :type => :numeric, :default => ::Logger::INFO, :aliases => %w(-v), :desc => 'Log level to use, 0-5 (see http://www.ruby-doc.org/stdlib/libdoc/logger/rdoc/)'
 
     option :socket,                     :type => :boolean, :aliases => %w(-s), :desc => 'Socket Mode for server and client connections.'
@@ -86,12 +87,14 @@ def configure_gc
       # Setup the protobuf logger.
       def configure_logger
         debug_say('Configuring logger')
-        ::Protobuf::Logger.configure({ :file => options.log || STDOUT,
-                                     :level => options.debug? ? ::Logger::DEBUG : options.level })
+
+        log_level = options.debug? ? ::Logger::DEBUG : options.level
+
+        ::Protobuf::Logging.initialize_logger(options.log, log_level)
 
         # Debug output the server options to the log file.
-        ::Protobuf::Logger.debug { 'Debugging options:' }
-        ::Protobuf::Logger.debug { options.inspect }
+        logger.debug { 'Debugging options:' }
+        logger.debug { options.inspect }
       end
 
       # Re-write the $0 var to have a nice process name in ps.
@@ -185,15 +188,16 @@ def runner_options
       end
 
       def say_and_exit(message, exception = nil)
-        message = set_color(message, :red) if ::Protobuf::Logger.file == STDOUT
+        message = set_color(message, :red) if options.log == STDOUT
+
+        logger.error { message }
 
-        ::Protobuf::Logger.error { message }
         if exception
           $stderr.puts "[#{exception.class.name}] #{exception.message}"
           $stderr.puts exception.backtrace.join("\n")
 
-          ::Protobuf::Logger.error { "[#{exception.class.name}] #{exception.message}" }
-          ::Protobuf::Logger.debug { exception.backtrace.join("\n") }
+          logger.error { "[#{exception.class.name}] #{exception.message}" }
+          logger.debug { exception.backtrace.join("\n") }
         end
 
         exit(1)
@@ -212,18 +216,18 @@ def create_zmq_runner
       end
 
       def shutdown_server
-        ::Protobuf::Logger.info { 'RPC Server shutting down...' }
+        logger.info { 'RPC Server shutting down...' }
         @runner.try(:stop)
         ::Protobuf::Rpc::ServiceDirectory.instance.stop
-        ::Protobuf::Logger.info { 'Shutdown complete' }
+        logger.info { 'Shutdown complete' }
       end
 
       # Start the runner and log the relevant options.
       def start_server
         debug_say('Running server')
 
         @runner.run do
-          ::Protobuf::Logger.info {
+          logger.info {
             "pid #{::Process.pid} -- #{@runner_mode} RPC Server listening at #{options.host}:#{options.port}"
           }
 

lib/protobuf/field/base_field.rb

@@ -1,9 +1,11 @@
-require 'protobuf/wire_type'
 require 'protobuf/field/field_array'
+require 'protobuf/logging'
+require 'protobuf/wire_type'
 
 module Protobuf
   module Field
     class BaseField
+      include ::Protobuf::Logging
 
       ##
       # Constants

lib/protobuf/field/bytes_field.rb

@@ -67,8 +67,8 @@ def define_setter
                 raise TypeError, "Unacceptable value #{val} for field #{field.name} of type #{field.type_class}"
               end
             rescue NoMethodError => ex
-              ::Protobuf::Logger.error { ex.message }
-              ::Protobuf::Logger.error { ex.backtrace.join("\n") }
+              logger.error { ex.message }
+              logger.error { ex.backtrace.join("\n") }
               raise TypeError, "Got NoMethodError attempting to set #{val} for field #{field.name} of type #{field.type_class}: #{ex.message}"
             end
           end

lib/protobuf/lifecycle.rb

@@ -1,6 +1,6 @@
 module Protobuf
   class Lifecycle
-    include ::Protobuf::Logger::LogMethods
+    include ::Protobuf::Logging
 
     def self.register(event_name, &blk)
       raise "Lifecycle register must have a block" unless block_given?

lib/protobuf/logger.rb

@@ -0,0 +1,49 @@
+module Protobuf
+  module Logging
+    def self.initialize_logger(log_target=$stdout, log_level=::Logger::INFO)
+      @counter ||= 0
+      @counter = @counter + 1
+      old_logger = defined?(@logger) ? @logger : nil
+      @logger = Logger.new(log_target)
+      @logger.level = log_level
+      old_logger.close if old_logger and close_old_logger?
+      @logger
+    end
+
+    def self.close_old_logger=(boolean)
+      @close_old_logger = !!boolean
+    end
+
+    def self.close_old_logger?
+      defined?(@close_old_logger) ? @close_old_logger : true
+    end
+
+    def self.logger
+      defined?(@logger) ? @logger : initialize_logger
+    end
+
+    def self.logger=(new_logger)
+      @logger = new_logger
+    end
+
+    def logger
+      ::Protobuf::Logging.logger
+    end
+
+    def log_exception(ex)
+      logger.error { ex.message }
+      logger.error { ex.backtrace[0..5].join("\n") }
+      logger.debug { ex.backtrace.join("\n") }
+    end
+
+    def log_signature
+      @_log_signature ||= "[#{self.class == Class ? self.name : self.class.name}]"
+    end
+
+    def sign_message(message)
+      "#{log_signature} #{message}"
+    end
+  end
+end
+
+# Inspired by [mperham](https://github.com/mperham/sidekiq)

lib/protobuf/logging.rb

@@ -1,14 +1,14 @@
 require 'forwardable'
 require 'protobuf'
-require 'protobuf/logger'
+require 'protobuf/logging'
 require 'protobuf/rpc/error'
 require 'protobuf/rpc/connector'
 
 module Protobuf
   module Rpc
     class Client
       extend Forwardable
-      include Protobuf::Logger::LogMethods
+      include Protobuf::Logging
 
       def_delegators :@connector, :options, :complete_cb, :success_cb, :failure_cb
       attr_reader :connector
@@ -29,7 +29,7 @@ class Client
       def initialize(options = {})
         raise "Invalid client configuration. Service must be defined." if options[:service].nil?
         @connector = Connector.connector_for_client.new(options)
-        log_debug { sign_message("Initialized with options: #{options.inspect}") }
+        logger.debug { sign_message("Initialized with options: #{options.inspect}") }
       end
 
       def log_signature
@@ -106,28 +106,28 @@ def on_success=(callable)
       def method_missing(method_name, *params)
         service = options[:service]
         unless service.rpc_method?(method_name)
-          log_error { sign_message("#{service.name}##{method_name.to_s} not rpc method, passing to super") }
+          logger.error { sign_message("#{service.name}##{method_name.to_s} not rpc method, passing to super") }
           super(method_name, *params)
         else
-          log_debug { sign_message("#{service.name}##{method_name.to_s}") }
+          logger.debug { sign_message("#{service.name}##{method_name.to_s}") }
           rpc = service.rpcs[method_name.to_sym]
 
           options[:request_type] = rpc.request_type
-          log_debug { sign_message("Request Type: #{options[:request_type].name}") }
+          logger.debug { sign_message("Request Type: #{options[:request_type].name}") }
 
           options[:response_type] = rpc.response_type
-          log_debug { sign_message("Response Type: #{options[:response_type].name}") }
+          logger.debug { sign_message("Response Type: #{options[:response_type].name}") }
 
           options[:method] = method_name.to_s
           options[:request] = params[0].is_a?(Hash) ? options[:request_type].new(params[0]) : params[0]
-          log_debug { sign_message("Request Data: #{options[:request].inspect}") }
+          logger.debug { sign_message("Request Data: #{options[:request].inspect}") }
 
           # Call client to setup on_success and on_failure event callbacks
           if block_given?
-            log_debug { sign_message("client setup callback given, invoking") }
+            logger.debug { sign_message("client setup callback given, invoking") }
             yield(self)
           else
-            log_debug { sign_message("no block given for callbacks") }
+            logger.debug { sign_message("no block given for callbacks") }
           end
 
           send_request

lib/protobuf/rpc/client.rb

@@ -1,5 +1,5 @@
 require 'timeout'
-require 'protobuf/logger'
+require 'protobuf/logging'
 require 'protobuf/rpc/rpc.pb'
 require 'protobuf/rpc/buffer'
 require 'protobuf/rpc/error'
@@ -23,7 +23,7 @@ module Connectors
       }
 
       class Base
-        include Protobuf::Logger::LogMethods
+        include Protobuf::Logging
 
         attr_reader :options
         attr_accessor :success_cb, :failure_cb, :complete_cb