logger.py

#!/usr/bin/env python3
"""
Centralized logging configuration for Multi-genome Synteny project.

Provides:
- Console logging (INFO level) for user-facing messages
- Rotating file logging for debugging and persistence
- Consistent formatting across all scripts
- Thread-safe logging for webapp use

Usage:
    from logger import get_logger
    logger = get_logger(__name__)
    
    logger.info("Processing started")
    logger.warning("Gene not found in BED file")
    logger.error("Failed to load blocks file")
"""

import logging
import sys
from datetime import datetime
from logging.handlers import RotatingFileHandler
from pathlib import Path
from typing import Optional

# =============================================================================
# CONFIGURATION
# =============================================================================

# Fixed log level (INFO for normal operation)
LOG_LEVEL = logging.INFO

# Log file settings - use centralized path config for env var support
try:
    from path_config import LOG_DIR
except ImportError:
    # Fallback if path_config not available
    LOG_DIR = Path(__file__).resolve().parent.parent / "logs"

LOG_FILE = LOG_DIR / "synteny_analysis.log"
MAX_LOG_SIZE = 5 * 1024 * 1024  # 5 MB per file
BACKUP_COUNT = 3  # Keep 3 backup files

# Formatters
CONSOLE_FORMAT = "[%(asctime)s] %(levelname)s: %(message)s"
CONSOLE_DATE_FORMAT = "%H:%M:%S"
FILE_FORMAT = "%(asctime)s - %(name)s - %(levelname)s - %(funcName)s:%(lineno)d - %(message)s"
FILE_DATE_FORMAT = "%Y-%m-%d %H:%M:%S"

# =============================================================================
# LOGGER SETUP
# =============================================================================

_loggers: dict = {}
_file_handler: Optional[RotatingFileHandler] = None
_initialized: bool = False


def _ensure_log_dir() -> bool:
    """Create log directory if it doesn't exist. Returns True on success."""
    try:
        LOG_DIR.mkdir(parents=True, exist_ok=True)
        return True
    except (PermissionError, OSError) as e:
        # Fall back to console-only logging if we can't create log dir
        print(f"Warning: Cannot create log directory {LOG_DIR}: {e}", file=sys.stderr)
        return False


def _get_file_handler() -> Optional[RotatingFileHandler]:
    """Get or create the shared rotating file handler."""
    global _file_handler
    
    if _file_handler is None and _ensure_log_dir():
        try:
            _file_handler = RotatingFileHandler(
                LOG_FILE,
                maxBytes=MAX_LOG_SIZE,
                backupCount=BACKUP_COUNT,
                encoding='utf-8'
            )
            _file_handler.setLevel(logging.DEBUG)  # File gets everything
            _file_handler.setFormatter(logging.Formatter(FILE_FORMAT, FILE_DATE_FORMAT))
        except (PermissionError, OSError) as e:
            print(f"Warning: Cannot create log file {LOG_FILE}: {e}", file=sys.stderr)
            _file_handler = None
    
    return _file_handler


def get_logger(name: str = "synteny") -> logging.Logger:
    """
    Get or create a logger with the given name.
    
    All loggers share:
    - A console handler (INFO level, user-facing)
    - A rotating file handler (DEBUG level, for debugging)
    
    Args:
        name: Logger name (typically __name__ of the calling module)
    
    Returns:
        Configured logging.Logger instance
    
    Example:
        logger = get_logger(__name__)
        logger.info("Starting analysis")
        logger.warning("Gene distance exceeds threshold")
        logger.error("Failed to parse BED file")
    """
    global _loggers
    
    if name in _loggers:
        return _loggers[name]
    
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)  # Capture everything, handlers filter
    logger.propagate = False  # Prevent duplicate messages
    
    # Console handler (user-facing, INFO and above)
    console_handler = logging.StreamHandler(sys.stderr)
    console_handler.setLevel(LOG_LEVEL)
    console_handler.setFormatter(logging.Formatter(CONSOLE_FORMAT, CONSOLE_DATE_FORMAT))
    logger.addHandler(console_handler)
    
    # File handler (debugging, all levels)
    file_handler = _get_file_handler()
    if file_handler and file_handler not in logger.handlers:
        logger.addHandler(file_handler)
    
    _loggers[name] = logger
    return logger


# =============================================================================
# CONVENIENCE FUNCTIONS (backward compatibility with pandas_utils)
# =============================================================================

# Default logger for module-level convenience functions
_default_logger: Optional[logging.Logger] = None


def _get_default_logger() -> logging.Logger:
    """Get or create the default logger for convenience functions."""
    global _default_logger
    if _default_logger is None:
        _default_logger = get_logger("synteny")
    return _default_logger


def log(msg: str) -> None:
    """Log an info message with timestamp (backward compatible)."""
    _get_default_logger().info(msg)


def log_info(msg: str) -> None:
    """Log an info message (alias for log)."""
    log(msg)


def log_step(msg: str) -> None:
    """Log a processing step (alias for log)."""
    log(msg)


def log_success(msg: str) -> None:
    """Log a success message with checkmark."""
    _get_default_logger().info(f"✓ {msg}")


def log_warning(msg: str) -> None:
    """Log a warning message."""
    _get_default_logger().warning(msg)


def log_error(msg: str) -> None:
    """Log an error message."""
    _get_default_logger().error(msg)


def log_debug(msg: str) -> None:
    """Log a debug message (only to file)."""
    _get_default_logger().debug(msg)


def die(msg: str, exit_code: int = 1) -> None:
    """Log error and exit program."""
    log_error(msg)
    sys.exit(exit_code)


# =============================================================================
# SESSION LOGGING
# =============================================================================

def log_session_start(script_name: str) -> None:
    """Log the start of an analysis session."""
    logger = _get_default_logger()
    logger.info("=" * 60)
    logger.info(f"SESSION START: {script_name}")
    logger.info(f"Timestamp: {datetime.now().strftime('%Y-%m-%d %H:%M:%S')}")
    logger.info("=" * 60)


def log_session_end(script_name: str, success: bool = True) -> None:
    """Log the end of an analysis session."""
    logger = _get_default_logger()
    status = "SUCCESS" if success else "FAILED"
    logger.info(f"SESSION END: {script_name} - {status}")
    logger.info("=" * 60)


# =============================================================================
# WEBAPP-SPECIFIC LOGGING
# =============================================================================

def get_webapp_logger() -> logging.Logger:
    """
    Get a logger configured for webapp use.
    Same as get_logger but with 'webapp' prefix for easy filtering.
    """
    return get_logger("synteny.webapp")


def log_request(endpoint: str, params: dict) -> None:
    """Log an incoming webapp request."""
    logger = get_logger("synteny.webapp")
    # Sanitize params (don't log full file contents)
    safe_params = {k: (v[:50] + "..." if isinstance(v, str) and len(v) > 50 else v) 
                   for k, v in params.items()}
    logger.info(f"REQUEST: {endpoint} - params: {safe_params}")


def log_response(endpoint: str, success: bool, message: str = "") -> None:
    """Log a webapp response."""
    logger = get_logger("synteny.webapp")
    status = "OK" if success else "ERROR"
    logger.info(f"RESPONSE: {endpoint} - {status}" + (f" - {message}" if message else ""))