def test_setLevelShowngLogger(loggerLevel, isSuperiorTo, logRecordLevel):
"""
Set gLogger level: check whether a log record should be displayed
"""
capturedBackend, log, sublog = gLoggerReset()
levels = gLogger.getAllPossibleLevels()
gLogger.setLevel(loggerLevel)
# convert level name into its integer value
logRecordLevelValue = LogLevels.getLevelValue(logRecordLevel)
res = gLogger._createLogRecord(logRecordLevelValue, 'message', '')
# clean the log to remove unecessary information
logstring = cleaningLog(capturedBackend.getvalue())
# if loggerLevel is superior to logRecordLevel then:
# - log record should not appear
# - shown should return False as the log doesn't appear
# - value returned by createLogRecord should be False too
isLoggerLvlSupToLogRecordLvl = LogLevels.getLevelValue(
loggerLevel) > logRecordLevelValue
assert isLoggerLvlSupToLogRecordLvl == isSuperiorTo
if isLoggerLvlSupToLogRecordLvl:
assert not gLogger.shown(logRecordLevel)
assert not res
assert logstring == ""
else:
assert gLogger.shown(logRecordLevel)
assert res
assert logstring == "Framework %s: message\n" % logRecordLevel.upper()
capturedBackend.truncate(0)
capturedBackend.seek(0)
def test_createLogRecord(sMsg, sVarMsg, exc_info, expected):
"""
Create logs of different levels with multiple logs
"""
capturedBackend, log, sublog = gLoggerReset()
# Set the level to debug
gLogger.setLevel("debug")
# dictionary of key = logger to use, value = output associated to the logger
logDict = {gLogger: "", log: "/log", sublog: "/log/sublog"}
# get list of existing levels, for each of them, a log record is created
levels = gLogger.getAllPossibleLevels()
for level in levels:
for logger, logInfo in logDict.items():
# createLogRecord is the method in charge of creating the log record
# debug, ..., always methods wrap the following method
# we use logLevels to get the int value corresponding to the level name
logger._createLogRecord(LogLevels.getLevelValue(level), sMsg,
sVarMsg, exc_info)
# clean the log to remove unecessary information
logstring = cleaningLog(capturedBackend.getvalue())
logExpected = "Framework%s %s: %s\n" % (logInfo, level, expected)
assert logExpected == logstring
capturedBackend.truncate(0)
capturedBackend.seek(0)
def test_showStack():
"""
Get the showStack
"""
capturedBackend, log, sublog = gLoggerReset()
# dictionary of key = logger to use, value = output associated to the logger
logDict = {gLogger: "", log: "/log", sublog: "/log/sublog"}
for logger, logInfo in logDict.items():
# By default, should not appear as the level is NOTICE
logger.showStack()
# clean the log to remove unecessary information
logstring = cleaningLog(capturedBackend.getvalue())
assert logstring == ""
capturedBackend.truncate(0)
capturedBackend.seek(0)
# Set level to debug
gLogger.setLevel("debug")
for logger, logInfo in logDict.items():
# The debug message should appear
logger.showStack()
# clean the log to remove unecessary information
logstring = cleaningLog(capturedBackend.getvalue())
assert logstring == "Framework%s DEBUG: \n" % logInfo
capturedBackend.truncate(0)
capturedBackend.seek(0)
def test_localSubLoggerObject(logLevel):
"""
Create a local subLogger and compare its output with the standard subLogger
for all the log levels
"""
capturedBackend, log, _ = gLoggerReset()
# Set the level to debug to always make sure that something is printed
log.setLevel("debug")
# Create a real subLogger and a localSubLogger
# with the same "name"
subLog = log.getSubLogger("child")
localSubLog = log.getSubLogger("child")
# Print and capture a message with the real sublogger
capturedBackend.truncate(0)
capturedBackend.seek(0)
getattr(subLog, logLevel)(logLevel)
subMsg = capturedBackend.getvalue()
# Print and capture a message with the local sublogger
capturedBackend.truncate(0)
capturedBackend.seek(0)
getattr(localSubLog, logLevel)(logLevel)
locMsg = capturedBackend.getvalue()
# Compare the output
assert subMsg == locMsg
def test_registerBackendgLogger(backends):
"""
Attach backends to gLogger, generate some logs from different loggers and check the content of the backends
"""
_, log, sublog = gLoggerReset()
# dictionary of available loggers
loggers = {"gLogger": gLogger, "log": log, "sublog": sublog}
# attach backends to the corresponding logger
for backend, params in backends.items():
logger = loggers[params["logger"]]
numberOfBackends = len(logger._backendsList)
logger.registerBackend(params["backendType"], params["backendOptions"])
# backend should be added to logger.backendList
assert len(logger._backendsList) == (numberOfBackends + 1)
# Generate logs from gLogger, log, sublog
gLogger.setLevel("notice")
gLogger.notice("msg")
log.notice("msg")
sublog.notice("msg")
# Check the content of the backends
for backend, params in backends.items():
content = params["extractBackendContent"](params["backendOptions"])
assert content == params["backendContent"]
def test_registerBackendgLogger(backends):
"""
Attach backends to gLogger, generate some logs from different loggers and check the content of the backends
"""
_, log, sublog = gLoggerReset()
# dictionary of available loggers
loggers = {'gLogger': gLogger, 'log': log, 'sublog': sublog}
# attach backends to the corresponding logger
for backend, params in backends.items():
logger = loggers[params['logger']]
numberOfBackends = len(logger._backendsList)
logger.registerBackend(params['backendType'], params['backendOptions'])
# backend should be added to logger.backendList
assert len(logger._backendsList) == (numberOfBackends + 1)
# Generate logs from gLogger, log, sublog
gLogger.setLevel('notice')
gLogger.notice('msg')
log.notice('msg')
sublog.notice('msg')
# Check the content of the backends
for backend, params in backends.items():
content = params['extractBackendContent'](params['backendOptions'])
assert content == params['backendContent']
def test_getAllPossibleLevels():
"""
Make sure getAllPossibleLevels returns every existing level
"""
_, log, sublog = gLoggerReset()
levels = ["DEBUG", "VERBOSE", "INFO", "WARN", "NOTICE", "ERROR", "ALWAYS", "FATAL"]
assert sorted(gLogger.getAllPossibleLevels()) == sorted(levels)
assert sorted(log.getAllPossibleLevels()) == sorted(levels)
assert sorted(sublog.getAllPossibleLevels()) == sorted(levels)
def test_showFormatOptionsgLogger(
header, threadID, timeStamp, context, msg, expectedLog, isThreadIDAvailable, isTimeStampAvailable
):
"""
Set gLogger options, check that options are inherited in log and sublog
"""
capturedBackend, log, sublog = gLoggerReset()
# setting these values should modify the way the log record is displayed
gLogger.showHeaders(header)
gLogger.showThreadIDs(threadID)
gLogger.showTimeStamps(timeStamp)
gLogger.showContexts(context)
# log and sublog should inherit from the changes
assert gLogger._options["headerIsShown"] == header
assert gLogger._options["threadIDIsShown"] == threadID
assert log._options["headerIsShown"] == gLogger._options["headerIsShown"]
assert log._options["timeStampIsShown"] == gLogger._options["timeStampIsShown"]
assert log._options["contextIsShown"] == gLogger._options["contextIsShown"]
assert log._options["threadIDIsShown"] == gLogger._options["threadIDIsShown"]
assert sublog._options["headerIsShown"] == log._options["headerIsShown"]
assert sublog._options["timeStampIsShown"] == log._options["timeStampIsShown"]
assert sublog._options["contextIsShown"] == log._options["contextIsShown"]
assert sublog._options["threadIDIsShown"] == log._options["threadIDIsShown"]
# create log records and check the format is correct
gLogger.notice(msg)
logValue = capturedBackend.getvalue()
# check that timestamp is available if it has to be available
assert ("UTC" in logValue) == isTimeStampAvailable
logstring = cleaningLog(logValue)
capturedBackend.truncate(0)
capturedBackend.seek(0)
log.notice(msg)
logValue = capturedBackend.getvalue()
assert ("UTC" in logValue) == isTimeStampAvailable
logstring += cleaningLog(logValue)
capturedBackend.truncate(0)
capturedBackend.seek(0)
sublog.notice(msg)
logValue = capturedBackend.getvalue()
assert ("UTC" in logValue) == isTimeStampAvailable
logstring += cleaningLog(logValue)
capturedBackend.truncate(0)
capturedBackend.seek(0)
# check that threadID is present in the log when it should be present
threadIDValue = str(thread.get_ident())
assert (threadIDValue in logstring) == isThreadIDAvailable
# as thread ID depends on the execution, we have to add it to the expected results
if isThreadIDAvailable:
expectedLog = expectedLog % (threadIDValue, threadIDValue, threadIDValue)
assert expectedLog == logstring
def test_setLevelInit():
"""
Test setLevel and getLevel: initialization of gLogger
"""
_, log, sublog = gLoggerReset()
# make sure gLogger and its subloggers have a common level when initialized
# we don't set the level of gLogger
assert gLogger.getLevel() == 'NOTICE'
assert log.getLevel() == 'NOTICE'
assert sublog.getLevel() == 'NOTICE'
def test_logsFromExtLibsHandlers(isEnabled, loggingLevel, numberHandlers, handlerType):
"""
Check that handlers attached are different according to the value of enableLogsFromExternalLibs()
"""
gLoggerReset()
# when enable, Logging should also report logs from external library
# a StreamHandler should be attached to the root logger by default
if isEnabled:
gLogger.enableLogsFromExternalLibs()
# in the other case, Logging should not report logs from external library
# a NullHandler disables the emission of the log records going to the root logger
else:
gLogger.disableLogsFromExternalLibs()
handlers = logging.getLogger().handlers
assert logging.getLogger().getEffectiveLevel() == loggingLevel
assert numberHandlers == len(handlers)
assert isinstance(handlers[0], handlerType)
def test_getSubLoggerObject():
"""
Create a sublogger, set its level, get a sublogger with the same name and check that is it the same object
"""
_, _, _ = gLoggerReset()
log = gLogger.getSubLogger("log")
log.setLevel("notice")
anotherLog = gLogger.getSubLogger("log")
assert log.getLevel() == anotherLog.getLevel()
assert log == anotherLog
def test_logsFromExtLibsLogs(isEnabled, loggerName, message, expected):
"""
Check whether logs are displayed according to the value of enableLogsFromExternalLibs()
"""
gLoggerReset()
# when enable, Logging should also report logs from external library
# logs from external libs should appear
if isEnabled:
gLogger.enableLogsFromExternalLibs()
# in the other case, Logging should not report logs from external library
# logs from external libs shouldn't appear
else:
gLogger.disableLogsFromExternalLibs()
# modify the output to capture logs of the root logger
bufferRoot = StringIO()
logging.getLogger().handlers[0].stream = bufferRoot
logging.getLogger(loggerName).info(message)
logstring = cleaningLog(bufferRoot.getvalue())
assert expected == logstring
def test_setLevelgLogger():
"""
Test setLevel and getLevel: set gLogger level
"""
_, log, sublog = gLoggerReset()
levels = gLogger.getAllPossibleLevels()
# as log and sublog levels has not been changed, they should inherit from the same level
for level in levels:
gLogger.setLevel(level)
assert gLogger.getLevel() == level.upper()
assert log.getLevel() == level.upper()
assert sublog.getLevel() == level.upper()
def test_showFormatOptionsSubLog(header, threadID, msg, expectedLog,
isThreadIDAvailable):
"""
Set sublog (child of log) options
"""
capturedBackend, log, sublog = gLoggerReset()
# set gLogger and log options, sublog options should not be modified
gLogger.showHeaders(True)
gLogger.showThreadIDs(False)
log.showHeaders(False)
log.showThreadIDs(False)
# set sublog options
sublog.showHeaders(header)
sublog.showThreadIDs(threadID)
# log should inherit from the options of gLogger, subLog shoud not inherit from log
assert gLogger._options["headerIsShown"]
assert not gLogger._options["threadIDIsShown"]
assert not log._options["headerIsShown"]
assert not log._options["threadIDIsShown"]
assert sublog._options["headerIsShown"] == header
assert sublog._options["threadIDIsShown"] == threadID
# create log records and check the format is correct
gLogger.notice(msg)
logstring = cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
log.notice(msg)
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
sublog.notice(msg)
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
expectedLog = "Framework NOTICE: message\nmessage\n" + expectedLog
threadIDValue = str(_thread.get_ident())
assert (threadIDValue in logstring) == isThreadIDAvailable
# as thread ID depends on the execution, we have to add it to the expected results
if isThreadIDAvailable:
expectedLog = expectedLog % threadIDValue
assert expectedLog == logstring
def test_logsFromExtLibsMultCalls():
"""
Calls the method several times to see whether we have duplication of the logs
"""
gLoggerReset()
for i in range(5):
gLogger.enableLogsFromExternalLibs()
handlers = logging.getLogger().handlers
assert len(handlers) == 1
assert isinstance(handlers[0], logging.StreamHandler)
for i in range(5):
gLogger.disableLogsFromExternalLibs()
handlers = logging.getLogger().handlers
assert len(handlers) == 1
assert isinstance(handlers[0], logging.NullHandler)
gLogger.enableLogsFromExternalLibs()
gLogger.disableLogsFromExternalLibs()
gLogger.enableLogsFromExternalLibs()
gLogger.disableLogsFromExternalLibs()
handlers = logging.getLogger().handlers
assert len(handlers) == 1
assert isinstance(handlers[0], logging.NullHandler)
gLogger.disableLogsFromExternalLibs()
gLogger.enableLogsFromExternalLibs()
gLogger.disableLogsFromExternalLibs()
gLogger.enableLogsFromExternalLibs()
handlers = logging.getLogger().handlers
assert len(handlers) == 1
assert isinstance(handlers[0], logging.StreamHandler)
def test_logsFromExtLibsPropag():
"""
Test the no propagation of the logs from the Logging objects to the root logger of 'logging'
"""
capturedBackend, _, _ = gLoggerReset()
gLogger.enableLogsFromExternalLibs()
# modify the output to capture logs of the root logger
bufferRoot = StringIO()
logging.getLogger().handlers[0].stream = bufferRoot
gLogger.error('message')
assert capturedBackend.getvalue() != ""
assert bufferRoot.getvalue() == ""
def test_setLevelStopPropagation():
"""
Test setLevel and getLevel: set gLogger level while log and sublog have already be set
"""
_, log, sublog = gLoggerReset()
levels = gLogger.getAllPossibleLevels()
# by changing gLogger level, log and sublog should not be affected anymore as they have been changed manually
log.setLevel('warn')
sublog.setLevel('verbose')
for level in levels:
gLogger.setLevel(level)
assert gLogger.getLevel() == level.upper()
assert log.getLevel() == 'WARN'
assert sublog.getLevel() == 'VERBOSE'
def test_setLevelLog():
"""
Test setLevel and getLevel: set log level
"""
_, log, sublog = gLoggerReset()
levels = gLogger.getAllPossibleLevels()
# set gLogger level
gLogger.setLevel('notice')
# by changing log level, gLogger should not be affected, subLogger should be
for level in levels:
log.setLevel(level)
assert gLogger.getLevel() == 'NOTICE'
assert log.getLevel() == level.upper()
assert sublog.getLevel() == level.upper()
def test_setLevelSublog():
"""
Test setLevel and getLevel: set sublog level
"""
_, log, sublog = gLoggerReset()
levels = gLogger.getAllPossibleLevels()
# set gLogger and log level
gLogger.setLevel('notice')
log.setLevel('warn')
# by changing sublog level, gLogger and log should not be affected
for level in levels:
sublog.setLevel(level)
assert gLogger.getLevel() == 'NOTICE'
assert log.getLevel() == 'WARN'
assert sublog.getLevel() == level.upper()
def test_showFormatOptionsLog(header, threadID, msg, expectedLog, isThreadIDAvailable):
"""
Set log (child of gLogger) options, check that options are inherited in sublog
"""
capturedBackend, log, sublog = gLoggerReset()
# set gLogger options, they should not be modified
gLogger.showHeaders(True)
gLogger.showThreadIDs(False)
# set log options
log.showHeaders(header)
log.showThreadIDs(threadID)
# sublog should inherit from the changes, gLogger should not be affected
assert gLogger._options['headerIsShown']
assert not gLogger._options['threadIDIsShown']
assert log._options['headerIsShown'] == header
assert log._options['threadIDIsShown'] == threadID
assert sublog._options['headerIsShown'] == log._options['headerIsShown']
assert sublog._options['threadIDIsShown'] == log._options['threadIDIsShown']
# create log records and check the format is correct
gLogger.notice(msg)
logstring = cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
log.notice(msg)
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
sublog.notice(msg)
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
expectedLog = "Framework NOTICE: message\n" + expectedLog
threadIDValue = str(thread.get_ident())
assert (threadIDValue in logstring) == isThreadIDAvailable
# as thread ID depends on the execution, we have to add it to the expected results
if isThreadIDAvailable:
expectedLog = expectedLog % (threadIDValue, threadIDValue)
assert expectedLog == logstring
def test_showFormatOptionsPropag():
"""
Make sure log and sublog don't inherit from gLogger options if already set
"""
capturedBackend, log, sublog = gLoggerReset()
# set logger options
log.showHeaders(False)
log.showThreadIDs(False)
# then, set gLogger options again
gLogger.showHeaders(True)
gLogger.showThreadIDs(True)
# log should not inherit from the options of gLogger as it has been modified by a developer
# subLog shoud inherit from log, it has not been modified
assert gLogger._options["headerIsShown"]
assert gLogger._options["threadIDIsShown"]
assert log._options["headerIsShown"] != gLogger._options["headerIsShown"]
assert log._options["threadIDIsShown"] != gLogger._options[
"threadIDIsShown"]
assert sublog._options["headerIsShown"] == log._options["headerIsShown"]
assert sublog._options["threadIDIsShown"] == log._options[
"threadIDIsShown"]
# a log record is sent, we then get the result to see if options have been taken into account
gLogger.notice("me")
logstring = cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
log.notice("ss")
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
sublog.notice("age")
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
threadID = str(_thread.get_ident())
expectedLog = "Framework [%s] NOTICE: me\nss\nage\n" % threadID
assert expectedLog == logstring
def test_showFormatOptionsInit():
"""
Check showHeaders and showThreadIDs methods at initialization
"""
capturedBackend, log, sublog = gLoggerReset()
# first, make sure options are inherited from gLogger
assert gLogger._options["headerIsShown"]
assert gLogger._options["timeStampIsShown"]
assert gLogger._options["contextIsShown"]
assert not gLogger._options["threadIDIsShown"]
assert log._options["headerIsShown"] == gLogger._options["headerIsShown"]
assert log._options["timeStampIsShown"] == gLogger._options[
"timeStampIsShown"]
assert log._options["contextIsShown"] == gLogger._options["contextIsShown"]
assert log._options["threadIDIsShown"] == gLogger._options[
"threadIDIsShown"]
assert sublog._options["headerIsShown"] == log._options["headerIsShown"]
assert sublog._options["timeStampIsShown"] == log._options[
"timeStampIsShown"]
assert sublog._options["contextIsShown"] == log._options["contextIsShown"]
assert sublog._options["threadIDIsShown"] == log._options[
"threadIDIsShown"]
# create log records and check that the format is correct
gLogger.notice("me")
logstring = cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
log.notice("ss")
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
sublog.notice("age")
logstring += cleaningLog(capturedBackend.getvalue())
capturedBackend.truncate(0)
capturedBackend.seek(0)
assert logstring == "Framework NOTICE: me\nFramework/log NOTICE: ss\nFramework/log/sublog NOTICE: age\n"
def test_getSubLoggerLogRecord():
"""
Create some subloggers and create a log record
"""
capturedBackend, log, sublog = gLoggerReset()
# Send a first log with a simple sublogger
log.always("message")
assert " Framework/log " in capturedBackend.getvalue()
# Reinitialize the buffer and send a log with a child of the sublogger
capturedBackend.truncate(0)
capturedBackend.seek(0)
sublog.always("message")
assert " Framework/log/sublog " in capturedBackend.getvalue()
# Generate a new sublogger from sublog
capturedBackend.truncate(0)
capturedBackend.seek(0)
subsublog = sublog.getSubLogger("subsublog")
subsublog.always("message")
assert " Framework/log/sublog/subsublog " in capturedBackend.getvalue()