From c6e23706f772fd3e9ff03c1c12f1a62714dc53d1 Mon Sep 17 00:00:00 2001 From: Stefan Richter Date: Fri, 12 Aug 2022 16:38:09 +0200 Subject: [PATCH] Improve logging output --- junkie/_junkie.py | 24 +++++++++++++++++------- test/test_junkie.py | 39 ++++++++++++++++++++------------------- 2 files changed, 37 insertions(+), 26 deletions(-) diff --git a/junkie/_junkie.py b/junkie/_junkie.py index 051e733..7427063 100644 --- a/junkie/_junkie.py +++ b/junkie/_junkie.py @@ -7,6 +7,7 @@ import junkie +LOGGER = logging.getLogger(junkie.__name__) BUILTINS = {item for item in vars(builtins).values() if isinstance(item, type)} @@ -21,19 +22,17 @@ def __init__(self, instances_and_factories: Mapping[str, Any] = None): self._instances_by_name = None self._instances_by_name_stack = [{}] - self.logger = logging.getLogger(junkie.__name__) - @contextmanager def inject(self, *names_and_factories: Union[str, Callable]) -> Union[Any, Tuple[Any]]: + LOGGER.debug("inject(%s)", Junkie._LogParams(*names_and_factories)) + with ExitStack() as self._exit_stack: self._instances_by_name = self._instances_by_name_stack[-1].copy() self._instances_by_name_stack.append(self._instances_by_name) if len(names_and_factories) == 1: - self.logger.debug("inject(%r)", names_and_factories[0]) yield self._build_instance(names_and_factories[0]) else: - self.logger.debug("inject(%r)", names_and_factories) yield self._build_tuple(*names_and_factories) self._instances_by_name_stack.pop() @@ -80,12 +79,13 @@ def _build_by_factory_function(self, factory_function: Callable, instance_name: parameters, args, kwargs = self._build_parameters(factory_function) - self.logger.debug("%s = %s(%s)", instance_name, factory_function.__name__, list(parameters.keys())) + log_params = Junkie._LogParams(*parameters.keys(), *args, **kwargs) + LOGGER.debug("%s = %s(%s)", instance_name or "_", factory_function.__name__, log_params) instance = factory_function(*parameters.values(), *args, **kwargs) if hasattr(instance, "__enter__"): - self.logger.debug("%s.__enter__()", instance_name) - self._exit_stack.push(lambda *exception_details: self.logger.debug("%s.__exit__()", instance_name)) + LOGGER.debug("%s.__enter__()", instance_name or "_") + self._exit_stack.push(lambda *exception_details: LOGGER.debug("%s.__exit__()", instance_name or "_")) instance = self._exit_stack.enter_context(instance) @@ -124,3 +124,13 @@ def _build_parameters(self, factory_function: Callable) -> (OrderedDict, tuple, ) return parameters, args, kwargs + + class _LogParams: + def __init__(self, *args, **kwargs): + self.args = args + self.kwargs = kwargs + + def __str__(self): + arg_params = list(map(str, self.args)) + kwarg_params = list(map(str, [f"{key}={repr(value)}" for key, value in self.kwargs.items()])) + return ", ".join(arg_params + kwarg_params) diff --git a/test/test_junkie.py b/test/test_junkie.py index 0a43a7e..76e14f9 100644 --- a/test/test_junkie.py +++ b/test/test_junkie.py @@ -6,7 +6,6 @@ from contextlib import contextmanager from unittest import skipIf -import junkie from junkie import Junkie, JunkieError @@ -253,43 +252,45 @@ def test_logging(self): self.maxDiff = None class Class: - def __init__(self, database_context, message_service, text): + def __init__(self, database_context, message_service, *args): self.database_context = database_context self.message_service = message_service - self.text = text + self.args = args @contextmanager - def create_database(connection_string): - yield "DB: " + connection_string + def create_database(connection_string, **kwargs): + yield "DB: " + connection_string + str(kwargs) @contextmanager def create_message_service(): yield "message-service" context = { - "text": "abc", "connection_string": lambda: "URL", "database_context": create_database, "message_service": create_message_service, "class": Class, + "args": ["app_name"], + "kwargs": {"engine": "sqlite"}, } with self.assertLogs(level="DEBUG") as logging_context: - with Junkie(context).inject("class"): + with Junkie(context).inject("class", Class): logging.getLogger(__name__).info("execute context block") - self.assertEqual([ - "DEBUG:{}:inject('class')".format(junkie.__name__), - "DEBUG:{}:connection_string = ([])".format(junkie.__name__), - "DEBUG:{}:database_context = create_database(['connection_string'])".format(junkie.__name__), - "DEBUG:{}:database_context.__enter__()".format(junkie.__name__), - "DEBUG:{}:message_service = create_message_service([])".format(junkie.__name__), - "DEBUG:{}:message_service.__enter__()".format(junkie.__name__), - "DEBUG:{}:class = Class(['database_context', 'message_service', 'text'])".format(junkie.__name__), - "INFO:{}:execute context block".format(__name__), - "DEBUG:{}:message_service.__exit__()".format(junkie.__name__), - "DEBUG:{}:database_context.__exit__()".format(junkie.__name__), - ], logging_context.output) + self.assertEqual(( + "DEBUG:inject(class, .Class'>)\n" + "DEBUG:connection_string = ()\n" + "DEBUG:database_context = create_database(connection_string, engine='sqlite')\n" + "DEBUG:database_context.__enter__()\n" + "DEBUG:message_service = create_message_service()\n" + "DEBUG:message_service.__enter__()\n" + "DEBUG:class = Class(database_context, message_service, app_name)\n" + "DEBUG:_ = Class(database_context, message_service, app_name)\n" + "INFO:test.test_junkie:execute context block\n" + "DEBUG:message_service.__exit__()\n" + "DEBUG:database_context.__exit__()" + ), "\n".join(logging_context.output).replace(":junkie:", ":")) def test_auto_inject(self): class A: