coe-mirror/coe_mirror.py

"""Mirror repos from git.churchofmalware.org Forgejo instance to pCloud.

Fetches all repos owned by Nightmare_Eclipse and stores per-commit zip snapshots.
Runs unattended via systemd timer twice daily. Local staging when pCloud unavailable.
"""

import json
import logging
import logging.handlers
import os
import re
import shutil
import subprocess
import sys
import time
import zipfile
from datetime import datetime, timedelta, timezone
from pathlib import Path
from fcntl import flock, LOCK_EX, LOCK_NB
from typing import List, Optional, Tuple
from urllib.parse import quote

import requests

# Module constants (overridable via env vars for testability)
API_BASE = "https://git.churchofmalware.org"
OWNER = "Nightmare_Eclipse"
PCLOUD_TARGET = Path.home() / "pCloudDrive" / "Hacking" / "Nightmare_Eclipse"
PENDING_DIR = Path.home() / ".local" / "share" / "coe-mirror" / "pending"
LOG_DIR = Path.home() / ".local" / "share" / "coe-mirror"
LOG_FILE = LOG_DIR / "coe-mirror.log"
LOCK_NAME = "coe-mirror.lock"
SHORT_SHA_LEN = 8
HTTP_TIMEOUT = 30
DOWNLOAD_TIMEOUT = 60
RETRY_BACKOFF = [0, 5, 30]  # seconds between attempts; len = max attempts
USER_AGENT = "coe-mirror/1.0"
REPO_NAME_RE = re.compile(r"^[a-zA-Z0-9._-]+$")

# Matrix configuration
MATRIX_HOMESERVER = "https://m.mealeyfamily.com"
MATRIX_ROOM = "!MBpPtYlQYMcngtpvJt:m.mealeyfamily.com"  # General
MATRIX_TOKEN_CACHE = LOG_DIR / "matrix-token.json"
MATRIX_TIMEOUT = 8
MATRIX_REFRESH_THRESHOLD_SECONDS = 1800  # refresh if <30 min left

# Allow env var overrides for testing and deployment flexibility
if env_pcloud := os.getenv("COE_MIRROR_PCLOUD_TARGET"):
    PCLOUD_TARGET = Path(env_pcloud)
if env_pending := os.getenv("COE_MIRROR_PENDING_DIR"):
    PENDING_DIR = Path(env_pending)
if env_hs := os.getenv("COE_MIRROR_MATRIX_HOMESERVER"):
    MATRIX_HOMESERVER = env_hs
if env_room := os.getenv("COE_MIRROR_MATRIX_ROOM"):
    MATRIX_ROOM = env_room

logger: logging.Logger = None  # Initialized in setup_logging()


def _safe_repo_name(name: str) -> bool:
    """Validate repo name against whitelist to prevent path traversal."""
    return bool(REPO_NAME_RE.fullmatch(name))


def setup_logging() -> None:
    """Configure logging to file and stderr with rotation."""
    global logger
    LOG_DIR.mkdir(parents=True, exist_ok=True)
    PENDING_DIR.mkdir(parents=True, exist_ok=True)

    logger = logging.getLogger("coe-mirror")
    logger.setLevel(logging.DEBUG)

    # Rotating file handler
    file_handler = logging.handlers.RotatingFileHandler(
        LOG_FILE, maxBytes=5 * 1024 * 1024, backupCount=3
    )
    file_handler.setLevel(logging.DEBUG)

    # Stderr handler for systemd journal
    stderr_handler = logging.StreamHandler(sys.stderr)
    stderr_handler.setLevel(logging.DEBUG)

    # Formatter
    formatter = logging.Formatter(
        "%(asctime)s %(levelname)s %(name)s: %(message)s"
    )
    file_handler.setFormatter(formatter)
    stderr_handler.setFormatter(formatter)

    logger.addHandler(file_handler)
    logger.addHandler(stderr_handler)


