From cbfee0b6dc3f6863d431121da99cff6da28d6f2a Mon Sep 17 00:00:00 2001 From: todd-cook <665389+todd-cook@users.noreply.github.com> Date: Wed, 20 Jan 2021 13:19:54 -0800 Subject: [PATCH 1/5] correcting logic to discern the lowest logging level --- thespian/system/multiprocCommon.py | 66 ++++++++++++++++-------------- 1 file changed, 35 insertions(+), 31 deletions(-) diff --git a/thespian/system/multiprocCommon.py b/thespian/system/multiprocCommon.py index 947f95f..cd38c9a 100644 --- a/thespian/system/multiprocCommon.py +++ b/thespian/system/multiprocCommon.py @@ -2,24 +2,23 @@ python 'multiprocess' module. Intended as a base class, not for direct usage.""" +import multiprocessing +import signal +import sys +from datetime import timedelta +from functools import partial +from typing import Any, Dict -import logging from thespian.actors import * -from thespian.system.systemBase import systemBase -from thespian.system.systemCommon import actorStartupFailed -from thespian.system.utilis import thesplog, checkActorCapabilities, partition -from thespian.system.transport import * -from thespian.system.logdirector import * -from thespian.system.utilis import setProcName, StatsManager from thespian.system.addressManager import ActorLocalAddress, CannotPickleAddress +from thespian.system.logdirector import * from thespian.system.messages.multiproc import * from thespian.system.sourceLoader import loadModuleFromHashSource -from functools import partial -import multiprocessing -import signal -from datetime import timedelta -import sys - +from thespian.system.systemBase import systemBase +from thespian.system.systemCommon import actorStartupFailed +from thespian.system.transport import * +from thespian.system.utilis import checkActorCapabilities, partition +from thespian.system.utilis import setProcName MAX_ADMIN_STARTUP_DELAY = timedelta(seconds=5) @@ -511,6 +510,28 @@ def shutdown_signal_detected(signum, frame): am.transport.interrupt_wait(signal_shutdown=True) return shutdown_signal_detected +def get_min_log_level(logDefs:Dict[str, Any])->int: + """ + Get the minimum logging level from a logging configuration definition. Tested here using example. + >>> import logging + >>> logDefs = {'version': 1, 'formatters': {'normal': {'format': '%(levelname)-8s %(message)s'}, 'actor': {'format': '%(levelname)-8s %(actorAddress)s => %(message)s'}}, 'filters': {'isActorLog': {'()': 'actorLogFilter'}, 'notActorLog': {'()': 'notActorLogFilter'}}, 'handlers': {'h1': {'class': 'logging.FileHandler', 'filename': 'example.log', 'formatter': 'normal', 'filters': ['notActorLog'], 'level': 20}, 'h2': {'class': 'logging.FileHandler', 'filename': 'example.log', 'formatter': 'actor', 'filters': ['isActorLog'], 'level': 20}}, 'loggers': {'': {'handlers': ['h1', 'h2'], 'level': 10}}} + >>> res = get_min_log_level(logDefs) + >>> res == logging.DEBUG + True + + """ + levelIn = lambda d: d.get('level', 0) + minLevelIn = lambda l: min(list(l)) if list(l) else 0 + lowestLevel = minLevelIn( + [minLevelIn([levelIn(logDefs[key][subkey]) + for subkey in logDefs[key] + if isinstance(logDefs[key][subkey], dict) + ]) + for key in logDefs + if key in ['loggers', 'handlers'] and isinstance(logDefs[key], dict) + ]) + return lowestLevel + def startChild(childClass, globalName, endpoint, transportClass, sourceHash, sourceToLoad, @@ -544,24 +565,7 @@ def startChild(childClass, globalName, endpoint, transportClass, # logging.shutdown() because (a) that does not do enough to reset, # and (b) it shuts down handlers, but we want to leave the parent's # handlers alone. - if logDefs: - levelIn = lambda d: d.get('level', 0) - minLevelIn = lambda l: min(list(l)) if list(l) else 0 - levels = list( - filter(None, - ([ minLevelIn([levelIn(logDefs[key][subkey]) - for subkey in logDefs[key] - # if subkey in [ 'loggers', 'handlers' - if isinstance(logDefs[key][subkey], dict) - ]) - if key in ['loggers', 'handlers'] and isinstance(logDefs[key], dict) - else (levelIn(logDefs[key]) if key == 'root' - else (logDefs[key] if key == 'level' - else None)) - for key in logDefs ]))) - lowestLevel = minLevelIn(levels) - else: - lowestLevel = 0 + lowestLevel = get_min_log_level(logDefs) if logDefs else 0 logging.root = ThespianLogForwarder(loggerAddr, transport, logLevel=lowestLevel) logging.Logger.root = logging.root logging.Logger.manager = logging.Manager(logging.Logger.root) From 36888659c9163198ac0c3d24e0d99bf77317a0d2 Mon Sep 17 00:00:00 2001 From: todd-cook <665389+todd-cook@users.noreply.github.com> Date: Wed, 20 Jan 2021 21:41:06 -0800 Subject: [PATCH 2/5] removed type hints. updated logic to be more resilient and agreement with the logging dict config documentation. added more doctests. --- thespian/system/multiprocCommon.py | 74 +++++++++++++++++++++++------- 1 file changed, 57 insertions(+), 17 deletions(-) diff --git a/thespian/system/multiprocCommon.py b/thespian/system/multiprocCommon.py index cd38c9a..000e82d 100644 --- a/thespian/system/multiprocCommon.py +++ b/thespian/system/multiprocCommon.py @@ -7,7 +7,6 @@ import sys from datetime import timedelta from functools import partial -from typing import Any, Dict from thespian.actors import * from thespian.system.addressManager import ActorLocalAddress, CannotPickleAddress @@ -510,27 +509,68 @@ def shutdown_signal_detected(signum, frame): am.transport.interrupt_wait(signal_shutdown=True) return shutdown_signal_detected -def get_min_log_level(logDefs:Dict[str, Any])->int: + +def get_min_log_level(logDefs): """ - Get the minimum logging level from a logging configuration definition. Tested here using example. + Determine the minimum logging level based on the rules in: + https://docs.python.org/3/library/logging.config.html#logging.config.dictConfig + + Note: The level and handlers entries are interpreted as for the root logger, + except that if a non-root logger’s level is specified as NOTSET, the system + consults loggers higher up the hierarchy to determine the effective + level of the logger. + + :param logDefs: a logging configuration dictionary object + :return: integer value of the lowest log level, or the default level: logging.WARNING. + >>> import logging - >>> logDefs = {'version': 1, 'formatters': {'normal': {'format': '%(levelname)-8s %(message)s'}, 'actor': {'format': '%(levelname)-8s %(actorAddress)s => %(message)s'}}, 'filters': {'isActorLog': {'()': 'actorLogFilter'}, 'notActorLog': {'()': 'notActorLogFilter'}}, 'handlers': {'h1': {'class': 'logging.FileHandler', 'filename': 'example.log', 'formatter': 'normal', 'filters': ['notActorLog'], 'level': 20}, 'h2': {'class': 'logging.FileHandler', 'filename': 'example.log', 'formatter': 'actor', 'filters': ['isActorLog'], 'level': 20}}, 'loggers': {'': {'handlers': ['h1', 'h2'], 'level': 10}}} - >>> res = get_min_log_level(logDefs) - >>> res == logging.DEBUG + >>> logDefs = {'version': 1, 'handlers': {'h1': {'class': + ... 'logging.FileHandler', 'filename': 'example.log', 'formatter': + ... 'normal', 'filters': ['notActorLog'], 'level': "INFO"}, 'h2': {'class': + ... 'logging.FileHandler', 'filename': 'example.log', 'formatter': + ... 'actor', 'filters': ['isActorLog'], 'level': "INFO"}}, + ... 'loggers': {'': {'handlers': ['h1', 'h2'], 'level': "DEBUG"}}} + >>> get_min_log_level(logDefs) == logging.DEBUG + True + >>> logDefs = {'version': 1, 'loggers': {'root' : {'level': 10}, 'level': 20}} + >>> min1 = get_min_log_level(logDefs) + >>> logDefs = {'version': 1, 'loggers': {'root': {'level': 20}, 'level': 10}} + >>> min2 = get_min_log_level(logDefs) + >>> min1 == min2 == 10 + True + >>> get_min_log_level({"version" : 1}) == logging.WARNING # default log level + True + >>> logDefs = {'version': 1, 'loggers': {'root': {'level': "INFO"}, + ... 'handler2': {"level": logging.NOTSET}}} + >>> get_min_log_level(logDefs) == logging.INFO True """ - levelIn = lambda d: d.get('level', 0) - minLevelIn = lambda l: min(list(l)) if list(l) else 0 - lowestLevel = minLevelIn( - [minLevelIn([levelIn(logDefs[key][subkey]) - for subkey in logDefs[key] - if isinstance(logDefs[key][subkey], dict) - ]) - for key in logDefs - if key in ['loggers', 'handlers'] and isinstance(logDefs[key], dict) - ]) - return lowestLevel + levels = [] + names_to_levels = {"NOTSET": logging.NOTSET, "DEBUG": logging.DEBUG, + "INFO": logging.INFO, "WARNING": logging.WARNING, + "ERROR": logging.ERROR, "CRITICAL": logging.CRITICAL} + + loggers = logDefs.get('loggers', {}) + root_val = loggers.get("", loggers.get("root", None)) + if root_val: + root_val = root_val.get('level') + root_val = names_to_levels.get(root_val, root_val) + + def dfs(mapping): + """Traverse and collect""" + for key, val in mapping.items(): + if isinstance(val, dict): + dfs(val) + if key == 'level': + if isinstance(val, str): + val = names_to_levels[val.upper()] + if val == logging.NOTSET and root_val and root_val > logging.NOTSET: + continue + levels.append(val) + + dfs(logDefs) + return min(levels) if levels else logging.WARNING def startChild(childClass, globalName, endpoint, transportClass, From 1a401fb1115583dcae2855092013aba9a00562bc Mon Sep 17 00:00:00 2001 From: todd-cook <665389+todd-cook@users.noreply.github.com> Date: Wed, 20 Jan 2021 21:46:01 -0800 Subject: [PATCH 3/5] corrected caller, since the default is logging.WARNING and not logging.NOTSET, 0 --- thespian/system/multiprocCommon.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/thespian/system/multiprocCommon.py b/thespian/system/multiprocCommon.py index 000e82d..5ea7412 100644 --- a/thespian/system/multiprocCommon.py +++ b/thespian/system/multiprocCommon.py @@ -605,7 +605,7 @@ def startChild(childClass, globalName, endpoint, transportClass, # logging.shutdown() because (a) that does not do enough to reset, # and (b) it shuts down handlers, but we want to leave the parent's # handlers alone. - lowestLevel = get_min_log_level(logDefs) if logDefs else 0 + lowestLevel = get_min_log_level(logDefs) logging.root = ThespianLogForwarder(loggerAddr, transport, logLevel=lowestLevel) logging.Logger.root = logging.root logging.Logger.manager = logging.Manager(logging.Logger.root) From 487d2310fe602179557e78cd23d33b7bcfa8c854 Mon Sep 17 00:00:00 2001 From: todd-cook <665389+todd-cook@users.noreply.github.com> Date: Thu, 21 Jan 2021 22:10:06 -0800 Subject: [PATCH 4/5] changes as requested --- thespian/system/multiprocCommon.py | 58 +++++++++++++++++------------- thespian/system/utilis.py | 3 +- 2 files changed, 36 insertions(+), 25 deletions(-) diff --git a/thespian/system/multiprocCommon.py b/thespian/system/multiprocCommon.py index 5ea7412..53706fe 100644 --- a/thespian/system/multiprocCommon.py +++ b/thespian/system/multiprocCommon.py @@ -2,10 +2,8 @@ python 'multiprocess' module. Intended as a base class, not for direct usage.""" -import multiprocessing import signal import sys -from datetime import timedelta from functools import partial from thespian.actors import * @@ -17,7 +15,7 @@ from thespian.system.systemCommon import actorStartupFailed from thespian.system.transport import * from thespian.system.utilis import checkActorCapabilities, partition -from thespian.system.utilis import setProcName +from thespian.system.utilis import setProcName, _name_to_level MAX_ADMIN_STARTUP_DELAY = timedelta(seconds=5) @@ -516,7 +514,7 @@ def get_min_log_level(logDefs): https://docs.python.org/3/library/logging.config.html#logging.config.dictConfig Note: The level and handlers entries are interpreted as for the root logger, - except that if a non-root logger’s level is specified as NOTSET, the system + except that if a non-root logger's level is specified as NOTSET, the system consults loggers higher up the hierarchy to determine the effective level of the logger. @@ -524,38 +522,50 @@ def get_min_log_level(logDefs): :return: integer value of the lowest log level, or the default level: logging.WARNING. >>> import logging - >>> logDefs = {'version': 1, 'handlers': {'h1': {'class': - ... 'logging.FileHandler', 'filename': 'example.log', 'formatter': - ... 'normal', 'filters': ['notActorLog'], 'level': "INFO"}, 'h2': {'class': - ... 'logging.FileHandler', 'filename': 'example.log', 'formatter': - ... 'actor', 'filters': ['isActorLog'], 'level': "INFO"}}, - ... 'loggers': {'': {'handlers': ['h1', 'h2'], 'level': "DEBUG"}}} + >>> import logging.config + >>> logDefs = {'version': 1, 'handlers': { + ... 'h1': {'class': 'logging.FileHandler', 'filename': 'example.log', 'filters': [], + ... 'level': "INFO"}, + ... 'h2': {'class': 'logging.FileHandler', 'filename': 'example.log', 'filters': [], + ... 'level': "INFO"}}, 'loggers': {'': {'handlers': ['h1', 'h2'], 'level': "DEBUG"}}} + >>> logging.config.dictConfig(logDefs) # prove the config is considered valid >>> get_min_log_level(logDefs) == logging.DEBUG True - >>> logDefs = {'version': 1, 'loggers': {'root' : {'level': 10}, 'level': 20}} + + >>> logDefs = {'version': 1, 'root': {'level': 10}, 'loggers': {'one': {'level': 20}}} + >>> logging.config.dictConfig(logDefs) >>> min1 = get_min_log_level(logDefs) - >>> logDefs = {'version': 1, 'loggers': {'root': {'level': 20}, 'level': 10}} + >>> logDefs = {'version': 1, 'root': {'level': 20}, 'loggers': {'one': {'level': 10}}} + >>> logging.config.dictConfig(logDefs) >>> min2 = get_min_log_level(logDefs) >>> min1 == min2 == 10 True - >>> get_min_log_level({"version" : 1}) == logging.WARNING # default log level + + >>> get_min_log_level({'version' : 1}) == logging.WARNING # default log level True - >>> logDefs = {'version': 1, 'loggers': {'root': {'level': "INFO"}, - ... 'handler2': {"level": logging.NOTSET}}} + + >>> logDefs = {'version': 1, + ... 'loggers': {'root': {'level': "INFO"}, 'handler2': {'level': logging.NOTSET}}} + >>> logging.config.dictConfig(logDefs) >>> get_min_log_level(logDefs) == logging.INFO True """ - levels = [] - names_to_levels = {"NOTSET": logging.NOTSET, "DEBUG": logging.DEBUG, - "INFO": logging.INFO, "WARNING": logging.WARNING, - "ERROR": logging.ERROR, "CRITICAL": logging.CRITICAL} - loggers = logDefs.get('loggers', {}) - root_val = loggers.get("", loggers.get("root", None)) + levels = [] + root_data = logDefs.get('root') + if root_data and root_data.get('level'): + if isinstance( root_data.get('level'), str): + root_val = _name_to_level.get(root_data.get('level'). upper()) + else: + root_val = root_data.get('level') + else: + loggers = logDefs.get('loggers', {}) + root_val_empty = loggers.get("", {}).get("level") + root_val_named = loggers.get("root", {}).get("level") + root_val = root_val_empty if root_val_empty else root_val_named if root_val: - root_val = root_val.get('level') - root_val = names_to_levels.get(root_val, root_val) + root_val = _name_to_level.get(root_val, root_val) def dfs(mapping): """Traverse and collect""" @@ -564,7 +574,7 @@ def dfs(mapping): dfs(val) if key == 'level': if isinstance(val, str): - val = names_to_levels[val.upper()] + val = _name_to_level[val.upper()] if val == logging.NOTSET and root_val and root_val > logging.NOTSET: continue levels.append(val) diff --git a/thespian/system/utilis.py b/thespian/system/utilis.py index f4ecb3c..796c80e 100644 --- a/thespian/system/utilis.py +++ b/thespian/system/utilis.py @@ -17,7 +17,8 @@ "ERROR": logging.ERROR, "WARNING": logging.WARNING, "INFO": logging.INFO, - "DEBUG": logging.DEBUG + "DEBUG": logging.DEBUG, + "NOTSET": logging.NOTSET } # Default/current logging controls From 162a1849c0a28f4d0fe1b9da095569aca4dc5586 Mon Sep 17 00:00:00 2001 From: todd-cook <665389+todd-cook@users.noreply.github.com> Date: Wed, 27 Jan 2021 12:30:01 -0800 Subject: [PATCH 5/5] further changes as requested --- thespian/system/multiprocCommon.py | 25 +++++++++++++++++++------ 1 file changed, 19 insertions(+), 6 deletions(-) diff --git a/thespian/system/multiprocCommon.py b/thespian/system/multiprocCommon.py index 53706fe..aae41e9 100644 --- a/thespian/system/multiprocCommon.py +++ b/thespian/system/multiprocCommon.py @@ -529,8 +529,8 @@ def get_min_log_level(logDefs): ... 'h2': {'class': 'logging.FileHandler', 'filename': 'example.log', 'filters': [], ... 'level': "INFO"}}, 'loggers': {'': {'handlers': ['h1', 'h2'], 'level': "DEBUG"}}} >>> logging.config.dictConfig(logDefs) # prove the config is considered valid - >>> get_min_log_level(logDefs) == logging.DEBUG - True + >>> get_min_log_level(logDefs) # logging.DEBUG + 10 >>> logDefs = {'version': 1, 'root': {'level': 10}, 'loggers': {'one': {'level': 20}}} >>> logging.config.dictConfig(logDefs) @@ -541,14 +541,26 @@ def get_min_log_level(logDefs): >>> min1 == min2 == 10 True - >>> get_min_log_level({'version' : 1}) == logging.WARNING # default log level - True + >>> get_min_log_level({'version' : 1}) # logging.WARNING is default log level + 30 >>> logDefs = {'version': 1, ... 'loggers': {'root': {'level': "INFO"}, 'handler2': {'level': logging.NOTSET}}} >>> logging.config.dictConfig(logDefs) - >>> get_min_log_level(logDefs) == logging.INFO - True + >>> get_min_log_level(logDefs) # logging.INFO + 20 + + >>> logDefs = {'version': 1, 'loggers': {'one': {'level': logging.NOTSET}}} + >>> logging.config.dictConfig(logDefs) + >>> get_min_log_level(logDefs) # logging.WARNING + 30 + + >>> logDefs = {'version': 1, + ... 'root': {'level': None}, + ... 'loggers': {'one': {'level': logging.NOTSET}}} + >>> logging.config.dictConfig(logDefs) + >>> get_min_log_level(logDefs) # logging.WARNING + 30 """ @@ -580,6 +592,7 @@ def dfs(mapping): levels.append(val) dfs(logDefs) + levels = [tmp for tmp in levels if tmp] # swallow None values return min(levels) if levels else logging.WARNING