""" Standardized logging utility to replace print statements and provide consistent logging patterns. """ import logging import sys from typing import Any, Dict, Optional, Union from functools import wraps from datetime import datetime import json from pathlib import Path from app.config import settings class StructuredLogger: """Enhanced logger with structured logging capabilities.""" def __init__(self, name: str, level: str = "INFO"): self.logger = logging.getLogger(name) self.logger.setLevel(getattr(logging, level.upper())) # Support bound context similar to loguru's bind self._bound_context: Dict[str, Any] = {} if not self.logger.handlers: self._setup_handlers() def _setup_handlers(self): """Setup console and file handlers with appropriate formatters.""" # Console handler console_handler = logging.StreamHandler(sys.stdout) console_formatter = logging.Formatter( '%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y-%m-%d %H:%M:%S' ) console_handler.setFormatter(console_formatter) self.logger.addHandler(console_handler) # File handler (if configured) if hasattr(settings, 'LOG_FILE_PATH') and settings.LOG_FILE_PATH: log_path = Path(settings.LOG_FILE_PATH) log_path.parent.mkdir(parents=True, exist_ok=True) file_handler = logging.FileHandler(log_path) file_formatter = logging.Formatter( '%(asctime)s - %(name)s - %(levelname)s - %(funcName)s:%(lineno)d - %(message)s', datefmt='%Y-%m-%d %H:%M:%S' ) file_handler.setFormatter(file_formatter) self.logger.addHandler(file_handler) def debug(self, message: str, **kwargs): """Log debug message with optional structured data.""" self._log(logging.DEBUG, message, **kwargs) def info(self, message: str, **kwargs): """Log info message with optional structured data.""" self._log(logging.INFO, message, **kwargs) def warning(self, message: str, **kwargs): """Log warning message with optional structured data.""" self._log(logging.WARNING, message, **kwargs) def error(self, message: str, **kwargs): """Log error message with optional structured data.""" self._log(logging.ERROR, message, **kwargs) def critical(self, message: str, **kwargs): """Log critical message with optional structured data.""" self._log(logging.CRITICAL, message, **kwargs) def _log(self, level: int, message: str, **kwargs): """Internal method to log with structured data.""" context: Dict[str, Any] = {} if self._bound_context: context.update(self._bound_context) if kwargs: context.update(kwargs) if context: structured_message = f"{message} | Context: {json.dumps(context, default=str)}" else: structured_message = message self.logger.log(level, structured_message) def bind(self, **kwargs): """Bind default context fields (compatibility with loguru-style usage).""" if kwargs: self._bound_context.update(kwargs) return self class ImportLogger(StructuredLogger): """Specialized logger for import operations.""" def __init__(self): super().__init__("import_operations", "INFO") def log_import_start(self, import_type: str, file_name: str, record_count: int = None): """Log the start of an import operation.""" context = { "import_type": import_type, "file_name": file_name, "timestamp": datetime.now().isoformat() } if record_count is not None: context["expected_records"] = record_count self.info(f"Starting {import_type} import", **context) def log_import_progress(self, processed: int, total: int = None, errors: int = 0): """Log import progress.""" context = { "processed": processed, "errors": errors, "timestamp": datetime.now().isoformat() } if total is not None: context["total"] = total context["progress_percent"] = round((processed / total) * 100, 2) self.info(f"Import progress: {processed} processed", **context) def log_import_error(self, line_number: int, error_message: str, row_data: Dict = None): """Log import errors with context.""" context = { "line_number": line_number, "error": error_message, "timestamp": datetime.now().isoformat() } if row_data: context["row_data"] = row_data self.warning(f"Import error at line {line_number}", **context) def log_import_complete(self, processed: int, errors: int, duration_seconds: float): """Log completion of import operation.""" context = { "total_processed": processed, "total_errors": errors, "duration_seconds": duration_seconds, "records_per_second": round(processed / max(duration_seconds, 0.1), 2), "timestamp": datetime.now().isoformat() } self.info(f"Import completed: {processed} processed, {errors} errors", **context) class SecurityLogger(StructuredLogger): """Specialized logger for security events.""" def __init__(self): super().__init__("security", "WARNING") def log_auth_attempt(self, username: str, success: bool, ip_address: str = None): """Log authentication attempts.""" context = { "username": username, "success": success, "ip_address": ip_address, "timestamp": datetime.now().isoformat() } if success: self.info("Successful authentication", **context) else: self.warning("Failed authentication attempt", **context) def log_permission_denied(self, username: str, resource: str, action: str): """Log permission denied events.""" context = { "username": username, "resource": resource, "action": action, "timestamp": datetime.now().isoformat() } self.warning("Permission denied", **context) def log_security_event(self, event_type: str, details: Dict[str, Any]): """Log general security events.""" context = { "event_type": event_type, "timestamp": datetime.now().isoformat(), **details } self.warning(f"Security event: {event_type}", **context) class DatabaseLogger(StructuredLogger): """Specialized logger for database operations.""" def __init__(self): super().__init__("database", "INFO") def log_query_performance(self, query_type: str, duration_ms: float, affected_rows: int = None): """Log database query performance.""" context = { "query_type": query_type, "duration_ms": duration_ms, "timestamp": datetime.now().isoformat() } if affected_rows is not None: context["affected_rows"] = affected_rows if duration_ms > 1000: # Log slow queries as warnings self.warning(f"Slow query detected: {query_type}", **context) else: self.debug(f"Query executed: {query_type}", **context) def log_transaction_event(self, event_type: str, details: Dict[str, Any] = None): """Log database transaction events.""" context = { "event_type": event_type, "timestamp": datetime.now().isoformat() } if details: context.update(details) self.info(f"Transaction {event_type}", **context) def log_function_call(logger: StructuredLogger = None, level: str = "DEBUG"): """ Decorator to log function calls with parameters and execution time. Args: logger: Logger instance to use (creates default if None) level: Log level to use """ def decorator(func): nonlocal logger if logger is None: logger = StructuredLogger(func.__module__, level) @wraps(func) def wrapper(*args, **kwargs): start_time = datetime.now() # Log function entry context = { "function": func.__name__, "args_count": len(args), "kwargs": list(kwargs.keys()), "start_time": start_time.isoformat() } logger.debug(f"Entering function {func.__name__}", **context) try: result = func(*args, **kwargs) # Log successful completion duration = (datetime.now() - start_time).total_seconds() logger.debug( f"Function {func.__name__} completed successfully", duration_seconds=duration, function=func.__name__ ) return result except Exception as e: # Log error duration = (datetime.now() - start_time).total_seconds() logger.error( f"Function {func.__name__} failed with error: {str(e)}", duration_seconds=duration, function=func.__name__, error_type=type(e).__name__ ) raise return wrapper return decorator # Local logger cache and factory to avoid circular imports with app.core.logging _loggers: dict[str, StructuredLogger] = {} def get_logger(name: str) -> StructuredLogger: """Return a cached StructuredLogger instance. This implementation is self-contained to avoid importing app.core.logging, which would create a circular import (core -> utils -> core). """ logger = _loggers.get(name) if logger is None: logger = StructuredLogger(name, getattr(settings, 'log_level', 'INFO')) _loggers[name] = logger return logger # Pre-configured logger instances app_logger = get_logger("application") import_logger = ImportLogger() security_logger = SecurityLogger() database_logger = DatabaseLogger() # Convenience functions def log_info(message: str, **kwargs): """Quick info logging.""" get_logger("application").info(message, **kwargs) def log_warning(message: str, **kwargs): """Quick warning logging.""" get_logger("application").warning(message, **kwargs) def log_error(message: str, **kwargs): """Quick error logging.""" get_logger("application").error(message, **kwargs) def log_debug(message: str, **kwargs): """Quick debug logging.""" get_logger("application").debug(message, **kwargs)