def acquire_lock() -> Optional[int]:
    """Acquire exclusive lock. Return lock fd on success, None if contended."""
    xdg_runtime = os.getenv("XDG_RUNTIME_DIR")
    lock_dir = Path(xdg_runtime) if xdg_runtime else Path("/tmp")
    lock_file = lock_dir / LOCK_NAME

    try:
        fd = os.open(str(lock_file), os.O_CREAT | os.O_WRONLY, 0o600)
        try:
            flock(fd, LOCK_EX | LOCK_NB)
            return fd
        except OSError:
            os.close(fd)
            return None
    except OSError as exc:
        logger.error("Failed to open lock file: %s", exc)
        return None


def release_lock(lock_fd: int) -> None:
    """Release and close the lock file descriptor."""
    try:
        os.close(lock_fd)
    except OSError:
        pass


def probe_pcloud() -> bool:
    """Probe pCloud health. Write tiny file, read back, delete. Return True if healthy."""
    try:
        probe_file = PCLOUD_TARGET / ".write_probe"
        PCLOUD_TARGET.mkdir(parents=True, exist_ok=True)

        probe_file.write_text("probe")
        # fsync on file descriptor, not stat
        with open(probe_file, "r") as f:
            os.fsync(f.fileno())
        content = probe_file.read_text()
        probe_file.unlink()

        if content != "probe":
            logger.warning("pCloud write verification failed (content mismatch); pcloud unavailable; queuing locally")
            return False
        return True
    except Exception as exc:
        logger.warning("pCloud probe failed: %s; pcloud unavailable; queuing locally", exc)
        return False


def place_into_pcloud(src: Path, dst: Path) -> bool:
    """Copy src → dst with size verification; unlink src only on success.

    Returns True on success, False on any failure. Never raises.
    """
    # Defense in depth: if src and dst are the same file, it's a no-op success
    if src.resolve() == dst.resolve():
        logger.debug("src and dst are the same file, no-op: %s", src)
        return True

    try:
        shutil.copy2(src, dst)
        src_size = src.stat().st_size
        dst_size = dst.stat().st_size
        if src_size != dst_size:
            logger.warning(
                "size mismatch placing %s → %s (src=%d dst=%d)",
                src, dst, src_size, dst_size
            )
            try:
                dst.unlink()
            except OSError:
                pass
            return False
        src.unlink()
        return True
    except Exception as exc:
        logger.warning("placement failed %s → %s: %s", src, dst, exc)
        return False


def fetch_repos(session: requests.Session) -> Optional[list]:
    """Fetch list of repos owned by OWNER. Return list of repo dicts or None on fatal error."""
    url = f"{API_BASE}/api/v1/users/{OWNER}/repos"

    for attempt, backoff in enumerate(RETRY_BACKOFF):
        if attempt > 0:
            logger.info("Retrying repo list fetch (attempt %d), backoff %ds", attempt + 1, backoff)
            time.sleep(backoff)

        try:
            resp = session.get(url, timeout=HTTP_TIMEOUT)
            if resp.status_code == 429:
                logger.debug("Got 429 on repo list, will retry")
                continue
            if resp.status_code >= 500:
                logger.debug("Got %d on repo list, will retry", resp.status_code)
                continue
            resp.raise_for_status()
            return resp.json()
        except requests.RequestException as exc:
            logger.debug("Attempt %d: %s", attempt + 1, exc)

    logger.error("Failed to fetch repos after %d attempts", len(RETRY_BACKOFF))
    return None


def fetch_branch_sha(session: requests.Session, repo_name: str, default_branch: str) -> Optional[str]:
    """Fetch commit SHA for repo's default branch. Return full hex SHA or None on error."""
    url = f"{API_BASE}/api/v1/repos/{OWNER}/{quote(repo_name, safe='')}/branches/{quote(default_branch, safe='')}"

    for attempt, backoff in enumerate(RETRY_BACKOFF):
        if attempt > 0:
            logger.debug("Retrying branch fetch for %s (attempt %d), backoff %ds",
                        repo_name, attempt + 1, backoff)
            time.sleep(backoff)

        try:
            resp = session.get(url, timeout=HTTP_TIMEOUT)
            if resp.status_code == 429:
                logger.debug("Got 429 on branch %s, will retry", repo_name)
                continue
            if resp.status_code >= 500:
                logger.debug("Got %d on branch %s, will retry", resp.status_code, repo_name)
                continue
            resp.raise_for_status()
            data = resp.json()
            return data.get("commit", {}).get("id")
        except requests.RequestException as exc:
            logger.debug("Attempt %d for %s: %s", attempt + 1, repo_name, exc)

    logger.error("Failed to fetch branch SHA for %s after %d attempts", repo_name, len(RETRY_BACKOFF))
    return None


