diff --git a/aries_cloudagent/config/default_per_tenant_logging_config.ini b/aries_cloudagent/config/default_multitenant_logging_config.ini similarity index 100% rename from aries_cloudagent/config/default_per_tenant_logging_config.ini rename to aries_cloudagent/config/default_multitenant_logging_config.ini diff --git a/aries_cloudagent/config/default_per_tenant_logging_config.yml b/aries_cloudagent/config/default_multitenant_logging_config.yml similarity index 100% rename from aries_cloudagent/config/default_per_tenant_logging_config.yml rename to aries_cloudagent/config/default_multitenant_logging_config.yml diff --git a/aries_cloudagent/config/logging.py b/aries_cloudagent/config/logging.py index 99a9e27517..98080c31fc 100644 --- a/aries_cloudagent/config/logging.py +++ b/aries_cloudagent/config/logging.py @@ -6,21 +6,21 @@ import os import re import sys -import yaml import time as mod_time -from importlib import resources - from contextvars import ContextVar from datetime import datetime, timedelta +from importlib import resources from logging.config import ( - dictConfigClass, - _create_formatters, _clearExistingHandlers, + _create_formatters, _install_handlers, _install_loggers, + dictConfigClass, ) from logging.handlers import BaseRotatingHandler from random import randint + +import yaml from portalocker import LOCK_EX, lock, unlock from pythonjsonlogger import jsonlogger @@ -28,9 +28,9 @@ from ..version import __version__ from .banner import Banner -DEFAULT_LOGGING_CONFIG_PATH = "aries_cloudagent.config:default_logging_config.ini" -DEFAULT_PER_TENANT_LOGGING_CONFIG_PATH_INI = ( - "aries_cloudagent.config:default_per_tenant_logging_config.ini" +DEFAULT_LOGGING_CONFIG_PATH_INI = "aries_cloudagent.config:default_logging_config.ini" +DEFAULT_MULTITENANT_LOGGING_CONFIG_PATH_INI = ( + "aries_cloudagent.config:default_multitenant_logging_config.ini" ) LOG_FORMAT_FILE_ALIAS_PATTERN = ( "%(asctime)s %(wallet_id)s %(levelname)s %(pathname)s:%(lineno)d %(message)s" @@ -101,6 +101,7 @@ def fileConfig( raise FileNotFoundError(f"{fname} doesn't exist") elif not os.path.getsize(fname): raise RuntimeError(f"{fname} is an empty file") + if isinstance(fname, configparser.RawConfigParser): cp = fname else: @@ -113,6 +114,7 @@ def fileConfig( cp.read(fname, encoding=encoding) except configparser.ParsingError as e: raise RuntimeError(f"{fname} is invalid: {e}") + if new_file_path: cp.set( "handler_timed_file_handler", @@ -126,6 +128,7 @@ def fileConfig( ) ), ) + formatters = _create_formatters(cp) with logging._lock: _clearExistingHandlers() @@ -136,10 +139,13 @@ def fileConfig( class LoggingConfigurator: """Utility class used to configure logging and print an informative start banner.""" + default_config_path_ini = DEFAULT_LOGGING_CONFIG_PATH_INI + default_multitenant_config_path_ini = DEFAULT_MULTITENANT_LOGGING_CONFIG_PATH_INI + @classmethod def configure( cls, - logging_config_path: str = None, + log_config_path: str = None, log_level: str = None, log_file: str = None, multitenant: bool = False, @@ -150,93 +156,135 @@ def configure( custom logging config :param log_level: str: (Default value = None) + + :param log_file: str: (Default value = None) Optional file name to write logs to + + :param multitenant: bool: (Default value = False) Optional flag if multitenant is + enabled """ - is_dict_config = False - if log_file: - write_to_log_file = True - elif log_file == "": - log_file = None - write_to_log_file = True - else: - write_to_log_file = False - if logging_config_path is not None: - config_path = logging_config_path - else: - if multitenant and write_to_log_file: - config_path = DEFAULT_PER_TENANT_LOGGING_CONFIG_PATH_INI - else: - config_path = DEFAULT_LOGGING_CONFIG_PATH - if write_to_log_file and not log_file: - raise ValueError( - "log_file (--log-file) must be provided " - "as config does not specify it." - ) - if ".yml" in config_path or ".yaml" in config_path: - is_dict_config = True - with open(config_path, "r") as stream: - log_config = yaml.safe_load(stream) - else: - log_config = load_resource(config_path, "utf-8") - if log_config: - if is_dict_config: - dictConfig(log_config, new_file_path=log_file) - else: - with log_config: - fileConfig( - log_config, - new_file_path=log_file if multitenant else None, - disable_existing_loggers=False, - ) - else: - logging.basicConfig(level=logging.WARNING) - logging.root.warning(f"Logging config file not found: {config_path}") + if multitenant: - file_handler_set = False - handler_pattern = None - # Create context filter to adapt wallet_id in logger messages - _cf = ContextFilter() - for _handler in logging.root.handlers: - if isinstance(_handler, TimedRotatingFileMultiProcessHandler): - file_handler_set = True - handler_pattern = _handler.formatter._fmt - # Set Json formatter for rotated file handler which - # cannot be set with config file. By default this will - # be set up. - _handler.setFormatter(jsonlogger.JsonFormatter(handler_pattern)) - # Add context filter to handlers - _handler.addFilter(_cf) - if log_level: - _handler.setLevel(log_level.upper()) - if not file_handler_set and log_file: - file_path = os.path.join( - os.path.dirname(os.path.realpath(__file__)).replace( - "aries_cloudagent/config", "" - ), - log_file, - ) - # If configuration is not provided within .ini or dict config file - # then by default the rotated file handler will have interval=7, - # when=d and backupCount=1 configuration - timed_file_handler = TimedRotatingFileMultiProcessHandler( - filename=file_path, - interval=7, - when="d", - backupCount=1, - ) - timed_file_handler.addFilter(_cf) - # By default this will be set up. - timed_file_handler.setFormatter( - jsonlogger.JsonFormatter(LOG_FORMAT_FILE_ALIAS_PATTERN) - ) - logging.root.handlers.append(timed_file_handler) - elif log_file and not multitenant: - # Don't go with rotated file handler when not in multitenant mode. + cls._configure_multitenant_logging( + log_config_path=log_config_path + or DEFAULT_MULTITENANT_LOGGING_CONFIG_PATH_INI, + log_level=log_level, + log_file=log_file, + ) + else: + cls._configure_logging( + log_config_path=log_config_path or DEFAULT_LOGGING_CONFIG_PATH_INI, + log_level=log_level, + log_file=log_file, + ) + + @classmethod + def _configure_logging(cls, log_config_path, log_level, log_file): + if log_file is not None and log_file == "": + raise ValueError( + "log_file (--log-file) must be provided in singletenant mode." + ) + + # Setup log config and log file if provided + cls._setup_log_config_file(log_config_path, log_file) + + # Set custom file handler + if log_file: logging.root.handlers.append( logging.FileHandler(log_file, encoding="utf-8") ) + + # Set custom log level if log_level: logging.root.setLevel(log_level.upper()) + @classmethod + def _configure_multitenant_logging(cls, log_config_path, log_level, log_file): + # Unlike in singletenant mode, the defualt config for multitenant mode + # specifies a default log_file if one is not explicitly provided + # so we don't need the same check here + + # Setup log config and log file if provided + cls._setup_log_config_file(log_config_path, log_file) + + # Set custom file handler(s) + ############################ + # Step through each root handler and find any TimedRotatingFileMultiProcessHandler + any_file_handlers_set = filter( + lambda handler: isinstance(handler, TimedRotatingFileMultiProcessHandler), + logging.root.handlers, + ) + + # Default context filter adds wallet_id to log records + log_filter = ContextFilter() + if (not any_file_handlers_set) and log_file: + file_path = os.path.join( + os.path.dirname(os.path.realpath(__file__)).replace( + "aries_cloudagent/config", "" + ), + log_file, + ) + # By default the timed rotated file handler will have: + # interval=7, when=d and backupCount=1 + timed_file_handler = TimedRotatingFileMultiProcessHandler( + filename=file_path, + interval=7, + when="d", + backupCount=1, + ) + timed_file_handler.addFilter(log_filter) + # By default this will be set up. + timed_file_handler.setFormatter( + jsonlogger.JsonFormatter(LOG_FORMAT_FILE_ALIAS_PATTERN) + ) + logging.root.handlers.append(timed_file_handler) + + else: + # Setup context filters for multitenant mode + for handler in logging.root.handlers: + if isinstance(handler, TimedRotatingFileMultiProcessHandler): + log_formater = handler.formatter._fmt + # Set Json formatter for rotated file handler which cannot be set with + # config file. + # By default this will be set up. + handler.setFormatter(jsonlogger.JsonFormatter(log_formater)) + # Add context filter to handlers + handler.addFilter(log_filter) + + # Sets a custom log level + if log_level: + handler.setLevel(log_level.upper()) + + # Set custom log level + if log_level: + logging.root.setLevel(log_level.upper()) + + @classmethod + def _setup_log_config_file(cls, log_config_path, log_file): + log_config, is_dict_config = cls._load_log_config(log_config_path) + + # Setup config + if not log_config: + logging.basicConfig(level=logging.WARNING) + logging.root.warning(f"Logging config file not found: {log_config_path}") + elif is_dict_config: + dictConfig(log_config, new_file_path=log_file or None) + else: + with log_config: + # The default log_file location is set here + # if one is not provided in the startup params + fileConfig( + log_config, + new_file_path=log_file or None, + disable_existing_loggers=False, + ) + + @classmethod + def _load_log_config(cls, log_config_path): + if ".yml" in log_config_path or ".yaml" in log_config_path: + with open(log_config_path, "r") as stream: + return yaml.safe_load(stream), True + return load_resource(log_config_path, "utf-8"), False + @classmethod def print_banner( cls, diff --git a/aries_cloudagent/config/tests/test_logging.py b/aries_cloudagent/config/tests/test_logging.py index 8ae25bad2b..2b092828ed 100644 --- a/aries_cloudagent/config/tests/test_logging.py +++ b/aries_cloudagent/config/tests/test_logging.py @@ -1,10 +1,7 @@ import contextlib - from io import StringIO - -from unittest import mock -from unittest import IsolatedAsyncioTestCase from tempfile import NamedTemporaryFile +from unittest import IsolatedAsyncioTestCase, mock from .. import logging as test_module @@ -21,7 +18,7 @@ def test_configure_default(self, mock_file_config, mock_load_resource): test_module.LoggingConfigurator.configure() mock_load_resource.assert_called_once_with( - test_module.DEFAULT_LOGGING_CONFIG_PATH, "utf-8" + test_module.DEFAULT_LOGGING_CONFIG_PATH_INI, "utf-8" ) mock_file_config.assert_called_once_with( mock_load_resource.return_value, @@ -29,25 +26,30 @@ def test_configure_default(self, mock_file_config, mock_load_resource): new_file_path=None, ) - def test_configure_with_per_tenant_config_file(self): + def test_configure_default_with_log_file_error_level(self): + log_file = NamedTemporaryFile() with mock.patch.object( - test_module, - "logging", - mock.MagicMock( - basicConfig=mock.MagicMock(), - FileHandler=mock.MagicMock(), - root=mock.MagicMock( - warning=mock.MagicMock(), - handlers=[], - ), - ), - ): + test_module, "load_resource", mock.MagicMock() + ) as mock_load: + mock_load.return_value = None test_module.LoggingConfigurator.configure( - log_file="test.log", - multitenant=True, + log_level="ERROR", log_file=log_file.name ) - def test_configure_with_per_tenant_yml_file(self): + @mock.patch.object(test_module, "load_resource", autospec=True) + @mock.patch.object(test_module, "fileConfig", autospec=True) + def test_configure_default_with_path(self, mock_file_config, mock_load_resource): + path = "a path" + test_module.LoggingConfigurator.configure(path) + + mock_load_resource.assert_called_once_with(path, "utf-8") + mock_file_config.assert_called_once_with( + mock_load_resource.return_value, + disable_existing_loggers=False, + new_file_path=None, + ) + + def test_configure_multitenant(self): with mock.patch.object( test_module, "logging", @@ -61,12 +63,11 @@ def test_configure_with_per_tenant_yml_file(self): ), ): test_module.LoggingConfigurator.configure( - logging_config_path="aries_cloudagent/config/default_per_tenant_logging_config.yml", log_file="test.log", multitenant=True, ) - def test_configure_with_default_config(self): + def test_configure_with_multitenant_with_yaml_file(self): with mock.patch.object( test_module, "logging", @@ -80,40 +81,11 @@ def test_configure_with_default_config(self): ), ): test_module.LoggingConfigurator.configure( + log_config_path="aries_cloudagent/config/default_multitenant_logging_config.yml", log_file="test.log", multitenant=True, ) - def test_configure_default_no_resource(self): - with mock.patch.object( - test_module, "load_resource", mock.MagicMock() - ) as mock_load: - mock_load.return_value = None - test_module.LoggingConfigurator.configure() - - def test_configure_default_file(self): - log_file = NamedTemporaryFile() - with mock.patch.object( - test_module, "load_resource", mock.MagicMock() - ) as mock_load: - mock_load.return_value = None - test_module.LoggingConfigurator.configure( - log_level="ERROR", log_file=log_file.name - ) - - @mock.patch.object(test_module, "load_resource", autospec=True) - @mock.patch.object(test_module, "fileConfig", autospec=True) - def test_configure_path(self, mock_file_config, mock_load_resource): - path = "a path" - test_module.LoggingConfigurator.configure(path) - - mock_load_resource.assert_called_once_with(path, "utf-8") - mock_file_config.assert_called_once_with( - mock_load_resource.return_value, - disable_existing_loggers=False, - new_file_path=None, - ) - def test_banner_did(self): stdout = StringIO() mock_http = mock.MagicMock(scheme="http", host="1.2.3.4", port=8081) diff --git a/aries_cloudagent/config/util.py b/aries_cloudagent/config/util.py index 00f9af8654..8ac52ff994 100644 --- a/aries_cloudagent/config/util.py +++ b/aries_cloudagent/config/util.py @@ -2,9 +2,9 @@ import os import re +from typing import Any, Mapping from configargparse import ArgumentTypeError -from typing import Any, Mapping from .logging import LoggingConfigurator @@ -17,7 +17,7 @@ def common_config(settings: Mapping[str, Any]): log_file = settings.get("log.file") multitenant_enabled = settings.get("multitenant.enabled") or False LoggingConfigurator.configure( - logging_config_path=log_config, + log_config_path=log_config, log_level=log_level, log_file=log_file, multitenant=multitenant_enabled,