def test_set_prefix(self, mock_file_write, mock_console_write,
mock_telem_write, mock_stdout_write):
lg = logger.Logger(logger.DEFAULT_LOGGER)
prefix = "YoloLogger"
lg.set_prefix(prefix)
self.assertEqual(lg.prefix, prefix)
lg.add_appender(logger.AppenderType.FILE,
logger.LogLevel.INFO,
path=self.log_file)
lg.add_appender(logger.AppenderType.TELEMETRY,
logger.LogLevel.WARNING,
path=add_log_event)
lg.add_appender(logger.AppenderType.CONSOLE,
logger.LogLevel.WARNING,
path="/dev/null")
lg.add_appender(logger.AppenderType.STDOUT,
logger.LogLevel.WARNING,
path=None)
lg.error("Test Log")
self.assertIn(prefix, mock_file_write.call_args[0][1])
self.assertIn(prefix, mock_console_write.call_args[0][1])
self.assertIn(prefix, mock_telem_write.call_args[0][1])
self.assertIn(prefix, mock_stdout_write.call_args[0][1])
def test_logger_should_log_micro_seconds(self, mock_dt):
# datetime.isoformat() skips ms if ms=0, this test ensures that ms is always set
file_name = "test.log"
file_path = os.path.join(self.tmp_dir, file_name)
test_logger = logger.Logger()
test_logger.add_appender(logger.AppenderType.FILE,
logger.LogLevel.INFO,
path=file_path)
ts_with_no_ms = datetime.utcnow().replace(microsecond=0)
mock_dt.utcnow = MagicMock(return_value=ts_with_no_ms)
test_logger.info("The time should contain milli-seconds")
with open(file_path, "r") as log_file:
log = log_file.read()
try:
time_in_file = datetime.strptime(
log.split(logger.LogLevel.STRINGS[logger.LogLevel.INFO])
[0].strip(), logger.Logger.LogTimeFormatInUTC)
except ValueError:
self.fail(
"Ensure timestamp follows ISO-8601 format and has micro seconds in it"
)
self.assertEqual(ts_with_no_ms, time_in_file,
"Timestamps dont match")
def test_console_output_enabled_should_return_false_when_there_are_no_console_appenders(
self):
my_logger = logger.Logger()
my_logger.add_appender(logger.AppenderType.STDOUT,
logger.LogLevel.INFO, None)
self.assertFalse(
my_logger.console_output_enabled(),
"Console output should not be enabled, appenders = {0}".format(
my_logger.appenders))
def test_add_appender(self, mock_file_write, mock_console_write,
mock_telem_write, mock_stdout_write):
lg = logger.Logger(logger.DEFAULT_LOGGER, "TestLogger1")
lg.add_appender(logger.AppenderType.FILE,
logger.LogLevel.INFO,
path=self.log_file)
lg.add_appender(logger.AppenderType.TELEMETRY,
logger.LogLevel.WARNING,
path=add_log_event)
lg.add_appender(logger.AppenderType.CONSOLE,
logger.LogLevel.WARNING,
path="/dev/null")
lg.add_appender(logger.AppenderType.STDOUT,
logger.LogLevel.WARNING,
path=None)
counter = 0
for appender in lg.appenders:
if isinstance(appender, logger.FileAppender):
counter += 1
elif isinstance(appender, logger.TelemetryAppender):
counter += 1
elif isinstance(appender, logger.ConsoleAppender):
counter += 1
elif isinstance(appender, logger.StdoutAppender):
counter += 1
# All 4 appenders should have been included.
self.assertEqual(4, counter)
# The write for all the loggers will get called, but the levels are honored in the individual write method
# itself. Each appender has its own test to validate the writing of the log message for different levels.
# For Reference: tests.common.test_logger.TestAppender
lg.warn("Test Log")
self.assertEqual(1, mock_file_write.call_count)
self.assertEqual(1, mock_console_write.call_count)
self.assertEqual(1, mock_telem_write.call_count)
self.assertEqual(1, mock_stdout_write.call_count)
lg.info("Test Log")
self.assertEqual(2, mock_file_write.call_count)
self.assertEqual(2, mock_console_write.call_count)
self.assertEqual(2, mock_telem_write.call_count)
self.assertEqual(2, mock_stdout_write.call_count)
lg.error("Test Log")
self.assertEqual(3, mock_file_write.call_count)
self.assertEqual(3, mock_console_write.call_count)
self.assertEqual(3, mock_telem_write.call_count)
self.assertEqual(3, mock_stdout_write.call_count)
def test_nested_logger(self, mock_file_write, mock_console_write,
mock_telem_write, mock_stdout_write):
"""
The purpose of this test is to see if the logger gets correctly created when passed it another logger and also
if the appender correctly gets the messages logged. This is how the ExtHandlerInstance logger works.
I initialize the default logger(logger), then create a new logger(lg) from it, and then log using logger & lg.
See if both logs are flowing through or not.
"""
parent_prefix = "ParentLogger"
child_prefix = "ChildLogger"
logger.add_logger_appender(logger.AppenderType.FILE,
logger.LogLevel.INFO,
path=self.log_file)
logger.add_logger_appender(logger.AppenderType.TELEMETRY,
logger.LogLevel.WARNING,
path=add_log_event)
logger.add_logger_appender(logger.AppenderType.CONSOLE,
logger.LogLevel.WARNING,
path="/dev/null")
logger.add_logger_appender(logger.AppenderType.STDOUT,
logger.LogLevel.WARNING)
logger.set_prefix(parent_prefix)
lg = logger.Logger(logger.DEFAULT_LOGGER, child_prefix)
lg.error("Test Log")
self.assertEqual(1, mock_file_write.call_count)
self.assertEqual(1, mock_console_write.call_count)
self.assertEqual(1, mock_telem_write.call_count)
self.assertEqual(1, mock_stdout_write.call_count)
self.assertIn(child_prefix, mock_file_write.call_args[0][1])
self.assertIn(child_prefix, mock_console_write.call_args[0][1])
self.assertIn(child_prefix, mock_telem_write.call_args[0][1])
self.assertIn(child_prefix, mock_stdout_write.call_args[0][1])
logger.error("Test Log")
self.assertEqual(2, mock_file_write.call_count)
self.assertEqual(2, mock_console_write.call_count)
self.assertEqual(2, mock_telem_write.call_count)
self.assertEqual(2, mock_stdout_write.call_count)
self.assertIn(parent_prefix, mock_file_write.call_args[0][1])
self.assertIn(parent_prefix, mock_console_write.call_args[0][1])
self.assertIn(parent_prefix, mock_telem_write.call_args[0][1])
self.assertIn(parent_prefix, mock_stdout_write.call_args[0][1])
def __init__(self, ext_handler, protocol):
self.ext_handler = ext_handler
self.protocol = protocol
self.operation = None
self.pkg = None
prefix = "[{0}]".format(self.get_full_name())
self.logger = logger.Logger(logger.DEFAULT_LOGGER, prefix)
try:
fileutil.mkdir(self.get_log_dir(), mode=0o744)
except IOError as e:
self.logger.error(u"Failed to create extension log dir: {0}", e)
log_file = os.path.join(self.get_log_dir(), "CommandExecution.log")
self.logger.add_appender(logger.AppenderType.FILE,
logger.LogLevel.INFO, log_file)
def test_disable_console_output_should_remove_all_console_appenders(self):
my_logger = logger.Logger()
my_logger.add_appender(logger.AppenderType.STDOUT,
logger.LogLevel.INFO, None)
my_logger.add_appender(logger.AppenderType.CONSOLE,
logger.LogLevel.INFO, None)
my_logger.add_appender(logger.AppenderType.STDOUT,
logger.LogLevel.INFO, None)
my_logger.add_appender(logger.AppenderType.CONSOLE,
logger.LogLevel.INFO, None)
my_logger.disable_console_output()
self.assertTrue(
len(my_logger.appenders) == 2 and all(
isinstance(a, logger.StdoutAppender)
for a in my_logger.appenders),
"The console appender was not removed: {0}".format(
my_logger.appenders))
def test_logger_should_log_in_utc(self):
file_name = "test.log"
file_path = os.path.join(self.tmp_dir, file_name)
test_logger = logger.Logger()
test_logger.add_appender(logger.AppenderType.FILE, logger.LogLevel.INFO, path=file_path)
before_write_utc = datetime.utcnow()
test_logger.info("The time should be in UTC")
with open(file_path, "r") as log_file:
log = log_file.read()
try:
time_in_file = datetime.strptime(log.split(logger.LogLevel.STRINGS[logger.LogLevel.INFO])[0].strip()
, u'%Y-%m-%dT%H:%M:%S.%fZ')
except ValueError:
self.fail("Ensure timestamp follows ISO-8601 format + 'Z' for UTC")
# If the time difference is > 5secs, there's a high probability that the time_in_file is in different TZ
self.assertTrue((time_in_file-before_write_utc) <= timedelta(seconds=5))
def set_logger(self):
prefix = "[{0}]".format(self.get_full_name())
self.logger = logger.Logger(logger.DEFAULT_LOGGER, prefix)
