better logging

2026-06-10 18:31:43 -04:00
parent b8445a1bb3
commit a2f18484a6
4 changed files with 203 additions and 37 deletions
@@ -15,12 +15,14 @@ RUN apt-get update && apt-get install -y --no-install-recommends \
    git \
    curl \
    g++ \
+    tini \
    && rm -rf /var/lib/apt/lists/* \
    && ln -sf /usr/bin/python3.12 /usr/bin/python \
    && ln -sf /usr/bin/python3.12 /usr/bin/python3

-RUN curl -LsSf https://astral.sh/uv/install.sh | sh
-ENV PATH="/root/.local/bin:${PATH}"
+RUN curl -LsSf https://astral.sh/uv/install.sh | sh \
+    && cp /root/.local/bin/uv /usr/local/bin/uv \
+    && chmod 755 /usr/local/bin/uv

 WORKDIR /app

@@ -42,5 +44,8 @@ ENV FORCE_CPU=false \
    HF_HOME=/models/huggingface \
    INSIGHTFACE_HOME=/models/insightface

-ENTRYPOINT ["/app/entrypoint.sh"]
+HEALTHCHECK --interval=1h --timeout=10s --start-period=60s --retries=3 \
+  CMD test -f /app/entrypoint.sh || exit 1
+
+ENTRYPOINT ["tini", "--", "/app/entrypoint.sh"]

@@ -1,17 +1,48 @@
 #!/bin/bash
 set -e

+export PYTHONUNBUFFERED=1
+
+# Function to log model status before each run
+check_models() {
+    echo "📦 Checking models..."
+
+    if [ -d "/models/insightface/models/buffalo_l" ]; then
+        echo "  ✅ InsightFace Buffalo_L: downloaded"
+    else
+        echo "  ⬇️  InsightFace Buffalo_L: downloading (~300MB)..."
+    fi
+
+    if [ -d "/models/huggingface/hub" ] && [ "$(find /models/huggingface/hub -maxdepth 1 -type d 2>/dev/null | wc -l)" -gt 1 ]; then
+        echo "  ✅ HuggingFace models: downloaded"
+    else
+        echo "  ⬇️  HuggingFace models: downloading (SigLIP ~1GB, YOLOv9c ~500MB)..."
+    fi
+
+    echo "🚀 Starting if-curator..."
+}
+
 SCHEDULE="${CRON_SCHEDULE:-}"
+AUTO="${AUTO_MODE:-false}"
+
+# Check if interactive mode is viable
+if [ "$AUTO" != "true" ] && [ ! -t 0 ]; then
+    echo "❌ AUTO_MODE is not enabled and no TTY is attached."
+    echo "❌ Set AUTO_MODE=true for headless/automated runs."
+    exit 1
+fi
+
+# Always run once on startup
+echo "▶ Running on startup..."
+check_models
+uv run if-curator

 if [ -z "$SCHEDULE" ]; then
-    echo "▶ No CRON_SCHEDULE set — running once"
-    uv run if-curator
+    echo "▶ No CRON_SCHEDULE set — exiting"
    exit 0
 fi

 echo "▶ CRON_SCHEDULE set to: $SCHEDULE"
-echo "▶ Running if-curator on schedule..."
-
-# Hand off to the Python scheduler
+echo "▶ Switching to scheduled mode..."
 exec uv run python3 /app/scheduler.py

@@ -210,41 +210,131 @@ def _resolve_strategy(strategy: str, has_embedding: bool) -> tuple[int | str, st


 def upload_to_frigate(jobs: list[dict]) -> None:
-    """Upload processed face crops to Frigate via API."""
+    """Upload processed face crops to Frigate via API with detailed logging."""
    frigate_url = os.environ.get("FRIGATE_URL", "")
    if not frigate_url:
-        rprint("[yellow]FRIGATE_URL not set, skipping upload.[/yellow]")
+        rprint("[yellow]⚠️  FRIGATE_URL not set, skipping upload.[/yellow]")
        return

-    uploaded, failed = 0, 0
+    rprint("\n[bold cyan]📤 Uploading to Frigate[/bold cyan]")
+    rprint(f"  Target: [dim]{frigate_url}[/dim]")
+
+    # Count total files to upload
+    total_files = 0
    for job in jobs:
        name = job["person"]["name"]
        person_dir = os.path.join(Config.OUTPUT_DIR, name)
        if not os.path.isdir(person_dir):
            continue
+        total_files += sum(
+            1 for f in os.listdir(person_dir)
+            if f.lower().endswith((".jpg", ".jpeg", ".png", ".webp"))
+        )

-        for fname in sorted(os.listdir(person_dir)):
-            fpath = os.path.join(person_dir, fname)
-            if not fname.lower().endswith((".jpg", ".jpeg", ".png", ".webp")):
+    if total_files == 0:
+        rprint("  [yellow]No images found to upload.[/yellow]")
+        return
+
+    rprint(f"  People: [bold]{len(jobs)}[/bold], Total images: [bold]{total_files}[/bold]")
+
+    uploaded, failed = 0, 0
+
+    with Progress(
+        SpinnerColumn(),
+        TextColumn("[progress.description]{task.description}"),
+        BarColumn(),
+        TaskProgressColumn(),
+        console=console,
+    ) as progress:
+        upload_task = progress.add_task("[green]Uploading to Frigate", total=total_files)
+
+        for job in jobs:
+            name = job["person"]["name"]
+            person_dir = os.path.join(Config.OUTPUT_DIR, name)
+            if not os.path.isdir(person_dir):
+                progress.console.print(f"  [dim]⏭️  {name}: no output directory, skipping[/dim]")
                continue
-            try:
-                with open(fpath, "rb") as f:
-                    resp = requests.post(
-                        f"{frigate_url}/api/faces/train/{name}/classify",
-                        files={"file": (fname, f, "image/jpeg")},
-                        timeout=30,
-                    )
-                if resp.status_code == 200:
-                    uploaded += 1
-                else:
+
+            person_files = sorted(
+                f for f in os.listdir(person_dir)
+                if f.lower().endswith((".jpg", ".jpeg", ".png", ".webp"))
+            )
+
+            if not person_files:
+                progress.console.print(f"  [dim]⏭️  {name}: no images found[/dim]")
+                continue
+
+            progress.console.print(f"  📁 {name}: uploading {len(person_files)} image(s)...")
+            person_uploaded = 0
+            person_failed = 0
+
+            for fname in person_files:
+                fpath = os.path.join(person_dir, fname)
+                try:
+                    with open(fpath, "rb") as f:
+                        resp = requests.post(
+                            f"{frigate_url}/api/faces/train/{name}/classify",
+                            files={"file": (fname, f, "image/jpeg")},
+                            timeout=30,
+                        )
+                    if resp.status_code == 200:
+                        uploaded += 1
+                        person_uploaded += 1
+                    else:
+                        failed += 1
+                        person_failed += 1
+                        progress.console.print(
+                            f"    [red]✗ {fname}: HTTP {resp.status_code}[/red]"
+                        )
+                        try:
+                            error_detail = resp.json().get("message", resp.text[:100])
+                            progress.console.print(f"      [dim]{error_detail}[/dim]")
+                        except Exception:
+                            progress.console.print(f"      [dim]{resp.text[:100]}[/dim]")
+                except requests.exceptions.ConnectionError:
                    failed += 1
-                    logger.warning(f"Frigate upload failed for {name}/{fname}: {resp.status_code}")
-            except Exception as e:
-                failed += 1
-                logger.warning(f"Frigate upload error for {name}/{fname}: {e}")
+                    person_failed += 1
+                    progress.console.print(
+                        f"    [red]✗ {fname}: Connection refused[/red]"
+                    )
+                except requests.exceptions.Timeout:
+                    failed += 1
+                    person_failed += 1
+                    progress.console.print(
+                        f"    [red]✗ {fname}: Request timed out (30s)[/red]"
+                    )
+                except Exception as e:
+                    failed += 1
+                    person_failed += 1
+                    progress.console.print(
+                        f"    [red]✗ {fname}: {type(e).__name__} - {e}[/red]"
+                    )

-    rprint(f"  [green]Frigate upload: {uploaded} succeeded, {failed} failed[/green]")
+                progress.advance(upload_task)

+            # Per-person summary
+            if person_failed == 0:
+                progress.console.print(
+                    f"  ✅ {name}: {person_uploaded}/{person_uploaded} uploaded"
+                )
+            else:
+                progress.console.print(
+                    f"  ⚠️  {name}: {person_uploaded} succeeded, {person_failed} failed"
+                )
+
+    # Grand summary
+    rprint("\n  [bold]Frigate Upload Summary:[/bold]")
+    rprint(f"    ✅ Succeeded: [green]{uploaded}[/green]")
+    if failed:
+        rprint(f"    ❌ Failed:    [red]{failed}[/red]")
+    else:
+        rprint(f"    ❌ Failed:    0")
+
+    if failed > 0:
+        rprint("  [yellow]Check logs above for per-file error details.[/yellow]")
+
+    if failed == total_files and total_files > 0:
+        rprint("  [bold red]All uploads failed. Verify FRIGATE_URL is reachable and API is enabled.[/bold red]")


 def _perform_selection(assets: list, limit: int | str, name: str, selection_mode: str, entity_type: str) -> list:
@@ -420,3 +510,4 @@ def main() -> None:

 if __name__ == "__main__":
    main()
+
@@ -8,6 +8,7 @@ import os
 import sys
 import subprocess
 import time
+from pathlib import Path

 try:
    from croniter import croniter
@@ -16,28 +17,66 @@ except ImportError:
    sys.exit(1)

 SCHEDULE = os.environ["CRON_SCHEDULE"]
-NOW = time.time()
+MODELS_DIR = os.environ.get("HF_HOME", "/models/huggingface")
+INSIGHTFACE_DIR = os.environ.get("INSIGHTFACE_HOME", "/models/insightface")

+# Ensure all subprocess output appears in docker logs
+RUN_ENV = {**os.environ, "PYTHONUNBUFFERED": "1"}
+
+
+def check_models():
+    """Log model download status before each run."""
+    print("📦 Checking models...", flush=True)
+
+    buffalo = Path(INSIGHTFACE_DIR) / "models" / "buffalo_l"
+    if buffalo.exists():
+        print("  ✅ InsightFace Buffalo_L: downloaded", flush=True)
+    else:
+        print("  ⬇️  InsightFace Buffalo_L: downloading (~300MB)...", flush=True)
+
+    hf_hub = Path(MODELS_DIR) / "hub"
+    if hf_hub.exists() and any(hf_hub.iterdir()):
+        print("  ✅ HuggingFace models: downloaded", flush=True)
+    else:
+        print("  ⬇️  HuggingFace models: downloading (SigLIP ~1GB, YOLOv9c ~500MB)...", flush=True)
+
+    print("🚀 Starting if-curator...", flush=True)
+
+
+def calc_time_display(seconds):
+    """Convert seconds to human-readable time."""
+    hours = int(seconds // 3600)
+    minutes = int((seconds % 3600) // 60)
+    if hours > 0:
+        return f"{hours}h {minutes}m"
+    return f"{minutes}m"
+
+
+NOW = time.time()
 cron = croniter(SCHEDULE, NOW)
 next_run = cron.get_next(float)

 while True:
    now = time.time()
    if now >= next_run:
-        print(f"\n▶ [{time.strftime('%Y-%m-%d %H:%M:%S')}] Starting if-curator...")
-        result = subprocess.run(["uv", "run", "if-curator"])
+        print(f"\n▶ [{time.strftime('%Y-%m-%d %H:%M:%S')}] Starting if-curator...", flush=True)
+        check_models()
+        result = subprocess.run(
+            ["uv", "run", "if-curator"],
+            env=RUN_ENV,
+        )
        if result.returncode == 0:
-            print(f"✅ Run complete.")
+            print("✅ Run complete.", flush=True)
        else:
-            print(f"⚠️  Run exited with code {result.returncode}")
+            print(f"⚠️  Run exited with code {result.returncode}", flush=True)

        next_run = cron.get_next(float)
        wait = next_run - time.time()
        if wait > 0:
-            print(f"▶ Next run: {time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(next_run))} (in {int(wait // 3600)}h {int((wait % 3600) // 60)}m)")
+            print(f"▶ Next run: {time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(next_run))} (in {calc_time_display(wait)})", flush=True)
        continue

    wait = next_run - now
-    print(f"▶ Next run: {time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(next_run))} (in {int(wait // 3600)}h {int((wait % 3600) // 60)}m)")
-    time.sleep(min(wait, 3600))  # Check every hour at most, or sooner if needed
+    print(f"▶ Next run: {time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(next_run))} (in {calc_time_display(wait)})", flush=True)
+    time.sleep(min(wait, 3600))