diff --git a/bincio/serve/cli.py b/bincio/serve/cli.py index 9825cc0..81b3c18 100644 --- a/bincio/serve/cli.py +++ b/bincio/serve/cli.py @@ -76,4 +76,11 @@ def serve(data_dir: str, site_dir: Optional[str], host: str, port: int, console.print(f" Users: [dim]unlimited[/dim]") console.print() - uvicorn.run(srv.app, host=host, port=port, log_level="info") + log_config = uvicorn.config.LOGGING_CONFIG.copy() + # Make bincio.serve logger emit at INFO through uvicorn's handler + log_config["loggers"]["bincio.serve"] = { + "handlers": ["default"], + "level": "INFO", + "propagate": False, + } + uvicorn.run(srv.app, host=host, port=port, log_level="info", log_config=log_config) diff --git a/bincio/serve/server.py b/bincio/serve/server.py index c8ffe24..4e862bb 100644 --- a/bincio/serve/server.py +++ b/bincio/serve/server.py @@ -9,6 +9,7 @@ Run via `bincio serve` CLI command. from __future__ import annotations import json +import logging import re import secrets import shutil @@ -19,6 +20,8 @@ import uuid from pathlib import Path from typing import Any, Optional +log = logging.getLogger("bincio.serve") + from fastapi import Cookie, FastAPI, File, Form, HTTPException, Request, Response, UploadFile from fastapi.responses import RedirectResponse, StreamingResponse from fastapi.middleware.cors import CORSMiddleware @@ -246,37 +249,52 @@ def _trigger_rebuild(handle: str) -> None: # Fast: only update data, skip Astro build. # Serialised with the same lock: merge_all wipes and recreates # _merged/activities/ — concurrent runs would corrupt each other. + log.info("rebuild[%s]: merge-only (no webroot)", _handle) with _rebuild_lock: - subprocess.run( + result = subprocess.run( [uv, "run", "bincio", "render", "--data-dir", _data_dir, "--site-dir", _site_dir, "--handle", _handle, "--no-build"], - stdout=subprocess.DEVNULL, - stderr=subprocess.DEVNULL, + capture_output=True, + text=True, ) + if result.returncode != 0: + log.error("rebuild[%s]: merge failed (rc=%d):\n%s\n%s", + _handle, result.returncode, result.stdout, result.stderr) + else: + log.info("rebuild[%s]: merge done", _handle) else: # Full build + rsync — serialised so concurrent uploads don't race + log.info("rebuild[%s]: full build + rsync to %s", _handle, _webroot) with _rebuild_lock: result = subprocess.run( [uv, "run", "bincio", "render", "--data-dir", _data_dir, "--site-dir", _site_dir, "--handle", _handle], - stdout=subprocess.DEVNULL, - stderr=subprocess.DEVNULL, + capture_output=True, + text=True, ) - if result.returncode == 0: - # Rsync built site to nginx webroot - subprocess.run( + if result.returncode != 0: + log.error("rebuild[%s]: build failed (rc=%d):\n%s\n%s", + _handle, result.returncode, result.stdout, result.stderr) + else: + log.info("rebuild[%s]: build done, rsyncing", _handle) + rsync = subprocess.run( ["rsync", "-a", "--delete", f"{_site_dir}/dist/", _webroot + "/"], - stdout=subprocess.DEVNULL, - stderr=subprocess.DEVNULL, + capture_output=True, + text=True, ) + if rsync.returncode != 0: + log.error("rebuild[%s]: rsync failed (rc=%d):\n%s\n%s", + _handle, rsync.returncode, rsync.stdout, rsync.stderr) + else: + log.info("rebuild[%s]: rsync done", _handle) except Exception: - pass # rebuild failure must never affect the calling request + log.exception("rebuild[%s]: unexpected error", _handle) threading.Thread(target=_run, daemon=True).start() @@ -551,6 +569,127 @@ async def admin_rebuild( return JSONResponse({"ok": True}) +@app.post("/api/admin/users/{handle}/rebuild-sync") +async def admin_rebuild_sync( + handle: str, + bincio_session: Optional[str] = Cookie(default=None), +) -> JSONResponse: + """Run merge+rebuild synchronously and return full output. Admin only. + + Unlike /rebuild (fire-and-forget), this blocks until done and returns stdout/stderr. + Use for debugging when you need to see what went wrong. + """ + _require_admin(bincio_session) + user_dir = _get_data_dir() / handle + if not user_dir.is_dir(): + raise HTTPException(404, f"No data directory for user '{handle}'") + if site_dir is None: + raise HTTPException(503, "Server has no --site-dir configured; rebuild not available") + + uv = shutil.which("uv") or str(Path.home() / ".local" / "bin" / "uv") + cmd = [uv, "run", "bincio", "render", + "--data-dir", str(data_dir), + "--site-dir", str(site_dir), + "--handle", handle, + "--no-build"] + if webroot: + cmd = [uv, "run", "bincio", "render", + "--data-dir", str(data_dir), + "--site-dir", str(site_dir), + "--handle", handle] + + result = subprocess.run(cmd, capture_output=True, text=True, timeout=300) + resp: dict[str, Any] = { + "ok": result.returncode == 0, + "returncode": result.returncode, + "stdout": result.stdout, + "stderr": result.stderr, + } + + if result.returncode == 0 and webroot: + rsync = subprocess.run( + ["rsync", "-a", "--delete", f"{site_dir}/dist/", str(webroot) + "/"], + capture_output=True, text=True, timeout=120, + ) + resp["rsync_returncode"] = rsync.returncode + resp["rsync_stdout"] = rsync.stdout + resp["rsync_stderr"] = rsync.stderr + resp["ok"] = rsync.returncode == 0 + + return JSONResponse(resp) + + +@app.get("/api/admin/users/{handle}/diag") +async def admin_diag( + handle: str, + bincio_session: Optional[str] = Cookie(default=None), +) -> JSONResponse: + """Return a diagnostic snapshot of a user's data directory. Admin only.""" + _require_admin(bincio_session) + user_dir = _get_data_dir() / handle + if not user_dir.is_dir(): + raise HTTPException(404, f"No data directory for user '{handle}'") + + def _count(path: Path, glob: str = "*") -> int: + return sum(1 for f in path.glob(glob) if f.is_file()) if path.exists() else 0 + + def _size_mb(path: Path) -> float: + if not path.exists(): + return 0.0 + return sum(f.stat().st_size for f in path.rglob("*") if f.is_file()) / 1_048_576 + + activities_dir = user_dir / "activities" + merged_dir = user_dir / "_merged" + originals_dir = user_dir / "originals" + uploads_dir = user_dir / "_uploads" + + merged_index = merged_dir / "index.json" + root_index = user_dir / "index.json" + + merged_activity_count: int | None = None + if merged_index.exists(): + try: + idx = json.loads(merged_index.read_text()) + merged_activity_count = len(idx.get("activities", [])) + except Exception: + merged_activity_count = -1 + + root_activity_count: int | None = None + if root_index.exists(): + try: + idx = json.loads(root_index.read_text()) + root_activity_count = len(idx.get("activities", [])) + except Exception: + root_activity_count = -1 + + return JSONResponse({ + "handle": handle, + "user_dir": str(user_dir), + "activities": { + "json_files": _count(activities_dir, "*.json"), + "geojson_files": _count(activities_dir, "*.geojson"), + "size_mb": round(_size_mb(activities_dir), 2), + }, + "originals": { + "exists": originals_dir.exists(), + "size_mb": round(_size_mb(originals_dir), 2), + "strava_originals": _count(originals_dir / "strava", "*.json") if (originals_dir / "strava").exists() else 0, + }, + "merged": { + "exists": merged_dir.exists(), + "activity_count_in_index": merged_activity_count, + "size_mb": round(_size_mb(merged_dir), 2), + }, + "root_index": { + "exists": root_index.exists(), + "activity_count": root_activity_count, + }, + "pending_uploads": _count(uploads_dir), + "dedup_cache_exists": (user_dir / ".bincio_cache.json").exists(), + "athlete_json_exists": (user_dir / "athlete.json").exists(), + }) + + def _wipe_user_activities(user_dir: Path) -> int: """Delete all extracted activity files and caches for a user. @@ -937,9 +1076,10 @@ async def upload_activity( added += 1 any_added = True yield f"data: {json.dumps({'type': 'progress', 'n': n, 'total': total_files, 'name': name, 'status': 'imported'})}\n\n" - except Exception: + except Exception as exc: errors += 1 - yield f"data: {json.dumps({'type': 'progress', 'n': n, 'total': total_files, 'name': name, 'status': 'error'})}\n\n" + log.error("upload[%s]: failed to process %s: %s", user.handle, name, exc, exc_info=True) + yield f"data: {json.dumps({'type': 'progress', 'n': n, 'total': total_files, 'name': name, 'status': 'error', 'detail': str(exc)})}\n\n" finally: if not kept: staged.unlink(missing_ok=True) @@ -999,18 +1139,32 @@ async def upload_strava_zip( from bincio.extract.strava_zip import strava_zip_iter from bincio.render.merge import merge_all + log.info("strava-zip[%s]: received %s, privacy=%s", user.handle, file.filename, privacy) + def event_stream(): any_imported = False + imported_count = 0 + error_count = 0 try: for event in strava_zip_iter(zip_path, dd, privacy=privacy): yield f"data: {json.dumps(event)}\n\n" - if event.get("type") == "progress" and event.get("status") == "imported": - any_imported = True + if event.get("type") == "progress": + status = event.get("status") + if status == "imported": + any_imported = True + imported_count += 1 + elif status == "error": + error_count += 1 + log.warning("strava-zip[%s]: error on %s: %s", + user.handle, event.get("name"), event.get("detail", "")) if event.get("type") == "done": + log.info("strava-zip[%s]: done — imported=%d errors=%d", + user.handle, imported_count, error_count) if any_imported: merge_all(dd) _trigger_rebuild(user.handle) except Exception as exc: + log.error("strava-zip[%s]: fatal error: %s", user.handle, exc, exc_info=True) yield f"data: {json.dumps({'type': 'error', 'message': str(exc)})}\n\n" finally: zip_path.unlink(missing_ok=True) diff --git a/site/src/pages/admin/index.astro b/site/src/pages/admin/index.astro index 3a977ec..8f6502c 100644 --- a/site/src/pages/admin/index.astro +++ b/site/src/pages/admin/index.astro @@ -31,6 +31,15 @@ import Base from '../../layouts/Base.astro'; + + +
+

Data directory snapshot —

+ +
+

+    
+

Reset all data for ?

@@ -44,10 +53,15 @@ import Base from '../../layouts/Base.astro';