dl-organizer/tests/test_logging.py

"""Unit tests for logging configuration."""

import logging
import tempfile
from pathlib import Path

import pytest

from vlm.logging_config import (
    setup_logging,
    get_logger,
    log_operation,
    MAX_LOG_SIZE,
    default_log_dir,
)


class TestLoggingSetup:
    """Test logging configuration setup."""
    
    def test_setup_logging_creates_logger(self, tmp_path):
        """Test that setup_logging creates a configured logger."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        assert logger is not None
        assert logger.name == "vlm"
        assert logger.level == logging.DEBUG
    
    def test_setup_logging_creates_log_directory(self, tmp_path):
        """Test that setup_logging creates the log directory."""
        log_dir = tmp_path / "logs"
        assert not log_dir.exists()
        
        setup_logging(log_level="INFO", log_dir=log_dir)
        
        assert log_dir.exists()
        assert log_dir.is_dir()
    
    def test_setup_logging_creates_log_file(self, tmp_path):
        """Test that setup_logging creates the log file."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        # Log a message to ensure file is created
        logger.info("Test message")
        
        log_file = tmp_path / "vlm.log"
        assert log_file.exists()
    
    def test_setup_logging_with_custom_log_file(self, tmp_path):
        """Test that setup_logging accepts custom log file name."""
        logger = setup_logging(
            log_level="INFO",
            log_dir=tmp_path,
            log_file="custom.log"
        )
        
        logger.info("Test message")
        
        log_file = tmp_path / "custom.log"
        assert log_file.exists()
    
    def test_setup_logging_invalid_level_raises_error(self, tmp_path):
        """Test that invalid log level raises ValueError."""
        with pytest.raises(ValueError, match="Invalid log level"):
            setup_logging(log_level="INVALID", log_dir=tmp_path)
    
    def test_setup_logging_accepts_valid_levels(self, tmp_path):
        """Test that all valid log levels are accepted."""
        valid_levels = ["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"]
        
        for level in valid_levels:
            logger = setup_logging(log_level=level, log_dir=tmp_path)
            assert logger is not None

    def test_setup_logging_falls_back_when_file_logging_unwritable(self, tmp_path, monkeypatch):
        """Test setup continues with console logging if file logging cannot initialize."""
        def fail_mkdir(self, parents=False, exist_ok=False):
            raise PermissionError("mock permission denied")

        monkeypatch.setattr(Path, "mkdir", fail_mkdir)

        logger = setup_logging(log_level="INFO", log_dir=tmp_path / "logs")

        logger.info("Console-only logging still works")
        assert len(logger.handlers) == 1
        assert isinstance(logger.handlers[0], logging.StreamHandler)


class TestDefaultPathResolution:
    """Test runtime default path resolution."""

    def test_default_log_dir_resolves_at_runtime(self, tmp_path, monkeypatch):
        """Test default log directory follows current Path.home() value."""
        monkeypatch.setattr(Path, "home", lambda: tmp_path)
        assert default_log_dir() == tmp_path / ".vlm" / "logs"


class TestDualOutput:
    """Test dual output to console and file."""
    
    def test_console_handler_respects_log_level(self, tmp_path):
        """Test that console handler only logs INFO+ messages."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        logger.debug("Debug message")
        logger.info("Info message")
        logger.warning("Warning message")
        
        # Check file contains all messages (DEBUG+)
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "Debug message" in log_content
        assert "Info message" in log_content
        assert "Warning message" in log_content
        
        # Verify console handler has INFO level
        console_handler = [h for h in logger.handlers if isinstance(h, logging.StreamHandler) and not isinstance(h, logging.handlers.RotatingFileHandler)][0]
        assert console_handler.level == logging.INFO
    
    def test_file_handler_logs_all_levels(self, tmp_path):
        """Test that file handler logs DEBUG+ messages."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        logger.debug("Debug message")
        logger.info("Info message")
        logger.warning("Warning message")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        # File should contain all levels
        assert "Debug message" in log_content
        assert "Info message" in log_content
        assert "Warning message" in log_content