def download_repo_zip(session: requests.Session, repo_name: str, full_sha: str) -> Optional[Path]:
    """Download repo zip for given SHA. Return Path to downloaded file (in PENDING_DIR) or None."""
    # Defense in depth: validate repo_name even though main() should have done so
    if not _safe_repo_name(repo_name):
        logger.error("refusing unsafe repo name in download_repo_zip: %r", repo_name)
        return None

    filename = f"{repo_name}_{full_sha[:SHORT_SHA_LEN]}.zip"
    partial_path = PENDING_DIR / f"{filename}.partial"
    final_path = PENDING_DIR / filename

    # URL-encode repo_name and full_sha for safety (defense in depth after main-level validation)
    url = f"{API_BASE}/{OWNER}/{quote(repo_name, safe='')}/archive/{quote(full_sha, safe='')}.zip"

    for attempt, backoff in enumerate(RETRY_BACKOFF):
        if attempt > 0:
            logger.debug("Retrying download for %s (attempt %d), backoff %ds",
                        filename, attempt + 1, backoff)
            time.sleep(backoff)

        try:
            resp = session.get(url, timeout=DOWNLOAD_TIMEOUT, stream=True)
            if resp.status_code == 429:
                logger.debug("Got 429 on download %s, will retry", filename)
                continue
            if resp.status_code >= 500:
                logger.debug("Got %d on download %s, will retry", resp.status_code, filename)
                continue
            resp.raise_for_status()

            # Stream to temp file
            partial_path.parent.mkdir(parents=True, exist_ok=True)
            with open(partial_path, "wb") as f:
                for chunk in resp.iter_content(chunk_size=65536):
                    if chunk:
                        f.write(chunk)

            # Validate zip
            if not zipfile.is_zipfile(partial_path):
                logger.error("Downloaded file is not a valid zip: %s", filename)
                partial_path.unlink()
                return None

            # Rename to final
            partial_path.rename(final_path)
            logger.info("Downloaded %s", filename)
            return final_path

        except requests.RequestException as exc:
            logger.debug("Attempt %d for %s: %s", attempt + 1, filename, exc)
        except Exception as exc:
            logger.error("Error downloading %s: %s", filename, exc)
            if partial_path.exists():
                partial_path.unlink()
            return None

    logger.error("Failed to download %s after %d attempts", filename, len(RETRY_BACKOFF))
    if partial_path.exists():
        partial_path.unlink()
    return None


def flush_pending(pcloud_healthy: bool) -> list:
    """Move all *.zip files from PENDING_DIR to PCLOUD_TARGET if healthy.

    Return list of (repo, short_sha, final_location) tuples for files moved.
    """
    moved = []
    if not pcloud_healthy or not PENDING_DIR.exists():
        return moved

    for pending_file in PENDING_DIR.glob("*.zip"):
        dst = PCLOUD_TARGET / pending_file.name
        if place_into_pcloud(pending_file, dst):
            # Extract repo name and short sha from filename
            name_parts = pending_file.stem.rsplit("_", 1)
            if len(name_parts) == 2:
                repo, short_sha = name_parts
                moved.append((repo, short_sha, str(dst)))
                logger.info("Flushed %s to pCloud", pending_file.name)

    return moved


def _read_token_cache() -> Optional[dict]:
    """Return cached token dict or None on any failure. Never raises."""
    try:
        if not MATRIX_TOKEN_CACHE.exists():
            return None
        with open(MATRIX_TOKEN_CACHE) as f:
            data = json.load(f)
        # Shape check
        if "access_token" in data and "expires_at" in data:
            return data
    except Exception as exc:
        logger.debug("token cache read failed: %s", exc)
    return None


