Log refresh-cycle steps and snapshot-rebuild phases

backend/app/routers/runs.py

@@ -1182,6 +1182,11 @@ def _run_refresh_cycle() -> None:
         )
         from ..services.run_entity_stats import refresh_entity_stats_snapshot
 
+        # Per-step timing: a rebuild that never completes shows up here as a step
+        # whose "done" log never arrives, so we can see which step starves it.
+        _cyc0 = time.time()
+        logger.info("refresh cycle: starting (leader)")
+
         # Warm the /charts page FIRST so the default no-filter view of each chart
         # is in Redis within seconds of a deploy, instead of waiting behind the
         # entity-stats snapshot walk below (which can run for minutes). Frame
@@ -1194,11 +1199,13 @@ def _run_refresh_cycle() -> None:
                 prewarm_charts()
         except Exception:
             logger.warning("charts prewarm failed", exc_info=True)
+        logger.info("refresh cycle: charts prewarm done at %.1fs", time.time() - _cyc0)
 
         try:
             refresh_stats_summary()
         except Exception:
             logger.warning("stats summary refresh failed", exc_info=True)
+        logger.info("refresh cycle: stats summary done at %.1fs", time.time() - _cyc0)
         # Pre-compute the default (category, character) ladder
         # views into leaderboard_summary. Reads for the common
         # combos become O(1) find_one instead of a 500ms
@@ -1207,6 +1214,11 @@ def _run_refresh_cycle() -> None:
             refresh_leaderboard_summary()
         except Exception:
             logger.warning("leaderboard summary refresh failed", exc_info=True)
+        logger.info(
+            "refresh cycle: leaderboard summary done at %.1fs, entering snapshot "
+            "rebuild",
+            time.time() - _cyc0,
+        )
         # Rebuild the shared entity-stats snapshot (tier-list
         # / Codex Score source) on the same leader-only loop.
         # Internally throttled, so this is a no-op find_one

backend/app/services/run_entity_stats.py

@@ -839,6 +839,12 @@ def _build_cache_data() -> tuple[dict, dict, dict, dict]:
     (solo/2p/3p/4p/a10/daily/custom); those land nested under each entity's
     ``brackets`` key, and `bracket_meta` carries their baselines + totals.
     """
+    # Phase timing so a stalled rebuild is diagnosable from the logs (the walk is
+    # otherwise silent until it completes). Which phase the last log names tells
+    # us where a rebuild that never finishes is stuck.
+    _t0 = time.time()
+    logger.info("snapshot rebuild: starting (loading run rows from the DB)")
+
     new_cache: dict[tuple[str, str], dict[str, Any]] = {}
     new_totals = {"total_runs": 0, "total_wins": 0}
 
@@ -909,6 +915,12 @@ def _build_cache_data() -> tuple[dict, dict, dict, dict]:
             ).fetchall()
             rows = [dict(r) for r in rows]
 
+    logger.info(
+        "snapshot rebuild: loaded %d run rows in %.1fs, now walking blob files",
+        len(rows),
+        time.time() - _t0,
+    )
+
     official_chars = _official_character_ids()
 
     # Per-username overall win rate (fraction, 5-run floor) for the skill-bracket
@@ -1222,6 +1234,13 @@ def _build_cache_data() -> tuple[dict, dict, dict, dict]:
                     skipped_ids,
                 )
 
+    logger.info(
+        "snapshot rebuild: blob walk done in %.1fs (%d entities), finalizing "
+        "(Codex Elo fits + bracket serialization)",
+        time.time() - _t0,
+        len(new_cache),
+    )
+
     # Fold the card-reward pick stats + fitted Codex Elo into the cache.
     # Cards that were offered but never decked still get an entry (picks=0
     # → no Win%/Score, but a valid Pick%/Elo). Starter cards that are