orion/app/core/logging.py

# app/core/logging.py
"""Hybrid logging system with file rotation and database storage.

This module provides classes and functions for:
- File-based logging with automatic rotation
- Database logging for critical events (WARNING, ERROR, CRITICAL)
- Dynamic log level configuration from database settings
- Log retention and cleanup policies
"""

import logging
import sys
import traceback
from datetime import UTC, datetime
from logging.handlers import RotatingFileHandler
from pathlib import Path

from app.core.config import settings


class DatabaseLogHandler(logging.Handler):
    """
    Custom logging handler that stores WARNING, ERROR, and CRITICAL logs in database.

    Runs asynchronously to avoid blocking application performance.
    Uses retry logic for SQLite database locking issues.
    """

    MAX_RETRIES = 3
    RETRY_DELAY = 0.1  # 100ms delay between retries

    def __init__(self):
        super().__init__()
        self.setLevel(logging.WARNING)  # Only log WARNING and above to database

    def emit(self, record):
        """Emit a log record to the database with retry logic for SQLite locking."""
        import time

        for attempt in range(self.MAX_RETRIES):
            try:
                from app.core.database import SessionLocal
                from models.database.admin import ApplicationLog

                # Skip if no database session available
                db = SessionLocal()
                if not db:
                    return

                try:
                    # Extract exception information if present
                    exception_type = None
                    exception_message = None
                    stack_trace = None

                    if record.exc_info:
                        exception_type = record.exc_info[0].__name__ if record.exc_info[0] else None
                        exception_message = str(record.exc_info[1]) if record.exc_info[1] else None
                        stack_trace = "".join(traceback.format_exception(*record.exc_info))

                    # Extract context from record (if middleware added it)
                    user_id = getattr(record, "user_id", None)
                    vendor_id = getattr(record, "vendor_id", None)
                    request_id = getattr(record, "request_id", None)
                    context = getattr(record, "context", None)

                    # Create log entry
                    log_entry = ApplicationLog(
                        timestamp=datetime.fromtimestamp(record.created, tz=UTC),
                        level=record.levelname,
                        logger_name=record.name,
                        module=record.module,
                        function_name=record.funcName,
                        line_number=record.lineno,
                        message=record.getMessage(),
                        exception_type=exception_type,
                        exception_message=exception_message,
                        stack_trace=stack_trace,
                        request_id=request_id,
                        user_id=user_id,
                        vendor_id=vendor_id,
                        context=context,
                    )

                    db.add(log_entry)
                    db.commit()
                    return  # Success, exit retry loop

                except Exception as e:
                    db.rollback()
                    # Check if it's a database locked error
                    if "database is locked" in str(e).lower():
                        if attempt < self.MAX_RETRIES - 1:
                            time.sleep(self.RETRY_DELAY * (attempt + 1))
                            continue
                    # For other errors or final attempt, silently skip
                    # Don't print to stderr to avoid log spam during imports
                    pass
                finally:
                    db.close()

            except Exception:
                # Silently fail - logging should never crash the app
                pass

            break  # Exit retry loop on non-recoverable errors


def get_log_level_from_db():
    """
    Get log level from database settings.
    Falls back to environment variable if not found.
    """
    try:
        from app.core.database import SessionLocal
        from app.services.admin_settings_service import admin_settings_service

        db = SessionLocal()
        if not db:
            return settings.log_level

        try:
            log_level = admin_settings_service.get_setting_value(
                db, "log_level", default=settings.log_level
            )
            return log_level.upper() if log_level else settings.log_level.upper()
        finally:
            db.close()
    except Exception:
        # If database not ready or error, fall back to settings
        return settings.log_level.upper()


def get_rotation_settings_from_db():
    """
    Get log rotation settings from database.
    Returns tuple: (max_bytes, backup_count)
    """
    try:
        from app.core.database import SessionLocal
        from app.services.admin_settings_service import admin_settings_service

        db = SessionLocal()
        if not db:
            return (10 * 1024 * 1024, 5)  # 10MB, 5 backups

        try:
            max_mb = admin_settings_service.get_setting_value(
                db, "log_file_max_size_mb", default=10
            )
            backup_count = admin_settings_service.get_setting_value(
                db, "log_file_backup_count", default=5
            )
            return (int(max_mb) * 1024 * 1024, int(backup_count))
        finally:
            db.close()
    except Exception:
        # Fall back to defaults
        return (10 * 1024 * 1024, 5)


def reload_log_level():
    """
    Reload log level from database without restarting application.
    Useful when log level is changed via admin panel.
    """
    try:
        new_level = get_log_level_from_db()
        logger = logging.getLogger()
        logger.setLevel(getattr(logging, new_level))
        logging.info(f"Log level changed to: {new_level}")
        return new_level
    except Exception as e:
        logging.error(f"Failed to reload log level: {e}")
        return None


def setup_logging():
    """Configure application logging with file rotation and database handlers."""
    # Determine log file path
    log_file_path = settings.log_file
    if log_file_path:
        log_file = Path(log_file_path)
    else:
        # Default to logs/app.log
        log_file = Path("logs") / "app.log"

    # Create logs directory if it doesn't exist
    log_file.parent.mkdir(parents=True, exist_ok=True)

    # Get log level from database (or fall back to env)
    log_level = get_log_level_from_db()

    # Get rotation settings from database (or fall back to defaults)
    max_bytes, backup_count = get_rotation_settings_from_db()

    # Configure root logger
    logger = logging.getLogger()
    logger.setLevel(getattr(logging, log_level))

    # Remove existing handlers
    for handler in logger.handlers[:]:
        logger.removeHandler(handler)

    # Create formatters
    detailed_formatter = logging.Formatter(
        "%(asctime)s - %(name)s - %(levelname)s - [%(module)s:%(funcName)s:%(lineno)d] - %(message)s"
    )
    simple_formatter = logging.Formatter(
        "%(asctime)s - %(levelname)s - %(message)s"
    )

    # Console handler (simple format)
    console_handler = logging.StreamHandler(sys.stdout)
    console_handler.setFormatter(simple_formatter)
    logger.addHandler(console_handler)

    # Rotating file handler (detailed format)
    file_handler = RotatingFileHandler(
        log_file,
        maxBytes=max_bytes,
        backupCount=backup_count,
        encoding="utf-8"
    )
    file_handler.setFormatter(detailed_formatter)
    logger.addHandler(file_handler)

    # Database handler for critical events (WARNING and above)
    try:
        db_handler = DatabaseLogHandler()
        db_handler.setFormatter(detailed_formatter)
        logger.addHandler(db_handler)
    except Exception as e:
        # If database handler fails, just use file logging
        print(f"Warning: Database logging handler could not be initialized: {e}", file=sys.stderr)

    # Configure specific loggers to reduce noise
    logging.getLogger("uvicorn.access").setLevel(logging.WARNING)
    logging.getLogger("sqlalchemy.engine").setLevel(logging.WARNING)

    # Log startup info
    logger.info("=" * 80)
    logger.info("LOGGING SYSTEM INITIALIZED")
    logger.info(f"Log Level: {log_level}")
    logger.info(f"Log File: {log_file}")
    logger.info(f"Max File Size: {max_bytes / (1024 * 1024):.1f} MB")
    logger.info(f"Backup Count: {backup_count}")
    logger.info(f"Database Logging: Enabled (WARNING and above)")
    logger.info("=" * 80)

    return logging.getLogger(__name__)