def _write_token_cache(access_token: str, expires_at_iso: str) -> None:
    """Write token cache with 0600 permissions. Never raises."""
    try:
        MATRIX_TOKEN_CACHE.parent.mkdir(parents=True, exist_ok=True)
        payload = {"access_token": access_token, "expires_at": expires_at_iso}
        # Write then chmod for atomicity-ish behavior
        tmp = MATRIX_TOKEN_CACHE.with_suffix(".tmp")
        with open(tmp, "w") as f:
            json.dump(payload, f)
        os.chmod(tmp, 0o600)
        os.replace(tmp, MATRIX_TOKEN_CACHE)
    except Exception as exc:
        logger.warning("token cache write failed: %s", exc)


def _fetch_creds() -> Optional[Tuple[str, str]]:
    """Fetch (user, password) from Infisical via creds. Return None on failure."""
    try:
        user = subprocess.run(
            ["creds", "get", "MATRIX_USER", "matrix"],
            capture_output=True, text=True, timeout=5
        )
        pw = subprocess.run(
            ["creds", "get", "MATRIX_PASSWORD", "matrix"],
            capture_output=True, text=True, timeout=5
        )
        if user.returncode == 0 and pw.returncode == 0:
            u, p = user.stdout.strip(), pw.stdout.strip()
            if u and p:
                return u, p
        logger.warning("creds returned non-zero for MATRIX_USER/MATRIX_PASSWORD")
    except FileNotFoundError:
        logger.warning("creds binary not found on PATH")
    except subprocess.TimeoutExpired:
        logger.warning("creds timed out fetching Matrix credentials")
    except Exception as exc:
        logger.warning("creds fetch failed: %s", exc)
    return None


def _matrix_login(session: requests.Session) -> Optional[str]:
    """Login via password, cache token, return access_token. None on failure."""
    creds = _fetch_creds()
    if not creds:
        return None
    user, password = creds
    url = f"{MATRIX_HOMESERVER}/_matrix/client/r0/login"
    body = {"type": "m.login.password", "user": user, "password": password}
    try:
        resp = session.post(url, json=body, timeout=MATRIX_TIMEOUT)
        if resp.status_code != 200:
            logger.warning("matrix login failed: HTTP %d", resp.status_code)
            return None
        data = resp.json()
        token = data.get("access_token")
        expires_in_ms = data.get("expires_in_ms", 0)
        if not token:
            logger.warning("matrix login returned no access_token")
            return None
        expires_at = datetime.now(timezone.utc) + timedelta(milliseconds=expires_in_ms)
        _write_token_cache(token, expires_at.isoformat())
        return token
    except requests.RequestException as exc:
        logger.warning("matrix login network error: %s", exc)
    except Exception as exc:
        logger.warning("matrix login unexpected error: %s", exc)
    return None


def _get_matrix_token(session: requests.Session, force_refresh: bool = False) -> Optional[str]:
    """Return a valid token. Read cache → check expiry → login if needed."""
    if not force_refresh:
        cached = _read_token_cache()
        if cached:
            try:
                expires_at = datetime.fromisoformat(cached["expires_at"])
                remaining = (expires_at - datetime.now(timezone.utc)).total_seconds()
                if remaining > MATRIX_REFRESH_THRESHOLD_SECONDS:
                    return cached["access_token"]
            except Exception as exc:
                logger.debug("cache expiry parse failed: %s", exc)
    return _matrix_login(session)


def _send_matrix(message: str) -> bool:
    """Send a Matrix message to MATRIX_ROOM. Return True on success.

    Non-fatal: any failure logs WARN and returns False. Never raises.
    Implements one 401 retry with token refresh.
    """
    with requests.Session() as session:
        session.headers.update({"User-Agent": USER_AGENT})

        encoded_room = quote(MATRIX_ROOM, safe="")
        url = f"{MATRIX_HOMESERVER}/_matrix/client/r0/rooms/{encoded_room}/send/m.room.message"
        body = {"msgtype": "m.text", "body": message}

        for attempt in (1, 2):
            token = _get_matrix_token(session, force_refresh=(attempt == 2))
            if not token:
                logger.warning("matrix send aborted: no token (attempt %d)", attempt)
                return False
            try:
                resp = session.post(
                    url,
                    json=body,
                    headers={"Authorization": f"Bearer {token}"},
                    timeout=MATRIX_TIMEOUT,
                )
                if resp.status_code == 200:
                    logger.info("matrix sent: %s", message[:80])
                    return True
                if resp.status_code == 401 and attempt == 1:
                    logger.info("matrix 401 on send; refreshing token and retrying")
                    continue
                logger.warning("matrix send failed: HTTP %d body=%s",
                               resp.status_code, resp.text[:200])
                return False
            except requests.RequestException as exc:
                logger.warning("matrix send network error: %s", exc)
                return False
            except Exception as exc:
                logger.warning("matrix send unexpected error: %s", exc)
                return False


