diff --git a/.gitignore b/.gitignore index 1fac919764..67aa252fa2 100644 --- a/.gitignore +++ b/.gitignore @@ -58,6 +58,7 @@ test-reports/ # Django stuff: *.log +*.lock local_settings.py db.sqlite3 diff --git a/Logging.md b/Logging.md index baa43755be..8660232f28 100644 --- a/Logging.md +++ b/Logging.md @@ -8,19 +8,22 @@ Acapy's logging is based on python's [logging lib](https://docs.python.org/3/how Log levels `DEBUG`, `INFO` and `WARNING` are available. Other log levels fall back to `WARNING`. +## Per Tenant Logging + +Supports writing of log messages to a file with `wallet_id` as the tenant identifier for each. To enable this, both multitenant mode [`--multitenant`] and writing to log file option [`--log-file`] are required. If both `--multitenant` and `--log-file` are not passed when starting up ACA-Py, then it will use `default_logging_config.ini` config [backward compatible] and not log at a per tenant level. + ## Command Line Arguments -* `--log-level` - The log level to log on std out. -* `--log-file` - Path to a file to log to. +* `--log-level` - The log level to log on std out +* `--log-file` - Enables writing of logs to file. The provided value becomes path to a file to log to. If no value or empty string is provided then it will try to get the path from the config file * `--log-config` - Specifies a custom logging configuration file - Example: ```sh ./bin/aca-py start --log-level debug --log-file acapy.log --log-config aries_cloudagent.config:default_per_tenant_logging_config.ini -./bin/aca-py start --log-level debug --log-file acapy.log --log-config ./aries_cloudagent/config/default_per_tenant_logging_config.yml +./bin/aca-py start --log-level debug --log-file --multitenant --log-config ./aries_cloudagent/config/default_per_tenant_logging_config.yml ``` ## Environment Variables diff --git a/aries_cloudagent/config/argparse.py b/aries_cloudagent/config/argparse.py index 016dff65a7..4cd6d730e6 100644 --- a/aries_cloudagent/config/argparse.py +++ b/aries_cloudagent/config/argparse.py @@ -992,13 +992,15 @@ def add_arguments(self, parser: ArgumentParser): parser.add_argument( "--log-file", dest="log_file", - type=str, metavar="", + nargs="?", + const="", default=None, env_var="ACAPY_LOG_FILE", help=( - "Overrides the output destination for the root logger (as defined " - "by the log config file) to the named ." + "--log-file enables writing of logs to file, if a value is " + "provided then it uses that as log file location, otherwise " + "the default location in log config file is used." ), ) parser.add_argument( @@ -1019,7 +1021,7 @@ def get_settings(self, args: Namespace) -> dict: settings = {} if args.log_config: settings["log.config"] = args.log_config - if args.log_file: + if args.log_file or args.log_file == "": settings["log.file"] = args.log_file if args.log_level: settings["log.level"] = args.log_level diff --git a/aries_cloudagent/config/logging.py b/aries_cloudagent/config/logging.py index 8fcc845b1f..8d60899cc1 100644 --- a/aries_cloudagent/config/logging.py +++ b/aries_cloudagent/config/logging.py @@ -1,21 +1,26 @@ """Utilities related to logging.""" - -from configparser import ConfigParser -from contextvars import ContextVar -from datetime import datetime, timedelta -from io import TextIOWrapper +import configparser +import io import logging -from logging.config import dictConfig, fileConfig -from logging.handlers import BaseRotatingHandler import os -from random import randint import re import sys import yaml import time as mod_time -from typing import TextIO - import pkg_resources + +from contextvars import ContextVar +from datetime import datetime, timedelta +from logging.config import ( + dictConfigClass, + _create_formatters, + _clearExistingHandlers, + _install_handlers, + _install_loggers, +) +from logging.handlers import BaseRotatingHandler +from random import randint +from typing import TextIO from portalocker import LOCK_EX, lock, unlock from pythonjsonlogger import jsonlogger @@ -67,12 +72,64 @@ def load_resource(path: str, encoding: str = None) -> TextIO: else: bstream = pkg_resources.resource_stream(components[0], components[1]) if encoding: - return TextIOWrapper(bstream, encoding=encoding) + return io.TextIOWrapper(bstream, encoding=encoding) return bstream except IOError: pass +def dictConfig(config, new_file_path=None): + """Custom dictConfig, https://github.com/python/cpython/blob/main/Lib/logging/config.py.""" + if new_file_path: + config["handlers"]["rotating_file"]["filename"] = f"{new_file_path}" + dictConfigClass(config).configure() + + +def fileConfig( + fname, + new_file_path=None, + defaults=None, + disable_existing_loggers=True, + encoding=None, +): + """Custom fileConfig to update filepath in ConfigParser file handler section.""" + if isinstance(fname, str): + if not os.path.exists(fname): + 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: + try: + cp = configparser.ConfigParser(defaults) + if hasattr(fname, "readline"): + cp.read_file(fname) + else: + encoding = io.text_encoding(encoding) + 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", + "args", + str( + ( + f"{new_file_path}", + "d", + 7, + 1, + ) + ), + ) + formatters = _create_formatters(cp) + with logging._lock: + _clearExistingHandlers() + handlers = _install_handlers(cp, formatters) + _install_loggers(cp, handlers, disable_existing_loggers) + + class LoggingConfigurator: """Utility class used to configure logging and print an informative start banner.""" @@ -92,50 +149,41 @@ def configure( :param log_level: str: (Default value = None) """ 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: + if multitenant and write_to_log_file: config_path = DEFAULT_PER_TENANT_LOGGING_CONFIG_PATH_INI - if log_file: - parsed = ConfigParser() - config_file_path = os.path.join( - os.path.dirname(os.path.realpath(__file__)), - config_path.split(":")[1], - ) - parsed.read(config_file_path) - parsed.set( - "handler_timed_file_handler", - "args", - str( - ( - log_file, - "d", - 7, - 1, - ) - ), - ) - with open(config_file_path, "w") as configfile: - parsed.write(configfile) 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) - if log_file: - log_config["handlers"]["rotating_file"]["filename"] = log_file - with open(config_path, "w") as fp: - yaml.dump(log_config, fp) else: log_config = load_resource(config_path, "utf-8") if log_config: if is_dict_config: - dictConfig(log_config) + dictConfig(log_config, new_file_path=log_file) else: with log_config: - fileConfig(log_config, disable_existing_loggers=False) + 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}") diff --git a/aries_cloudagent/config/tests/test_logging.py b/aries_cloudagent/config/tests/test_logging.py index 0bd6d7c514..7d8d220a0c 100644 --- a/aries_cloudagent/config/tests/test_logging.py +++ b/aries_cloudagent/config/tests/test_logging.py @@ -24,7 +24,9 @@ def test_configure_default(self, mock_file_config, mock_load_resource): test_module.DEFAULT_LOGGING_CONFIG_PATH, "utf-8" ) mock_file_config.assert_called_once_with( - mock_load_resource.return_value, disable_existing_loggers=False + mock_load_resource.return_value, + disable_existing_loggers=False, + new_file_path=None, ) def test_configure_with_per_tenant_config_file(self): @@ -107,7 +109,9 @@ def test_configure_path(self, mock_file_config, mock_load_resource): 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 + mock_load_resource.return_value, + disable_existing_loggers=False, + new_file_path=None, ) def test_banner_did(self): @@ -140,7 +144,7 @@ def test_load_resource(self): with mock.patch.object( test_module.pkg_resources, "resource_stream", mock.MagicMock() ) as mock_res_stream, mock.patch.object( - test_module, "TextIOWrapper", mock.MagicMock() + test_module.io, "TextIOWrapper", mock.MagicMock() ) as mock_text_io_wrapper: test_module.load_resource("abc:def", encoding="utf-8") diff --git a/demo/features/0160-connection.feature b/demo/features/0160-connection.feature index fd6aa56b2f..1a7bf68a76 100644 --- a/demo/features/0160-connection.feature +++ b/demo/features/0160-connection.feature @@ -13,12 +13,12 @@ Feature: RFC 0160 Aries agent connection functions @GHA @WalletType_Askar Examples: - | Acme_capabilities | Bob_capabilities | - | --public-did | | - | --public-did --did-exchange | --did-exchange | - | --public-did --mediation | --mediation | - | --public-did --multitenant | --multitenant | - | --public-did --mediation --multitenant | --mediation --multitenant | + | Acme_capabilities | Bob_capabilities | + | --public-did | | + | --public-did --did-exchange | --did-exchange | + | --public-did --mediation | --mediation | + | --public-did --multitenant | --multitenant | + | --public-did --mediation --multitenant --log-file | --mediation --multitenant --log-file | @GHA @WalletType_Askar_AnonCreds Examples: diff --git a/demo/features/0453-issue-credential.feature b/demo/features/0453-issue-credential.feature index 7522c3933e..2a6f735035 100644 --- a/demo/features/0453-issue-credential.feature +++ b/demo/features/0453-issue-credential.feature @@ -18,7 +18,7 @@ Feature: RFC 0453 Aries agent issue credential | --public-did | | driverslicense | Data_DL_NormalizedValues | | --public-did --did-exchange | --did-exchange | driverslicense | Data_DL_NormalizedValues | | --public-did --mediation | --mediation | driverslicense | Data_DL_NormalizedValues | - | --public-did --multitenant | --multitenant | driverslicense | Data_DL_NormalizedValues | + | --public-did --multitenant | --multitenant --log-file | driverslicense | Data_DL_NormalizedValues | @GHA @WalletType_Askar_AnonCreds Examples: @@ -127,11 +127,11 @@ Feature: RFC 0453 Aries agent issue credential @GHA @WalletType_Askar Examples: - | Acme_capabilities | Bob_capabilities | Schema_name | Credential_data | - | --public-did --cred-type json-ld | | driverslicense | Data_DL_NormalizedValues | - | --public-did --cred-type json-ld --did-exchange | --did-exchange | driverslicense | Data_DL_NormalizedValues | - | --public-did --cred-type json-ld --mediation | --mediation | driverslicense | Data_DL_NormalizedValues | - | --public-did --cred-type json-ld --multitenant | --multitenant | driverslicense | Data_DL_NormalizedValues | + | Acme_capabilities | Bob_capabilities | Schema_name | Credential_data | + | --public-did --cred-type json-ld | | driverslicense | Data_DL_NormalizedValues | + | --public-did --cred-type json-ld --did-exchange | --did-exchange | driverslicense | Data_DL_NormalizedValues | + | --public-did --cred-type json-ld --mediation | --mediation | driverslicense | Data_DL_NormalizedValues | + | --public-did --cred-type json-ld --multitenant --log-file | --multitenant | driverslicense | Data_DL_NormalizedValues | @GHA @WalletType_Askar_AnonCreds Examples: diff --git a/demo/run_bdd b/demo/run_bdd index 55ec5595fa..40c42bdf65 100755 --- a/demo/run_bdd +++ b/demo/run_bdd @@ -21,6 +21,10 @@ fi for i in "$@" do + # Demo agent with --multitenant requires the ../log dir to exist and write access to it + if [ ! -d "../log" ]; then + mkdir ../log && chmod -R uga+rws ../log + fi if [ ! -z "$SKIP" ]; then SKIP="" continue @@ -73,12 +77,9 @@ do continue ;; --timing) - if [ ! -d "../logs" ]; then - mkdir ../logs && chmod -R uga+rws ../logs - fi - if [ "$(ls -ld ../logs | grep dr..r..rwx)" == "" ]; then - echo "Error: To use the --timing parameter, the directory '../logs' must exist and all users must be able to write to it." - echo "For example, to create the directory and then set the permissions use: 'mkdir ../logs; chmod uga+rws ../logs'" + if [ "$(ls -ld ../log | grep dr..r..rwx)" == "" ]; then + echo "Error: To use the --timing parameter, the directory '../log' must exist and all users must be able to write to it." + echo "For example, to create the directory and then set the permissions use: 'mkdir ../log; chmod uga+rws ../log'" exit 1 fi continue @@ -236,6 +237,6 @@ DOCKER=${DOCKER:-docker} $DOCKER run --name $AGENT --rm ${DOCKER_OPTS} \ --network=${DOCKER_NET} \ -p 0.0.0.0:$AGENT_PORT_RANGE:$AGENT_PORT_RANGE \ - -v "/$(pwd)/../logs:/home/aries/logs" \ + -v "/$(pwd)/../log:/home/aries/log" \ $DOCKER_ENV \ aries-bdd-image $ARGS diff --git a/demo/run_demo b/demo/run_demo index cd247f070c..3a133526ae 100755 --- a/demo/run_demo +++ b/demo/run_demo @@ -25,6 +25,11 @@ j=1 for i in "$@" do ((j++)) + # Demo agent with --multitenant requires the ../log dir to exist and write access to it + if [ ! -d "../log" ]; then + mkdir ../log && chmod -R uga+rws ../log + DOCKER_VOL="${DOCKER_VOL} -v /$(pwd)/../log:/home/aries/log" + fi if [ ! -z "$SKIP" ]; then SKIP="" continue @@ -77,15 +82,11 @@ do continue ;; --timing) - if [ ! -d "../logs" ]; then - mkdir ../logs && chmod -R uga+rws ../logs - fi - if [ "$(ls -ld ../logs | grep dr..r..rwx)" == "" ]; then - echo "Error: To use the --timing parameter, the directory '../logs' must exist and all users must be able to write to it." - echo "For example, to create the directory and then set the permissions use: 'mkdir ../logs; chmod uga+rws ../logs'" + if [ "$(ls -ld ../log | grep dr..r..rwx)" == "" ]; then + echo "Error: To use the --timing parameter, the directory '../log' must exist and all users must be able to write to it." + echo "For example, to create the directory and then set the permissions use: 'mkdir ../log; chmod uga+rws ../log'" exit 1 fi - DOCKER_VOL="${DOCKER_VOL} -v /$(pwd)/../logs:/home/aries/logs" continue ;; --bg) diff --git a/demo/runners/agent_container.py b/demo/runners/agent_container.py index 6dcff17115..5d86e7ecaf 100644 --- a/demo/runners/agent_container.py +++ b/demo/runners/agent_container.py @@ -1365,7 +1365,9 @@ def arg_parser(ident: str = None, port: int = 8020): ) parser.add_argument( "--log-file", - type=str, + nargs="?", + const="", + default=None, metavar="", help="Output destination for the root logger.", ) @@ -1415,8 +1417,10 @@ async def create_agent_with_args(args, ident: str = None): if arg_file: with open(arg_file) as f: arg_file_dict = yaml.safe_load(f) - - log_file = args.log_file or os.getenv("ACAPY_LOG_FILE") + if args.log_file or args.log_file == "": + log_file = args.log_file + else: + log_file = os.getenv("ACAPY_LOG_FILE") log_config = args.log_config or os.getenv("ACAPY_LOG_CONFIG") log_level = args.log_level # if we don't have a tails server url then guess it diff --git a/demo/runners/performance.py b/demo/runners/performance.py index 26daf4a87d..4a0794caa8 100644 --- a/demo/runners/performance.py +++ b/demo/runners/performance.py @@ -738,7 +738,9 @@ async def check_received_pings(agent, issue_count, pb): ) parser.add_argument( "--log-file", - type=str, + nargs="?", + const="", + default=None, metavar="", help=("Output destination for the root logger."), ) diff --git a/demo/runners/support/agent.py b/demo/runners/support/agent.py index 64a7d1a562..2da2f5db62 100644 --- a/demo/runners/support/agent.py +++ b/demo/runners/support/agent.py @@ -519,7 +519,7 @@ def get_agent_args(self): "--public-invites", # ("--log-level", "debug"), ] - if self.log_file: + if self.log_file or self.log_file == "": result.extend( [ ("--log-file", self.log_file), diff --git a/docker/Dockerfile.demo b/docker/Dockerfile.demo index fae85cc937..837dfb221e 100644 --- a/docker/Dockerfile.demo +++ b/docker/Dockerfile.demo @@ -22,7 +22,7 @@ ADD scripts ./scripts RUN pip3 install --no-cache-dir -e . -RUN mkdir demo logs && chown -R aries:aries demo logs && chmod -R ug+rw demo logs +RUN mkdir demo && chown -R aries:aries demo && chmod -R ug+rw demo # Add and install demo code ADD demo/requirements.txt ./demo/requirements.txt diff --git a/docker/Dockerfile.run b/docker/Dockerfile.run index 1f19feccb6..79839a3d93 100644 --- a/docker/Dockerfile.run +++ b/docker/Dockerfile.run @@ -16,7 +16,7 @@ RUN pip install --no-cache-dir poetry RUN mkdir -p aries_cloudagent && touch aries_cloudagent/__init__.py ADD pyproject.toml poetry.lock README.md ./ -RUN mkdir -p logs && chmod -R ug+rw logs +RUN mkdir -p log && chmod -R ug+rw log RUN poetry install -E "askar bbs" diff --git a/scripts/run_docker b/scripts/run_docker index 1a6b984cbe..c8657576a3 100755 --- a/scripts/run_docker +++ b/scripts/run_docker @@ -46,7 +46,7 @@ if [ -n "${ENABLE_PTVSD}" ]; then ARGS="${ARGS} -e ENABLE_PTVSD=\"${ENABLE_PTVSD}\" -p $PTVSD_PORT:$PTVSD_PORT" fi -ARGS="${ARGS} -v $(pwd)/../logs:/home/indy/logs" +ARGS="${ARGS} -v $(pwd)/../log:/home/aries/log" if [ -n "${WEBHOOK_URL}" ]; then ARGS="${ARGS} -e WEBHOOK_URL=\"${WEBHOOK_URL}\""