diff --git a/app/lib_log_v3.py b/app/lib_log_v3.py new file mode 100644 index 0000000..ecdb23f --- /dev/null +++ b/app/lib_log_v3.py @@ -0,0 +1,77 @@ +import functools +import logging +import logging.config +from typing import Any + +# Global logger instance used throughout the app +log = logging.getLogger('root') + +def get_logger(name: str): + """Returns a logger instance by name.""" + return logging.getLogger(name) + +def setup_logging(settings: Any): + """ + Configures logging based on provided settings. + Moving this here prevents immediate execution on module import. + """ + log_file_path = getattr(settings, 'LOG_PATH', {}).get('app', '/logs/aether_api.log') + + try: + logging.config.dictConfig({ + 'version': 1, + 'disable_existing_loggers': False, # Critical to not kill FastAPI/Uvicorn loggers + 'formatters': { + 'default': {'format': '[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s'}, + 'long': {'format': '[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s', 'datefmt': '%Y-%m-%d %H:%M:%S'}, + 'short': {'format': '[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s', 'datefmt': '%H:%M:%S'}, + }, + 'handlers': { + 'console': { + 'class': 'logging.StreamHandler', + 'stream': 'ext://sys.stderr', + 'formatter': 'short', + }, + 'log_file_all': { + 'level': 'NOTSET', + 'class': 'logging.handlers.RotatingFileHandler', + 'formatter': 'long', + 'filename': log_file_path, + 'maxBytes': 10485760, # 10 MB + 'backupCount': 9 + }, + }, + 'loggers': { + 'uvicorn': {'handlers': ['console'], 'level': 'INFO'}, + }, + 'root': { + 'handlers': ['log_file_all'], + 'level': 'WARNING', + } + }) + log.info(f"Logging successfully configured. Path: {log_file_path}") + except Exception as e: + print(f"Error configuring logging: {e}") + logging.basicConfig(level=logging.WARNING) + +def logger_reset(func): + """ + Decorator to log function entry/exit and reset log levels. + """ + @functools.wraps(func) + def wrapper(*args, **kwargs): + # Local safer access to root logger + root_log = logging.getLogger('root') + + if func.__name__ not in ['redis_lookup_id_random', 'sql_enable_part', 'sql_hidden_part']: + root_log.info(f'*** Function: "{func.__name__}()"') + + root_log.debug(f'*** Function Positional Args: {args}\nFunction Key Args: {kwargs}') + init_log_level = root_log.level + + returned_result = func(*args, **kwargs) + + # Reset level in case it was changed during func execution + root_log.setLevel(init_log_level) + return returned_result + return wrapper diff --git a/app/log.py b/app/log.py index 7f1e892..38d4b46 100644 --- a/app/log.py +++ b/app/log.py @@ -1,110 +1,5 @@ -import functools, logging, logging.config +import logging +from app.lib_log_v3 import log, logger_reset, get_logger, setup_logging -from app.config import settings - -# stream options: 'ext://sys.stderr' or 'ext://sys.stdout' - -# NOTE: This log config is confusing and may need work... 2022-10-07 -# 'uvicorn' under 'loggers' creates an output to the 'console' handler -# Do not also add 'console' handler to the 'root' 'handlers' list -# For now just using that to add or remove file logging options. -try: - logging.config.dictConfig({ - 'version': 1, - 'formatters': { - 'default': {'format': '[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s'}, - 'long': {'format': '[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s', 'datefmt': '%Y-%m-%d %H:%M:%S'}, - 'short': {'format': '[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s', 'datefmt': '%H:%M:%S', 'use_colors': True}, - }, - #'filename': 'example.log', - # 'level': logging.ERROR, - 'handlers': { - 'console': { - 'class': 'logging.StreamHandler', - 'stream': 'ext://sys.stderr', - 'formatter': 'short', - }, - 'log_file_all': { - 'level': 'NOTSET', - 'class': 'logging.handlers.RotatingFileHandler', - 'formatter': 'long', - 'filename': settings.LOG_PATH['app'], - 'maxBytes': 10485760, # 5,242,880 = 5 MB; 10,485,760 = 10 MB - 'backupCount': 9 - }, - # 'log_file_warning': { - # 'level': 'WARNING', - # 'class': 'logging.handlers.RotatingFileHandler', - # 'formatter': 'long', - # 'filename': settings.LOG_PATH['app_warning'], - # 'maxBytes': 512000, # 524,288 = 512KB - # 'backupCount': 9 - # }, - # 'test_handler': { - # 'class': 'logging.StreamHandler', - # 'level': 'INFO', - # 'formatter': 'short', - # }, - # 'test_handler_all_rotate': { - # 'class': 'logging.handlers.RotatingFileHandler', - # 'level': 'NOTSET', - # 'formatter': 'short', - # 'filename': '/logs/test_rotate.log', - # 'maxBytes': 100000, # 5120000 = 5 MB - # 'backupCount': 2, - # } - }, - 'loggers': { - # 'uvicorn': {'handlers': ['default'], 'level': 'INFO'}, - 'uvicorn': {'handlers': ['console'], 'level': 'INFO'}, - # 'uvicorn.error': {'level': 'INFO', 'handlers': ['default'], 'propagate': True}, - # 'uvicorn.error': {'level': 'INFO', 'handlers': ['console'], 'propagate': True}, - # 'uvicorn.access': {'handlers': ['access'], 'level': 'INFO', 'propagate': False}, - # 'gunicorn': {'handlers': ['console'], 'level': 'INFO'}, - }, - 'root': { - 'handlers': ['log_file_all'], #, 'log_file_all', 'log_file_warning'], - # 'handlers': ['console', 'log_file_all'], #, 'log_file_all', 'log_file_warning'], - 'level': 'WARNING', # WARNING - } - }) -except Exception as e: - print(f"Error configuring logging: {e}") - # Fallback basic config? - logging.basicConfig(level=logging.WARNING) - - -log = logging.getLogger('root') -# log.setLevel(logging.INFO) # DEBUG > INFO > WARNING > ERROR > CRITICAL -# logging.basicConfig( -# format='[%(asctime)s] %(levelname)s @ %(module)s.%(funcName)s()#%(lineno)d: %(message)s' -# ) - - -def get_logger(name: str): - return logging.getLogger(name) - - -# ### BEGIN ### Log ### logger_reset() ### -# https://realpython.com/primer-on-python-decorators/ -# Updated 2022-02-15 -def logger_reset(func): - # log.setLevel(logging.WARNING) # DEBUG, INFO, WARNING, ERROR, EXCEPTION, CRITICAL - # log.info(locals()) - @functools.wraps(func) - def wrapper(*args, **kwargs): - # Local logger instance to avoid global dependency issues - # log = logging.getLogger(func.__module__) # Use the module's logger? Or root? - # Using root for now to maintain behavior, but safer access - log = logging.getLogger('root') - - if func.__name__ not in ['redis_lookup_id_random', 'sql_enable_part', 'sql_hidden_part']: - log.info(f'*** Function: "{func.__name__}()"') - log.debug(f'*** Function Positional Args: {args}\nFunction Key Args: {kwargs}') - init_log_level = log.level - returned_result = func(*args, **kwargs) - log.debug(f'*** Function finished: "{func.__name__}()". Resetting logger level to level: {log.level} ***') - log.setLevel(init_log_level) - return returned_result - return wrapper -# ### END ### Log ### logger_reset() ### +# Re-exporting for backward compatibility with ~200 existing imports +__all__ = ['log', 'logging', 'logger_reset', 'get_logger', 'setup_logging'] diff --git a/app/main.py b/app/main.py index c9afa6b..f620c89 100644 --- a/app/main.py +++ b/app/main.py @@ -14,6 +14,7 @@ from . import config # from app.lib_general import common_route_params, Common_Route_Params import logging import app.log +from app.log import setup_logging # Import middleware with alias to avoid shadowing 'app' FastAPI instance from app.middleware import add_process_time_header as process_time_middleware @@ -39,10 +40,11 @@ async def lifespan(app: FastAPI): """ Handles application startup and shutdown lifecycle. """ - log.setLevel(logging.INFO) + # 1. Initialize Logging early but safely + setup_logging(config.settings) log.info('### **** *** ** * Aether API v4 using FastAPI - Startup Lifespan Initiated * ** *** **** ###') - # 1. Bootstrapping Configuration from DB with robust error handling + # 2. Bootstrapping Configuration from DB with robust error handling log.info("Bootstrapping Configuration...") try: if bootstrap_db_config(config.settings):