From 52efbfc2cdd9a2bf4ff277e6660853d540e542be Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Sun, 1 Dec 2019 23:26:25 -0500 Subject: [PATCH] Log task and actor names where possible Prepend the actor and task names in each log emission. This makes debugging much more sane since you can see from which process and running task the log message originates from! Resolves #13 --- tractor/_state.py | 25 +++++++++++++++++++++++-- tractor/log.py | 15 +++++++++++---- 2 files changed, 34 insertions(+), 6 deletions(-) diff --git a/tractor/_state.py b/tractor/_state.py index 704fae7..f479d41 100644 --- a/tractor/_state.py +++ b/tractor/_state.py @@ -3,6 +3,7 @@ Per process state """ from typing import Optional +import trio _current_actor: Optional['Actor'] = None # type: ignore @@ -10,6 +11,26 @@ _current_actor: Optional['Actor'] = None # type: ignore def current_actor() -> 'Actor': # type: ignore """Get the process-local actor instance. """ - if not _current_actor: - raise RuntimeError("No actor instance has been defined yet?") + if _current_actor is None: + raise RuntimeError("No local actor has been initialized yet") return _current_actor + + +class ActorContextInfo: + "Dyanmic lookup for local actor and task names" + def __iter__(self): + return iter(('task', 'actor')) + + def __getitem__(self, key: str): + if key == 'task': + try: + return trio._core.current_task().name + except RuntimeError: + # not inside `trio.run()` yet + return 'no task context' + elif key == 'actor': + try: + return current_actor().name + except RuntimeError: + # no local actor initialize yet + return 'no actor context' diff --git a/tractor/log.py b/tractor/log.py index 9433e93..769fae4 100644 --- a/tractor/log.py +++ b/tractor/log.py @@ -7,6 +7,8 @@ import logging import colorlog # type: ignore from typing import Optional +from ._state import ActorContextInfo + _proj_name = 'tractor' _default_loglevel = None @@ -18,7 +20,7 @@ LOG_FORMAT = ( # "{bold_white}{log_color}{asctime}{reset}" "{log_color}{asctime}{reset}" " {bold_white}{thin_white}({reset}" - "{thin_white}{processName}: {threadName}{reset}{bold_white}{thin_white})" + "{thin_white}{actor}, {process}, {task}){reset}{bold_white}{thin_white})" " {reset}{log_color}[{reset}{bold_log_color}{levelname}{reset}{log_color}]" " {log_color}{name}" " {thin_white}{filename}{log_color}:{reset}{thin_white}{lineno}{log_color}" @@ -54,6 +56,10 @@ def get_logger(name: str = None) -> logging.Logger: log = rlog.getChild(name) log.level = rlog.level + # add our actor-task aware adapter which will dynamically look up + # the actor and task names at each log emit + log = logging.LoggerAdapter(log, ActorContextInfo()) + # additional levels for name, val in LEVELS.items(): logging.addLevelName(val, name) @@ -66,9 +72,10 @@ def get_logger(name: str = None) -> logging.Logger: def get_console_log(level: str = None, name: str = None) -> logging.Logger: '''Get the package logger and enable a handler which writes to stderr. - Yeah yeah, i know we can use ``DictConfig``. You do it... + Yeah yeah, i know we can use ``DictConfig``. You do it. ''' log = get_logger(name) # our root logger + logger = log.logger if not level: return log @@ -77,7 +84,7 @@ def get_console_log(level: str = None, name: str = None) -> logging.Logger: if not any( handler.stream == sys.stderr # type: ignore - for handler in log.handlers if getattr(handler, 'stream', None) + for handler in logger.handlers if getattr(handler, 'stream', None) ): handler = logging.StreamHandler() formatter = colorlog.ColoredFormatter( @@ -88,7 +95,7 @@ def get_console_log(level: str = None, name: str = None) -> logging.Logger: style='{', ) handler.setFormatter(formatter) - log.addHandler(handler) + logger.addHandler(handler) return log