From b8c34afef851b5056505a520b8478c6a56ed0da8 Mon Sep 17 00:00:00 2001 From: Shroominic Date: Thu, 11 Dec 2025 10:50:50 +0800 Subject: [PATCH] improve logging --- routstr/algorithm.py | 12 ------------ routstr/core/db.py | 3 --- routstr/core/logging.py | 10 ++++++++++ routstr/core/main.py | 6 +++--- routstr/payment/price.py | 4 ---- routstr/upstream/base.py | 17 ++--------------- routstr/upstream/helpers.py | 2 +- routstr/upstream/ppqai.py | 18 ------------------ 8 files changed, 16 insertions(+), 56 deletions(-) diff --git a/routstr/algorithm.py b/routstr/algorithm.py index a1b6babd..acd059eb 100644 --- a/routstr/algorithm.py +++ b/routstr/algorithm.py @@ -150,18 +150,6 @@ def should_prefer_model( # Prefer lower adjusted cost should_replace = candidate_adjusted < current_adjusted - # Log provider changes when candidate wins - if should_replace: - candidate_provider_name = getattr( - candidate_provider, "provider_type", "unknown" - ) - current_provider_name = getattr(current_provider, "provider_type", "unknown") - logger.debug( - f"Model selection for alias '{alias}': choosing {candidate_provider_name} " - f"(cost: ${candidate_adjusted:.6f}) over {current_provider_name} " - f"(cost: ${current_adjusted:.6f})" - ) - return should_replace diff --git a/routstr/core/db.py b/routstr/core/db.py index c6effbe3..48cabc07 100644 --- a/routstr/core/db.py +++ b/routstr/core/db.py @@ -126,8 +126,6 @@ def run_migrations() -> None: import pathlib try: - logger.info("Starting database migrations") - # Get the path to the alembic.ini file project_root = pathlib.Path(__file__).resolve().parents[2] alembic_ini_path = project_root / "alembic.ini" @@ -144,7 +142,6 @@ def run_migrations() -> None: alembic_cfg.set_main_option("sqlalchemy.url", DATABASE_URL) # Run migrations to the latest revision - logger.info("Running migrations to latest revision") command.upgrade(alembic_cfg, "head") logger.info("Database migrations completed successfully") diff --git a/routstr/core/logging.py b/routstr/core/logging.py index 65b6a5c0..00474949 100644 --- a/routstr/core/logging.py +++ b/routstr/core/logging.py @@ -338,6 +338,11 @@ def setup_logging() -> None: "handlers": ["console"] if console_enabled else [], "propagate": False, }, + "openai": { + "level": "WARNING", + "handlers": ["console"] if console_enabled else [], + "propagate": False, + }, "httpcore": { "level": "WARNING", "handlers": ["console"] if console_enabled else [], @@ -360,6 +365,11 @@ def setup_logging() -> None: }, "watchfiles.main": {"level": "WARNING", "handlers": [], "propagate": False}, "aiosqlite": {"level": "ERROR", "handlers": [], "propagate": False}, + "alembic": { + "level": "WARNING", + "handlers": ["console"] if console_enabled else [], + "propagate": False, + }, }, "root": { "level": log_level, diff --git a/routstr/core/main.py b/routstr/core/main.py index 06b86d65..d2974d4a 100644 --- a/routstr/core/main.py +++ b/routstr/core/main.py @@ -54,9 +54,6 @@ async def lifespan(_: FastAPI) -> AsyncGenerator[None, None]: try: # Run database migrations on startup - # This ensures the database schema is always up-to-date in production - # Migrations are idempotent - running them multiple times is safe - logger.info("Running database migrations") run_migrations() # Initialize database connection pools @@ -104,6 +101,9 @@ async def lifespan(_: FastAPI) -> AsyncGenerator[None, None]: yield + except asyncio.CancelledError: + # Expected during shutdown + pass except Exception as e: logger.error( "Application startup failed", diff --git a/routstr/payment/price.py b/routstr/payment/price.py index c20ac34e..9011ce1d 100644 --- a/routstr/payment/price.py +++ b/routstr/payment/price.py @@ -110,10 +110,6 @@ async def _update_prices() -> None: return BTC_USD_PRICE = btc_price SATS_USD_PRICE = btc_price / 100_000_000 - logger.info( - "Updated BTC/USD price", - extra={"btc_usd": btc_price, "sats_usd": SATS_USD_PRICE}, - ) def btc_usd_price() -> float: diff --git a/routstr/upstream/base.py b/routstr/upstream/base.py index 64eb6a4c..7726b5f6 100644 --- a/routstr/upstream/base.py +++ b/routstr/upstream/base.py @@ -1726,7 +1726,6 @@ class BaseUpstreamProvider: Returns: List of Model objects with pricing """ - logger.debug(f"Fetching models for {self.provider_type or self.base_url}") try: or_models, provider_models_response = await asyncio.gather( @@ -1753,18 +1752,9 @@ class BaseUpstreamProvider: else: not_found_models.append(model_id) - logger.info( - "Fetched models for provider", - extra={ - "provider": self.provider_type or self.base_url, - "found_count": len(found_models), - "not_found_count": len(not_found_models), - }, - ) - if not_found_models: logger.debug( - "Models not found in OpenRouter", + f"({len(not_found_models)}/{len(provider_model_ids)}) unmatched models for {self.provider_type or self.base_url}", extra={"not_found_models": not_found_models}, ) @@ -1832,10 +1822,7 @@ class BaseUpstreamProvider: self._models_cache = models_with_fees self._models_by_id = {m.id: m for m in self._models_cache} - logger.info( - f"Refreshed models cache for {self.provider_type or self.base_url}", - extra={"model_count": len(models)}, - ) + except Exception as e: logger.error( f"Failed to refresh models cache for {self.provider_type or self.base_url}", diff --git a/routstr/upstream/helpers.py b/routstr/upstream/helpers.py index 3d91550f..b453af1f 100644 --- a/routstr/upstream/helpers.py +++ b/routstr/upstream/helpers.py @@ -193,7 +193,7 @@ async def init_upstreams() -> list[BaseUpstreamProvider]: if provider: await provider.refresh_models_cache() upstreams.append(provider) - logger.info( + logger.debug( f"Initialized {provider_row.provider_type} provider", extra={ "base_url": provider_row.base_url, diff --git a/routstr/upstream/ppqai.py b/routstr/upstream/ppqai.py index 24013edb..0b4dfb08 100644 --- a/routstr/upstream/ppqai.py +++ b/routstr/upstream/ppqai.py @@ -102,11 +102,6 @@ class PPQAIUpstreamProvider(BaseUpstreamProvider): url = f"{self.base_url}/models" headers = {"Authorization": f"Bearer {self.api_key}"} - logger.debug( - "Fetching models from PPQ.AI", - extra={"url": url, "has_api_key": bool(self.api_key)}, - ) - try: async with httpx.AsyncClient(timeout=30.0) as client: response = await client.get(url, headers=headers) @@ -114,10 +109,6 @@ class PPQAIUpstreamProvider(BaseUpstreamProvider): data = response.json() models_data = data.get("data", []) - logger.info( - "Fetched models from PPQ.AI", - extra={"model_count": len(models_data)}, - ) or_models = [ Model(**model) # type: ignore @@ -198,15 +189,6 @@ class PPQAIUpstreamProvider(BaseUpstreamProvider): return models - except httpx.HTTPStatusError as e: - logger.error( - "HTTP error fetching models from PPQ.AI", - extra={ - "status_code": e.response.status_code, - "error": str(e), - }, - ) - return [] except Exception as e: logger.error( "Error fetching models from PPQ.AI",