diff --git a/api/app.py b/api/app.py index 672c367..14df8d8 100644 --- a/api/app.py +++ b/api/app.py @@ -20,7 +20,7 @@ from api.metrics_guard import MetricsGuardMiddleware from api.security_headers import SecurityHeadersMiddleware from api.origin_validator import OriginValidatorMiddleware from dotenv import load_dotenv -from fastapi import Depends, FastAPI, HTTPException, Query +from fastapi import Depends, FastAPI, HTTPException, Query, Response from fastapi.responses import JSONResponse, StreamingResponse from pydantic import BaseModel from starlette.requests import Request @@ -151,9 +151,11 @@ async def unhandled_exception_handler(request: Request, exc: Exception) -> JSONR @app.get("/api/status") -async def get_status() -> dict[str, str | None]: +async def get_status(response: Response) -> dict[str, str | None]: + t0 = time.monotonic() repository = ListingRepository(engine) last_updated = repository.get_last_updated() + response.headers["Server-Timing"] = f"db_query;dur={(time.monotonic() - t0) * 1000:.1f}" return { "status": "OK", "last_updated": last_updated.isoformat() if last_updated else None, @@ -163,12 +165,15 @@ async def get_status() -> dict[str, str | None]: @app.get("/api/listing") async def get_listing( user: Annotated[User, Depends(get_current_user)], + response: Response, limit: int = 5, ) -> dict[str, list]: """Get listings from the database.""" limit = min(limit, _rate_limit_config.listing_limit_cap) repository = ListingRepository(engine) + t0 = time.monotonic() result = await listing_service.get_listings(repository, limit=limit) + response.headers["Server-Timing"] = f"get_listings;dur={(time.monotonic() - t0) * 1000:.1f}" logger.info(f"Fetched {result.total_count} listings for {user.email}") return {"listings": result.listings} @@ -177,23 +182,30 @@ async def get_listing( async def get_listing_geojson( user: Annotated[User, Depends(get_current_user)], query_parameters: Annotated[QueryParameters, Depends(get_query_parameters)], + response: Response, limit: int | None = None, decision_filter: str = "all", ) -> dict: """Get listings as GeoJSON for map display.""" + timings: list[str] = [] + t0_total = time.monotonic() + if limit is not None: limit = min(limit, _rate_limit_config.geojson_limit_cap) else: limit = _rate_limit_config.geojson_limit_cap repository = ListingRepository(engine) + t0 = time.monotonic() result = await export_service.export_to_geojson( repository, query_parameters=query_parameters, limit=limit, ) + timings.append(f"export_geojson;dur={(time.monotonic() - t0) * 1000:.1f}") # Apply decision filtering if decision_filter != "everything": + t0 = time.monotonic() user_id = _get_user_id_safe(user.email) if user_id is not None: decision_repo = DecisionRepository(engine) @@ -208,7 +220,10 @@ async def get_listing_geojson( ) ] result.data["features"] = features + timings.append(f"decision_filter;dur={(time.monotonic() - t0) * 1000:.1f}") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return result.data @@ -525,7 +540,12 @@ async def stream_listing_geojson( timings: list[str] = [] # Build POI distances lookup if requested - poi_distances_lookup = _build_poi_distances_lookup(user.email, query_parameters.listing_type) if include_poi_distances else None + if include_poi_distances: + t0 = time.monotonic() + poi_distances_lookup = _build_poi_distances_lookup(user.email, query_parameters.listing_type) + timings.append(f"poi_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") + else: + poi_distances_lookup = None t0 = time.monotonic() cached_count = get_cached_count(query_parameters) @@ -533,7 +553,10 @@ async def stream_listing_geojson( if cached_count is not None and cached_count > 0 and not include_poi_distances: app_metrics.geojson_cache_operations.add(1, {"result": "hit"}) + t0 = time.monotonic() stale = is_cache_stale(query_parameters) + timings.append(f"stale_check;dur={(time.monotonic() - t0) * 1000:.1f}") + timings.append('source;desc="cache"') if stale: app_metrics.cache_stale_serves_total.add(1) # Fire-and-forget background repopulation @@ -549,6 +572,7 @@ async def stream_listing_geojson( ) else: app_metrics.geojson_cache_operations.add(1, {"result": "miss"}) + timings.append('source;desc="db"') generator = _instrumented_stream( _stream_from_db( query_parameters, batch_size, limit, poi_distances_lookup, @@ -696,9 +720,13 @@ class ListingDetailResponse(BaseModel): async def get_listing_detail( user: Annotated[User, Depends(get_current_user)], listing_id: int, + response: Response, listing_type: str = Query(default="RENT"), ) -> ListingDetailResponse: """Get detailed information for a single listing.""" + timings: list[str] = [] + t0_total = time.monotonic() + repository = ListingRepository(engine) lt = ListingType(listing_type) t_step = time.monotonic() @@ -708,10 +736,12 @@ async def get_listing_detail( app_metrics.listing_detail_step_duration_seconds.record( time.monotonic() - t_step, {"step": "fetch_listing"} ) + timings.append(f"fetch_listing;dur={(time.monotonic() - t_step) * 1000:.1f}") if not listings: raise HTTPException(status_code=404, detail="Listing not found") listing = listings[0] + t_parse = time.monotonic() additional_info = listing.additional_info or {} property_info = additional_info.get("property", {}) @@ -782,6 +812,7 @@ async def get_listing_detail( furnish_type_val = str(ft) # Load user's decision for this listing + timings.append(f"parse_detail;dur={(time.monotonic() - t_parse) * 1000:.1f}") t_step = time.monotonic() decision_val: str | None = None user_id = _get_user_id_safe(user.email) @@ -795,6 +826,7 @@ async def get_listing_detail( app_metrics.listing_detail_step_duration_seconds.record( time.monotonic() - t_step, {"step": "load_decision"} ) + timings.append(f"load_decision;dur={(time.monotonic() - t_step) * 1000:.1f}") # Load POI distances t_step = time.monotonic() @@ -818,6 +850,9 @@ async def get_listing_detail( app_metrics.listing_detail_step_duration_seconds.record( time.monotonic() - t_step, {"step": "load_poi_distances"} ) + timings.append(f"load_poi_distances;dur={(time.monotonic() - t_step) * 1000:.1f}") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return ListingDetailResponse( id=listing.id, diff --git a/api/decision_routes.py b/api/decision_routes.py index e698625..db902d3 100644 --- a/api/decision_routes.py +++ b/api/decision_routes.py @@ -1,7 +1,8 @@ import logging +import time from typing import Annotated -from fastapi import APIRouter, Depends, HTTPException, Query +from fastapi import APIRouter, Depends, HTTPException, Query, Response from pydantic import BaseModel, Field from api.auth import User, get_current_user @@ -55,11 +56,17 @@ async def set_decision( user: Annotated[User, Depends(get_current_user)], listing_id: int, body: SetDecisionRequest, + response: Response, ) -> DecisionResponse: """Set or update a like/dislike decision for a listing.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = DecisionRepository(engine) try: + t0 = time.monotonic() result = decision_service.set_decision( repo, user_id=user_id, @@ -67,19 +74,31 @@ async def set_decision( listing_type=body.listing_type, decision=body.decision, ) + timings.append(f"upsert;dur={(time.monotonic() - t0) * 1000:.1f}") except ValueError as e: raise HTTPException(status_code=400, detail=str(e)) + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return _to_response(result) @decision_router.get("", response_model=list[DecisionResponse]) async def get_decisions( user: Annotated[User, Depends(get_current_user)], + response: Response, ) -> list[DecisionResponse]: """Get all decisions for the current user.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = DecisionRepository(engine) + t0 = time.monotonic() decisions = decision_service.get_user_decisions(repo, user_id) + timings.append(f"fetch;dur={(time.monotonic() - t0) * 1000:.1f}") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return [_to_response(d) for d in decisions] @@ -87,17 +106,26 @@ async def get_decisions( async def delete_decision( user: Annotated[User, Depends(get_current_user)], listing_id: int, + response: Response, listing_type: str = Query(..., description="RENT or BUY"), ) -> dict[str, bool]: """Remove a decision (un-like/un-dislike).""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = DecisionRepository(engine) try: + t0 = time.monotonic() deleted = decision_service.remove_decision( repo, user_id, listing_id, listing_type ) + timings.append(f"delete;dur={(time.monotonic() - t0) * 1000:.1f}") except ValueError as e: raise HTTPException(status_code=400, detail=str(e)) if not deleted: raise HTTPException(status_code=404, detail="Decision not found") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return {"success": True} diff --git a/api/poi_routes.py b/api/poi_routes.py index 8d2c256..6f7ed97 100644 --- a/api/poi_routes.py +++ b/api/poi_routes.py @@ -1,7 +1,8 @@ import logging +import time from typing import Annotated -from fastapi import APIRouter, Depends, HTTPException +from fastapi import APIRouter, Depends, HTTPException, Response from pydantic import BaseModel, Field from api.auth import User, get_current_user @@ -79,11 +80,20 @@ def _poi_to_response(poi: "poi_service.PointOfInterest") -> POIResponse: @poi_router.get("", response_model=list[POIResponse]) async def list_pois( user: Annotated[User, Depends(get_current_user)], + response: Response, ) -> list[POIResponse]: """List all POIs for the current user.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) + t0 = time.monotonic() pois = poi_service.get_user_pois(repo, user_id) + timings.append(f"fetch_pois;dur={(time.monotonic() - t0) * 1000:.1f}") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return [_poi_to_response(p) for p in pois] @@ -91,10 +101,16 @@ async def list_pois( async def create_poi( user: Annotated[User, Depends(get_current_user)], body: CreatePOIRequest, + response: Response, ) -> POIResponse: """Create a new POI.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) + t0 = time.monotonic() result = poi_service.create_poi( repo, user_id=user_id, @@ -103,6 +119,9 @@ async def create_poi( latitude=body.latitude, longitude=body.longitude, ) + timings.append(f"create;dur={(time.monotonic() - t0) * 1000:.1f}") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return _poi_to_response(result.poi) @@ -111,10 +130,16 @@ async def update_poi( user: Annotated[User, Depends(get_current_user)], poi_id: int, body: UpdatePOIRequest, + response: Response, ) -> POIResponse: """Update an existing POI.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) + t0 = time.monotonic() result = poi_service.update_poi( repo, poi_id=poi_id, @@ -124,8 +149,11 @@ async def update_poi( latitude=body.latitude, longitude=body.longitude, ) + timings.append(f"update;dur={(time.monotonic() - t0) * 1000:.1f}") if result is None: raise HTTPException(status_code=404, detail="POI not found") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return _poi_to_response(result.poi) @@ -133,13 +161,22 @@ async def update_poi( async def delete_poi( user: Annotated[User, Depends(get_current_user)], poi_id: int, + response: Response, ) -> dict[str, bool]: """Delete a POI and its associated distances.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) + t0 = time.monotonic() deleted = poi_service.delete_poi(repo, poi_id, user_id) + timings.append(f"delete;dur={(time.monotonic() - t0) * 1000:.1f}") if not deleted: raise HTTPException(status_code=404, detail="POI not found") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return {"success": True} @@ -148,16 +185,24 @@ async def calculate_distances( user: Annotated[User, Depends(get_current_user)], poi_id: int, body: CalculateRequest, + response: Response, ) -> dict[str, str]: """Trigger distance calculation for a POI.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) # Verify POI exists and belongs to user + t0 = time.monotonic() poi = poi_service.get_poi(repo, poi_id) if poi is None or poi.user_id != user_id: raise HTTPException(status_code=404, detail="POI not found") + timings.append(f"verify_poi;dur={(time.monotonic() - t0) * 1000:.1f}") + t0 = time.monotonic() result = poi_service.trigger_calculation( poi_id=poi_id, travel_modes=body.travel_modes, @@ -165,33 +210,51 @@ async def calculate_distances( user_email=user.email, listing_ids=body.listing_ids, ) + timings.append(f"trigger;dur={(time.monotonic() - t0) * 1000:.1f}") if result.task_id: task_service.add_task_for_user(user.email, result.task_id) + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return {"task_id": result.task_id or "", "message": result.message} @poi_router.get("/distances/bulk") async def get_bulk_distances( user: Annotated[User, Depends(get_current_user)], + response: Response, listing_type: ListingType = ListingType.RENT, ) -> dict[int, list[POIDistanceResponse]]: """Get all POI distances for the current user, keyed by listing ID.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) + t0 = time.monotonic() pois = {p.id: p for p in poi_service.get_user_pois(repo, user_id)} + timings.append(f"fetch_pois;dur={(time.monotonic() - t0) * 1000:.1f}") if not pois: + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return {} from repositories.listing_repository import ListingRepository from database import engine as db_engine listing_repo = ListingRepository(db_engine) + t0 = time.monotonic() all_ids = list(listing_repo.get_listing_ids(listing_type)) + timings.append(f"fetch_ids;dur={(time.monotonic() - t0) * 1000:.1f}") if not all_ids: + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return {} + t0 = time.monotonic() distances = repo.get_distances_for_listings(all_ids, listing_type, user_id) + timings.append(f"fetch_distances;dur={(time.monotonic() - t0) * 1000:.1f}") result: dict[int, list[POIDistanceResponse]] = {} for d in distances: @@ -205,6 +268,8 @@ async def get_bulk_distances( distance_meters=d.distance_meters, ) ) + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return result @@ -212,19 +277,30 @@ async def get_bulk_distances( async def get_distances( user: Annotated[User, Depends(get_current_user)], listing_id: int, + response: Response, listing_type: ListingType = ListingType.RENT, ) -> list[POIDistanceResponse]: """Get POI distances for a specific listing.""" + timings: list[str] = [] + t0_total = time.monotonic() + t0 = time.monotonic() user_id = _get_user_id(user) + timings.append(f"user_lookup;dur={(time.monotonic() - t0) * 1000:.1f}") repo = POIRepository(engine) + t0 = time.monotonic() poi_repo_pois = { p.id: p for p in poi_service.get_user_pois(repo, user_id) } + timings.append(f"fetch_pois;dur={(time.monotonic() - t0) * 1000:.1f}") + t0 = time.monotonic() distances = poi_service.get_distances_for_listing( repo, listing_id, listing_type, user_id ) + timings.append(f"fetch_distances;dur={(time.monotonic() - t0) * 1000:.1f}") + timings.append(f"total;dur={(time.monotonic() - t0_total) * 1000:.1f}") + response.headers["Server-Timing"] = ", ".join(timings) return [ POIDistanceResponse( poi_id=d.poi_id, diff --git a/grafana/dashboard.json b/grafana/dashboard.json index 834b006..0735da7 100644 --- a/grafana/dashboard.json +++ b/grafana/dashboard.json @@ -3531,6 +3531,133 @@ ], "title": "Listing Detail Load Time", "type": "stat" + }, + { + "collapsed": false, + "gridPos": { "h": 1, "w": 24, "x": 0, "y": 115 }, + "id": 250, + "panels": [], + "title": "Per-Endpoint Latency Comparison", + "type": "row" + }, + { + "datasource": { "type": "prometheus", "uid": "PBFA97CFB590B2093" }, + "description": "p50 and p95 request latency per endpoint", + "fieldConfig": { + "defaults": { + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "drawStyle": "line", + "fillOpacity": 10, + "gradientMode": "none", + "hideFrom": { "legend": false, "tooltip": false, "viz": false }, + "insertNulls": false, + "lineInterpolation": "smooth", + "lineWidth": 2, + "pointSize": 5, + "scaleDistribution": { "type": "linear" }, + "showPoints": "auto", + "spanNulls": false, + "stacking": { "group": "A", "mode": "none" }, + "thresholdsStyle": { "mode": "off" } + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { "color": "green", "value": null }, + { "color": "yellow", "value": 500 }, + { "color": "red", "value": 2000 } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { "h": 10, "w": 16, "x": 0, "y": 116 }, + "id": 251, + "options": { + "legend": { "calcs": ["mean", "max"], "displayMode": "table", "placement": "bottom" }, + "tooltip": { "mode": "multi", "sort": "desc" } + }, + "pluginVersion": "12.3.0", + "targets": [ + { + "datasource": { "type": "prometheus", "uid": "PBFA97CFB590B2093" }, + "editorMode": "code", + "expr": "histogram_quantile(0.50, sum by (le, http_route) (rate(http_server_duration_milliseconds_bucket{job=\"realestate-crawler-api\"}[5m])))", + "legendFormat": "p50 {{http_route}}", + "range": true, + "refId": "A" + }, + { + "datasource": { "type": "prometheus", "uid": "PBFA97CFB590B2093" }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum by (le, http_route) (rate(http_server_duration_milliseconds_bucket{job=\"realestate-crawler-api\"}[5m])))", + "legendFormat": "p95 {{http_route}}", + "range": true, + "refId": "B" + } + ], + "title": "Endpoint Latency p50/p95", + "type": "timeseries" + }, + { + "datasource": { "type": "prometheus", "uid": "PBFA97CFB590B2093" }, + "description": "p95 latency per endpoint, sorted descending", + "fieldConfig": { + "defaults": { + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { "color": "green", "value": null }, + { "color": "yellow", "value": 500 }, + { "color": "red", "value": 2000 } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { "h": 10, "w": 8, "x": 16, "y": 116 }, + "id": 252, + "options": { + "displayMode": "gradient", + "maxVizHeight": 300, + "minVizHeight": 16, + "minVizWidth": 8, + "namePlacement": "auto", + "orientation": "horizontal", + "reduceOptions": { "calcs": ["lastNotNull"], "fields": "", "values": false }, + "showUnfilled": true, + "sizing": "auto", + "valueMode": "color" + }, + "pluginVersion": "12.3.0", + "targets": [ + { + "datasource": { "type": "prometheus", "uid": "PBFA97CFB590B2093" }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum by (le, http_route) (rate(http_server_duration_milliseconds_bucket{job=\"realestate-crawler-api\"}[5m])))", + "legendFormat": "{{http_route}}", + "instant": true, + "refId": "A" + } + ], + "title": "Endpoint Latency Ranking (p95)", + "transformations": [ + { + "id": "sortBy", + "options": { "fields": {}, "sort": [{ "desc": true, "field": "Value" }] } + } + ], + "type": "bargauge" } ], "preload": false,