dl-organizer/src/vlm/executor.py

"""Execution engine for Video Library Manager.

This module provides safe execution of file operations with:
- Dry-run mode (default): simulates operations without making changes
- Execute mode: performs actual file operations (requires explicit confirmation)
- Comprehensive logging of all operations
- Error handling and resilience
"""

import json
import logging
from datetime import datetime
from pathlib import Path
from typing import Optional
from uuid import uuid4

from .config import Config
from .logging_config import get_logger, log_operation
from .models import ExecutionPlan, FileOperation, OperationResult, RollbackLog
from .quarantine import QuarantineManager
from .state import StateManager
from .transaction import TransactionLog
from .utils import ensure_utc, is_within_root, utc_now


class ExecutionEngine:
    """Engine for executing file operations safely with dry-run support."""

    def __init__(
        self,
        logger: Optional[logging.Logger] = None,
        config: Optional[Config] = None,
        verbose_operations: bool = False,
        state_manager: Optional[StateManager] = None,
    ):
        """Initialize the execution engine.

        Args:
            logger: Optional logger instance (uses default if not provided)
            config: Optional config (required for quarantine operations)
            verbose_operations: Emit per-operation dry-run logs at INFO when True
            state_manager: Optional state manager for updating file statuses
        """
        self.logger = logger or get_logger()
        self.config = config
        self.verbose_operations = verbose_operations
        self.state_manager = state_manager
        self._quarantine_manager: Optional[QuarantineManager] = (
            QuarantineManager(config, self.logger) if config else None
        )
    
    def execute_plan(
        self,
        plan: ExecutionPlan,
        mode: str = "dry-run",
        confirmed: bool = False
    ) -> tuple[list[OperationResult], dict, Optional[RollbackLog]]:
        """Execute an execution plan with the specified mode.
        
        Args:
            plan: The execution plan to execute
            mode: Execution mode - "dry-run" (default) or "execute"
            confirmed: Whether execution has been explicitly confirmed (required for execute mode)
        
        Returns:
            Tuple of (operation results, execution summary, rollback log)
            - operation results: List of results for each operation
            - execution summary: Dict with counts of successful, failed, and skipped operations
            - rollback log: RollbackLog if mode is "execute", None for dry-run
        
        Raises:
            ValueError: If mode is invalid or execute mode used without confirmation
        """
        # Validate mode
        if mode not in ("dry-run", "execute"):
            raise ValueError(f"Invalid mode: {mode}. Must be 'dry-run' or 'execute'")
        
        # Require confirmation for execute mode
        if mode == "execute" and not confirmed:
            raise ValueError(
                "Execute mode requires explicit confirmation. "
                "Set confirmed=True or use --confirm flag in CLI"
            )
        
        log_operation(
            self.logger,
            logging.INFO,
            f"Starting execution in {mode} mode with {len(plan.operations)} operations",
            operation_type="execute"
        )

        # Initialize transaction log for execute mode
        transaction_log = None
        if mode == "execute":
            log_path = Path.home() / ".vlm" / "transaction.json"
            try:
                transaction_log = TransactionLog(log_path)
                transaction_log.start_transaction(plan)
            except OSError as exc:
                log_operation(
                    self.logger,
                    logging.WARNING,
                    f"Transaction log disabled (cannot write {log_path}): {exc}",
                    operation_type="execute",
                )
                transaction_log = None
        
        # Execute all operations
        results = []
        for i, operation in enumerate(plan.operations):
            try:
                result = self.execute_operation(operation, mode)
            except Exception as exc:  # pragma: no cover - defensive containment
                error_msg = (
                    f"Unexpected failure during {operation.operation_type}: {exc}"
                )
                self.logger.exception(
                    error_msg,
                    extra={
                        "operation_type": "execute",
                        "file_path": f" - {operation.source_path}",
                    },
                )
                result = OperationResult(
                    operation=operation,
                    success=False,
                    error_message=error_msg,
                    executed_at=utc_now(),
                )
            results.append(result)

            # Update transaction and state logs in execute mode
            if mode == "execute":
                if transaction_log:
                    try:
                        transaction_log.mark_operation_complete(
                            i, result.success, result.error_message
                        )
                    except OSError as exc:
                        log_operation(
                            self.logger,
                            logging.WARNING,
                            f"Failed to update transaction log: {exc}",
                            operation_type="execute",
                        )
                        transaction_log = None
                
                # Update file state if successful and not a no-op
                if result.success and operation.operation_type != "no-op" and self.state_manager:
                    new_status = "quarantined" if operation.operation_type == "quarantine" else "executed"
                    self.state_manager.set_file_state(
                        operation.source_path, 
                        status=new_status,
                        reason=operation.reason
                    )
                    # We could save state incrementally, but saving at the end is more efficient.
                    # For extra safety, we'll save every 10 operations.
                    if (i + 1) % 10 == 0:
                        self.state_manager.save()
        
        # Finalize transaction and state
        if mode == "execute":
            if transaction_log:
                status = "completed" if all(r.success for r in results) else "failed"
                try:
                    transaction_log.complete_transaction(status=status)
                except OSError as exc:
                    log_operation(
                        self.logger,
                        logging.WARNING,
                        f"Failed to finalize transaction log: {exc}",
                        operation_type="execute",
                    )
            if self.state_manager:
                self.state_manager.save()
        
        # Generate execution summary
        summary = self._generate_execution_summary(results)
        
        # Create rollback log only in execute mode
        rollback_log = None
        if mode == "execute":
            # Only include successful operations in rollback log
            successful_operations = [r for r in results if r.success]
            rollback_log = RollbackLog(
                log_id=str(uuid4()),
                execution_plan_id=plan.plan_id,
                executed_at=utc_now(),
                operations=successful_operations
            )
            
            log_operation(
                self.logger,
                logging.INFO,
                f"Created rollback log with {len(successful_operations)} successful operations",
                operation_type="execute"
            )
        
        # Log execution summary
        self._log_execution_summary(summary, mode)
        
        return results, summary, rollback_log
    
    def _validate_library_root_boundaries(
        self,
        operation: FileOperation,
        executed_at: datetime,
    ) -> OperationResult | None:
        """Reject move/rename operations that escape the configured library root."""
        if not self.config or operation.operation_type not in ("move", "rename"):
            return None

        if not is_within_root(operation.source_path, self.config.library_root):
            error_msg = f"Unsafe source outside library root: {operation.source_path}"
            log_operation(
                self.logger,
                logging.ERROR,
                error_msg,
                operation_type="execute",
                file_path=operation.source_path,
            )
            return OperationResult(
                operation=operation,
                success=False,
                error_message=error_msg,
                executed_at=executed_at,
            )

        if operation.destination_path and not is_within_root(
            operation.destination_path, self.config.library_root
        ):
            error_msg = (
                f"Unsafe destination outside library root: {operation.destination_path}"
            )
            log_operation(
                self.logger,
                logging.ERROR,
                error_msg,
                operation_type="execute",
                file_path=operation.source_path,
            )
            return OperationResult(
                operation=operation,
                success=False,
                error_message=error_msg,
                executed_at=executed_at,
            )

        return None

    def execute_operation(
        self,
        operation: FileOperation,
        mode: str
    ) -> OperationResult:
        """Execute a single file operation.
        
        Args:
            operation: The file operation to execute
            mode: Execution mode - "dry-run" or "execute"
        
        Returns:
            OperationResult with success status and any error message
        """
        executed_at = utc_now()

        # Handle no-op operations
        if operation.operation_type == "no-op":
            log_operation(
                self.logger,
                logging.DEBUG,
                f"Skipping no-op operation: {operation.reason}",
                operation_type="execute",
                file_path=operation.source_path
            )
            return OperationResult(
                operation=operation,
                success=True,
                error_message=None,
                executed_at=executed_at
            )

        # Handle preserve-directory operations
        if operation.operation_type == "preserve-directory":
            log_operation(
                self.logger,
                logging.DEBUG,
                f"Preserving directory: {operation.reason}",
                operation_type="execute",
                file_path=operation.source_path
            )
            return OperationResult(
                operation=operation,
                success=True,
                error_message=None,
                executed_at=executed_at
            )

        # Handle quarantine operations (no destination_path; use QuarantineManager)
        if operation.operation_type == "quarantine":
            if not self._quarantine_manager:
                return OperationResult(
                    operation=operation,
                    success=False,
                    error_message="Config required for quarantine operations",
                    executed_at=executed_at
                )
            if mode == "dry-run":
                level = logging.INFO if self.verbose_operations else logging.DEBUG
                log_operation(
                    self.logger,
                    level,
                    f"[DRY-RUN] Would quarantine: {operation.source_path} ({operation.reason})",
                    operation_type="execute",
                    file_path=operation.source_path
                )
                return OperationResult(
                    operation=operation,
                    success=True,
                    error_message=None,
                    executed_at=executed_at
                )
            # Quarantine the file and return the result directly
            # (includes the actual quarantine destination_path for rollback)
            return self._quarantine_manager.quarantine_file(
                operation.source_path, operation.reason
            )

        # Handle conflicted operations
        if operation.has_conflict:
            log_operation(
                self.logger,
                logging.WARNING,
                f"Skipping conflicted operation: {operation.conflict_reason}",
                operation_type="execute",
                file_path=operation.source_path
            )
            return OperationResult(
                operation=operation,
                success=False,
                error_message=f"Conflict: {operation.conflict_reason}",
                executed_at=executed_at
            )
        
        boundary_error = self._validate_library_root_boundaries(operation, executed_at)
        if boundary_error is not None:
            return boundary_error

        # Execute based on mode
        if mode == "dry-run":
            return self._simulate_operation(operation, executed_at)
        else:
            return self._perform_operation(operation, executed_at)
    
    def _simulate_operation(
        self,
        operation: FileOperation,
        executed_at: datetime
    ) -> OperationResult:
        """Simulate an operation in dry-run mode without making changes.
        
        Args:
            operation: The file operation to simulate
            executed_at: Timestamp of execution
        
        Returns:
            OperationResult indicating what would happen
        """
        dest = operation.destination_path
        msg = (
            f"[DRY-RUN] Would quarantine: {operation.source_path} ({operation.reason})"
            if operation.operation_type == "quarantine"
            else f"[DRY-RUN] Would {operation.operation_type}: {operation.source_path} -> {dest}"
        )
        log_operation(
            self.logger,
            logging.INFO if self.verbose_operations else logging.DEBUG,
            msg,
            operation_type="execute",
            file_path=operation.source_path
        )
        
        return OperationResult(
            operation=operation,
            success=True,
            error_message=None,
            executed_at=executed_at
        )
    
    def _perform_operation(
        self,
        operation: FileOperation,
        executed_at: datetime
    ) -> OperationResult:
        """Perform an actual file operation.
        
        Args:
            operation: The file operation to perform
            executed_at: Timestamp of execution
        
        Returns:
            OperationResult with success status and any error message
        """
        try:
            # Validate source file exists
            if not operation.source_path.exists():
                error_msg = f"Source file does not exist: {operation.source_path}"
                log_operation(
                    self.logger,
                    logging.ERROR,
                    error_msg,
                    operation_type="execute",
                    file_path=operation.source_path
                )
                return OperationResult(
                    operation=operation,
                    success=False,
                    error_message=error_msg,
                    executed_at=executed_at
                )
            
            # Create destination directory if needed
            if operation.destination_path:
                operation.destination_path.parent.mkdir(parents=True, exist_ok=True)
                
                # Perform the move/rename operation
                operation.source_path.rename(operation.destination_path)
                
                log_operation(
                    self.logger,
                    logging.INFO,
                    f"Successfully {operation.operation_type}: "
                    f"{operation.source_path} -> {operation.destination_path}",
                    operation_type="execute",
                    file_path=operation.source_path
                )
            
            return OperationResult(
                operation=operation,
                success=True,
                error_message=None,
                executed_at=executed_at
            )
            
        except Exception as e:
            error_msg = f"Failed to {operation.operation_type}: {str(e)}"
            log_operation(
                self.logger,
                logging.ERROR,
                error_msg,
                operation_type="execute",
                file_path=operation.source_path
            )
            return OperationResult(
                operation=operation,
                success=False,
                error_message=error_msg,
                executed_at=executed_at
            )
    
    def _generate_execution_summary(
        self,
        results: list[OperationResult]
    ) -> dict:
        """Generate a structured execution summary.
        
        Args:
            results: List of operation results
        
        Returns:
            Dictionary with counts of successful, failed, and skipped operations
        """
        successful = sum(1 for r in results if r.success)
        failed = sum(
            1
            for r in results
            if (not r.success) and (not r.operation.has_conflict)
        )
        skipped = sum(
            1 for r in results
            if r.operation.operation_type == "no-op" or r.operation.has_conflict
        )
        
        return {
            "successful": successful,
            "failed": failed,
            "skipped": skipped,
            "total": len(results)
        }
    
    def _log_execution_summary(
        self,
        summary: dict,
        mode: str
    ) -> None:
        """Log a summary of execution results.
        
        Args:
            summary: Execution summary dictionary
            mode: Execution mode that was used
        """
        summary_msg = (
            f"Execution summary ({mode} mode): "
            f"{summary['successful']} successful, {summary['failed']} failed, {summary['skipped']} skipped"
        )
        
        log_operation(
            self.logger,
            logging.INFO,
            summary_msg,
            operation_type="execute"
        )
    
    def save_rollback_log(
        self,
        rollback_log: RollbackLog,
        output_path: Path
    ) -> None:
        """Save rollback log to disk in JSON format.
        
        Args:
            rollback_log: The rollback log to save
            output_path: Path where the rollback log should be saved
        """
        # Convert rollback log to JSON-serializable format
        log_data = {
            "vlm_schema_version": "1.0",
            "log_id": rollback_log.log_id,
            "execution_plan_id": rollback_log.execution_plan_id,
            "executed_at": rollback_log.executed_at.isoformat(),
            "operations": [
                {
                    "operation_type": op.operation.operation_type,
                    "source_path": str(op.operation.source_path),
                    "destination_path": str(op.operation.destination_path) if op.operation.destination_path else None,
                    "reason": op.operation.reason,
                    "success": op.success,
                    "error_message": op.error_message,
                    "executed_at": op.executed_at.isoformat()
                }
                for op in rollback_log.operations
            ]
        }
        
        # Ensure output directory exists
        output_path.parent.mkdir(parents=True, exist_ok=True)
        
        # Write to file
        with open(output_path, 'w', encoding='utf-8') as f:
            json.dump(log_data, f, indent=2)
        
        log_operation(
            self.logger,
            logging.INFO,
            f"Saved rollback log to {output_path}",
            operation_type="execute"
        )
    def load_rollback_log(
        self,
        log_path: Path
    ) -> RollbackLog:
        """Load rollback log from disk.

        Args:
            log_path: Path to the rollback log JSON file

        Returns:
            RollbackLog object loaded from the file

        Raises:
            FileNotFoundError: If the log file does not exist
            ValueError: If the log file is invalid JSON or missing required fields
        """
        if not log_path.exists():
            raise FileNotFoundError(f"Rollback log not found: {log_path}")

        try:
            with open(log_path, 'r', encoding='utf-8') as f:
                log_data = json.load(f)

            # Reconstruct RollbackLog from JSON data
            operations = []
            for op_data in log_data["operations"]:
                # Reconstruct FileOperation
                file_op = FileOperation(
                    operation_type=op_data["operation_type"],
                    source_path=Path(op_data["source_path"]),
                    destination_path=Path(op_data["destination_path"]) if op_data["destination_path"] else None,
                    reason=op_data["reason"],
                    has_conflict=False,  # Conflicts don't matter for rollback
                    conflict_reason=None
                )

                # Reconstruct OperationResult (normalize naive datetime to UTC)
                op_result = OperationResult(
                    operation=file_op,
                    success=op_data["success"],
                    error_message=op_data["error_message"],
                    executed_at=ensure_utc(datetime.fromisoformat(op_data["executed_at"]))
                )
                operations.append(op_result)

            rollback_log = RollbackLog(
                log_id=log_data["log_id"],
                execution_plan_id=log_data["execution_plan_id"],
                executed_at=ensure_utc(datetime.fromisoformat(log_data["executed_at"])),
                operations=operations
            )

            log_operation(
                self.logger,
                logging.INFO,
                f"Loaded rollback log from {log_path} with {len(operations)} operations",
                operation_type="rollback"
            )

            return rollback_log

        except (json.JSONDecodeError, KeyError) as e:
            raise ValueError(f"Invalid rollback log format: {str(e)}")

    def rollback(
        self,
        rollback_log: RollbackLog
    ) -> tuple[list[OperationResult], dict]:
        """Rollback operations from a rollback log (best-effort).

        This method attempts to reverse all operations in the rollback log by moving
        files from their destination back to their source. Operations are processed
        in LIFO (Last In, First Out) order for best-effort restoration.

        Args:
            rollback_log: The rollback log containing operations to reverse

        Returns:
            Tuple of (rollback results, rollback summary)
            - rollback results: List of OperationResult for each rollback attempt
            - rollback summary: Dict with counts of successful, failed, and skipped operations
        """
        log_operation(
            self.logger,
            logging.INFO,
            f"Starting rollback of {len(rollback_log.operations)} operations (LIFO order)",
            operation_type="rollback"
        )

        # Reverse the operation list (LIFO order)
        reversed_operations = list(reversed(rollback_log.operations))

        # Attempt to rollback each operation
        results = []
        for original_result in reversed_operations:
            result = self._rollback_operation(original_result)
            results.append(result)

        # Generate rollback summary
        summary = self._generate_rollback_summary(results)

        # Log rollback summary
        self._log_rollback_summary(summary)

        return results, summary

    def _rollback_operation(
        self,
        original_result: OperationResult
    ) -> OperationResult:
        """Rollback a single operation (best-effort).

        Args:
            original_result: The original operation result to rollback

        Returns:
            OperationResult indicating success or failure of the rollback
        """
        operation = original_result.operation
        executed_at = utc_now()

        # Skip no-op operations
        if operation.operation_type == "no-op":
            log_operation(
                self.logger,
                logging.DEBUG,
                f"Skipping rollback of no-op operation",
                operation_type="rollback",
                file_path=operation.source_path
            )
            return OperationResult(
                operation=operation,
                success=True,
                error_message=None,
                executed_at=executed_at
            )

        # Handle quarantine operations using QuarantineManager
        if operation.operation_type == "quarantine":
            if not self._quarantine_manager:
                error_msg = "Cannot rollback quarantine: QuarantineManager not available"
                log_operation(
                    self.logger,
                    logging.ERROR,
                    error_msg,
                    operation_type="rollback"
                )
                return OperationResult(
                    operation=operation,
                    success=False,
                    error_message=error_msg,
                    executed_at=executed_at
                )

            # Use QuarantineManager to restore the file
            if operation.destination_path:
                restore_result = self._quarantine_manager.restore_from_quarantine(
                    operation.destination_path
                )
                return OperationResult(
                    operation=operation,
                    success=restore_result.success,
                    error_message=restore_result.error_message,
                    executed_at=executed_at
                )
            else:
                error_msg = "Cannot rollback quarantine: no destination path recorded"
                return OperationResult(
                    operation=operation,
                    success=False,
                    error_message=error_msg,
                    executed_at=executed_at
                )

        try:
            # For move/rename operations, reverse the direction
            # Original: source -> destination
            # Rollback: destination -> source
            if operation.destination_path and operation.destination_path.exists():
                # Move file back from destination to source
                operation.destination_path.rename(operation.source_path)

                log_operation(
                    self.logger,
                    logging.INFO,
                    f"Successfully rolled back: {operation.destination_path} -> {operation.source_path}",
                    operation_type="rollback",
                    file_path=operation.destination_path
                )

                return OperationResult(
                    operation=operation,
                    success=True,
                    error_message=None,
                    executed_at=executed_at
                )
            else:
                # Destination file doesn't exist - cannot rollback
                error_msg = f"Cannot rollback: destination file not found at {operation.destination_path}"
                log_operation(
                    self.logger,
                    logging.WARNING,
                    error_msg,
                    operation_type="rollback",
                    file_path=operation.destination_path
                )
                return OperationResult(
                    operation=operation,
                    success=False,
                    error_message=error_msg,
                    executed_at=executed_at
                )

        except Exception as e:
            # Handle rollback failures gracefully - log and continue
            error_msg = f"Failed to rollback operation: {str(e)}"
            log_operation(
                self.logger,
                logging.ERROR,
                error_msg,
                operation_type="rollback",
                file_path=operation.destination_path
            )
            return OperationResult(
                operation=operation,
                success=False,
                error_message=error_msg,
                executed_at=executed_at
            )

    def _generate_rollback_summary(
        self,
        results: list[OperationResult]
    ) -> dict:
        """Generate a structured rollback summary.

        Args:
            results: List of rollback operation results

        Returns:
            Dictionary with counts of successful, failed, and skipped operations
        """
        successful = sum(1 for r in results if r.success)
        failed = sum(1 for r in results if not r.success)
        skipped = sum(
            1 for r in results
            if r.operation.operation_type == "no-op"
        )

        return {
            "successful": successful,
            "failed": failed,
            "skipped": skipped,
            "total": len(results)
        }

    def _log_rollback_summary(
        self,
        summary: dict
    ) -> None:
        """Log a summary of rollback results.

        Args:
            summary: Rollback summary dictionary
        """
        summary_msg = (
            f"Rollback summary: "
            f"{summary['successful']} successful, {summary['failed']} failed, {summary['skipped']} skipped"
        )

        log_operation(
            self.logger,
            logging.INFO,
            summary_msg,
            operation_type="rollback"
        )