diff --git a/lib/protobuf/cli.rb b/lib/protobuf/cli.rb index 01f92af8..ad0716c6 100644 --- a/lib/protobuf/cli.rb +++ b/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,10 +216,10 @@ 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. @@ -223,7 +227,7 @@ 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}" } diff --git a/lib/protobuf/field/base_field.rb b/lib/protobuf/field/base_field.rb index 378daa1c..b688f180 100644 --- a/lib/protobuf/field/base_field.rb +++ b/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 diff --git a/lib/protobuf/field/bytes_field.rb b/lib/protobuf/field/bytes_field.rb index 6f7c86c4..6b7e6c17 100644 --- a/lib/protobuf/field/bytes_field.rb +++ b/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 diff --git a/lib/protobuf/lifecycle.rb b/lib/protobuf/lifecycle.rb index 145784b6..b1c2fa2c 100644 --- a/lib/protobuf/lifecycle.rb +++ b/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? diff --git a/lib/protobuf/logger.rb b/lib/protobuf/logger.rb deleted file mode 100644 index 30397c27..00000000 --- a/lib/protobuf/logger.rb +++ /dev/null @@ -1,86 +0,0 @@ -require 'logger' - -module Protobuf - class Logger < ::Logger - - class << self - attr_accessor :file, :level - - # Stub out the log methods for Protobuf::Logger as singleton methods - [:debug, :info, :warn, :error, :fatal, :any, :add, :log].each do |m| - define_method(m) do |*params, &block| - instance && instance.__send__(m, *params, &block) - end - end - end - - # One-line file/level configuration - def self.configure(options) - self.file = options.fetch(:file, false) - self.level = options.fetch(:level, false) - end - - # Use to reset the instance - def self.reset_device! - self.file = self.level = @__instance = nil - end - - # Singleton instance - def self.instance - @__instance ||= begin - log = nil - - if @file && @level - log = new(self.file) - log.level = self.level - end - - log - end - end - - # - # LogMethods module for log method including, e.g.: - # - # class MyClass - # include Protobuf::Logger::LogMethods - # ... - # end - # - # Produce a module to allow "include" in other classes to avoid - # cluttering the namespace of the including class with the other methods defined above - # - module LogMethods - [:debug, :info, :warn, :error, :fatal, :any, :add, :log].each do |m| - define_method("log_#{m}") do |*params, &block| - params.map! { |message| sign_message(message) } - ::Protobuf::Logger.__send__(m, *params, &block) - end - end - - # When included, also extend the LogMethods module for class access. - def self.included(base) - base.extend(LogMethods) - end - - # We often want to log an exception, so let's make that a core - # concern of the logger. - # - def log_exception(ex) - log_error { ex.message } - log_error { ex.backtrace[0..5].join("\n") } - log_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 -end diff --git a/lib/protobuf/logging.rb b/lib/protobuf/logging.rb new file mode 100644 index 00000000..47f5b8f3 --- /dev/null +++ b/lib/protobuf/logging.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) diff --git a/lib/protobuf/rpc/client.rb b/lib/protobuf/rpc/client.rb index 0d0c0d4e..373e3b0e 100644 --- a/lib/protobuf/rpc/client.rb +++ b/lib/protobuf/rpc/client.rb @@ -1,6 +1,6 @@ require 'forwardable' require 'protobuf' -require 'protobuf/logger' +require 'protobuf/logging' require 'protobuf/rpc/error' require 'protobuf/rpc/connector' @@ -8,7 +8,7 @@ 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 diff --git a/lib/protobuf/rpc/connectors/base.rb b/lib/protobuf/rpc/connectors/base.rb index d846d974..9f7735ab 100644 --- a/lib/protobuf/rpc/connectors/base.rb +++ b/lib/protobuf/rpc/connectors/base.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 diff --git a/lib/protobuf/rpc/connectors/common.rb b/lib/protobuf/rpc/connectors/common.rb index 4db2bc28..8c7a84cd 100644 --- a/lib/protobuf/rpc/connectors/common.rb +++ b/lib/protobuf/rpc/connectors/common.rb @@ -19,17 +19,17 @@ def request_caller def complete @stats.stop - log_info { @stats.to_s } - log_debug { sign_message('Response proceessing complete') } + logger.info { @stats.to_s } + logger.debug { sign_message('Response proceessing complete') } @complete_cb.call(self) unless @complete_cb.nil? rescue => e - log_error { sign_message('Complete callback error encountered') } + logger.error { sign_message('Complete callback error encountered') } log_exception(e) raise end def data_callback(data) - log_debug { sign_message('Using data_callback') } + logger.debug { sign_message('Using data_callback') } @used_data_callback = true @data = data end @@ -42,11 +42,11 @@ def fail(code, message) @error = ClientError.new @error.code = Protobuf::Socketrpc::ErrorReason.fetch(code) @error.message = message - log_debug { sign_message("Server failed request (invoking on_failure): #{@error.inspect}") } + logger.debug { sign_message("Server failed request (invoking on_failure): #{@error.inspect}") } @failure_cb.call(@error) unless @failure_cb.nil? rescue => e - log_error { sign_message("Failure callback error encountered") } + logger.error { sign_message("Failure callback error encountered") } log_exception(e) raise ensure @@ -71,7 +71,7 @@ def parse_response # Close up the connection as we no longer need it close_connection - log_debug { sign_message("Parsing response from server (connection closed)") } + logger.debug { sign_message("Parsing response from server (connection closed)") } # Parse out the raw response @stats.response_size = @response_data.size unless @response_data.nil? @@ -79,13 +79,13 @@ def parse_response # Determine success or failure based on parsed data if response_wrapper.has_field?(:error_reason) - log_debug { sign_message("Error response parsed") } + logger.debug { sign_message("Error response parsed") } # fail the call if we already know the client is failed # (don't try to parse out the response payload) fail(response_wrapper.error_reason, response_wrapper.error) else - log_debug { sign_message("Successful response parsed") } + logger.debug { sign_message("Successful response parsed") } # Ensure client_response is an instance parsed = @options[:response_type].decode(response_wrapper.response_proto.to_s) @@ -125,10 +125,10 @@ def setup_connection end def succeed(response) - log_debug { sign_message("Server succeeded request (invoking on_success)") } + logger.debug { sign_message("Server succeeded request (invoking on_success)") } @success_cb.call(response) unless @success_cb.nil? rescue => e - log_error { sign_message("Success callback error encountered") } + logger.error { sign_message("Success callback error encountered") } log_exception(e) fail(:RPC_ERROR, "An exception occurred while calling on_success: #{e.message}") ensure @@ -153,7 +153,7 @@ def validate_request_type! def verify_callbacks unless any_callbacks? - log_debug { sign_message("No callbacks set, using data_callback") } + logger.debug { sign_message("No callbacks set, using data_callback") } @success_cb = @failure_cb = self.method(:data_callback) end end diff --git a/lib/protobuf/rpc/connectors/socket.rb b/lib/protobuf/rpc/connectors/socket.rb index 1507acc7..26fd0e97 100644 --- a/lib/protobuf/rpc/connectors/socket.rb +++ b/lib/protobuf/rpc/connectors/socket.rb @@ -5,7 +5,7 @@ module Rpc module Connectors class Socket < Base include Protobuf::Rpc::Connectors::Common - include Protobuf::Logger::LogMethods + include Protobuf::Logging def send_request timeout_wrap do @@ -24,18 +24,18 @@ def log_signature def close_connection @socket.close - log_debug { sign_message('Connector closed') } + logger.debug { sign_message('Connector closed') } end def connect_to_rpc_server @socket = TCPSocket.new(options[:host], options[:port]) - log_debug { sign_message("Connection established #{options[:host]}:#{options[:port]}") } + logger.debug { sign_message("Connection established #{options[:host]}:#{options[:port]}") } end # Method to determine error state, must be used with Connector api def error? return true if @error - log_debug { sign_message("Error state : #{@socket.closed?}") } + logger.debug { sign_message("Error state : #{@socket.closed?}") } @socket.closed? end @@ -51,7 +51,7 @@ def read_data end def read_response - log_debug { sign_message("error? is #{error?}") } + logger.debug { sign_message("error? is #{error?}") } return if error? response_buffer = ::Protobuf::Rpc::Buffer.new(:read) response_buffer << read_data @@ -65,7 +65,7 @@ def send_data request_buffer.set_data(@request_data) @socket.write(request_buffer.write) @socket.flush - log_debug { sign_message("write closed") } + logger.debug { sign_message("write closed") } end end end diff --git a/lib/protobuf/rpc/connectors/zmq.rb b/lib/protobuf/rpc/connectors/zmq.rb index 7097759f..84a4f190 100644 --- a/lib/protobuf/rpc/connectors/zmq.rb +++ b/lib/protobuf/rpc/connectors/zmq.rb @@ -12,7 +12,7 @@ class Zmq < Base # Included Modules # include Protobuf::Rpc::Connectors::Common - include Protobuf::Logger::LogMethods + include Protobuf::Logging ## # Class Constants @@ -71,9 +71,9 @@ def create_socket if socket # Make sure the context builds the socket socket.setsockopt(::ZMQ::LINGER, 0) - log_debug { sign_message("Establishing connection: #{server_uri}") } + logger.debug { sign_message("Establishing connection: #{server_uri}") } zmq_error_check(socket.connect(server_uri), :socket_connect) - log_debug { sign_message("Connection established to #{server_uri}") } + logger.debug { sign_message("Connection established to #{server_uri}") } if first_alive_load_balance? begin @@ -155,21 +155,21 @@ def send_request_with_timeout(timeout, attempt = 0) poller = ::ZMQ::Poller.new poller.register_readable(socket) - log_debug { sign_message("Sending Request (attempt #{attempt}, #{socket})") } + logger.debug { sign_message("Sending Request (attempt #{attempt}, #{socket})") } zmq_error_check(socket.send_string(@request_data), :socket_send_string) - log_debug { sign_message("Waiting #{timeout} seconds for response (attempt #{attempt}, #{socket})") } + logger.debug { sign_message("Waiting #{timeout} seconds for response (attempt #{attempt}, #{socket})") } if poller.poll(timeout * 1000) == 1 zmq_error_check(socket.recv_string(@response_data = ""), :socket_recv_string) - log_debug { sign_message("Response received (attempt #{attempt}, #{socket})") } + logger.debug { sign_message("Response received (attempt #{attempt}, #{socket})") } else - log_debug { sign_message("Timed out waiting for response (attempt #{attempt}, #{socket})") } + logger.debug { sign_message("Timed out waiting for response (attempt #{attempt}, #{socket})") } raise RequestTimeout end ensure - log_debug { sign_message("Closing Socket") } + logger.debug { sign_message("Closing Socket") } zmq_error_check(socket.close, :socket_close) if socket - log_debug { sign_message("Socket closed") } + logger.debug { sign_message("Socket closed") } end # The service we're attempting to connect to diff --git a/lib/protobuf/rpc/middleware/exception_handler.rb b/lib/protobuf/rpc/middleware/exception_handler.rb index 010a1b8f..b29ea29b 100644 --- a/lib/protobuf/rpc/middleware/exception_handler.rb +++ b/lib/protobuf/rpc/middleware/exception_handler.rb @@ -2,7 +2,7 @@ module Protobuf module Rpc module Middleware class ExceptionHandler - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging attr_reader :app diff --git a/lib/protobuf/rpc/middleware/logger.rb b/lib/protobuf/rpc/middleware/logger.rb index 93dd17b1..9f4bd308 100644 --- a/lib/protobuf/rpc/middleware/logger.rb +++ b/lib/protobuf/rpc/middleware/logger.rb @@ -42,7 +42,7 @@ class Instrumenter attr_reader :env def flush(env) - Protobuf::Logger.info { to_s(env) } + ::Protobuf::Logging.logger.info { to_s(env) } end def start diff --git a/lib/protobuf/rpc/middleware/request_decoder.rb b/lib/protobuf/rpc/middleware/request_decoder.rb index fa74ad5d..de42a77b 100644 --- a/lib/protobuf/rpc/middleware/request_decoder.rb +++ b/lib/protobuf/rpc/middleware/request_decoder.rb @@ -2,7 +2,7 @@ module Protobuf module Rpc module Middleware class RequestDecoder - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging attr_reader :app, :env @@ -27,7 +27,7 @@ def call(env) end def log_signature - env.signature || super + env.log_signature || super end private @@ -57,7 +57,7 @@ def request # def request_wrapper @request_wrapper ||= begin - log_debug { sign_message("Decoding request: #{env.encoded_request}") } + logger.debug { sign_message("Decoding request: #{env.encoded_request}") } Socketrpc::Request.decode(env.encoded_request) end rescue => exception diff --git a/lib/protobuf/rpc/middleware/response_encoder.rb b/lib/protobuf/rpc/middleware/response_encoder.rb index 5d6188ab..11c53613 100644 --- a/lib/protobuf/rpc/middleware/response_encoder.rb +++ b/lib/protobuf/rpc/middleware/response_encoder.rb @@ -2,7 +2,7 @@ module Protobuf module Rpc module Middleware class ResponseEncoder - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging attr_reader :app, :env @@ -19,7 +19,7 @@ def call(env) end def log_signature - env.signature || super + env.log_signature || super end private @@ -27,7 +27,7 @@ def log_signature # Encode the response wrapper to return to the client # def encoded_response - log_debug { sign_message("Encoding response: #{response.inspect}") } + logger.debug { sign_message("Encoding response: #{response.inspect}") } env.encoded_response = wrapped_response.encode rescue => exception diff --git a/lib/protobuf/rpc/server.rb b/lib/protobuf/rpc/server.rb index f76bcd58..27dbaf8a 100644 --- a/lib/protobuf/rpc/server.rb +++ b/lib/protobuf/rpc/server.rb @@ -1,5 +1,5 @@ require 'protobuf' -require 'protobuf/logger' +require 'protobuf/logging' require 'protobuf/rpc/rpc.pb' require 'protobuf/rpc/buffer' require 'protobuf/rpc/env' diff --git a/lib/protobuf/rpc/servers/socket/server.rb b/lib/protobuf/rpc/servers/socket/server.rb index 7efdd65b..e184c9d8 100644 --- a/lib/protobuf/rpc/servers/socket/server.rb +++ b/lib/protobuf/rpc/servers/socket/server.rb @@ -5,7 +5,7 @@ module Protobuf module Rpc module Socket class Server - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging AUTO_COLLECT_TIMEOUT = 5 # seconds @@ -19,7 +19,7 @@ def cleanup? end def cleanup_threads - log_debug { sign_message("Thread cleanup - #{@threads.size} - start") } + logger.debug { sign_message("Thread cleanup - #{@threads.size} - start") } @threads = @threads.select do |t| if t[:thread].alive? @@ -31,7 +31,7 @@ def cleanup_threads end end - log_debug { sign_message("Thread cleanup - #{@threads.size} - complete") } + logger.debug { sign_message("Thread cleanup - #{@threads.size} - complete") } end def log_signature @@ -47,7 +47,7 @@ def new_worker(socket) end def run - log_debug { sign_message("Run") } + logger.debug { sign_message("Run") } host = @options[:host] port = @options[:port] backlog = @options[:backlog] @@ -63,7 +63,7 @@ def run @running = true while running? - log_debug { sign_message("Waiting for connections") } + logger.debug { sign_message("Waiting for connections") } ready_cnxns = IO.select(@listen_fds, [], [], AUTO_COLLECT_TIMEOUT) rescue nil if ready_cnxns @@ -73,13 +73,13 @@ def run when !running? then # no-op when client == @server then - log_debug { sign_message("Accepted new connection") } + logger.debug { sign_message("Accepted new connection") } client, sockaddr = @server.accept @listen_fds << client else unless @working.include?(client) @working << @listen_fds.delete(client) - log_debug { sign_message("Working") } + logger.debug { sign_message("Working") } @threads << { :thread => new_worker(client), :socket => client } cleanup_threads if cleanup? diff --git a/lib/protobuf/rpc/servers/socket/worker.rb b/lib/protobuf/rpc/servers/socket/worker.rb index aa443347..984ae01e 100644 --- a/lib/protobuf/rpc/servers/socket/worker.rb +++ b/lib/protobuf/rpc/servers/socket/worker.rb @@ -1,12 +1,12 @@ require 'protobuf/rpc/server' -require 'protobuf/logger' +require 'protobuf/logging' module Protobuf module Rpc module Socket class Worker include ::Protobuf::Rpc::Server - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging def initialize(sock, &complete_cb) @socket = sock diff --git a/lib/protobuf/rpc/servers/zmq/server.rb b/lib/protobuf/rpc/servers/zmq/server.rb index 51a5d1ae..c45c487f 100644 --- a/lib/protobuf/rpc/servers/zmq/server.rb +++ b/lib/protobuf/rpc/servers/zmq/server.rb @@ -100,7 +100,7 @@ def broadcast_heartbeat @beacon_socket.send(heartbeat.encode, 0) - log_debug { sign_message("sent heartbeat to #{beacon_uri}") } + logger.debug { sign_message("sent heartbeat to #{beacon_uri}") } end def broadcast_heartbeat? @@ -204,7 +204,7 @@ def start_missing_workers if missing_workers > 0 missing_workers.times { start_worker } - log_debug { sign_message("#{total_workers} workers started") } + logger.debug { sign_message("#{total_workers} workers started") } end end @@ -303,7 +303,7 @@ def start_worker rescue => e message = "Worker failed: #{e.inspect}\n #{e.backtrace.join($/)}" $stderr.puts(message) - log_error { message } + logger.error { message } end end end diff --git a/lib/protobuf/rpc/servers/zmq/util.rb b/lib/protobuf/rpc/servers/zmq/util.rb index 3d95ce0f..af7dcde5 100644 --- a/lib/protobuf/rpc/servers/zmq/util.rb +++ b/lib/protobuf/rpc/servers/zmq/util.rb @@ -11,7 +11,7 @@ module Zmq WORKERS_AVAILABLE = "\5" module Util - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging def self.included(base) base.extend(::Protobuf::Rpc::Zmq::Util) diff --git a/lib/protobuf/rpc/servers/zmq_runner.rb b/lib/protobuf/rpc/servers/zmq_runner.rb index 2ed1ab52..70b53548 100644 --- a/lib/protobuf/rpc/servers/zmq_runner.rb +++ b/lib/protobuf/rpc/servers/zmq_runner.rb @@ -3,7 +3,7 @@ module Protobuf module Rpc class ZmqRunner - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging def initialize(options) @options = case @@ -38,12 +38,12 @@ def stop def register_signals trap(:TTIN) do @server.add_worker - log_info { "Increased worker size to: #{@server.total_workers}" } + logger.info { "Increased worker size to: #{@server.total_workers}" } end trap(:TTOU) do - log_info { "Current worker size: #{@server.workers.size}" } - log_info { "Current worker size: #{@server.busy_worker_count}" } + logger.info { "Current worker size: #{@server.workers.size}" } + logger.info { "Current worker size: #{@server.busy_worker_count}" } end end end diff --git a/lib/protobuf/rpc/service.rb b/lib/protobuf/rpc/service.rb index 12efbc10..1c5f1e8c 100644 --- a/lib/protobuf/rpc/service.rb +++ b/lib/protobuf/rpc/service.rb @@ -1,4 +1,4 @@ -require 'protobuf/logger' +require 'protobuf/logging' require 'protobuf/rpc/client' require 'protobuf/rpc/error' require 'protobuf/rpc/service_filters' @@ -10,7 +10,7 @@ module Rpc RpcMethod = Struct.new("RpcMethod", :method, :request_type, :response_type) class Service - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging include ::Protobuf::Rpc::ServiceFilters DEFAULT_HOST = '127.0.0.1'.freeze diff --git a/lib/protobuf/rpc/service_directory.rb b/lib/protobuf/rpc/service_directory.rb index bc7874d4..868e53be 100644 --- a/lib/protobuf/rpc/service_directory.rb +++ b/lib/protobuf/rpc/service_directory.rb @@ -11,7 +11,7 @@ module Protobuf module Rpc class ServiceDirectory include ::Singleton - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging DEFAULT_ADDRESS = "0.0.0.0" DEFAULT_PORT = 53000 @@ -116,7 +116,7 @@ def running? def start unless running? init_socket - log_info { sign_message("listening to udp://#{self.class.address}:#{self.class.port}") } + logger.info { sign_message("listening to udp://#{self.class.address}:#{self.class.port}") } @thread = Thread.new { self.send(:run) } end @@ -124,7 +124,7 @@ def start end def stop - log_info { sign_message("Stopping directory") } + logger.info { sign_message("Stopping directory") } @thread.try(:kill).try(:join) @socket.try(:close) @@ -151,7 +151,7 @@ def add_or_update_listing(uuid, server) end trigger(action, listing) - log_debug { sign_message("#{action} server: #{server.inspect}") } + logger.debug { sign_message("#{action} server: #{server.inspect}") } end def init_socket @@ -177,7 +177,7 @@ def process_beacon(beacon) remove_listing(uuid) end else - log_info { sign_message("Ignoring incomplete beacon: #{beacon.inspect}") } + logger.info { sign_message("Ignoring incomplete beacon: #{beacon.inspect}") } end end @@ -193,7 +193,7 @@ def read_beacon end def remove_expired_listings - log_debug { sign_message("Removing expired listings") } + logger.debug { sign_message("Removing expired listings") } @listings_by_uuid.each do |uuid, listing| remove_listing(uuid) if listing.expired? end @@ -202,7 +202,7 @@ def remove_expired_listings def remove_listing(uuid) listing = @listings_by_uuid[uuid] or return - log_debug { sign_message("Removing listing: #{listing.inspect}") } + logger.debug { sign_message("Removing listing: #{listing.inspect}") } @listings_by_service.each do |service, listings| listings.delete(listing) @@ -233,7 +233,7 @@ def run end end rescue => e - log_debug { sign_message("ERROR: (#{e.class}) #{e.message}\n#{e.backtrace.join("\n")}") } + logger.debug { sign_message("ERROR: (#{e.class}) #{e.message}\n#{e.backtrace.join("\n")}") } retry end diff --git a/lib/protobuf/rpc/service_dispatcher.rb b/lib/protobuf/rpc/service_dispatcher.rb index 469af8e7..91dacb42 100644 --- a/lib/protobuf/rpc/service_dispatcher.rb +++ b/lib/protobuf/rpc/service_dispatcher.rb @@ -1,9 +1,9 @@ -require 'protobuf/logger' +require 'protobuf/logging' module Protobuf module Rpc class ServiceDispatcher - include ::Protobuf::Logger::LogMethods + include ::Protobuf::Logging attr_reader :env diff --git a/lib/protobuf/rpc/stat.rb b/lib/protobuf/rpc/stat.rb index 5dd504ca..5ab9407e 100644 --- a/lib/protobuf/rpc/stat.rb +++ b/lib/protobuf/rpc/stat.rb @@ -1,6 +1,6 @@ require 'date' require 'time' -require 'protobuf/logger' +require 'protobuf/logging' module Protobuf module Rpc diff --git a/spec/benchmark/tasks.rb b/spec/benchmark/tasks.rb index 8c45d685..f90554fd 100644 --- a/spec/benchmark/tasks.rb +++ b/spec/benchmark/tasks.rb @@ -13,8 +13,8 @@ # Including a way to turn on debug logger for spec runs if ENV["DEBUG"] puts 'debugging' - debug_log = File.expand_path('../debug_bench.log', File.dirname(__FILE__) ) - Protobuf::Logger.configure(:file => debug_log, :level => ::Logger::DEBUG) + debug_log = File.expand_path('../../../debug_bench.log', __FILE__) + Protobuf::Logging.initialize_logger(debug_log, ::Logger::DEBUG) end namespace :benchmark do diff --git a/spec/lib/protobuf/cli_spec.rb b/spec/lib/protobuf/cli_spec.rb index 9d8280c1..24fde5e0 100644 --- a/spec/lib/protobuf/cli_spec.rb +++ b/spec/lib/protobuf/cli_spec.rb @@ -19,6 +19,12 @@ runner } + around(:each) do |example| + logger = ::Protobuf::Logging.logger + example.run + ::Protobuf::Logging.logger = logger + end + before(:each) do allow(::Protobuf::Rpc::SocketRunner).to receive(:new).and_return(sock_runner) allow(::Protobuf::Rpc::ZmqRunner).to receive(:new).and_return(zmq_runner) @@ -88,9 +94,9 @@ let(:test_args) { [ '--log=mylog.log', '--level=0' ] } it 'sends the log file and level options to the runner' do - expect(::Protobuf::Logger).to receive(:configure) do |options| - expect(options[:file]).to eq 'mylog.log' - expect(options[:level]).to eq 0 + expect(::Protobuf::Logging).to receive(:initialize_logger) do |file, level| + expect(file).to eq 'mylog.log' + expect(level).to eq 0 end described_class.start(args) end diff --git a/spec/lib/protobuf/logger_spec.rb b/spec/lib/protobuf/logger_spec.rb deleted file mode 100644 index 6a28aa3f..00000000 --- a/spec/lib/protobuf/logger_spec.rb +++ /dev/null @@ -1,136 +0,0 @@ -require 'protobuf/logger' -require 'stringio' -require 'fileutils' - -describe Protobuf::Logger do - - subject { Protobuf::Logger } - - before(:each) do - Protobuf::Logger.reset_device! - Protobuf::Logger.file = '/dev/null' - Protobuf::Logger.level = ::Logger::INFO - end - - after(:all) do - ::FileUtils.rm_f('myfile.log') - end - - describe '.instance' do - - it 'doesn\'t create a logger if the file was not set' do - subject.file = nil - expect(subject.instance).to be_nil - end - - it 'doesn\'t create a logger if the level was not set' do - subject.level = nil - expect(subject.instance).to be_nil - end - - it 'gets a new instance of the logger when file and level are set' do - expect(subject.file).to_not be_nil - expect(subject.level).to_not be_nil - expect(subject.instance).to_not be_nil - end - - it 'keeps the same object from multiple calls to instance' do - expect(subject.instance).to equal(subject.instance) - end - - end - - describe '.configure' do - before(:each) { subject.reset_device! } - it 'sets the file and level in one call' do - expect(subject.file).to_not be - expect(subject.level).to_not be - expect(subject.instance).to_not be - subject.configure :file => 'myfile.log', :level => ::Logger::WARN - expect(subject.file).to eq('myfile.log') - expect(subject.level).to eq(::Logger::WARN) - expect(subject.instance.level).to eq(::Logger::WARN) - end - - end - - describe '.reset_device!' do - - it 'resets the logger instance, file, and level' do - expect(subject.instance).to be - expect(subject.file).to be - expect(subject.level).to be - subject.reset_device! - expect(subject.instance).to_not be - expect(subject.file).to_not be - expect(subject.level).to_not be - end - - end - - context 'when logging' do - - it 'doesn\'t raise errors when log instance is nil' do - subject.reset_device! - expect(subject.instance).to be_nil - expect { - subject.debug 'No errors here' - subject.info 'No errors here' - subject.warn 'No errors here' - subject.error 'No errors here' - subject.fatal 'No errors here' - subject.add 'No errors here' - subject.log 'No errors here' - }.to_not raise_error - end - - it 'logs correctly when instance is valid' do - expect(subject.instance).to_not be_nil - expect(subject.instance).to receive(:info).with('Should log great') - subject.info 'Should log great' - end - - end - - describe Protobuf::Logger::LogMethods do - - context 'when included in another class' do - - before(:all) do - class MyTestClass - include Protobuf::Logger::LogMethods - end - end - - subject { MyTestClass.new } - - it { is_expected.to respond_to(:log_debug) } - it { is_expected.to respond_to(:log_info) } - it { is_expected.to respond_to(:log_warn) } - it { is_expected.to respond_to(:log_error) } - it { is_expected.to respond_to(:log_fatal) } - it { is_expected.to respond_to(:log_add) } - it { is_expected.to respond_to(:log_log) } - - context '#log_exception' do - it 'logs the exception message as an error and backtrace as debug' do - expect(subject).to receive(:log_error).twice - expect(subject).to receive(:log_debug) - subject.log_exception(RuntimeError.new('this is an exception')) - end - end - - specify { expect(subject.log_signature).to eq "[MyTestClass]" } - describe '#sign_message' do - specify { expect(subject.sign_message("this is a test")).to eq "[MyTestClass] this is a test" } - specify { expect(subject.class.sign_message("this is a test")).to eq "[MyTestClass] this is a test" } - end - - it 'passes all embedded log calls to Logger instance' do - expect(Protobuf::Logger.instance).to receive(:debug).with('[MyTestClass] log this') - subject.log_debug('log this') - end - - end - end -end diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index 07b4c16b..414f80d5 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -1,6 +1,3 @@ -require 'simplecov' -SimpleCov.start - require 'timeout' require 'rubygems' require 'bundler' @@ -20,10 +17,14 @@ # Including a way to turn on debug logger for spec runs if ENV.key?('DEBUG') - debug_log = ::File.expand_path('../debug_specs.log', File.dirname(__FILE__) ) - ::Protobuf::Logger.configure(:file => debug_log, :level => ::Logger::DEBUG) + debug_log = ::File.expand_path('../../debug_specs.log', __FILE__ ) + ::Protobuf::Logging.initialize_logger(debug_log, ::Logger::DEBUG) +else + ::Protobuf::Logging.initialize_logger('/dev/null') end +::Protobuf::Logging.close_old_logger = false + # Get rid of the deprecation env var if present (messes with specs). ENV.delete("PB_IGNORE_DEPRECATIONS") diff --git a/spec/support/server.rb b/spec/support/server.rb index a88db354..55e4dbea 100644 --- a/spec/support/server.rb +++ b/spec/support/server.rb @@ -1,5 +1,5 @@ require 'ostruct' -require 'protobuf/logger' +require 'protobuf/logging' require 'protobuf/rpc/server' require 'protobuf/rpc/servers/socket/server' require 'protobuf/rpc/servers/socket_runner' @@ -33,7 +33,7 @@ def post_init end class StubServer - include Protobuf::Logger::LogMethods + include Protobuf::Logging attr_accessor :options @@ -58,7 +58,7 @@ def start else start_socket_server end - log_debug { sign_message("Server started #{@options.host}:#{@options.port}") } + logger.debug { sign_message("Server started #{@options.host}:#{@options.port}") } end def start_socket_server