From 2f066bd11848da38f9709f1e968d7b314f357ff3 Mon Sep 17 00:00:00 2001 From: Bogdan Irimie Date: Wed, 20 May 2020 10:50:48 +0300 Subject: [PATCH] (FACT-2617) Fix for tests/external_facts/external_fact_stderr_messages_output_to_stderr.rb (#522) * (FACT-2617) If a logger is provided, use it for all log levels. * (FACT-2617) Fix tests. * (FACT-2617) Revert logger to implementation without send as it interferes with Kernel :warn * (FACT-2617) Remove multi logger. * (FACT-2617) Se default log level on default logger. * (FACT-2617) Set logger to nil before it is initialised. * (FACT-2617) Fix acceptance tests. * (FACT-2617) Set log level to default when initialising default logger. * (FACT-2617) Only set default log level if the logger was uninitialised. * (FACT-2617) Fix rubocop. * (FACT-2617) Make colorize method private. --- lib/facter.rb | 2 +- lib/framework/cli/cli_launcher.rb | 3 +- lib/framework/core/file_loader.rb | 2 +- lib/framework/logging/logger.rb | 92 +++++++------- lib/framework/logging/logger_helper.rb | 19 +++ lib/framework/logging/multilogger.rb | 119 ------------------ spec/facter/util/file_helper_spec.rb | 14 +-- .../internal/internal_fact_manager_spec.rb | 10 +- spec/framework/logging/logger_spec.rb | 10 +- 9 files changed, 85 insertions(+), 186 deletions(-) create mode 100644 lib/framework/logging/logger_helper.rb delete mode 100644 lib/framework/logging/multilogger.rb diff --git a/lib/facter.rb b/lib/facter.rb index f3d84d76b..b92503022 100644 --- a/lib/facter.rb +++ b/lib/facter.rb @@ -12,7 +12,7 @@ module Facter class ResolveCustomFactError < StandardError; end Options.init - Log.add_legacy_logger(STDOUT) + Log.output(STDOUT) @already_searched = {} @trace = false diff --git a/lib/framework/cli/cli_launcher.rb b/lib/framework/cli/cli_launcher.rb index 4a6874f4d..1a8fdc1d3 100755 --- a/lib/framework/cli/cli_launcher.rb +++ b/lib/framework/cli/cli_launcher.rb @@ -2,9 +2,8 @@ # frozen_string_literal: true require 'thor' -require "#{ROOT_DIR}/lib/framework/logging/multilogger.rb" require "#{ROOT_DIR}/lib/framework/logging/logger.rb" -Facter::Log.add_legacy_logger(STDERR) +Facter::Log.output(STDERR) require "#{ROOT_DIR}/lib/facter" require "#{ROOT_DIR}/lib/framework/cli/cli" diff --git a/lib/framework/core/file_loader.rb b/lib/framework/core/file_loader.rb index 55818957b..7eda6e3b3 100644 --- a/lib/framework/core/file_loader.rb +++ b/lib/framework/core/file_loader.rb @@ -22,7 +22,7 @@ def load_lib_dirs(*dirs) load_lib_dirs('framework', 'core', 'options') require "#{ROOT_DIR}/lib/framework/core/options" -require "#{ROOT_DIR}/lib/framework/logging/multilogger" +require "#{ROOT_DIR}/lib/framework/logging/logger_helper" require "#{ROOT_DIR}/lib/framework/logging/logger" require "#{ROOT_DIR}/lib/util/file_helper" diff --git a/lib/framework/logging/logger.rb b/lib/framework/logging/logger.rb index 83c6e9e8b..e350b2d6e 100644 --- a/lib/framework/logging/logger.rb +++ b/lib/framework/logging/logger.rb @@ -11,9 +11,7 @@ module Facter DEFAULT_LOG_LEVEL = :warn class Log - @@legacy_logger = nil - @@logger = MultiLogger.new([]) - @@logger.level = :warn + @@logger = nil @@message_callback = nil @@has_errors = false @@ -33,47 +31,36 @@ def level def errors? @@has_errors end - end - def initialize(logged_class) - determine_callers_name(logged_class) - end + def output(output) + return if @@logger - def self.add_legacy_logger(output) - return if @@legacy_logger + @@logger = Logger.new(output) + set_logger_format + @@logger.level = DEFAULT_LOG_LEVEL + end - @@legacy_logger = Logger.new(output) - @@legacy_logger.level = DEFAULT_LOG_LEVEL - set_format_for_legacy_logger - @@logger.add_logger(@@legacy_logger) + def set_logger_format + @@logger.formatter = proc do |severity, datetime, _progname, msg| + datetime = datetime.strftime(@datetime_format || '%Y-%m-%d %H:%M:%S.%6N ') + "[#{datetime}] #{severity} #{msg} \n" + end + end end - def determine_callers_name(sender_self) - @class_name = case sender_self - when String - sender_self - when Class - sender_self.name - when Module - sender_self.name - else # when class is singleton - sender_self.class.name - end - end + def initialize(logged_class) + @class_name = LoggerHelper.determine_callers_name(logged_class) + return unless @@logger.nil? - def self.set_format_for_legacy_logger - @@legacy_logger.formatter = proc do |severity, datetime, _progname, msg| - datetime = datetime.strftime(@datetime_format || '%Y-%m-%d %H:%M:%S.%6N ') - "[#{datetime}] #{severity} #{msg} \n" - end + @@logger = Logger.new(STDOUT) + @@logger.level = DEFAULT_LOG_LEVEL end def debug(msg) return unless debugging_active? if msg.nil? || msg.empty? - invoker = caller(1..1).first.slice(/.*:\d+/) - empty_message_error(msg, invoker) + empty_message_error(msg) elsif @@message_callback @@message_callback.call(:debug, msg) else @@ -83,38 +70,57 @@ def debug(msg) end def info(msg) - msg = colorize(msg, GREEN) if Options[:color] - @@logger.info(@class_name + ' - ' + msg) + if msg.nil? || msg.empty? + empty_message_error(msg) + elsif @@message_callback + @@message_callback.call(:info, msg) + else + msg = colorize(msg, GREEN) if Options[:color] + @@logger.info(@class_name + ' - ' + msg) + end end def warn(msg) - msg = colorize(msg, YELLOW) if Options[:color] - - @@logger.warn(@class_name + ' - ' + msg) + if msg.nil? || msg.empty? + empty_message_error(msg) + elsif @@message_callback + @@message_callback.call(:warn, msg) + else + msg = colorize(msg, YELLOW) if Options[:color] + @@logger.warn(@class_name + ' - ' + msg) + end end def error(msg, colorize = false) @@has_errors = true - msg = colorize(msg, RED) if colorize || Options[:color] - @@logger.error(@class_name + ' - ' + msg) + + if msg.nil? || msg.empty? + empty_message_error(msg) + elsif @@message_callback + @@message_callback.call(:error, msg) + else + msg = colorize(msg, RED) if colorize || Options[:color] + @@logger.error(@class_name + ' - ' + msg) + end end + private + def colorize(msg, color) return msg if OsDetector.instance.identifier.eql?(:windows) "\e[0;#{color}m#{msg}\e[0m" end - private - def debugging_active? return true unless Facter.respond_to?(:debugging?) Facter.debugging? end - def empty_message_error(msg, invoker) - self.warn "#{self.class}#debug invoked with invalid message #{msg.inspect}:#{msg.class} at #{invoker}" + def empty_message_error(msg) + invoker = caller(1..1).first.slice(/.*:\d+/) + @@logger.warn "#{self.class}#debug invoked with invalid message #{msg.inspect}:#{msg.class} at #{invoker}" end end end diff --git a/lib/framework/logging/logger_helper.rb b/lib/framework/logging/logger_helper.rb new file mode 100644 index 000000000..b7b6bd30d --- /dev/null +++ b/lib/framework/logging/logger_helper.rb @@ -0,0 +1,19 @@ +# frozen_string_literal: true + +class LoggerHelper + class << self + def determine_callers_name(sender_self) + class_name = case sender_self + when String + sender_self + when Class + sender_self.name + when Module + sender_self.name + else # when class is singleton + sender_self.class.name + end + class_name + end + end +end diff --git a/lib/framework/logging/multilogger.rb b/lib/framework/logging/multilogger.rb deleted file mode 100644 index 359a88851..000000000 --- a/lib/framework/logging/multilogger.rb +++ /dev/null @@ -1,119 +0,0 @@ -# frozen_string_literal: true - -module Facter - require 'logger' - # MultiLogger is an implementation of Ruby logging which can tee the log to - # multiple endpoints. - # This class reeks of :reek:TooManyMethods. - class MultiLogger < Logger - # Array of loggers to be logged to. These can be anything that acts reasonably - # like a Logger. - attr_reader :loggers - - # For things like level and progname, retrieve from the first active logging. - # There's an implicit assumption that these will be the same across all - # contained loggers. - - # Logging severity threshold (e.g. Logger::INFO). - def level - loggers.first.level - end - - def level=(value) - loggers.each { |logger| logger.level = value } - end - - # Program name to include in log messages. - def progname - loggers.first.progname - end - - def progname=(value) - loggers.each { |logger| logger.progname = value } - end - - # Set date-time format. - # +datetime_format+:: A string suitable for passing to +strftime+. - def datetime_format=(datetime_format) - loggers.each { |logger| logger.datetime_format = datetime_format } - end - - # Returns the date format being used. See #datetime_format= - def datetime_format - loggers.first.datetime_format - end - - # Returns +true+ if the current severity level allows for the printing of - # +DEBUG+ messages. - def debug? - loggers.first.level <= DEBUG - end - - # Returns +true+ iff the current severity level allows for the printing of - # +INFO+ messages. - def info? - loggers.first.level <= INFO - end - - # Returns +true+ iff the current severity level allows for the printing of - # +WARN+ messages. - def warn? - loggers.first.level <= WARN - end - - # Returns +true+ iff the current severity level allows for the printing of - # +ERROR+ messages. - def error? - loggers.first.level <= ERROR - end - - # - # === Synopsis - # - # MultiLogger.new([logger1, logger2]) - # - # === Args - # - # +loggers+:: - # An array of loggers. Each one gets every message that is sent to the - # MultiLogger instance. - # - # === Description - # - # Create an instance. - # - def initialize(loggers) - @loggers = loggers - end - - def add_logger(logger) - @loggers << logger - end - - # Methods that write to logs just write to each contained logging in turn - def add(severity, message = nil, progname = nil, &block) - loggers.each { |logger| logger.add(severity, message, progname, &block) } - end - alias log add - - def debug(progname = nil, &block) - loggers.each { |logger| logger.debug(progname, &block) } - end - - def info(progname = nil, &block) - loggers.each { |logger| logger.info(progname, &block) } - end - - def warn(progname = nil, &block) - loggers.each { |logger| logger.warn(progname, &block) } - end - - def error(progname = nil, &block) - loggers.each { |logger| logger.error(progname, &block) } - end - - def close - loggers.each(&:close) - end - end -end diff --git a/spec/facter/util/file_helper_spec.rb b/spec/facter/util/file_helper_spec.rb index 1508c5733..ad65b049d 100644 --- a/spec/facter/util/file_helper_spec.rb +++ b/spec/facter/util/file_helper_spec.rb @@ -7,15 +7,15 @@ let(:content) { 'file content' } let(:error_message) { 'Facter::Util::FileHelper - File at: /Users/admin/file.txt is not accessible.' } let(:array_content) { ['line 1', 'line 2', 'line 3'] } - let(:multi_logger_double) { instance_spy(Facter::MultiLogger, level: :warn) } + let(:logger_double) { instance_spy(Logger) } before do - Facter::Log.class_variable_set(:@@logger, multi_logger_double) + Facter::Log.class_variable_set(:@@logger, logger_double) allow(Facter).to receive(:debugging?).and_return(true) end after do - Facter::Log.class_variable_set(:@@logger, Facter::MultiLogger.new([])) + Facter::Log.class_variable_set(:@@logger, Logger.new(STDOUT)) end shared_context 'when file is readable' do @@ -57,7 +57,7 @@ it "doesn't log anything" do file_helper.safe_read(path) - expect(multi_logger_double).not_to have_received(:debug) + expect(logger_double).not_to have_received(:debug) end end @@ -87,7 +87,7 @@ it 'logs a debug message' do file_helper.safe_read(path) - expect(multi_logger_double).to have_received(:debug) + expect(logger_double).to have_received(:debug) .with(error_message) end end @@ -120,7 +120,7 @@ it "doesn't log anything" do file_helper.safe_readlines(path) - expect(multi_logger_double).not_to have_received(:debug) + expect(logger_double).not_to have_received(:debug) end end @@ -150,7 +150,7 @@ it 'logs a debug message' do file_helper.safe_read(path) - expect(multi_logger_double).to have_received(:debug).with(error_message) + expect(logger_double).to have_received(:debug).with(error_message) end end end diff --git a/spec/framework/core/fact/internal/internal_fact_manager_spec.rb b/spec/framework/core/fact/internal/internal_fact_manager_spec.rb index ece8b72bb..d3d16295e 100644 --- a/spec/framework/core/fact/internal/internal_fact_manager_spec.rb +++ b/spec/framework/core/fact/internal/internal_fact_manager_spec.rb @@ -64,7 +64,7 @@ type: :core) end - let(:multi_logger_double) { instance_spy(Facter::MultiLogger) } + let(:logger_double) { instance_spy(Logger) } before do allow(os_name_class_spy).to receive(:new).and_return(os_name_instance_spy) @@ -73,12 +73,12 @@ exception.set_backtrace(%w[error backtrace]) allow(os_name_instance_spy).to receive(:call_the_resolver).and_raise(exception) - allow(multi_logger_double).to receive(:error) - Facter::Log.class_variable_set(:@@logger, multi_logger_double) + allow(logger_double).to receive(:error) + Facter::Log.class_variable_set(:@@logger, logger_double) end after do - Facter::Log.class_variable_set(:@@logger, Facter::MultiLogger.new([])) + Facter::Log.class_variable_set(:@@logger, Logger.new(STDOUT)) end it 'does not store the fact value' do @@ -90,7 +90,7 @@ it 'logs backtrace as error' do internal_fact_manager.resolve_facts([searched_fact]) - expect(multi_logger_double).to have_received(:error).with("Facter::InternalFactManager - error\nbacktrace") + expect(logger_double).to have_received(:error).with("Facter::InternalFactManager - error\nbacktrace") end end end diff --git a/spec/framework/logging/logger_spec.rb b/spec/framework/logging/logger_spec.rb index b62952d7d..d8ad64bfe 100644 --- a/spec/framework/logging/logger_spec.rb +++ b/spec/framework/logging/logger_spec.rb @@ -3,7 +3,7 @@ describe Logger do subject(:log) { Facter::Log.new(Class) } - let(:multi_logger_double) { instance_spy(Facter::MultiLogger, level: :warn) } + let(:multi_logger_double) { instance_spy(Logger) } before do Facter::Log.class_variable_set(:@@logger, multi_logger_double) @@ -11,7 +11,7 @@ end after do - Facter::Log.class_variable_set(:@@logger, Facter::MultiLogger.new([])) + Facter::Log.class_variable_set(:@@logger, Logger.new(STDOUT)) end describe '#debug' do @@ -238,10 +238,4 @@ expect(multi_logger_double).to have_received(:level=).with(:error) end end - - describe '#level' do - it 'get the log level' do - expect(Facter::Log.level).to eq(:warn) - end - end end