[eric] backend: timestamp each startup background task to pin the cold-start loop stall

- instrumented cold v1.3.88 proved the lifespans are 141ms even cold; the ~18s
  cold gap is a backgrounded create_task blocking the event loop AFTER lifespan
  startup but BEFORE uvicorn reports ready (what the health probe waits on)
- add [perf] entry/segment logs to the post-startup background tasks: mcp refresh,
  skill refresh, 9router ensure (+ prelude bisection), and svc._post/_post_or_spool
- logging only, no behavior change; next cold log names the exact blocking call

backend/apps/mcp_registry/mcp_registry.py

@@ -292,6 +292,7 @@ def _apply_stars(servers: dict[str, dict]):
 async def _refresh_loop():
     """Background loop that refreshes the cache on startup and then hourly."""
     global _cache, _cache_updated_at
+    logger.info("[perf] bg mcp._refresh_loop entered")
     while True:
         try:
             community, google = await asyncio.gather(

backend/apps/nine_router/process.py

@@ -342,9 +342,11 @@ async def ensure_running():
     """Start 9Router if not already running. Serialized so concurrent callers
     (the background auto-start + a dispatch-time ensure) can't double-spawn."""
     global _start_lock
+    logger.info("[perf] bg 9r.ensure_running entered")
     if _start_lock is None:
         _start_lock = asyncio.Lock()
     async with _start_lock:
+        logger.info("[perf] bg 9r.ensure_running past lock")
         await _ensure_running_impl()
 
 
@@ -376,8 +378,10 @@ async def _ensure_running_impl():
         else:
             logger.info("9Router already running on port %d", NINE_ROUTER_PORT)
             return
+    logger.info("[perf] bg 9r past is_running()")
     _9router_dir = _find_9router_dir()
     _patch = _gpt5_patch_path()
+    logger.info("[perf] bg 9r found dir+patch")
 
     if _is_packaged:
         # Packaged: run the pre-built standalone server staged at
@@ -393,6 +397,7 @@ async def _ensure_running_impl():
         if not os.path.exists(standalone_server):
             _report_start_failure("server_missing", router_dir_found=True)
             return
+        logger.info("[perf] bg 9r pre find_node")
         node = _find_node()
         if not node:
             _report_start_failure("node_not_found", router_dir_found=True, server_found=True)

backend/apps/service/client.py

@@ -194,9 +194,12 @@ def _base_url() -> str:
 
 async def _post(path: str, body: dict) -> int | None:
     url = f"{_base_url()}{path}"
+    logger.info("[perf] bg svc._post client-create %s", path)
     try:
         async with httpx.AsyncClient(timeout=_TIMEOUT_SECONDS) as c:
+            logger.info("[perf] bg svc._post sending %s", path)
             r = await c.post(url, json=body)
+        logger.info("[perf] bg svc._post done %s", path)
         return r.status_code
     except Exception as e:
         logger.debug("service POST %s failed: %s", path, e)
@@ -214,6 +217,7 @@ def _retryable(status: int | None) -> bool:
 
 async def _post_or_spool(path: str, body: dict, kind: str) -> None:
     global _inflight
+    logger.info("[perf] bg svc._post_or_spool entered path=%s", path)
     if _test_sink is not None:
         try:
             _test_sink(kind, body)

backend/apps/skill_registry/skill_registry.py

@@ -166,6 +166,7 @@ async def _fetch_all_skills() -> dict[str, dict]:
 
 async def _refresh_loop():
     global _cache, _cache_updated_at
+    logger.info("[perf] bg skill._refresh_loop entered")
     backoff = _RETRY_BACKOFF_START_S
     while True:
         ok = False