def notify(summary: List[Tuple[str, str, str]]) -> None:
    """Build a Matrix message and POST it. Non-fatal."""
    if not summary:
        return
    repos = [f"{repo}@{short_sha}" for repo, short_sha, _ in summary]
    repos_str = ", ".join(repos)
    text = (
        f"coe-mirror: {len(repos)} new from Nightmare_Eclipse: {repos_str}"
    )
    # Always log the intended message so behavior is visible even when Matrix is down
    logger.info("notify: %s", text)
    _send_matrix(text)


def main() -> int:
    """Main entry point."""
    setup_logging()

    lock_fd = acquire_lock()
    if lock_fd is None:
        logger.debug("Lock already held; another instance running, exiting gracefully")
        return 0

    try:
        logger.info("coe-mirror starting")

        # Probe pCloud health
        pcloud_healthy = probe_pcloud()
        logger.info("pCloud health check: %s", "healthy" if pcloud_healthy else "unavailable")

        # Flush pending at start
        initial_flush = flush_pending(pcloud_healthy)

        # Create session and fetch repos
        session = requests.Session()
        session.headers.update({"User-Agent": USER_AGENT})

        repos = fetch_repos(session)
        if repos is None:
            logger.error("Fatal: could not fetch repos")
            return 1

        logger.info("Fetched %d repos", len(repos))

        new_files = []

        # Process each repo
        for repo in repos:
            repo_name = repo.get("name")
            default_branch = repo.get("default_branch", "main")

            if not repo_name:
                logger.warning("Repo object missing 'name'")
                continue

            # Fix 1: Reject unsafe repo names to prevent path traversal
            if not _safe_repo_name(repo_name):
                logger.warning("refusing unsafe repo name: %r", repo_name)
                continue

            sha = fetch_branch_sha(session, repo_name, default_branch)
            if sha is None:
                logger.error("Skipping %s (could not fetch branch SHA)", repo_name)
                continue

            # Fix 3: Check existence before download to avoid SameFileError
            filename = f"{repo_name}_{sha[:SHORT_SHA_LEN]}.zip"
            pcloud_path = PCLOUD_TARGET / filename
            pending_path = PENDING_DIR / filename
            already_have = (pcloud_path.exists() and pcloud_path.stat().st_size > 0) \
                        or (pending_path.exists() and pending_path.stat().st_size > 0)
            if already_have:
                logger.info("Skipping %s (already present)", filename)
                continue

            downloaded = download_repo_zip(session, repo_name, sha)
            if downloaded:
                short_sha = sha[:SHORT_SHA_LEN]
                # Try to place it
                if pcloud_healthy:
                    dst = PCLOUD_TARGET / downloaded.name
                    if place_into_pcloud(downloaded, dst):
                        new_files.append((repo_name, short_sha, str(dst)))
                    else:
                        logger.info("File %s left in pending (placement failed)", downloaded.name)
                        new_files.append((repo_name, short_sha, str(downloaded)))
                else:
                    logger.info("pCloud unhealthy; %s queued in pending", downloaded.name)
                    new_files.append((repo_name, short_sha, str(downloaded)))

        # Flush pending at end
        final_flush = flush_pending(pcloud_healthy)
        new_files.extend(final_flush)

        # Notify
        notify(new_files)

        logger.info("coe-mirror complete")
        return 0

    finally:
        release_lock(lock_fd)


if __name__ == "__main__":
    sys.exit(main())