Fix delete errors and add startup timing logs

- Wrap delete_player_from_hf and delete_session_from_hf in try/except
so a failed HF folder deletion no longer causes the endpoint to
return 500 after local deletion already succeeded
- Add [SPORALIZE]-prefixed timing logs to startup, weight resolution,
storage sync, and pipeline execution so cold-start slowness is
visible in HF Spaces logs

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>

api.py

@@ -115,6 +115,8 @@ def sync_storage_from_hf(force: bool = False):
         if not force and (now - _storage_last_sync_ts) < STORAGE_SYNC_INTERVAL_SECONDS:
             return
 
+        print(f"[SPORALIZE] Storage sync: downloading from HF repo '{STORAGE_DATASET_REPO_ID}'...", flush=True)
+        t0 = time.time()
         sync_cache_root = os.path.join(RUNTIME_ROOT, "storage-sync-cache")
         os.makedirs(sync_cache_root, exist_ok=True)
         local_repo_dir = os.path.join(sync_cache_root, safe_name(STORAGE_DATASET_REPO_ID))
@@ -133,6 +135,7 @@ def sync_storage_from_hf(force: bool = False):
                 shutil.rmtree(STORAGE_ROOT, ignore_errors=True)
             shutil.copytree(source_storage, STORAGE_ROOT, dirs_exist_ok=True)
         _storage_last_sync_ts = time.time()
+        print(f"[SPORALIZE] Storage sync: done in {time.time() - t0:.1f}s", flush=True)
 
 
 def push_session_to_hf(player_id: str, session_id: str, session_dir: str):
@@ -284,28 +287,36 @@ def load_pipeline_callable(pipeline_root: str):
 def ensure_weight_file(spec: dict, pipeline_root: str):
     override_path = os.environ.get(spec["override_env"])
     if override_path and os.path.isfile(override_path):
+        print(f"[SPORALIZE] Weight '{spec['filename']}': using env override at {override_path}", flush=True)
         return override_path
 
     pipeline_weight = os.path.join(pipeline_root, "Weights", spec["filename"])
     if os.path.isfile(pipeline_weight):
+        print(f"[SPORALIZE] Weight '{spec['filename']}': found in pipeline bundle", flush=True)
         return pipeline_weight
 
     local_fallback = spec.get("local_fallback")
     if local_fallback and os.path.isfile(local_fallback):
+        print(f"[SPORALIZE] Weight '{spec['filename']}': using local fallback at {local_fallback}", flush=True)
         return local_fallback
 
     os.makedirs(WEIGHTS_RUNTIME_ROOT, exist_ok=True)
     cached_path = os.path.join(WEIGHTS_RUNTIME_ROOT, spec["filename"])
     if os.path.isfile(cached_path):
+        print(f"[SPORALIZE] Weight '{spec['filename']}': cache hit at {cached_path}", flush=True)
         return cached_path
 
-    return hf_hub_download(
+    print(f"[SPORALIZE] Weight '{spec['filename']}': not cached, downloading from HF repo '{spec['repo_id']}'...", flush=True)
+    t0 = time.time()
+    result = hf_hub_download(
         repo_id=spec["repo_id"],
         repo_type=spec.get("repo_type", "model"),
         filename=spec["repo_file"],
         token=get_hf_token(),
         local_dir=WEIGHTS_RUNTIME_ROOT,
     )
+    print(f"[SPORALIZE] Weight '{spec['filename']}': downloaded in {time.time() - t0:.1f}s -> {result}", flush=True)
+    return result
 
 
 def ensure_runtime_ready(force: bool = False):
@@ -995,8 +1006,14 @@ def get_cors_origins():
 
 @app.on_event("startup")
 def startup_event():
+    print("[SPORALIZE] Server startup: initializing runtime...", flush=True)
+    t0 = time.time()
     ensure_runtime_ready()
+    print(f"[SPORALIZE] Runtime ready in {time.time() - t0:.1f}s (pipeline_source={runtime_state.get('pipeline_source')})", flush=True)
+    t1 = time.time()
     sync_storage_from_hf(force=True)
+    print(f"[SPORALIZE] Storage sync done in {time.time() - t1:.1f}s", flush=True)
+    print(f"[SPORALIZE] Startup complete in {time.time() - t0:.1f}s total", flush=True)
 
 
 @app.get("/healthz")
@@ -1113,7 +1130,10 @@ def delete_session(session_id: str):
     player_dir = os.path.dirname(session_dir)
     player_id = os.path.basename(player_dir)
     shutil.rmtree(session_dir, ignore_errors=True)
-    delete_session_from_hf(player_id, session_id)
+    try:
+        delete_session_from_hf(player_id, session_id)
+    except Exception:
+        pass
 
     if os.path.isdir(player_dir) and not os.listdir(player_dir):
         os.rmdir(player_dir)
@@ -1128,7 +1148,10 @@ def delete_player(player_id: str):
         raise HTTPException(status_code=404, detail="Player storage not found")
 
     shutil.rmtree(player_dir, ignore_errors=True)
-    delete_player_from_hf(player_id)
+    try:
+        delete_player_from_hf(player_id)
+    except Exception:
+        pass
     return {"status": "deleted", "playerId": player_id}
 
 cors_origins = get_cors_origins()
@@ -1627,7 +1650,8 @@ def run_analysis_job(
 
         ensure_not_cancelled()
 
-        print(f"Starting physical pipeline execution for {session_id}...")
+        print(f"[SPORALIZE] Pipeline start: session={session_id} target_size={target_w}x{target_h} cameras={list(camera_map.keys())}", flush=True)
+        _pipeline_t0 = time.time()
         set_progress(client_id, 20.0, "Extracting 3D Kinematics", status="running", sessionId=session_id)
 
         def progress_tracker(current_act, total_act, step, total_frames):
@@ -1650,6 +1674,7 @@ def run_analysis_job(
             return True
 
         reports = runtime["run_pipeline"](camera_map, utils_paths, sizes, progress_tracker)
+        print(f"[SPORALIZE] Pipeline done: session={session_id} elapsed={time.time() - _pipeline_t0:.1f}s actions={len(reports)}", flush=True)
         ensure_not_cancelled()
 
         set_progress(client_id, 92.0, "Preparing Playback Assets", status="running", sessionId=session_id)