class TestLogFormat:
    """Test log message formatting."""
    
    def test_log_includes_timestamp(self, tmp_path):
        """Test that log entries include timestamps."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        logger.info("Test message")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        # Check for timestamp format (YYYY-MM-DD HH:MM:SS)
        import re
        timestamp_pattern = r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}'
        assert re.search(timestamp_pattern, log_content)
    
    def test_log_includes_level(self, tmp_path):
        """Test that log entries include log level."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        logger.info("Test message")
        logger.warning("Warning message")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "INFO" in log_content
        assert "WARNING" in log_content
    
    def test_log_includes_operation_type(self, tmp_path):
        """Test that log entries include operation type."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        log_operation(logger, logging.INFO, "Test message", operation_type="scan")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "[scan]" in log_content
    
    def test_log_includes_file_path(self, tmp_path):
        """Test that log entries include file paths when provided."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        test_path = Path("/test/path/file.mp4")
        log_operation(
            logger,
            logging.INFO,
            "Processing file",
            operation_type="parse",
            file_path=test_path
        )
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert str(test_path) in log_content
    
    def test_log_without_file_path(self, tmp_path):
        """Test that log entries work without file path."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        log_operation(logger, logging.INFO, "Test message", operation_type="general")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "Test message" in log_content
        assert "[general]" in log_content


class TestLogRotation:
    """Test log rotation at 10MB threshold."""
    
    def test_log_rotation_creates_backup(self, tmp_path):
        """Test that log rotation creates backup files."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        # Write enough data to trigger rotation (slightly over 10MB)
        large_message = "x" * 1024  # 1KB message
        num_messages = (MAX_LOG_SIZE // 1024) + 100  # Exceed 10MB
        
        for i in range(num_messages):
            logger.info(f"{large_message} - {i}")
        
        # Check that backup file was created
        log_file = tmp_path / "vlm.log"
        backup_file = tmp_path / "vlm.log.1"
        
        assert log_file.exists()
        assert backup_file.exists()
    
    def test_log_file_size_stays_under_limit(self, tmp_path):
        """Test that log file size stays under 10MB after rotation."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        # Write enough data to trigger rotation
        large_message = "x" * 1024  # 1KB message
        num_messages = (MAX_LOG_SIZE // 1024) + 100  # Exceed 10MB
        
        for i in range(num_messages):
            logger.info(f"{large_message} - {i}")
        
        log_file = tmp_path / "vlm.log"
        
        # Current log file should be smaller than MAX_LOG_SIZE
        assert log_file.stat().st_size < MAX_LOG_SIZE


class TestGetLogger:
    """Test get_logger function."""
    
    def test_get_logger_returns_logger(self):
        """Test that get_logger returns a logger instance."""
        logger = get_logger()
        
        assert logger is not None
        assert logger.name == "vlm"
    
    def test_get_logger_creates_default_config(self):
        """Test that get_logger creates default configuration if needed."""
        # Clear any existing handlers
        logger = logging.getLogger("vlm")
        logger.handlers.clear()
        
        # Get logger should set up default configuration
        logger = get_logger()
        
        assert len(logger.handlers) > 0


class TestLogOperation:
    """Test log_operation helper function."""
    
    def test_log_operation_with_all_parameters(self, tmp_path):
        """Test log_operation with all parameters."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        test_path = Path("/test/file.mp4")
        
        log_operation(
            logger,
            logging.INFO,
            "Processing file",
            operation_type="execute",
            file_path=test_path
        )
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "Processing file" in log_content
        assert "[execute]" in log_content
        assert str(test_path) in log_content
    
    def test_log_operation_with_minimal_parameters(self, tmp_path):
        """Test log_operation with minimal parameters."""
        logger = setup_logging(log_level="INFO", log_dir=tmp_path)
        
        log_operation(logger, logging.INFO, "Simple message")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "Simple message" in log_content
        assert "[general]" in log_content
    
    def test_log_operation_different_levels(self, tmp_path):
        """Test log_operation with different log levels."""
        logger = setup_logging(log_level="DEBUG", log_dir=tmp_path)
        
        log_operation(logger, logging.DEBUG, "Debug message", operation_type="scan")
        log_operation(logger, logging.INFO, "Info message", operation_type="parse")
        log_operation(logger, logging.WARNING, "Warning message", operation_type="execute")
        log_operation(logger, logging.ERROR, "Error message", operation_type="rollback")
        
        log_file = tmp_path / "vlm.log"
        log_content = log_file.read_text()
        
        assert "DEBUG" in log_content
        assert "INFO" in log_content
        assert "WARNING" in log_content
        assert "ERROR" in log_content