Refactor: Modularize logging and finalize lifespan integration

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

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
+# Re-exporting for backward compatibility with ~200 existing imports
-
+__all__ = ['log', 'logging', 'logger_reset', 'get_logger', 'setup_logging']
-# 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() ###

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):