diff --git a/backend/app/api/deps.py b/backend/app/api/deps.py index 4f9c8b44b..a84c3c33d 100644 --- a/backend/app/api/deps.py +++ b/backend/app/api/deps.py @@ -15,7 +15,7 @@ from app.core.config import settings from app.core.db import engine from app.core.security import api_key_manager -from app.core.telemetry import set_request_log_context +from app.core.telemetry import bind_sentry_user, set_request_log_context from app.crud.organization import validate_organization from app.crud.project import validate_project from app.models import ( @@ -45,13 +45,7 @@ def get_db() -> Generator[Session, None, None]: def _set_tenant_span_attributes(auth_context: AuthContext) -> None: - """Tag the active OTel span and log context with tenant info after auth. - - Sets org/project on: - - OTel span → Sentry traces filterable by tenant - - log context → every log record in this request carries org_id/project_id - - Sentry scope → tags on all events for this request - """ + """Stamp org/project on the span, log context and Sentry scope after auth.""" span = trace.get_current_span() if span.is_recording(): span.set_attribute("user.id", str(auth_context.user.id)) @@ -60,10 +54,10 @@ def _set_tenant_span_attributes(auth_context: AuthContext) -> None: if auth_context.project: span.set_attribute("tenant.project_id", auth_context.project.id) - set_request_log_context( - org_id=auth_context.organization.id if auth_context.organization else None, - project_id=auth_context.project.id if auth_context.project else None, - ) + org_id = auth_context.organization.id if auth_context.organization else None + project_id = auth_context.project.id if auth_context.project else None + set_request_log_context(org_id=org_id, project_id=project_id) + bind_sentry_user(user_id=auth_context.user.id, org_id=org_id, project_id=project_id) def _authenticate_with_jwt(session: Session, token: str) -> AuthContext: diff --git a/backend/app/celery/celery_app.py b/backend/app/celery/celery_app.py index c563277e1..a98d133f8 100644 --- a/backend/app/celery/celery_app.py +++ b/backend/app/celery/celery_app.py @@ -2,18 +2,17 @@ from celery import Celery from celery.signals import ( - worker_init, + setup_logging, task_failure, task_postrun, task_prerun, - setup_logging, + worker_init, worker_process_init, ) from kombu import Exchange, Queue from app.core.config import settings from app.core.logger import configure_logging -from app.core.sentry_filters import before_send_filter, before_send_transaction_filter logger = logging.getLogger(__name__) _telemetry_initialized = False @@ -35,37 +34,25 @@ def _initialize_worker_observability() -> None: import sentry_sdk from sentry_sdk.integrations.celery import CeleryIntegration from sentry_sdk.integrations.httpx import HttpxIntegration - from sentry_sdk.integrations.logging import LoggingIntegration from sentry_sdk.integrations.sqlalchemy import SqlalchemyIntegration - sentry_sdk.init( - dsn=str(settings.SENTRY_DSN), - environment=settings.ENVIRONMENT, - release=settings.API_VERSION, - instrumenter="otel", - traces_sample_rate=1.0, - max_request_body_size="never", - enable_logs=True, - before_send=before_send_filter, - before_send_transaction=before_send_transaction_filter, + from app.core.telemetry import init_sentry + + init_sentry( integrations=[ - LoggingIntegration( - level=logging.INFO, - sentry_logs_level=logging.INFO, - ), - CeleryIntegration( - propagate_traces=False, - monitor_beat_tasks=False, - ), - ], - disabled_integrations=[ - SqlalchemyIntegration(), - HttpxIntegration(), + CeleryIntegration(propagate_traces=True, monitor_beat_tasks=False) ], + disabled_integrations=[SqlalchemyIntegration(), HttpxIntegration()], ) + + @task_prerun.connect(weak=False) + def _tag_sentry_task(task: "celery.Task", **_: object) -> None: # type: ignore[name-defined] + """Tag the task's Sentry scope with its name so Issues can be filtered by task.""" + sentry_sdk.set_tag("celery.task_name", task.name) + _sentry_initialized = True - if not _telemetry_initialized: + if settings.OTEL_ENABLED and not _telemetry_initialized: from app.core.telemetry import flush_telemetry, setup_telemetry setup_telemetry(service_name="kaapi-celery") @@ -88,9 +75,10 @@ def log_pool_status(task: "celery.Task", **_: object) -> None: # type: ignore[n If checked_out equals pool size right when a task starts, connections are being held across tasks (likely across LLM API calls) and leaking. """ - from app.core.db import engine from sqlalchemy.pool import QueuePool + from app.core.db import engine + pool = engine.pool if isinstance(pool, QueuePool): logger.info( @@ -106,9 +94,10 @@ def log_pool_status_post(task: "celery.Task", **_: object) -> None: # type: ign Compare with task_prerun log — if checked_out is the same or higher after the task, connections were not returned and are leaking. """ - from app.core.db import engine from sqlalchemy.pool import QueuePool + from app.core.db import engine + pool = engine.pool if isinstance(pool, QueuePool): logger.info( @@ -126,9 +115,10 @@ def log_pool_status_failure( Failures are the most likely path for sessions to leak — exceptions can bypass session cleanup if not guarded by a context manager. """ - from app.core.db import engine from sqlalchemy.pool import QueuePool + from app.core.db import engine + pool = engine.pool if isinstance(pool, QueuePool): logger.warning( diff --git a/backend/app/celery/tasks/job_execution.py b/backend/app/celery/tasks/job_execution.py index 483384364..1288876a8 100644 --- a/backend/app/celery/tasks/job_execution.py +++ b/backend/app/celery/tasks/job_execution.py @@ -26,6 +26,7 @@ from app.celery.celery_app import celery_app from app.celery.utils import gevent_timeout from app.core.config import settings +from app.core.telemetry import LogModuleEnum, log_context if TYPE_CHECKING: from app.services.notifications.eval_completion import ( @@ -41,6 +42,8 @@ # app/core/logger.py and app/celery/utils.py). DEFAULT_TRACE_ID = "N/A" +SENTRY_NO_PROPAGATE_HEADERS: dict[str, bool] = {"sentry-propagate-traces": False} + def _set_trace(trace_id: str) -> None: correlation_id.set(trace_id) @@ -403,6 +406,7 @@ def run_assessment_api_batch( "trace_id": trace_id, }, countdown=POLL_COUNTDOWN_SECONDS, + headers=SENTRY_NO_PROPAGATE_HEADERS.copy(), ) return result @@ -451,12 +455,13 @@ def run_evaluation_fast_chunk( f"task_id={current_task.request.id}" ) - return _run_with_otel_parent( - self, - lambda: execute_fast_evaluation_chunk( - eval_run_id=eval_run_id, chunk_index=chunk_index - ), - ) + with log_context(module=LogModuleEnum.FASTEVALS): + return _run_with_otel_parent( + self, + lambda: execute_fast_evaluation_chunk( + eval_run_id=eval_run_id, chunk_index=chunk_index + ), + ) @celery_app.task(bind=True, queue="default", priority=6) @@ -478,10 +483,11 @@ def run_evaluation_fast_aggregate( f"eval_run_id={eval_run_id} | task_id={current_task.request.id}" ) - return _run_with_otel_parent( - self, - lambda: execute_fast_evaluation_aggregate(eval_run_id=eval_run_id), - ) + with log_context(module=LogModuleEnum.FASTEVALS): + return _run_with_otel_parent( + self, + lambda: execute_fast_evaluation_aggregate(eval_run_id=eval_run_id), + ) # Priority 6 (fast-eval tier): same band as run_prompt_improvement — one graph diff --git a/backend/app/core/config.py b/backend/app/core/config.py index 809f872c6..7bf84205b 100644 --- a/backend/app/core/config.py +++ b/backend/app/core/config.py @@ -6,6 +6,7 @@ from pydantic import ( EmailStr, + Field, HttpUrl, PostgresDsn, computed_field, @@ -158,6 +159,12 @@ def AWS_S3_BUCKET(self) -> str: BACKEND_SERVICE_NAME: str = "kaapi-backend" CRON_SERVICE_NAME: str = "kaapi-cron" + SENTRY_TRACES_SAMPLE_RATE: float = Field(default=1.0, ge=0.0, le=1.0) + SENTRY_SEND_DEFAULT_PII: bool = False + SENTRY_ERROR_SAMPLE_RATE: float = Field(default=1.0, ge=0.0, le=1.0) + SENTRY_PROFILE_SESSION_SAMPLE_RATE: float = Field(default=1.0, ge=0.0, le=1.0) + SENTRY_PROFILE_LIFECYCLE: Literal["manual", "trace"] = "trace" + # Threshold Request Rate per minute THRESHOLD_LLM_CALL_RATE: int = 15 THRESHOLD_COLLECTIONS_RATE: int = 3 diff --git a/backend/app/core/db.py b/backend/app/core/db.py index 9f81df5a4..ffce68da5 100644 --- a/backend/app/core/db.py +++ b/backend/app/core/db.py @@ -1,6 +1,7 @@ from sqlmodel import Session, create_engine, select from app import crud +from app.core.config import settings from app.core.telemetry import instrument_db_engine from app.models import User, UserCreate @@ -33,7 +34,8 @@ def get_engine(): # Create a default engine for backward compatibility engine = get_engine() -instrument_db_engine(engine) +if settings.OTEL_ENABLED: + instrument_db_engine(engine) # make sure all SQLModel models are imported (app.models) before initializing DB diff --git a/backend/app/core/exception_handlers.py b/backend/app/core/exception_handlers.py index 4d1e4d747..c0d2653a5 100644 --- a/backend/app/core/exception_handlers.py +++ b/backend/app/core/exception_handlers.py @@ -1,6 +1,7 @@ import re from collections import defaultdict +import sentry_sdk from fastapi import FastAPI, Request, HTTPException from fastapi.exceptions import RequestValidationError from fastapi.responses import JSONResponse @@ -109,6 +110,7 @@ async def http_exception_handler( @app.exception_handler(Exception) async def generic_error_handler(request: Request, exc: Exception) -> JSONResponse: + sentry_sdk.capture_exception(exc) return JSONResponse( status_code=HTTP_500_INTERNAL_SERVER_ERROR, content=APIResponse.failure_response( diff --git a/backend/app/core/langfuse/langfuse.py b/backend/app/core/langfuse/langfuse.py index 9668924b6..27d5e0224 100644 --- a/backend/app/core/langfuse/langfuse.py +++ b/backend/app/core/langfuse/langfuse.py @@ -321,9 +321,6 @@ def wrapper( completion_config: NativeCompletionConfig, query: QueryParams, **kwargs ): if not credentials: - logger.info( - "[observe_llm_execution] No credentials - skipping observability" - ) return func(completion_config, query, **kwargs) try: diff --git a/backend/app/core/logger.py b/backend/app/core/logger.py index 8a1ffe441..113615e63 100644 --- a/backend/app/core/logger.py +++ b/backend/app/core/logger.py @@ -8,6 +8,7 @@ from asgi_correlation_id import correlation_id from app.core.config import settings +from app.core.telemetry.context import LogContextFilter LOG_DIR = settings.LOG_DIR os.makedirs(LOG_DIR, exist_ok=True) @@ -17,7 +18,7 @@ LOGGING_LEVEL = logging.INFO LOGGING_FORMAT = ( "%(asctime)s - [%(service_name)s] - [%(correlation_id)s] - " - "%(levelname)s - %(name)s - %(message)s" + "%(levelname)s - %(_log_location)s - %(message)s" ) _service_name_context: ContextVar[str | None] = ContextVar( "kaapi_service_name", default=None @@ -102,6 +103,7 @@ def configure_logging(service_name: str | None = None) -> None: stream_handler.setFormatter(formatter) stream_handler.addFilter(CorrelationIdFilter()) stream_handler.addFilter(ServiceNameFilter(resolved_service_name)) + stream_handler.addFilter(LogContextFilter()) file_handler = RotatingFileHandler( LOG_FILE_PATH, maxBytes=10 * 1024 * 1024, backupCount=5 @@ -109,7 +111,9 @@ def configure_logging(service_name: str | None = None) -> None: file_handler.setFormatter(formatter) file_handler.addFilter(CorrelationIdFilter()) file_handler.addFilter(ServiceNameFilter(resolved_service_name)) + file_handler.addFilter(LogContextFilter()) + root_logger.addFilter(LogContextFilter()) root_logger.handlers.clear() root_logger.addHandler(stream_handler) root_logger.addHandler(file_handler) diff --git a/backend/app/core/middleware.py b/backend/app/core/middleware.py index 6a1c9be77..daeea828c 100644 --- a/backend/app/core/middleware.py +++ b/backend/app/core/middleware.py @@ -5,10 +5,13 @@ from asgi_correlation_id import correlation_id from fastapi import Request, Response from opentelemetry import trace +from starlette.middleware.base import RequestResponseEndpoint from starlette.types import ASGIApp, Receive, Scope, Send from app.core.config import settings from app.core.logger import log_service_name +from app.core.telemetry import record_http_request, record_unmatched_request +from app.core.telemetry.http import UNMATCHED_ROUTE logger = logging.getLogger("http_request_logger") @@ -19,6 +22,10 @@ } ) +CRON_PATH_PREFIX: str = f"{settings.API_V1_STR}/cron/" + +TRACE_EXCLUDED_PATH_PREFIXES: frozenset[str] = frozenset({CRON_PATH_PREFIX}) + class StripTrailingSlashMiddleware: """ @@ -47,11 +54,13 @@ def _resolve_http_route(request: Request) -> str: """ route = request.scope.get("route") templated = getattr(route, "path", None) - return templated or "unmatched" + return templated or UNMATCHED_ROUTE -async def http_request_logger(request: Request, call_next) -> Response: - if request.url.path.startswith(f"{settings.API_V1_STR}/cron/"): +async def http_request_logger( + request: Request, call_next: RequestResponseEndpoint +) -> Response: + if request.url.path.startswith(CRON_PATH_PREFIX): with log_service_name(settings.CRON_SERVICE_NAME): return await _log_http_request(request, call_next) @@ -69,38 +78,43 @@ def _resolve_request_body_size(request: Request) -> int: return 0 -async def _log_http_request(request: Request, call_next) -> Response: +async def _log_http_request( + request: Request, call_next: RequestResponseEndpoint +) -> Response: start_time = time.time() method = request.method raw_path = request.url.path + metrics_enabled = raw_path not in SILENT_LOG_PATHS request_body_size = _resolve_request_body_size(request) span = trace.get_current_span() if span.is_recording(): - span.set_attribute("http.request.method", method) - span.set_attribute("http.request_method", method) - span.set_attribute("http.method", method) span.set_attribute("http.request.body.size", request_body_size) if sentry_sdk.get_client().is_active(): sentry_sdk.set_tag("http.method", method) - sentry_sdk.set_tag("http.request.method", method) if request_id := correlation_id.get(): sentry_sdk.set_tag("correlation_id", request_id) try: response = await call_next(request) except Exception: + duration_ms = (time.time() - start_time) * 1000 status = 500 http_route = _resolve_http_route(request) - if span.is_recording(): - span.set_attribute("http.route", http_route) - span.set_attribute("http.status_code", status) - span.set_attribute("http.response.status_code", status) if sentry_sdk.get_client().is_active(): sentry_sdk.set_tag("http.route", http_route) sentry_sdk.set_tag("http.status_code", str(status)) - sentry_sdk.set_tag("http.response.status_code", str(status)) + if http_route == UNMATCHED_ROUTE: + record_unmatched_request(method=method) + elif metrics_enabled: + record_http_request( + method=method, + http_route=http_route, + status=status, + duration_ms=duration_ms, + request_body_size=request_body_size, + ) logger.exception("Unhandled exception during request") raise @@ -108,48 +122,24 @@ async def _log_http_request(request: Request, call_next) -> Response: status = response.status_code http_route = _resolve_http_route(request) - if span.is_recording(): - span.set_attribute("http.route", http_route) - span.set_attribute("http.status_code", status) - span.set_attribute("http.response.status_code", status) - span.set_attribute("http.request.duration_ms", round(duration_ms, 2)) + if sentry_sdk.get_client().is_active(): + sentry_sdk.set_tag("http.route", http_route) + sentry_sdk.set_tag("http.status_code", str(status)) - if raw_path not in SILENT_LOG_PATHS: + if http_route == UNMATCHED_ROUTE: + record_unmatched_request(method=method) + elif metrics_enabled: logger.info( f"[_log_http_request] {method} {raw_path} - {status} [{duration_ms:.2f}ms] " f"| request_body_size: {request_body_size}B " f"| correlation_id: {correlation_id.get()}" ) - - try: - if sentry_sdk.get_client().is_active(): - sentry_sdk.set_tag("http.route", http_route) - sentry_sdk.set_tag("http.status_code", str(status)) - sentry_sdk.set_tag("http.response.status_code", str(status)) - - attrs = { - "http.method": method, - "http.route": http_route, - "http.status_code": str(status), - } - sentry_sdk.metrics.count("http.server.request.count", 1, attributes=attrs) - sentry_sdk.metrics.distribution( - "http.server.request.body.size", - request_body_size, - unit="byte", - attributes=attrs, - ) - sentry_sdk.metrics.distribution( - "http.server.request.duration", - duration_ms, - unit="millisecond", - attributes=attrs, - ) - if status >= 400: - sentry_sdk.metrics.count( - "http.server.request.error", 1, attributes=attrs - ) - except Exception: - logger.debug("[http_request_logger] Sentry metric emit failed") + record_http_request( + method=method, + http_route=http_route, + status=status, + duration_ms=duration_ms, + request_body_size=request_body_size, + ) return response diff --git a/backend/app/core/sentry_filters.py b/backend/app/core/sentry_filters.py deleted file mode 100644 index ae82b436f..000000000 --- a/backend/app/core/sentry_filters.py +++ /dev/null @@ -1,148 +0,0 @@ -import re -from typing import Any - - -_REDACTED = "[REDACTED]" - -# LLM job kwargs land in Sentry via sentry_sdk's CeleryIntegration; these keys -# carry end-user text and must be redacted before that happens. -_LLM_JOB_TASK_NAMES = { - "app.celery.tasks.job_execution.run_llm_job", - "app.celery.tasks.job_execution.run_llm_chain_job", - "app.celery.tasks.job_execution.run_response_job", -} -_SENSITIVE_REQUEST_DATA_KEYS = ( - "query", - "request_metadata", - "response", - "output", - "callback_url", -) - - -_SQL_OR_CONNECT = re.compile(r"^(select|insert|update|delete|connect)\b", re.IGNORECASE) -_HTTP_SEND_RECEIVE = re.compile(r"http (send|receive)$", re.IGNORECASE) -_DB_QUERY_SPAN = re.compile(r"^db\.query$", re.IGNORECASE) -_BARE_HTTP_METHOD = re.compile( - r"^(GET|HEAD|OPTIONS|POST|PUT|PATCH|DELETE|TRACE|CONNECT)$", re.IGNORECASE -) -_NOISE_PATH = re.compile( - r"(^/health/?$|^/robots\.txt$|^/favicon\.ico$|^/wp-admin|^/wp-login|^/xmlrpc\.php$)", - re.IGNORECASE, -) - - -def _extract_path(event: dict[str, Any]) -> str: - request = event.get("request") - if not isinstance(request, dict): - return "" - - url = request.get("url") - if isinstance(url, str) and url: - if "://" in url: - after_scheme = url.split("://", 1)[1] - if "/" in after_scheme: - return "/" + after_scheme.split("/", 1)[1].split("?", 1)[0] - return "/" - return url.split("?", 1)[0] - return "" - - -def _should_drop_transaction(event: dict[str, Any]) -> bool: - transaction = str(event.get("transaction") or "").strip() - path = _extract_path(event) - - # Sentry shows probe traffic as bare "GET"/"HEAD" transactions. - if _BARE_HTTP_METHOD.match(transaction): - return True - - # Drop known non-app noise paths (probes / scanners). - if path and _NOISE_PATH.search(path): - return True - - return False - - -def before_send_transaction_filter( - event: dict[str, Any], hint: dict[str, Any] -) -> dict[str, Any] | None: - """Drop low-signal spans before they ship to Sentry. - - Filters out: - - ASGI lifecycle spans ending with `http send` / `http receive` - - DB spans carrying `db.system` - - SQL / `connect` spans matched by description prefix - - Custom DB query spans (`db.query`) - """ - if _should_drop_transaction(event): - return None - - spans = event.get("spans") - if not isinstance(spans, list): - return event - - filtered: list[dict[str, Any]] = [] - for span in spans: - if not isinstance(span, dict): - continue - - data = span.get("data") if isinstance(span.get("data"), dict) else {} - desc = str(span.get("description") or span.get("name") or "").strip() - op = str(span.get("op") or "").strip() - - if _HTTP_SEND_RECEIVE.search(desc): - continue - if _DB_QUERY_SPAN.search(desc) or _DB_QUERY_SPAN.search(op): - continue - if data.get("db.system") is not None: - continue - if _SQL_OR_CONNECT.match(desc): - continue - - filtered.append(span) - - event["spans"] = filtered - return event - - -def _redact_llm_job_kwargs(kwargs: dict[str, Any]) -> dict[str, Any]: - """Replaces end-user text fields and identifying URLs in an LLM job's - request_data with a placeholder, leaving non-sensitive fields (config, ids) - intact. - """ - request_data = kwargs.get("request_data") - if not isinstance(request_data, dict): - return kwargs - - redacted_request_data = dict(request_data) - for key in _SENSITIVE_REQUEST_DATA_KEYS: - if key in redacted_request_data: - redacted_request_data[key] = _REDACTED - - redacted_kwargs = dict(kwargs) - redacted_kwargs["request_data"] = redacted_request_data - return redacted_kwargs - - -def before_send_filter( - event: dict[str, Any], hint: dict[str, Any] -) -> dict[str, Any] | None: - """Strips end-user query/response text from LLM job celery-job context - before an event reaches Sentry. - """ - extra = event.get("extra") - if not isinstance(extra, dict): - return event - - celery_job = extra.get("celery-job") - if not isinstance(celery_job, dict): - return event - - if celery_job.get("task_name") not in _LLM_JOB_TASK_NAMES: - return event - - kwargs = celery_job.get("kwargs") - if isinstance(kwargs, dict): - celery_job["kwargs"] = _redact_llm_job_kwargs(kwargs) - - return event diff --git a/backend/app/core/telemetry.py b/backend/app/core/telemetry.py deleted file mode 100644 index c8effbfbc..000000000 --- a/backend/app/core/telemetry.py +++ /dev/null @@ -1,606 +0,0 @@ -import json -import logging -import time -from collections.abc import Iterator -from contextlib import contextmanager -from contextvars import ContextVar -from typing import TYPE_CHECKING, Any - -import sentry_sdk -from opentelemetry import context as otel_context -from opentelemetry import trace -from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor -from opentelemetry.instrumentation.httpx import HTTPXClientInstrumentor -from opentelemetry.instrumentation.logging import LoggingInstrumentor -from opentelemetry.instrumentation.requests import RequestsInstrumentor -from opentelemetry.instrumentation.utils import _SUPPRESS_HTTP_INSTRUMENTATION_KEY -from opentelemetry.propagate import set_global_textmap -from opentelemetry.sdk.resources import SERVICE_NAME, Resource -from opentelemetry.sdk.trace import TracerProvider - -from app.core.config import settings - -if TYPE_CHECKING: - from app.models.llm.response import LLMCallResponse - -logger = logging.getLogger(__name__) - -_log_context_var: ContextVar[dict[str, str] | None] = ContextVar( - "kaapi_log_context", default=None -) - - -def _emit_sentry_metric( - metric_type: str, - name: str, - value: float, - *, - unit: str | None = None, - attributes: dict[str, str | int | float] | None = None, -) -> None: - """Best-effort Sentry metric emission. No-op if SDK is not active.""" - try: - if not sentry_sdk.get_client().is_active(): - return - if metric_type == "count": - sentry_sdk.metrics.count( - name=name, value=value, unit=unit, attributes=attributes - ) - elif metric_type == "gauge": - sentry_sdk.metrics.gauge( - name=name, value=value, unit=unit, attributes=attributes - ) - elif metric_type == "distribution": - sentry_sdk.metrics.distribution( - name=name, value=value, unit=unit, attributes=attributes - ) - except Exception: - logger.debug("[_emit_sentry_metric] Failed to emit %s (%s)", name, metric_type) - - -def set_request_log_context( - org_id: int | None = None, - project_id: int | None = None, -) -> None: - """Attach org/project to the current request's log context and Sentry scope. - - Call once per authenticated request (from the auth dependency). All subsequent - log records in this request will carry org_id and project_id automatically - via LogContextFilter — no need to add them to individual log statements. - """ - current = _log_context_var.get() or {} - payload = dict(current) - if org_id is not None: - payload["org_id"] = str(org_id) - if project_id is not None: - payload["project_id"] = str(project_id) - _log_context_var.set(payload) - - try: - if sentry_sdk.get_client().is_active(): - if org_id is not None: - sentry_sdk.set_tag("tenant.org_id", str(org_id)) - if project_id is not None: - sentry_sdk.set_tag("tenant.project_id", str(project_id)) - except Exception: - pass - - -@contextmanager -def log_context( - *, tag: str | None = None, **fields: str | int | float | bool | None -) -> Iterator[None]: - """Attach structured log context for the current execution scope. - - Example: - with log_context(tag="llm-call", job_id=job_id): - logger.info("...") - """ - current = _log_context_var.get() or {} - payload = dict(current) - if tag: - payload["tag"] = tag - payload.setdefault("system", tag) - for key, value in fields.items(): - if value is None: - continue - payload[key] = str(value) - token = _log_context_var.set(payload) - try: - yield - finally: - _log_context_var.reset(token) - - -class LogContextFilter(logging.Filter): - """Attach structured context fields from `log_context(...)` to LogRecords.""" - - _LLM_CALL_PREFIXES = ( - "app.services.llm", - "app.api.routes.llm", - "app.crud.llm", - ) - _COLLECTION_PREFIXES = ( - "app.services.collections", - "app.api.routes.collections", - "app.crud.collection", - ) - - def filter(self, record: logging.LogRecord) -> bool: - context_payload = _log_context_var.get() - has_explicit_tag = False - if context_payload: - for key, value in context_payload.items(): - setattr(record, key, value) - has_explicit_tag = bool(context_payload.get("tag")) - - if not has_explicit_tag: - logger_name = record.name or "" - if logger_name.startswith(self._LLM_CALL_PREFIXES): - record.tag = "llm-call" - if not hasattr(record, "system"): - record.system = "llm-call" - elif logger_name.startswith(self._COLLECTION_PREFIXES): - record.tag = "collection" - if not hasattr(record, "system"): - record.system = "collection" - - if not hasattr(record, "lifecycle"): - span = trace.get_current_span() - if span is not None and span.is_recording(): - span_name = getattr(span, "name", None) - if isinstance(span_name, str) and span_name: - record.lifecycle = span_name - return True - - -def _build_resource(service_name: str | None = None) -> Resource: - return Resource.create( - { - SERVICE_NAME: service_name or settings.OTEL_SERVICE_NAME, - "deployment.environment": settings.ENVIRONMENT, - "service.version": settings.API_VERSION, - } - ) - - -def setup_telemetry(service_name: str | None = None) -> None: - """Initialize OpenTelemetry tracing and bridge spans into Sentry. - - Sentry is the single sink: - - Traces: OTel TracerProvider -> SentrySpanProcessor -> Sentry - - Logs: stdlib logging -> Sentry LoggingIntegration (configured at - sentry_sdk.init time; see app/main.py and celery_app.py) - - Metrics: code calls _emit_sentry_metric / sentry_sdk.metrics.* directly - - Args: - service_name: Override OTEL_SERVICE_NAME (e.g. "kaapi-celery" in workers). - """ - root_logger = logging.getLogger() - log_context_filter = LogContextFilter() - if not any(isinstance(f, LogContextFilter) for f in root_logger.filters): - root_logger.addFilter(log_context_filter) - for handler in root_logger.handlers: - if not any(isinstance(f, LogContextFilter) for f in handler.filters): - handler.addFilter(log_context_filter) - - if not settings.OTEL_ENABLED: - logger.info("[setup_telemetry] OTEL_ENABLED is False, skipping") - return - - resource = _build_resource(service_name) - tracer_provider = TracerProvider(resource=resource) - - # Bridge OTel spans into Sentry as Sentry transactions and spans, with full attribute and error capture. - if settings.SENTRY_DSN: - from sentry_sdk.integrations.opentelemetry import ( - SentryPropagator, - SentrySpanProcessor, - ) - - tracer_provider.add_span_processor(SentrySpanProcessor()) - # Downstream services extract sentry-trace, not W3C traceparent. - set_global_textmap(SentryPropagator()) - - trace.set_tracer_provider(tracer_provider) - - # Auto-instrumentation — generates OTel spans the SentrySpanProcessor forwards - LoggingInstrumentor().instrument(set_logging_format=False) - HTTPXClientInstrumentor().instrument() - RequestsInstrumentor().instrument() - try: - # Circular import fix - from opentelemetry.instrumentation.celery import CeleryInstrumentor - - CeleryInstrumentor().instrument() - except Exception: - logger.exception("[setup_telemetry] Failed to instrument Celery") - - logger.debug( - "[setup_telemetry] OpenTelemetry initialized (service=%s, sink=Sentry)", - service_name or settings.OTEL_SERVICE_NAME, - ) - - -def _llm_call_attrs( - provider: str, - model: str, - operation: str, - organization_id: int | None, - project_id: int | None, -) -> dict[str, str]: - attrs: dict[str, str] = { - "gen_ai.system": provider, - "gen_ai.request.model": model, - "gen_ai.operation.name": operation, - } - if organization_id is not None: - attrs["kaapi.organization_id"] = str(organization_id) - if project_id is not None: - attrs["kaapi.project_id"] = str(project_id) - return attrs - - -def record_llm_call_started( - provider: str, - model: str, - operation: str, - organization_id: int | None = None, - project_id: int | None = None, -) -> None: - """Emit LLM call-start metric to Sentry.""" - if not settings.OTEL_ENABLED: - return - attrs = _llm_call_attrs(provider, model, operation, organization_id, project_id) - _emit_sentry_metric("count", "llm.call.total", 1, attributes=attrs) - - -def record_llm_call_finished( - provider: str, - model: str, - operation: str, - duration_ms: float, - input_tokens: int | None = None, - output_tokens: int | None = None, - total_tokens: int | None = None, - error: bool = False, - organization_id: int | None = None, - project_id: int | None = None, -) -> None: - """Emit LLM call-completion metrics (latency, tokens, errors) to Sentry.""" - if not settings.OTEL_ENABLED: - return - attrs = _llm_call_attrs(provider, model, operation, organization_id, project_id) - - _emit_sentry_metric( - "distribution", - "llm.call.duration", - duration_ms, - unit="millisecond", - attributes=attrs, - ) - if error: - _emit_sentry_metric("count", "llm.call.errors", 1, attributes=attrs) - if input_tokens is not None: - _emit_sentry_metric("count", "llm.tokens.input", input_tokens, attributes=attrs) - if output_tokens is not None: - _emit_sentry_metric( - "count", "llm.tokens.output", output_tokens, attributes=attrs - ) - if total_tokens is not None: - _emit_sentry_metric("count", "llm.tokens.total", total_tokens, attributes=attrs) - - -def set_gen_ai_request_attributes( - span: trace.Span, - *, - provider: str, - model: str, - operation: str, - organization_id: int | None, - project_id: int | None, - params: dict[str, Any] | None = None, -) -> None: - """Set OTel GenAI request attributes on `span` (semantic-convention keys + kaapi ids).""" - span.set_attribute("gen_ai.system", provider) - span.set_attribute("gen_ai.provider.name", provider) - span.set_attribute("gen_ai.operation.name", operation) - if model: - span.set_attribute("gen_ai.request.model", model) - if organization_id is not None: - span.set_attribute("kaapi.organization_id", organization_id) - span.set_attribute("gen_ai.request.organization_id", organization_id) - if project_id is not None: - span.set_attribute("kaapi.project_id", project_id) - span.set_attribute("gen_ai.request.project_id", project_id) - - params = params or {} - for attr_key, param_key in ( - ("gen_ai.request.temperature", "temperature"), - ("gen_ai.request.max_tokens", "max_tokens"), - ("gen_ai.request.top_p", "top_p"), - ("gen_ai.request.presence_penalty", "presence_penalty"), - ("gen_ai.request.frequency_penalty", "frequency_penalty"), - ): - if param_key in params: - span.set_attribute(attr_key, params.get(param_key)) - - tools = params.get("tools") - if tools is not None: - span.set_attribute("gen_ai.request.available_tools", json.dumps(tools)) - - -def set_gen_ai_response_attributes( - span: trace.Span, *, response: "LLMCallResponse" -) -> None: - """Set OTel GenAI response attributes (usage, model) on `span`.""" - usage = response.usage - if usage: - span.set_attribute("gen_ai.usage.input_tokens", usage.input_tokens) - span.set_attribute("gen_ai.usage.output_tokens", usage.output_tokens) - span.set_attribute("gen_ai.usage.total_tokens", usage.total_tokens) - if getattr(usage, "reasoning_tokens", None) is not None: - span.set_attribute( - "gen_ai.usage.output_tokens.reasoning", usage.reasoning_tokens - ) - - if response.response and response.response.model: - span.set_attribute("gen_ai.response.model", response.response.model) - - -@contextmanager -def suppress_http_instrumentation() -> Iterator[None]: - """Suppress OTel HTTP client auto-instrumentation for the wrapped block. - - Used around LLM provider calls so the outbound HTTP call does not emit a - redundant child span — the LLM-level span already carries the trace. - """ - token = otel_context.attach( - otel_context.set_value(_SUPPRESS_HTTP_INSTRUMENTATION_KEY, True) - ) - try: - yield - finally: - otel_context.detach(token) - - -def record_db_query_finished( - *, - duration_ms: float, - operation: str | None = None, - error: bool = False, -) -> None: - """Emit DB query metrics to Sentry.""" - if not settings.OTEL_ENABLED: - return - - attrs: dict[str, str] = {} - if operation: - attrs["db.operation"] = operation - - _emit_sentry_metric("count", "db.query.total", 1, attributes=attrs) - _emit_sentry_metric( - "distribution", - "db.query.duration", - duration_ms, - unit="millisecond", - attributes=attrs, - ) - if error: - _emit_sentry_metric("count", "db.query.failed", 1, attributes=attrs) - - -def record_db_pool_stats( - *, - active: int, - idle: int, - total: int, - overflow: int, -) -> None: - """Emit SQLAlchemy pool stats as Sentry gauges.""" - if not settings.OTEL_ENABLED: - return - - _emit_sentry_metric("gauge", "db.pool.active", active) - _emit_sentry_metric("gauge", "db.pool.idle", idle) - _emit_sentry_metric("gauge", "db.pool.total", total) - _emit_sentry_metric("gauge", "db.pool.overflow", overflow) - - -def record_stale_pending_jobs( - *, - table: str, - status: str, - stale_count: int, - oldest_age_seconds: int | None, - job_type: str | None = None, - action_type: str | None = None, - dimensional: bool = False, -) -> None: - """Emit aggregate pending-job monitor metrics to Sentry. - - When ``dimensional`` is True, the metric is emitted under a separate - name so per-group counts (grouped by job_type/action_type) do not get - summed together with the table-level count in Sentry dashboards. - """ - attrs: dict[str, str] = { - "job.table": table, - "job.status": status, - } - if job_type: - attrs["job.type"] = job_type - if action_type: - attrs["job.action_type"] = action_type - - count_metric = ( - "jobs.pending.stale.by_dimension.count" - if dimensional - else "jobs.pending.stale.count" - ) - age_metric = ( - "jobs.pending.oldest_age_seconds.by_dimension" - if dimensional - else "jobs.pending.oldest_age_seconds" - ) - - _emit_sentry_metric( - "gauge", - count_metric, - stale_count, - attributes=attrs, - ) - if oldest_age_seconds is not None: - _emit_sentry_metric( - "gauge", - age_metric, - oldest_age_seconds, - unit="second", - attributes=attrs, - ) - - -def record_rate_threshold( - *, - project_id: int, - project_name: str | None, - category: str, - request_count: int, - threshold: int, -) -> None: - """Emit rate threshold exceeded event to Sentry.""" - - try: - if not sentry_sdk.get_client().is_active(): - return - with sentry_sdk.push_scope() as scope: - scope.set_tag("alert.type", "threshold_rate_monitor") - scope.set_tag("tenant.project_id", project_id) - scope.set_tag("route_category", category) - scope.set_extra("request_count", request_count) - scope.set_extra("threshold", threshold) - sentry_sdk.capture_message( - f"[Threshold-Monitor] {category} rate limit exceeded for project {project_id} | {project_name}: {request_count} req/min " - f"(limit {threshold}/min)", - level="warning", - ) - except Exception as e: - logger.exception("[record_rate_threshold] Failed to emit alert", exc_info=e) - - -def flush_telemetry(timeout_millis: int = 10000) -> None: - """Force-flush OTel spans into Sentry, then flush Sentry's transport. - - Called from Celery task_postrun: workers can recycle via max_tasks_per_child - before the SentrySpanProcessor's internal queue drains, otherwise dropping - closing spans and ERROR breadcrumbs from the just-finished task. - """ - if not settings.OTEL_ENABLED: - return - try: - tp = trace.get_tracer_provider() - if hasattr(tp, "force_flush"): - tp.force_flush(timeout_millis=timeout_millis) - except Exception: - logger.exception("[flush_telemetry] Failed to flush tracer provider") - - try: - if sentry_sdk.get_client().is_active(): - sentry_sdk.flush(timeout=timeout_millis / 1000) - except Exception: - logger.exception("[flush_telemetry] Failed to flush Sentry") - - -def instrument_app(app: object) -> None: - """Instrument the FastAPI app. Call after the app is created.""" - if not settings.OTEL_ENABLED: - return - # Health checks are high-volume/noise and should not generate traces. - FastAPIInstrumentor.instrument_app( # type: ignore[arg-type] - app, - excluded_urls=r"^/health/?$", - ) - logger.debug("[instrument_app] FastAPI instrumented with OpenTelemetry") - - -def instrument_db_engine(engine: object) -> None: - """Instrument SQLAlchemy engine with DB query spans + pool gauges.""" - if not settings.OTEL_ENABLED: - return - if getattr(engine, "_kaapi_db_telemetry_instrumented", False): - return - - try: - from sqlalchemy import event - except Exception: - logger.exception("[instrument_db_engine] Failed importing SQLAlchemy events") - return - - def _pool_snapshot(pool: Any) -> tuple[int, int, int, int] | None: - if not all(hasattr(pool, attr) for attr in ("checkedout", "size", "overflow")): - return None - active = int(pool.checkedout()) - idle = int(pool.checkedin()) if hasattr(pool, "checkedin") else 0 - configured_size = int(pool.size()) - overflow = int(pool.overflow()) - total = max(configured_size + overflow, active + idle) - return active, idle, total, overflow - - def _emit_pool_metrics(pool: Any) -> None: - snapshot = _pool_snapshot(pool) - if not snapshot: - return - active, idle, total, overflow = snapshot - record_db_pool_stats(active=active, idle=idle, total=total, overflow=overflow) - - @event.listens_for(engine, "before_cursor_execute") - def _before_cursor_execute( - conn, cursor, statement, parameters, context, executemany - ) -> None: - del cursor, parameters, executemany - context._kaapi_db_started_at = time.perf_counter() - context._kaapi_db_operation = ( - str(statement).split(None, 1)[0].upper() if statement else "UNKNOWN" - ) - _emit_pool_metrics(conn.engine.pool) - - @event.listens_for(engine, "after_cursor_execute") - def _after_cursor_execute( - conn, cursor, statement, parameters, context, executemany - ) -> None: - del cursor, statement, parameters, executemany - started_at = getattr(context, "_kaapi_db_started_at", None) - duration_ms = ( - (time.perf_counter() - started_at) * 1000 if started_at is not None else 0.0 - ) - operation = getattr(context, "_kaapi_db_operation", None) - record_db_query_finished( - duration_ms=duration_ms, operation=operation, error=False - ) - _emit_pool_metrics(conn.engine.pool) - - @event.listens_for(engine, "handle_error") - def _handle_error(exception_context) -> None: - context = exception_context.execution_context - if context is None: - return - started_at = getattr(context, "_kaapi_db_started_at", None) - duration_ms = ( - (time.perf_counter() - started_at) * 1000 if started_at is not None else 0.0 - ) - operation = getattr(context, "_kaapi_db_operation", None) - record_db_query_finished( - duration_ms=duration_ms, operation=operation, error=True - ) - - @event.listens_for(engine.pool, "checkout") - def _on_checkout(dbapi_connection, connection_record, connection_proxy) -> None: - del dbapi_connection, connection_record, connection_proxy - _emit_pool_metrics(engine.pool) - - @event.listens_for(engine.pool, "checkin") - def _on_checkin(dbapi_connection, connection_record) -> None: - del dbapi_connection, connection_record - _emit_pool_metrics(engine.pool) - - engine._kaapi_db_telemetry_instrumented = True - logger.debug("[instrument_db_engine] SQLAlchemy DB telemetry enabled") diff --git a/backend/app/core/telemetry/__init__.py b/backend/app/core/telemetry/__init__.py new file mode 100644 index 000000000..ff3cf5198 --- /dev/null +++ b/backend/app/core/telemetry/__init__.py @@ -0,0 +1,41 @@ +"""Observability package: public API for OTel tracing, Sentry init, log context, HTTP/DB/LLM metrics.""" + +from app.core.telemetry.context import ( + LogModuleEnum, + bind_sentry_user, + log_context, + set_request_log_context, +) +from app.core.telemetry.db import instrument_db_engine +from app.core.telemetry.http import record_http_request, record_unmatched_request +from app.core.telemetry.llm import ( + record_llm_call_finished, + record_llm_call_started, + set_gen_ai_request_attributes, + set_gen_ai_response_attributes, + suppress_http_instrumentation, +) +from app.core.telemetry.metrics import record_rate_threshold, record_stale_pending_jobs +from app.core.telemetry.sentry import init_sentry +from app.core.telemetry.tracing import flush_telemetry, instrument_app, setup_telemetry + +__all__ = [ + "LogModuleEnum", + "bind_sentry_user", + "flush_telemetry", + "init_sentry", + "instrument_app", + "instrument_db_engine", + "log_context", + "record_http_request", + "record_llm_call_finished", + "record_llm_call_started", + "record_rate_threshold", + "record_stale_pending_jobs", + "record_unmatched_request", + "set_gen_ai_request_attributes", + "set_gen_ai_response_attributes", + "set_request_log_context", + "setup_telemetry", + "suppress_http_instrumentation", +] diff --git a/backend/app/core/telemetry/context.py b/backend/app/core/telemetry/context.py new file mode 100644 index 000000000..c4c64cb13 --- /dev/null +++ b/backend/app/core/telemetry/context.py @@ -0,0 +1,234 @@ +"""Request-scoped log context: log_context(), LogContextFilter, tenant tags and Sentry user binding.""" + +import logging +from collections.abc import Generator +from contextlib import contextmanager +from contextvars import ContextVar +from enum import StrEnum + +import sentry_sdk +from opentelemetry import trace + +logger = logging.getLogger(__name__) + +_log_context_var: ContextVar[dict[str, str] | None] = ContextVar( + "kaapi_log_context", default=None +) + +# Sentry skips "_"-prefixed record attributes, so only LOG_MODULE_FIELD reaches Sentry Logs. +LOG_MODULE_FIELD = "log_module" +LOG_LOCATION_FIELD = "_log_location" + + +class LogModuleEnum(StrEnum): + KNOWLEDGEBASE = "knowledgebase" + LLM_CALL = "llm-call" + LLM_CHAIN = "llm-chain" + CONFIG_VERSION = "config-version" + ASSESSMENT = "assessment" + EVALS = "evals" + FASTEVALS = "fastevals" + + +# Exact logger name (the module's __name__) -> owning module. A new logging file joins here. +_LOGGER_MODULES: dict[str, LogModuleEnum] = { + # -------- KNOWLEDGEBASE -------- + "app.api.routes.collection_job": LogModuleEnum.KNOWLEDGEBASE, + "app.api.routes.collections": LogModuleEnum.KNOWLEDGEBASE, + "app.api.routes.doc_transformation_job": LogModuleEnum.KNOWLEDGEBASE, + "app.api.routes.documents": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.collection.collection": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.collection.collection_job": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.document.doc_transformation_job": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.document.document": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.document_collection": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.rag.gemini": LogModuleEnum.KNOWLEDGEBASE, + "app.crud.rag.open_ai": LogModuleEnum.KNOWLEDGEBASE, + "app.services.collections.create_collection": LogModuleEnum.KNOWLEDGEBASE, + "app.services.collections.delete_collection": LogModuleEnum.KNOWLEDGEBASE, + "app.services.collections.helpers": LogModuleEnum.KNOWLEDGEBASE, + "app.services.collections.providers.gemini": LogModuleEnum.KNOWLEDGEBASE, + "app.services.collections.providers.openai": LogModuleEnum.KNOWLEDGEBASE, + "app.services.collections.providers.registry": LogModuleEnum.KNOWLEDGEBASE, + "app.services.doctransform.job": LogModuleEnum.KNOWLEDGEBASE, + "app.services.doctransform.zerox_transformer": LogModuleEnum.KNOWLEDGEBASE, + "app.services.documents.helpers": LogModuleEnum.KNOWLEDGEBASE, + "app.services.documents.validator": LogModuleEnum.KNOWLEDGEBASE, + # -------- LLM_CALL -------- + "app.api.routes.llm": LogModuleEnum.LLM_CALL, + "app.crud.llm": LogModuleEnum.LLM_CALL, + "app.services.llm.guardrails": LogModuleEnum.LLM_CALL, + "app.services.llm.jobs": LogModuleEnum.LLM_CALL, + "app.services.llm.mappers": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.claude": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.eleven_ai": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.google_aistudio": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.google_gcp": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.open_ai": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.registry": LogModuleEnum.LLM_CALL, + "app.services.llm.providers.sarvam_ai": LogModuleEnum.LLM_CALL, + # -------- LLM_CHAIN -------- + "app.api.routes.llm_chain": LogModuleEnum.LLM_CHAIN, + "app.crud.llm_chain": LogModuleEnum.LLM_CHAIN, + "app.services.llm.chain.chain": LogModuleEnum.LLM_CHAIN, + "app.services.llm.chain.executor": LogModuleEnum.LLM_CHAIN, + # -------- CONFIG_VERSION -------- + "app.crud.config.config": LogModuleEnum.CONFIG_VERSION, + "app.crud.config.version": LogModuleEnum.CONFIG_VERSION, + # -------- ASSESSMENT -------- + "app.api.routes.assessment.api": LogModuleEnum.ASSESSMENT, + "app.crud.assessment.api": LogModuleEnum.ASSESSMENT, + "app.crud.assessment.submission": LogModuleEnum.ASSESSMENT, + "app.services.assessment.api.batch": LogModuleEnum.ASSESSMENT, + "app.services.assessment.api.callbacks": LogModuleEnum.ASSESSMENT, + "app.services.assessment.api.result_files": LogModuleEnum.ASSESSMENT, + "app.services.assessment.api.results": LogModuleEnum.ASSESSMENT, + "app.services.assessment.api.submission": LogModuleEnum.ASSESSMENT, + "app.services.assessment.api.submission_store": LogModuleEnum.ASSESSMENT, + "app.services.assessment.submission": LogModuleEnum.ASSESSMENT, + # -------- EVALS -------- + "app.api.routes.evaluations.v2.dataset": LogModuleEnum.EVALS, + "app.api.routes.evaluations.v2.evaluation": LogModuleEnum.EVALS, + "app.api.routes.evaluations.v2.iteration": LogModuleEnum.EVALS, + "app.api.routes.evaluations.v2.prompt_improvement": LogModuleEnum.EVALS, + "app.crud.evaluations.iteration": LogModuleEnum.EVALS, + "app.crud.evaluations.judge": LogModuleEnum.EVALS, + "app.crud.evaluations.judge_stage": LogModuleEnum.EVALS, + "app.crud.evaluations.summary": LogModuleEnum.EVALS, + "app.services.evaluations.iteration": LogModuleEnum.EVALS, + "app.services.evaluations.iteration_checkpointer": LogModuleEnum.EVALS, + "app.services.evaluations.iteration_graph": LogModuleEnum.EVALS, + "app.services.evaluations.prompt_improvement": LogModuleEnum.EVALS, + # -------- FASTEVALS -------- + "app.crud.evaluations.fast": LogModuleEnum.FASTEVALS, + "app.crud.evaluations.fast_chunks": LogModuleEnum.FASTEVALS, + "app.services.evaluations.fast": LogModuleEnum.FASTEVALS, +} + + +def set_request_log_context( + org_id: int | None = None, + project_id: int | None = None, +) -> None: + """Attach org/project to the request's log context and Sentry tags.""" + current = _log_context_var.get() or {} + payload = dict(current) + if org_id is not None: + payload["org_id"] = str(org_id) + if project_id is not None: + payload["project_id"] = str(project_id) + _log_context_var.set(payload) + + try: + if sentry_sdk.get_client().is_active(): + if org_id is not None: + sentry_sdk.set_tag("tenant.org_id", str(org_id)) + if project_id is not None: + sentry_sdk.set_tag("tenant.project_id", str(project_id)) + except Exception: + logger.debug("[set_request_log_context] Failed to tag Sentry scope") + + +def bind_sentry_user( + user_id: int | None = None, + org_id: int | None = None, + project_id: int | None = None, +) -> None: + """Bind caller ids to the Sentry scope only; log context would add per-user cardinality.""" + try: + if not sentry_sdk.get_client().is_active(): + return + sentry_user: dict[str, str] = {} + if user_id is not None: + sentry_user["id"] = str(user_id) + if org_id is not None: + sentry_user["org_id"] = str(org_id) + if project_id is not None: + sentry_user["project_id"] = str(project_id) + if sentry_user: + sentry_sdk.set_user(sentry_user) + except Exception: + logger.debug("[bind_sentry_user] Failed to bind Sentry user") + + +@contextmanager +def log_context( + *, + tag: str | None = None, + module: LogModuleEnum | None = None, + **fields: str | int | float | bool | None, +) -> Generator[None]: + """Attach structured log context for the current execution scope. + + `module` overrides the logger-path module for every log in the block, for flows + that run another flow's code (e.g. an LLM chain calling LLM-call helpers). + """ + current = _log_context_var.get() or {} + payload = dict(current) + if tag: + payload["tag"] = tag + payload.setdefault("system", tag) + if module: + payload[LOG_MODULE_FIELD] = module.value + for key, value in fields.items(): + if value is None: + continue + payload[key] = str(value) + token = _log_context_var.set(payload) + try: + yield + finally: + _log_context_var.reset(token) + + +class LogContextFilter(logging.Filter): + """Attach structured context fields from `log_context(...)` to LogRecords.""" + + _LLM_CALL_PREFIXES = ( + "app.services.llm", + "app.api.routes.llm", + "app.crud.llm", + ) + _COLLECTION_PREFIXES = ( + "app.services.collections", + "app.api.routes.collections", + "app.crud.collection", + ) + + def filter(self, record: logging.LogRecord) -> bool: + context_payload = _log_context_var.get() + has_explicit_tag = False + if context_payload: + for key, value in context_payload.items(): + setattr(record, key, value) + has_explicit_tag = bool(context_payload.get("tag")) + + if not has_explicit_tag: + logger_name = record.name or "" + if logger_name.startswith(self._LLM_CALL_PREFIXES): + record.tag = "llm-call" + if not hasattr(record, "system"): + record.system = "llm-call" + elif logger_name.startswith(self._COLLECTION_PREFIXES): + record.tag = "collection" + if not hasattr(record, "system"): + record.system = "collection" + + module = (context_payload or {}).get(LOG_MODULE_FIELD) or _LOGGER_MODULES.get( + record.name + ) + if module: + setattr(record, LOG_MODULE_FIELD, str(module)) + setattr( + record, + LOG_LOCATION_FIELD, + f"[{module}] {record.name}" if module else record.name, + ) + + if not hasattr(record, "lifecycle"): + span = trace.get_current_span() + if span is not None and span.is_recording(): + span_name = getattr(span, "name", None) + if isinstance(span_name, str) and span_name: + record.lifecycle = span_name + return True diff --git a/backend/app/core/telemetry/db.py b/backend/app/core/telemetry/db.py new file mode 100644 index 000000000..caab90156 --- /dev/null +++ b/backend/app/core/telemetry/db.py @@ -0,0 +1,267 @@ +"""SQLAlchemy telemetry: query spans, slow-query/failure/pool/connection/transaction metrics, SQLSTATE tags.""" + +import logging +import time + +import sentry_sdk +from opentelemetry import trace +from opentelemetry.instrumentation.sqlalchemy import SQLAlchemyInstrumentor +from sqlalchemy import ExceptionContext, event +from sqlalchemy.engine import Connection, Engine +from sqlalchemy.engine.interfaces import DBAPIConnection, DBAPICursor, ExecutionContext +from sqlalchemy.pool import ConnectionPoolEntry, Pool, PoolProxiedConnection, QueuePool + +from app.core.telemetry.metrics import emit_sentry_metric + +logger = logging.getLogger(__name__) + +DB_SLOW_QUERY_MS: int = 500 + +DB_ROWS_ATTRIBUTE: str = "db.rows_affected" + +_INSTRUMENTED_ATTR = "_kaapi_db_telemetry_instrumented" +_STARTED_AT_ATTR = "_kaapi_db_started_at" +_OPERATION_ATTR = "_kaapi_db_operation" + +NOTABLE_SQLSTATES: dict[str, str] = { + "40P01": "deadlock_detected", + "57014": "query_canceled", # statement timeout + "40001": "serialization_failure", + "55P03": "lock_not_available", # lock timeout + "08006": "connection_failure", + "08003": "connection_does_not_exist", + "53300": "too_many_connections", +} + +_DB_CONNECTION_EVENT_METRICS: dict[str, str] = { + "opened": "db.connection.opened", + "closed": "db.connection.closed", + "invalidated": "db.connection.invalidated", +} + +_DB_TRANSACTION_METRICS: dict[str, str] = { + "commit": "db.transaction.commit", + "rollback": "db.transaction.rollback", +} + + +def record_db_query_failed( + *, + operation: str | None = None, + sqlstate: str | None = None, +) -> None: + """Emit a DB query-failure counter to Sentry. Per-query duration/throughput come from spans.""" + + attrs: dict[str, str | int | float] = {} + if operation: + attrs["db.operation"] = operation + if sqlstate: + attrs["db.sqlstate"] = sqlstate + + emit_sentry_metric("count", "db.query.failed", 1, attributes=attrs) + + +def record_db_slow_query(operation: str | None = None) -> None: + """Emit a slow-query counter to Sentry (queries at/above DB_SLOW_QUERY_MS).""" + + attrs: dict[str, str | int | float] = {} + if operation: + attrs["db.operation"] = operation + + emit_sentry_metric("count", "db.query.slow", 1, attributes=attrs) + + +def record_db_connection_event(event: str) -> None: + """Emit a connection-lifecycle counter (opened/closed/invalidated) to Sentry.""" + + metric = _DB_CONNECTION_EVENT_METRICS.get(event) + if metric is None: + return + emit_sentry_metric("count", metric, 1) + + +def record_db_transaction(outcome: str) -> None: + """Emit a transaction-outcome counter (commit/rollback) to Sentry for ratio tracking.""" + + metric = _DB_TRANSACTION_METRICS.get(outcome) + if metric is None: + return + emit_sentry_metric("count", metric, 1) + + +def _tag_db_error(sqlstate: str | None) -> None: + """Tag the active Sentry scope + span with a DB error's Postgres SQLSTATE.""" + if not sqlstate: + return + try: + span = trace.get_current_span() + if span.is_recording(): + span.set_attribute("db.sqlstate", sqlstate) + if sentry_sdk.get_client().is_active(): + sentry_sdk.set_tag("db.system", "postgresql") + sentry_sdk.set_tag("db.sqlstate", sqlstate) + name = NOTABLE_SQLSTATES.get(sqlstate) + if name: + sentry_sdk.set_tag("db.error.name", name) + except Exception: + logger.debug("[_tag_db_error] Failed to tag DB error | sqlstate: %s", sqlstate) + + +def record_db_pool_stats( + *, + active: int, + idle: int, + total: int, + overflow: int, +) -> None: + """Emit SQLAlchemy pool stats as Sentry gauges.""" + + emit_sentry_metric("gauge", "db.pool.active", active) + emit_sentry_metric("gauge", "db.pool.idle", idle) + emit_sentry_metric("gauge", "db.pool.total", total) + emit_sentry_metric("gauge", "db.pool.overflow", overflow) + + +def instrument_db_engine(engine: Engine) -> None: + """Instrument a SQLAlchemy engine: query spans, slow-query/pool/connection/transaction metrics.""" + if getattr(engine, _INSTRUMENTED_ATTR, False): + return + + # ProxyTracer defers to the provider set later in setup_telemetry(); load order is safe. + try: + SQLAlchemyInstrumentor().instrument(engine=engine) + except Exception: + logger.exception( + "[instrument_db_engine] Failed to load SQLAlchemy span instrumentation" + ) + + def _pool_snapshot(pool: Pool) -> tuple[int, int, int, int] | None: + if not isinstance(pool, QueuePool): + return None + active = pool.checkedout() + idle = pool.checkedin() + overflow = pool.overflow() + total = max(pool.size() + overflow, active + idle) + return active, idle, total, overflow + + def _emit_pool_metrics(pool: Pool) -> None: + snapshot = _pool_snapshot(pool) + if not snapshot: + return + active, idle, total, overflow = snapshot + record_db_pool_stats(active=active, idle=idle, total=total, overflow=overflow) + + @event.listens_for(engine, "before_cursor_execute") + def _before_cursor_execute( + conn: Connection, + cursor: DBAPICursor, + statement: str, + parameters: object, + context: ExecutionContext, + executemany: bool, + ) -> None: + del cursor, parameters, executemany + setattr(context, _STARTED_AT_ATTR, time.perf_counter()) + setattr( + context, + _OPERATION_ATTR, + statement.split(None, 1)[0].upper() if statement else "UNKNOWN", + ) + _emit_pool_metrics(conn.engine.pool) + + @event.listens_for(engine, "after_cursor_execute") + def _after_cursor_execute( + conn: Connection, + cursor: DBAPICursor, + statement: str, + parameters: object, + context: ExecutionContext, + executemany: bool, + ) -> None: + del cursor, statement, parameters, executemany + started_at = getattr(context, _STARTED_AT_ATTR, None) + if started_at is not None: + duration_ms = (time.perf_counter() - started_at) * 1000 + if duration_ms >= DB_SLOW_QUERY_MS: + record_db_slow_query(getattr(context, _OPERATION_ATTR, None)) + _emit_pool_metrics(conn.engine.pool) + + # insert=True: must run before the instrumentor's hook ends the span. + @event.listens_for(engine, "after_cursor_execute", insert=True) + def _record_db_rows( + conn: Connection, + cursor: DBAPICursor, + statement: str, + parameters: object, + context: ExecutionContext, + executemany: bool, + ) -> None: + del conn, statement, parameters, executemany + span = getattr(context, "_otel_span", None) + rowcount = getattr(cursor, "rowcount", None) + if span is None or rowcount is None or rowcount < 0: + return + if span.is_recording(): + span.set_attribute(DB_ROWS_ATTRIBUTE, int(rowcount)) + + @event.listens_for(engine, "handle_error") + def _handle_error(exception_context: ExceptionContext) -> None: + context = exception_context.execution_context + operation = ( + getattr(context, _OPERATION_ATTR, None) if context is not None else None + ) + sqlstate = getattr(exception_context.original_exception, "sqlstate", None) + _tag_db_error(sqlstate) + record_db_query_failed(operation=operation, sqlstate=sqlstate) + + @event.listens_for(engine.pool, "checkout") + def _on_checkout( + dbapi_connection: DBAPIConnection, + connection_record: ConnectionPoolEntry, + connection_proxy: PoolProxiedConnection, + ) -> None: + del dbapi_connection, connection_record, connection_proxy + _emit_pool_metrics(engine.pool) + + @event.listens_for(engine.pool, "checkin") + def _on_checkin( + dbapi_connection: DBAPIConnection, connection_record: ConnectionPoolEntry + ) -> None: + del dbapi_connection, connection_record + _emit_pool_metrics(engine.pool) + + @event.listens_for(engine.pool, "connect") + def _on_connect( + dbapi_connection: DBAPIConnection, connection_record: ConnectionPoolEntry + ) -> None: + del dbapi_connection, connection_record + record_db_connection_event("opened") + + @event.listens_for(engine.pool, "close") + def _on_close( + dbapi_connection: DBAPIConnection, connection_record: ConnectionPoolEntry + ) -> None: + del dbapi_connection, connection_record + record_db_connection_event("closed") + + @event.listens_for(engine.pool, "invalidate") + def _on_invalidate( + dbapi_connection: DBAPIConnection, + connection_record: ConnectionPoolEntry, + exception: BaseException | None, + ) -> None: + del dbapi_connection, connection_record, exception + record_db_connection_event("invalidated") + + @event.listens_for(engine, "commit") + def _on_commit(conn: Connection) -> None: + del conn + record_db_transaction("commit") + + @event.listens_for(engine, "rollback") + def _on_rollback(conn: Connection) -> None: + del conn + record_db_transaction("rollback") + + setattr(engine, _INSTRUMENTED_ATTR, True) + logger.debug("[instrument_db_engine] SQLAlchemy DB telemetry enabled") diff --git a/backend/app/core/telemetry/http.py b/backend/app/core/telemetry/http.py new file mode 100644 index 000000000..a11b8640c --- /dev/null +++ b/backend/app/core/telemetry/http.py @@ -0,0 +1,49 @@ +"""HTTP request metrics (count, duration, body size, errors) emitted from core/middleware.py.""" + +from app.core.telemetry.metrics import emit_sentry_metric + +HTTP_ERROR_STATUS_THRESHOLD: int = 400 +UNMATCHED_ROUTE: str = "unmatched" + + +def record_http_request( + *, + method: str, + http_route: str, + status: int, + duration_ms: float, + request_body_size: int = 0, +) -> None: + """Emit HTTP traffic, latency, payload-size and error counters to Sentry.""" + attrs: dict[str, str | int | float] = { + "http.method": method, + "http.route": http_route, + "http.status_code": str(status), + } + emit_sentry_metric("count", "http.server.request.count", 1, attributes=attrs) + emit_sentry_metric( + "distribution", + "http.server.request.duration", + duration_ms, + unit="millisecond", + attributes=attrs, + ) + emit_sentry_metric( + "distribution", + "http.server.request.body.size", + request_body_size, + unit="byte", + attributes=attrs, + ) + if status >= HTTP_ERROR_STATUS_THRESHOLD: + emit_sentry_metric("count", "http.server.request.error", 1, attributes=attrs) + + +def record_unmatched_request(*, method: str) -> None: + """Count requests that matched no route (scanners/bots) without a route label.""" + emit_sentry_metric( + "count", + "http.server.request.unmatched", + 1, + attributes={"http.method": method}, + ) diff --git a/backend/app/core/telemetry/llm.py b/backend/app/core/telemetry/llm.py new file mode 100644 index 000000000..32423f847 --- /dev/null +++ b/backend/app/core/telemetry/llm.py @@ -0,0 +1,145 @@ +"""LLM call telemetry: gen_ai span attributes, call/token metrics, HTTP span suppression around provider calls.""" + +import json +from collections.abc import Generator, Mapping +from contextlib import contextmanager +from typing import TYPE_CHECKING + +from opentelemetry import trace +from opentelemetry.instrumentation.utils import ( + suppress_http_instrumentation as otel_suppress_http_instrumentation, +) + +from app.core.telemetry.metrics import emit_sentry_metric + +if TYPE_CHECKING: + from app.models.llm.response import LLMCallResponse + + +def _llm_call_attrs( + provider: str, + model: str, + operation: str, + organization_id: int | None, + project_id: int | None, +) -> dict[str, str]: + attrs: dict[str, str] = { + "gen_ai.system": provider, + "gen_ai.request.model": model, + "gen_ai.operation.name": operation, + } + if organization_id is not None: + attrs["kaapi.organization_id"] = str(organization_id) + if project_id is not None: + attrs["kaapi.project_id"] = str(project_id) + return attrs + + +def record_llm_call_started( + provider: str, + model: str, + operation: str, + organization_id: int | None = None, + project_id: int | None = None, +) -> None: + """Emit LLM call-start metric to Sentry.""" + attrs = _llm_call_attrs(provider, model, operation, organization_id, project_id) + emit_sentry_metric("count", "llm.call.total", 1, attributes=attrs) + + +def record_llm_call_finished( + provider: str, + model: str, + operation: str, + duration_ms: float, + input_tokens: int | None = None, + output_tokens: int | None = None, + total_tokens: int | None = None, + error: bool = False, + organization_id: int | None = None, + project_id: int | None = None, +) -> None: + """Emit LLM call-completion metrics (latency, tokens, errors) to Sentry.""" + attrs = _llm_call_attrs(provider, model, operation, organization_id, project_id) + + emit_sentry_metric( + "distribution", + "llm.call.duration", + duration_ms, + unit="millisecond", + attributes=attrs, + ) + if error: + emit_sentry_metric("count", "llm.call.errors", 1, attributes=attrs) + if input_tokens is not None: + emit_sentry_metric("count", "llm.tokens.input", input_tokens, attributes=attrs) + if output_tokens is not None: + emit_sentry_metric( + "count", "llm.tokens.output", output_tokens, attributes=attrs + ) + if total_tokens is not None: + emit_sentry_metric("count", "llm.tokens.total", total_tokens, attributes=attrs) + + +def set_gen_ai_request_attributes( + span: trace.Span, + *, + provider: str, + model: str, + operation: str, + organization_id: int | None, + project_id: int | None, + params: Mapping[str, object] | None = None, +) -> None: + """Set OTel GenAI request attributes on `span` (semantic-convention keys + kaapi ids).""" + span.set_attribute("gen_ai.system", provider) + span.set_attribute("gen_ai.provider.name", provider) + span.set_attribute("gen_ai.operation.name", operation) + if model: + span.set_attribute("gen_ai.request.model", model) + if organization_id is not None: + span.set_attribute("kaapi.organization_id", organization_id) + span.set_attribute("gen_ai.request.organization_id", organization_id) + if project_id is not None: + span.set_attribute("kaapi.project_id", project_id) + span.set_attribute("gen_ai.request.project_id", project_id) + + params = params or {} + for attr_key, param_key in ( + ("gen_ai.request.temperature", "temperature"), + ("gen_ai.request.max_tokens", "max_tokens"), + ("gen_ai.request.top_p", "top_p"), + ("gen_ai.request.presence_penalty", "presence_penalty"), + ("gen_ai.request.frequency_penalty", "frequency_penalty"), + ): + value = params.get(param_key) + if isinstance(value, str | bool | int | float): + span.set_attribute(attr_key, value) + + tools = params.get("tools") + if tools is not None: + span.set_attribute("gen_ai.request.available_tools", json.dumps(tools)) + + +def set_gen_ai_response_attributes( + span: trace.Span, *, response: "LLMCallResponse" +) -> None: + """Set OTel GenAI response attributes (usage, model) on `span`.""" + usage = response.usage + if usage: + span.set_attribute("gen_ai.usage.input_tokens", usage.input_tokens) + span.set_attribute("gen_ai.usage.output_tokens", usage.output_tokens) + span.set_attribute("gen_ai.usage.total_tokens", usage.total_tokens) + reasoning_tokens = getattr(usage, "reasoning_tokens", None) + if reasoning_tokens is not None: + span.set_attribute("gen_ai.usage.output_tokens.reasoning", reasoning_tokens) + + if response.response and response.response.model: + span.set_attribute("gen_ai.response.model", response.response.model) + + +@contextmanager +def suppress_http_instrumentation() -> Generator[None]: + """Skip OTel HTTP client spans for the block; the LLM span already covers the call.""" + with otel_suppress_http_instrumentation(): + yield diff --git a/backend/app/core/telemetry/metrics.py b/backend/app/core/telemetry/metrics.py new file mode 100644 index 000000000..f519612e3 --- /dev/null +++ b/backend/app/core/telemetry/metrics.py @@ -0,0 +1,110 @@ +"""Sentry metrics emitter plus platform monitors: stale pending jobs, rate-threshold alerts.""" + +import logging +from collections.abc import Mapping +from typing import Literal + +import sentry_sdk + +logger = logging.getLogger(__name__) + +MetricType = Literal["count", "gauge", "distribution"] +MetricAttributes = Mapping[str, str | int | float] + + +def emit_sentry_metric( + metric_type: MetricType, + name: str, + value: float, + *, + unit: str | None = None, + attributes: MetricAttributes | None = None, +) -> None: + """Best-effort Sentry metric emission. No-op if SDK is not active.""" + try: + if not sentry_sdk.get_client().is_active(): + return + emitter = getattr(sentry_sdk.metrics, metric_type) + emitter(name=name, value=value, unit=unit, attributes=dict(attributes or {})) + except Exception: + logger.debug("[emit_sentry_metric] Failed to emit %s (%s)", name, metric_type) + + +def record_stale_pending_jobs( + *, + table: str, + status: str, + stale_count: int, + oldest_age_seconds: int | None, + job_type: str | None = None, + action_type: str | None = None, + dimensional: bool = False, +) -> None: + """Emit aggregate pending-job monitor metrics to Sentry. + + When ``dimensional`` is True, the metric is emitted under a separate + name so per-group counts (grouped by job_type/action_type) do not get + summed together with the table-level count in Sentry dashboards. + """ + attrs: dict[str, str] = { + "job.table": table, + "job.status": status, + } + if job_type: + attrs["job.type"] = job_type + if action_type: + attrs["job.action_type"] = action_type + + count_metric = ( + "jobs.pending.stale.by_dimension.count" + if dimensional + else "jobs.pending.stale.count" + ) + age_metric = ( + "jobs.pending.oldest_age_seconds.by_dimension" + if dimensional + else "jobs.pending.oldest_age_seconds" + ) + + emit_sentry_metric( + "gauge", + count_metric, + stale_count, + attributes=attrs, + ) + if oldest_age_seconds is not None: + emit_sentry_metric( + "gauge", + age_metric, + oldest_age_seconds, + unit="second", + attributes=attrs, + ) + + +def record_rate_threshold( + *, + project_id: int, + project_name: str | None, + category: str, + request_count: int, + threshold: int, +) -> None: + """Emit rate threshold exceeded event to Sentry.""" + + try: + if not sentry_sdk.get_client().is_active(): + return + with sentry_sdk.new_scope() as scope: + scope.set_tag("alert.type", "threshold_rate_monitor") + scope.set_tag("tenant.project_id", project_id) + scope.set_tag("route_category", category) + scope.set_extra("request_count", request_count) + scope.set_extra("threshold", threshold) + sentry_sdk.capture_message( + f"[Threshold-Monitor] {category} rate limit exceeded for project {project_id} | {project_name}: {request_count} req/min " + f"(limit {threshold}/min)", + level="warning", + ) + except Exception: + logger.exception("[record_rate_threshold] Failed to emit alert") diff --git a/backend/app/core/telemetry/sentry/__init__.py b/backend/app/core/telemetry/sentry/__init__.py new file mode 100644 index 000000000..e26afd7a5 --- /dev/null +++ b/backend/app/core/telemetry/sentry/__init__.py @@ -0,0 +1,5 @@ +"""Sentry SDK wiring: init_sentry() shared by API and Celery worker.""" + +from app.core.telemetry.sentry.init import init_sentry + +__all__ = ["init_sentry"] diff --git a/backend/app/core/telemetry/sentry/filters.py b/backend/app/core/telemetry/sentry/filters.py new file mode 100644 index 000000000..00f37a69f --- /dev/null +++ b/backend/app/core/telemetry/sentry/filters.py @@ -0,0 +1,204 @@ +"""Sentry before_send filters: drop probe events, scrub genai content, request PII and LLM job kwargs.""" + +import re +from importlib import import_module +from urllib.parse import urlsplit + +from sentry_sdk.integrations import Integration +from sentry_sdk.types import Event, Hint, Log + +from app.core.config import settings + +_SENSITIVE_HEADERS: frozenset[str] = frozenset( + {"authorization", "cookie", "set-cookie", "x-api-key"} +) + +_GENAI_CONTENT_KEYS: frozenset[str] = frozenset( + { + "gen_ai.request.messages", + "gen_ai.response.text", + "gen_ai.response.tool_calls", + "gen_ai.choice", + "gen_ai.embeddings.input", + "gen_ai.system_instructions", + "gen_ai.tool.input", + "gen_ai.tool.output", + "gen_ai.user.message", + "gen_ai.prompt", + "gen_ai.completion", + "ai.input_messages", + "ai.responses", + "ai.prompt", + "ai.texts", + "ai.tool_calls", + "ai.function_call", + "ai.search_queries", + "langfuse.observation.input", + "langfuse.observation.output", + "langfuse.trace.input", + "langfuse.trace.output", + } +) + +_GENAI_SCRUB_MAX_DEPTH: int = 8 + +# Sentry auto-enables these per installed SDK; they record prompts when PII is on. +_GENAI_INTEGRATIONS: tuple[tuple[str, str], ...] = ( + ("sentry_sdk.integrations.anthropic", "AnthropicIntegration"), + ("sentry_sdk.integrations.google_genai", "GoogleGenAIIntegration"), + ("sentry_sdk.integrations.langgraph", "LanggraphIntegration"), + ("sentry_sdk.integrations.openai", "OpenAIIntegration"), +) + +_REDACTED = "[REDACTED]" + +# CeleryIntegration ships task kwargs; these keys carry end-user text. +_LLM_JOB_TASK_NAMES = { + "app.celery.tasks.job_execution.run_llm_job", + "app.celery.tasks.job_execution.run_llm_chain_job", +} +_SENSITIVE_REQUEST_DATA_KEYS = ("query",) +_INSTRUCTIONS_KEY = "instructions" + + +_BARE_HTTP_METHOD = re.compile( + r"^(GET|HEAD|OPTIONS|POST|PUT|PATCH|DELETE|TRACE|CONNECT)$", re.IGNORECASE +) +_NOISE_PATH = re.compile( + r"(^/health/?$|^/robots\.txt$|^/favicon\.ico$|^/wp-admin|^/wp-login|^/xmlrpc\.php$)", + re.IGNORECASE, +) + + +def _request_path(event: Event) -> str: + request = event.get("request") + url = request.get("url") if isinstance(request, dict) else None + return urlsplit(url).path if isinstance(url, str) else "" + + +def _is_probe_event(event: Event) -> bool: + # Sentry shows probe traffic as bare "GET"/"HEAD" transactions. + transaction = str(event.get("transaction") or "").strip() + if _BARE_HTTP_METHOD.match(transaction): + return True + path = _request_path(event) + return bool(path and _NOISE_PATH.search(path)) + + +def genai_privacy_integrations() -> list[Integration]: + """AI integrations pinned to include_prompts=False; missing SDKs are skipped.""" + integrations: list[Integration] = [] + for module_path, class_name in _GENAI_INTEGRATIONS: + try: + integration_class = getattr(import_module(module_path), class_name) + integrations.append(integration_class(include_prompts=False)) + except Exception: + continue + return integrations + + +def _is_genai_content_key(key: object) -> bool: + """True for a genai content key or one of its unpacked sub-keys (`...messages.0.content`).""" + if not isinstance(key, str): + return False + lowered = key.lower() + return any( + lowered == content_key or lowered.startswith(f"{content_key}.") + for content_key in _GENAI_CONTENT_KEYS + ) + + +def scrub_genai_content(payload: object, depth: int = 0) -> None: + """Strip genai prompt/completion values in-place from a nested Sentry payload.""" + if depth > _GENAI_SCRUB_MAX_DEPTH: + return + if isinstance(payload, dict): + for key in list(payload): + if _is_genai_content_key(key): + del payload[key] + else: + scrub_genai_content(payload[key], depth + 1) + elif isinstance(payload, list): + for item in payload: + scrub_genai_content(item, depth + 1) + + +def _scrub_request(event: Event) -> None: + """Drop the body always (LLM routes carry the user message); headers/cookies/query only when PII is off.""" + request = event.get("request") + if not isinstance(request, dict): + return + if "data" in request: + request["data"] = _REDACTED + if settings.SENTRY_SEND_DEFAULT_PII: + return + headers = request.get("headers") + if isinstance(headers, dict): + for key in headers: + if str(key).lower() in _SENSITIVE_HEADERS: + headers[key] = _REDACTED + if "cookies" in request: + request["cookies"] = _REDACTED + if request.get("query_string"): + request["query_string"] = _REDACTED + + +def _scrub_llm_job_kwargs(event: Event) -> None: + """Redact the user query and every config `instructions` in LLM task kwargs; keep other params.""" + extra = event.get("extra") + celery_job = extra.get("celery-job") if isinstance(extra, dict) else None + if not isinstance(celery_job, dict): + return + if celery_job.get("task_name") not in _LLM_JOB_TASK_NAMES: + return + kwargs = celery_job.get("kwargs") + request_data = kwargs.get("request_data") if isinstance(kwargs, dict) else None + if not isinstance(request_data, dict): + return + for key in _SENSITIVE_REQUEST_DATA_KEYS: + if key in request_data: + request_data[key] = _REDACTED + _redact_instructions(request_data) + + +def _redact_instructions(payload: object, depth: int = 0) -> None: + """Replace every `instructions` value in a nested config (call or chain blocks) with a placeholder.""" + if depth > _GENAI_SCRUB_MAX_DEPTH: + return + if isinstance(payload, dict): + for key, value in payload.items(): + if key == _INSTRUCTIONS_KEY and value is not None: + payload[key] = _REDACTED + else: + _redact_instructions(value, depth + 1) + elif isinstance(payload, list): + for item in payload: + _redact_instructions(item, depth + 1) + + +def before_send_transaction_filter(event: Event, _hint: Hint) -> Event | None: + """Scrub genai content from transactions; probe/bot spans are dropped earlier in tracing.""" + scrub_genai_content(event) + return event + + +def before_send_error_filter(event: Event, _hint: Hint) -> Event | None: + """Drop probe events; scrub request body/PII, LLM job kwargs and genai content.""" + try: + if _is_probe_event(event): + return None + _scrub_request(event) + _scrub_llm_job_kwargs(event) + scrub_genai_content(event) + except Exception: + return event + return event + + +def before_send_log_filter(log: Log, _hint: Hint) -> Log | None: + """Strip genai content from Sentry log attributes before shipping.""" + try: + scrub_genai_content(log.get("attributes")) + except Exception: + return log + return log diff --git a/backend/app/core/telemetry/sentry/init.py b/backend/app/core/telemetry/sentry/init.py new file mode 100644 index 000000000..c33a631ba --- /dev/null +++ b/backend/app/core/telemetry/sentry/init.py @@ -0,0 +1,51 @@ +"""sentry_sdk.init() with shared sampling, profiling, PII and before_send filters.""" + +import logging + +import sentry_sdk +from sentry_sdk.integrations import Integration +from sentry_sdk.integrations.logging import LoggingIntegration + +from app.core.config import settings +from app.core.telemetry.sentry.filters import ( + before_send_error_filter, + before_send_log_filter, + before_send_transaction_filter, + genai_privacy_integrations, +) + +SENTRY_MAX_BREADCRUMBS = 30 + + +def init_sentry( + *, + integrations: list[Integration], + disabled_integrations: list[Integration], +) -> None: + """Initialise the Sentry SDK with the shared sampling, privacy and filter config.""" + if not settings.SENTRY_DSN: + return + sentry_sdk.init( + dsn=str(settings.SENTRY_DSN), + environment=settings.ENVIRONMENT, + release=settings.API_VERSION, + instrumenter="otel", + traces_sample_rate=settings.SENTRY_TRACES_SAMPLE_RATE, + sample_rate=settings.SENTRY_ERROR_SAMPLE_RATE, + profile_session_sample_rate=settings.SENTRY_PROFILE_SESSION_SAMPLE_RATE, + profile_lifecycle=settings.SENTRY_PROFILE_LIFECYCLE, + send_default_pii=settings.SENTRY_SEND_DEFAULT_PII, + enable_logs=True, + include_local_variables=False, + max_request_body_size="never", + max_breadcrumbs=SENTRY_MAX_BREADCRUMBS, + before_send=before_send_error_filter, + before_send_transaction=before_send_transaction_filter, + before_send_log=before_send_log_filter, + integrations=[ + LoggingIntegration(level=logging.INFO, sentry_logs_level=logging.INFO), + *genai_privacy_integrations(), + *integrations, + ], + disabled_integrations=disabled_integrations, + ) diff --git a/backend/app/core/telemetry/tracing.py b/backend/app/core/telemetry/tracing.py new file mode 100644 index 000000000..7bd9a2982 --- /dev/null +++ b/backend/app/core/telemetry/tracing.py @@ -0,0 +1,212 @@ +"""OTel tracing setup: TracerProvider, Sentry span processor and noise filter, FastAPI instrumentation, flush.""" + +import logging +import os +import re +from collections.abc import Mapping +from typing import Literal + +import sentry_sdk +from fastapi import FastAPI +from opentelemetry import context as otel_context +from opentelemetry import trace +from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor +from opentelemetry.instrumentation.httpx import HTTPXClientInstrumentor +from opentelemetry.instrumentation.logging import LoggingInstrumentor +from opentelemetry.instrumentation.requests import RequestsInstrumentor +from opentelemetry.propagate import set_global_textmap +from opentelemetry.sdk.resources import SERVICE_NAME, Resource +from opentelemetry.sdk.trace import ReadableSpan, TracerProvider +from opentelemetry.trace import SpanContext, SpanKind, StatusCode, format_span_id +from sentry_sdk.integrations.opentelemetry import SentryPropagator, SentrySpanProcessor +from sentry_sdk.tracing import Span as SentrySpan + +from app.core.config import settings + +logger = logging.getLogger(__name__) + +# "dup" keeps old `http.method` for Sentry's op mapping; must run before app.core.db imports. +OTEL_SEMCONV_OPT_IN_ENV = "OTEL_SEMCONV_STABILITY_OPT_IN" +OTEL_SEMCONV_OPT_IN_DEFAULT = "http/dup" +os.environ.setdefault(OTEL_SEMCONV_OPT_IN_ENV, OTEL_SEMCONV_OPT_IN_DEFAULT) + +FASTAPI_EXCLUDED_SPANS: list[Literal["receive", "send"]] = ["receive", "send"] +HTTP_ROUTE_ATTRIBUTE = "http.route" + + +def _should_drop_unrouted_server_span( + *, is_root: bool, kind: SpanKind, attributes: Mapping[str, object] | None +) -> bool: + """True for a root server span that matched no route: scanner/bot traffic.""" + return ( + is_root + and kind == SpanKind.SERVER + and HTTP_ROUTE_ATTRIBUTE not in (attributes or {}) + ) + + +def _should_drop_bare_http_trace( + *, is_root: bool, kind: SpanKind, status_code: StatusCode, had_children: bool +) -> bool: + """True for a root server span with no children and no error: nothing worth a trace.""" + return ( + is_root + and not had_children + and kind == SpanKind.SERVER + and status_code != StatusCode.ERROR + ) + + +def _build_resource(service_name: str | None = None) -> Resource: + return Resource.create( + { + SERVICE_NAME: service_name or settings.OTEL_SERVICE_NAME, + "deployment.environment": settings.ENVIRONMENT, + "service.version": settings.API_VERSION, + } + ) + + +class _NoiseFilteringSpanProcessor(SentrySpanProcessor): + """Drop childless, error-free HTTP root spans so bare single-span traces never ship.""" + + def __init__(self) -> None: + super().__init__() + self._traces_with_children: set[int] = set() + + def on_start( + self, + otel_span: ReadableSpan, + parent_context: otel_context.Context | None = None, + ) -> None: + parent = otel_span.parent + span_context = otel_span.get_span_context() + if parent is not None and not parent.is_remote and span_context is not None: + self._traces_with_children.add(span_context.trace_id) + super().on_start(otel_span, parent_context) + + def on_end(self, otel_span: ReadableSpan) -> None: + span_context = otel_span.get_span_context() + if span_context is None: + super().on_end(otel_span) + return + parent = otel_span.parent + is_root = parent is None or parent.is_remote + had_children = span_context.trace_id in self._traces_with_children + if is_root: + self._traces_with_children.discard(span_context.trace_id) + if _should_drop_unrouted_server_span( + is_root=is_root, kind=otel_span.kind, attributes=otel_span.attributes + ) or _should_drop_bare_http_trace( + is_root=is_root, + kind=otel_span.kind, + status_code=otel_span.status.status_code, + had_children=had_children, + ): + self._forget_span(otel_span, span_context) + return + super().on_end(otel_span) + + def _update_transaction_with_otel_data( + self, sentry_span: SentrySpan, otel_span: ReadableSpan + ) -> None: + """Base class keeps only method/status on the root span; forward every attribute.""" + super()._update_transaction_with_otel_data(sentry_span, otel_span) + for key, value in (otel_span.attributes or {}).items(): + sentry_span.set_data(key, value) + + def _forget_span(self, otel_span: ReadableSpan, span_context: SpanContext) -> None: + """Same bookkeeping as SentrySpanProcessor.on_end, minus shipping the span.""" + span_id = format_span_id(span_context.span_id) + self.otel_span_map.pop(span_id, None) + if otel_span.start_time is not None: + started_minute = int(otel_span.start_time / 1e9 / 60) + bucket = self.open_spans.get(started_minute) + if bucket is not None: + bucket.discard(span_id) + self._prune_old_spans() + + +def setup_telemetry(service_name: str | None = None) -> None: + """Initialize OTel tracing and bridge spans into Sentry; logs/metrics go via the SDK directly.""" + resource = _build_resource(service_name) + tracer_provider = TracerProvider(resource=resource) + + if settings.SENTRY_DSN: + tracer_provider.add_span_processor(_NoiseFilteringSpanProcessor()) + # Downstream services extract sentry-trace, not W3C traceparent. + set_global_textmap(SentryPropagator()) + + trace.set_tracer_provider(tracer_provider) + + LoggingInstrumentor().instrument(set_logging_format=False) + HTTPXClientInstrumentor().instrument() + RequestsInstrumentor().instrument() + try: + # Circular import fix + from opentelemetry.instrumentation.celery import CeleryInstrumentor + + CeleryInstrumentor().instrument() # type: ignore[no-untyped-call] + except Exception: + logger.exception("[setup_telemetry] Failed to instrument Celery") + + try: + from opentelemetry.instrumentation.redis import RedisInstrumentor + + RedisInstrumentor().instrument() + except Exception: + logger.exception("[setup_telemetry] Failed to instrument Redis") + + try: + from opentelemetry.instrumentation.botocore import BotocoreInstrumentor + + BotocoreInstrumentor().instrument() # type: ignore[no-untyped-call] + except Exception: + logger.exception("[setup_telemetry] Failed to instrument botocore") + + +def flush_telemetry(timeout_millis: int = 10000) -> None: + """Force-flush OTel spans into Sentry, then flush Sentry's transport. + + Called from Celery task_postrun: workers can recycle via max_tasks_per_child + before the SentrySpanProcessor's internal queue drains, otherwise dropping + closing spans and ERROR breadcrumbs from the just-finished task. + """ + try: + tp = trace.get_tracer_provider() + if hasattr(tp, "force_flush"): + tp.force_flush(timeout_millis=timeout_millis) + except Exception: + logger.exception("[flush_telemetry] Failed to flush tracer provider") + + try: + if sentry_sdk.get_client().is_active(): + sentry_sdk.flush(timeout=timeout_millis / 1000) + except Exception: + logger.exception("[flush_telemetry] Failed to flush Sentry") + + +def instrument_app(app: FastAPI) -> None: + """Instrument the FastAPI app. Call after the app is created.""" + from app.core.middleware import SILENT_LOG_PATHS, TRACE_EXCLUDED_PATH_PREFIXES + + # Doc/schema paths are read off the app so they follow config. + exact_paths = set(SILENT_LOG_PATHS) + for attr in ( + "docs_url", + "redoc_url", + "openapi_url", + "swagger_ui_oauth2_redirect_url", + ): + path = getattr(app, attr, None) + if path: + exact_paths.add(path) + + patterns = [rf"^{re.escape(p)}/?$" for p in exact_paths] + patterns += [rf"^{re.escape(p)}" for p in TRACE_EXCLUDED_PATH_PREFIXES] + excluded_urls = ",".join(sorted(patterns)) + FastAPIInstrumentor.instrument_app( + app, + excluded_urls=excluded_urls, + exclude_spans=FASTAPI_EXCLUDED_SPANS, + ) diff --git a/backend/app/main.py b/backend/app/main.py index e52025b00..3f49b6d35 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -1,6 +1,3 @@ -import logging - -import sentry_sdk from asgi_correlation_id.middleware import CorrelationIdMiddleware from fastapi import FastAPI from fastapi.openapi.utils import get_openapi @@ -8,7 +5,6 @@ from sentry_sdk.integrations.celery import CeleryIntegration from sentry_sdk.integrations.fastapi import FastApiIntegration from sentry_sdk.integrations.httpx import HttpxIntegration -from sentry_sdk.integrations.logging import LoggingIntegration from sentry_sdk.integrations.sqlalchemy import SqlalchemyIntegration from sentry_sdk.integrations.starlette import StarletteIntegration @@ -18,8 +14,7 @@ from app.core.exception_handlers import register_exception_handlers from app.core.logger import configure_logging from app.core.middleware import StripTrailingSlashMiddleware, http_request_logger -from app.core.sentry_filters import before_send_filter, before_send_transaction_filter -from app.core.telemetry import instrument_app, setup_telemetry +from app.core.telemetry import init_sentry, instrument_app, setup_telemetry from app.load_env import load_environment # Load environment variables @@ -27,35 +22,18 @@ configure_logging(service_name=settings.BACKEND_SERVICE_NAME) -if settings.SENTRY_DSN: - sentry_sdk.init( - dsn=str(settings.SENTRY_DSN), - environment=settings.ENVIRONMENT, - release=settings.API_VERSION, - instrumenter="otel", - traces_sample_rate=1.0, - # LLM input/output is end-user text; never attach request/response - # bodies to error events or trace transactions. - max_request_body_size="never", - enable_logs=True, - before_send=before_send_filter, - before_send_transaction=before_send_transaction_filter, - integrations=[ - LoggingIntegration( - level=logging.INFO, - sentry_logs_level=logging.INFO, - ), - ], - disabled_integrations=[ - FastApiIntegration(), - StarletteIntegration(), - SqlalchemyIntegration(), - CeleryIntegration(), - HttpxIntegration(), - ], - ) - -setup_telemetry(service_name=settings.BACKEND_SERVICE_NAME) +init_sentry( + integrations=[], + disabled_integrations=[ + FastApiIntegration(), + StarletteIntegration(), + SqlalchemyIntegration(), + CeleryIntegration(), + HttpxIntegration(), + ], +) +if settings.OTEL_ENABLED: + setup_telemetry(service_name=settings.BACKEND_SERVICE_NAME) def custom_generate_unique_id(route: APIRoute) -> str: @@ -105,7 +83,8 @@ def custom_openapi(): register_exception_handlers(app) -instrument_app(app) +if settings.OTEL_ENABLED: + instrument_app(app) # health check endpoint for uptime monitoring diff --git a/backend/app/services/assessment/api/batch.py b/backend/app/services/assessment/api/batch.py index 3f296e552..0e760b63e 100644 --- a/backend/app/services/assessment/api/batch.py +++ b/backend/app/services/assessment/api/batch.py @@ -571,8 +571,8 @@ def _parse_verdict(output: str | None) -> Verdict: } except (json.JSONDecodeError, TypeError, AttributeError): logger.warning( - "[_parse_verdict] Unparseable verdict, failing open | output=%s", - output[:200], + "[_parse_verdict] Unparseable verdict, failing open | output_len=%s", + len(output), ) return {"verdict": True, "reasoning": ""} diff --git a/backend/app/services/llm/jobs.py b/backend/app/services/llm/jobs.py index c07084d34..726c47287 100644 --- a/backend/app/services/llm/jobs.py +++ b/backend/app/services/llm/jobs.py @@ -20,6 +20,7 @@ from app.core.providers import Provider from app.core.langfuse.langfuse import observe_llm_execution from app.core.telemetry import ( + LogModuleEnum, set_gen_ai_request_attributes, set_gen_ai_response_attributes, flush_telemetry, @@ -210,6 +211,7 @@ def start_chain_job( with log_context( tag="llm-chain", + module=LogModuleEnum.LLM_CHAIN, lifecycle="llm.chain.start_job", job_id=job.id, project_id=project_id, @@ -1556,6 +1558,7 @@ def execute_chain_job( with log_context( tag="llm-chain", + module=LogModuleEnum.LLM_CHAIN, lifecycle="llm.chain.execute_job", job_id=job_uuid, task_id=task_id, diff --git a/backend/app/services/llm/providers/google_aistudio.py b/backend/app/services/llm/providers/google_aistudio.py index 4ccb9eb76..16724c87c 100644 --- a/backend/app/services/llm/providers/google_aistudio.py +++ b/backend/app/services/llm/providers/google_aistudio.py @@ -169,10 +169,6 @@ def _execute_stt( else: merged_instruction = f"{lang_instruction}. {forced_transcription_text}" - logger.info( - f"The merged instructions is {merged_instruction} and output language is {output_language} and input language is {input_language}" - ) - # Materialize the AudioRef to a temp file so the genai SDK can upload it. with resolved_input.to_path() as audio_path: gemini_file = self.client.files.upload(file=audio_path) diff --git a/backend/app/tests/assessment/test_api_submission.py b/backend/app/tests/assessment/test_api_submission.py index f35c496f5..adecc8900 100644 --- a/backend/app/tests/assessment/test_api_submission.py +++ b/backend/app/tests/assessment/test_api_submission.py @@ -127,6 +127,22 @@ def test_creates_assessment_run_and_dispatches(self, db) -> None: assert bag["stage_status"] == AssessmentStatus.PENDING.value assert bag["callback_url"].startswith("https://hook.example") + def test_immediate_dispatch_keeps_trace_propagation(self, db) -> None: + auth = get_user_test_auth_context(db) + config = _assessment_config(db, auth.project_id) + request = _request(config, [{"a": "one"}]) + + with patch("app.celery.tasks.job_execution.run_assessment_api_batch") as task: + submission.submit( + session=db, + request=request, + organization_id=auth.organization_id, + project_id=auth.project_id, + ) + + task.delay.assert_called_once() + assert "headers" not in task.delay.call_args.kwargs + def test_row_missing_strict_column_is_422(self, db) -> None: auth = get_user_test_auth_context(db) config = _assessment_config( diff --git a/backend/app/tests/celery/test_celery_app.py b/backend/app/tests/celery/test_celery_app.py new file mode 100644 index 000000000..f40275440 --- /dev/null +++ b/backend/app/tests/celery/test_celery_app.py @@ -0,0 +1,92 @@ +import importlib +from types import SimpleNamespace +from unittest.mock import MagicMock, patch + +from sqlalchemy.pool import QueuePool + +celery_app = importlib.import_module("app.celery.celery_app") + + +def _queue_pool_engine() -> MagicMock: + pool = MagicMock(spec=QueuePool) + pool.checkedout.return_value = 1 + pool.size.return_value = 5 + pool.overflow.return_value = 0 + return MagicMock(pool=pool) + + +class TestPoolStatusSignals: + def test_prerun_and_postrun_log_pool_state(self, caplog) -> None: + engine = _queue_pool_engine() + task = SimpleNamespace(name="run_llm_job") + with patch("app.core.db.engine", engine), caplog.at_level("INFO"): + celery_app.log_pool_status(task=task) + celery_app.log_pool_status_post(task=task) + + messages = [r.getMessage() for r in caplog.records] + assert any("task=run_llm_job checked_out=1" in m for m in messages) + assert any("POST task=run_llm_job" in m for m in messages) + + def test_failure_logs_exception_name(self, caplog) -> None: + engine = _queue_pool_engine() + with patch("app.core.db.engine", engine), caplog.at_level("WARNING"): + celery_app.log_pool_status_failure( + task_id="t1", + exception=ValueError("x"), + sender=SimpleNamespace(name="job"), + ) + + assert any( + "FAILED task=job task_id=t1 exc=ValueError" in r.getMessage() + for r in caplog.records + ) + + +class TestWorkerObservabilityInit: + def test_initialises_sentry_and_telemetry_once(self) -> None: + init_sentry = MagicMock() + setup = MagicMock() + with ( + patch.object(celery_app, "_sentry_initialized", False), + patch.object(celery_app, "_telemetry_initialized", False), + patch.object(celery_app, "_flush_hook_registered", False), + patch.object(celery_app.settings, "OTEL_ENABLED", True), + patch.object( + celery_app.settings, "SENTRY_DSN", "https://k@o.ingest.sentry.io/1" + ), + patch("app.core.telemetry.init_sentry", init_sentry), + patch("app.core.telemetry.setup_telemetry", setup), + patch.object(celery_app, "configure_logging", MagicMock()), + ): + celery_app._initialize_worker_observability() + celery_app._initialize_worker_observability() + + init_sentry.assert_called_once() + setup.assert_called_once_with(service_name="kaapi-celery") + + def test_tags_sentry_scope_with_task_name_on_prerun(self) -> None: + hooks: list = [] + sentry = MagicMock() + with ( + patch.object(celery_app, "_sentry_initialized", False), + patch.object(celery_app, "_telemetry_initialized", True), + patch.object( + celery_app.settings, "SENTRY_DSN", "https://k@o.ingest.sentry.io/1" + ), + patch("app.core.telemetry.init_sentry", MagicMock()), + patch.object( + celery_app.task_prerun, + "connect", + MagicMock(side_effect=lambda **_: hooks.append), + ), + patch.object(celery_app, "configure_logging", MagicMock()), + patch.dict("sys.modules", {"sentry_sdk": sentry}), + ): + celery_app._initialize_worker_observability() + hooks[0]( + task=SimpleNamespace(name="app.celery.tasks.job_execution.run_llm_job") + ) + + sentry.set_tag.assert_called_once_with( + "celery.task_name", "app.celery.tasks.job_execution.run_llm_job" + ) diff --git a/backend/app/tests/celery/test_job_execution.py b/backend/app/tests/celery/test_job_execution.py new file mode 100644 index 000000000..c18eb32e8 --- /dev/null +++ b/backend/app/tests/celery/test_job_execution.py @@ -0,0 +1,58 @@ +from unittest.mock import patch + +import pytest + +from app.celery.tasks import job_execution + +SENTINEL = object() + + +@pytest.mark.parametrize( + ("task_name", "service_target"), + [ + ("run_llm_job", "app.services.llm.jobs.execute_job"), + ("run_llm_chain_job", "app.services.llm.jobs.execute_chain_job"), + ("run_response_job", "app.services.response.jobs.execute_job"), + ], +) +class TestJobWrappers: + def test_returns_service_result(self, task_name, service_target): + task = getattr(job_execution, task_name) + with ( + patch.object(job_execution, "_set_trace", lambda trace_id: None), + patch(service_target, return_value=SENTINEL), + ): + result = task(project_id=1, job_id="job-1", trace_id="trace-1") + + assert result is SENTINEL + + +class TestAssessmentApiBatchReenqueue: + def _run(self, requeue: bool): + with ( + patch.object(job_execution, "_set_trace", lambda trace_id: None), + patch( + "app.services.assessment.api.batch.run_batch_stage", + return_value={"requeue": requeue}, + ), + patch.object( + job_execution.run_assessment_api_batch, "apply_async" + ) as apply_async, + ): + job_execution.run_assessment_api_batch( + execution_id=1, organization_id=2, project_id=3, trace_id="trace-1" + ) + return apply_async + + def test_reenqueue_passes_no_propagate_header(self): + apply_async = self._run(requeue=True) + + apply_async.assert_called_once() + assert apply_async.call_args.kwargs["headers"] == { + "sentry-propagate-traces": False + } + + def test_no_reenqueue_when_stage_not_requeued(self): + apply_async = self._run(requeue=False) + + apply_async.assert_not_called() diff --git a/backend/app/tests/core/telemetry/__init__.py b/backend/app/tests/core/telemetry/__init__.py new file mode 100644 index 000000000..e69de29bb diff --git a/backend/app/tests/core/telemetry/sentry/__init__.py b/backend/app/tests/core/telemetry/sentry/__init__.py new file mode 100644 index 000000000..e69de29bb diff --git a/backend/app/tests/core/telemetry/sentry/test_sentry_filters.py b/backend/app/tests/core/telemetry/sentry/test_sentry_filters.py new file mode 100644 index 000000000..ba6bb2633 --- /dev/null +++ b/backend/app/tests/core/telemetry/sentry/test_sentry_filters.py @@ -0,0 +1,327 @@ +from typing import Any +from unittest.mock import MagicMock, patch + +from app.core.telemetry.sentry import filters as sentry_filters + + +class TestBeforeSendErrorFilter: + def test_drops_probe_scanner_event(self) -> None: + event = {"transaction": "GET", "request": {"url": "http://x/health"}} + assert sentry_filters.before_send_error_filter(event, {}) is None + + def test_scrubs_pii_when_send_default_pii_off(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "request": { + "url": "http://x/api/v1/llm/generate", + "headers": { + "Authorization": "Bearer secret", + "Cookie": "session=abc", + "Set-Cookie": "session=abc", + "X-API-KEY": "sk-123", + "User-Agent": "curl/8", + }, + "query_string": "token=secret", + "cookies": {"session": "abc"}, + "data": {"password": "hunter2"}, + }, + } + with patch.object(sentry_filters.settings, "SENTRY_SEND_DEFAULT_PII", False): + result = sentry_filters.before_send_error_filter(event, {}) + + assert result is event + headers = result["request"]["headers"] + assert headers["Authorization"] == sentry_filters._REDACTED + assert headers["Cookie"] == sentry_filters._REDACTED + assert headers["Set-Cookie"] == sentry_filters._REDACTED + assert headers["X-API-KEY"] == sentry_filters._REDACTED + assert headers["User-Agent"] == "curl/8" + assert result["request"]["query_string"] == sentry_filters._REDACTED + assert result["request"]["cookies"] == sentry_filters._REDACTED + assert result["request"]["data"] == sentry_filters._REDACTED + + def test_passes_normal_event_through(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "request": { + "url": "http://x/api/v1/llm/generate", + "headers": {"User-Agent": "curl/8"}, + }, + } + with patch.object(sentry_filters.settings, "SENTRY_SEND_DEFAULT_PII", False): + result = sentry_filters.before_send_error_filter(event, {}) + + assert result is event + assert result["request"]["headers"]["User-Agent"] == "curl/8" + + def test_keeps_headers_when_send_default_pii_on(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "request": { + "url": "http://x/api/v1/llm/generate", + "headers": {"Authorization": "Bearer secret"}, + "cookies": {"session": "abc"}, + }, + } + with patch.object(sentry_filters.settings, "SENTRY_SEND_DEFAULT_PII", True): + result = sentry_filters.before_send_error_filter(event, {}) + + assert result["request"]["headers"]["Authorization"] == "Bearer secret" + assert result["request"]["cookies"] == {"session": "abc"} + + def test_returns_event_on_internal_exception(self) -> None: + bad_event = MagicMock() + bad_event.get.side_effect = RuntimeError("malformed") + + assert sentry_filters.before_send_error_filter(bad_event, {}) is bad_event + + def test_scrubs_request_body_when_send_default_pii_on(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "request": { + "url": "http://x/api/v1/llm/generate", + "data": {"query": {"input": "what is my aadhaar number"}}, + }, + } + with patch.object(sentry_filters.settings, "SENTRY_SEND_DEFAULT_PII", True): + result = sentry_filters.before_send_error_filter(event, {}) + + assert result["request"]["data"] == sentry_filters._REDACTED + + def test_scrubs_genai_content_from_error_event(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "contexts": { + "trace": { + "data": { + "gen_ai.request.messages": [{"content": "user secret"}], + "gen_ai.response.text": "model answer", + "gen_ai.request.model": "gpt-4o", + } + } + }, + } + with patch.object(sentry_filters.settings, "SENTRY_SEND_DEFAULT_PII", False): + result = sentry_filters.before_send_error_filter(event, {}) + + data = result["contexts"]["trace"]["data"] + assert "gen_ai.request.messages" not in data + assert "gen_ai.response.text" not in data + assert data["gen_ai.request.model"] == "gpt-4o" + + +class TestScrubGenaiContent: + def test_drops_content_keys_and_unpacked_subkeys(self) -> None: + payload = { + "gen_ai.request.messages": ["hi"], + "gen_ai.request.messages.0.content": "hi", + "gen_ai.response.text": "hello", + "ai.input_messages": ["hi"], + "langfuse.trace.output": "hello", + "gen_ai.usage.total_tokens": 42, + } + sentry_filters.scrub_genai_content(payload) + + assert payload == {"gen_ai.usage.total_tokens": 42} + + def test_is_case_insensitive(self) -> None: + payload = {"GEN_AI.Response.Text": "hello"} + sentry_filters.scrub_genai_content(payload) + + assert payload == {} + + def test_walks_nested_lists_and_dicts(self) -> None: + payload = { + "spans": [ + {"data": {"gen_ai.response.text": "hello", "gen_ai.system": "openai"}} + ] + } + sentry_filters.scrub_genai_content(payload) + + assert payload["spans"][0]["data"] == {"gen_ai.system": "openai"} + + def test_stops_at_max_depth(self) -> None: + deepest: dict = {"gen_ai.response.text": "hello"} + payload: dict = deepest + for _ in range(sentry_filters._GENAI_SCRUB_MAX_DEPTH + 2): + payload = {"nested": payload} + + sentry_filters.scrub_genai_content(payload) + + assert deepest == {"gen_ai.response.text": "hello"} + + +class TestBeforeSendTransactionFilter: + def test_scrubs_genai_content_from_spans(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "spans": [ + { + "op": "gen_ai.chat", + "description": "chat gpt-4o", + "data": { + "gen_ai.request.messages": [{"content": "user secret"}], + "gen_ai.response.text": "model answer", + "gen_ai.usage.total_tokens": 12, + }, + } + ], + } + result = sentry_filters.before_send_transaction_filter(event, {}) + + assert result is not None + span_data = result["spans"][0]["data"] + assert span_data == {"gen_ai.usage.total_tokens": 12} + + def test_keeps_gen_ai_span_itself(self) -> None: + event = { + "transaction": "POST /api/v1/llm/generate", + "spans": [{"op": "gen_ai.chat", "description": "chat gpt-4o", "data": {}}], + } + result = sentry_filters.before_send_transaction_filter(event, {}) + + assert result is not None + assert len(result["spans"]) == 1 + + +class TestBeforeSendLogFilter: + def test_scrubs_genai_attributes(self) -> None: + log = { + "body": "[execute] done", + "attributes": { + "gen_ai.response.text": "model answer", + "org_id": "1", + }, + } + assert sentry_filters.before_send_log_filter(log, {}) is log + assert log["attributes"] == {"org_id": "1"} + + def test_returns_log_on_internal_exception(self) -> None: + bad_log = MagicMock() + bad_log.get.side_effect = RuntimeError("malformed") + + assert sentry_filters.before_send_log_filter(bad_log, {}) is bad_log + + +class TestGenaiPrivacyIntegrations: + def test_all_returned_integrations_disable_prompts(self) -> None: + integrations = sentry_filters.genai_privacy_integrations() + + assert integrations + assert all(i.include_prompts is False for i in integrations) + + def test_skips_integrations_whose_sdk_is_missing(self) -> None: + with patch.object( + sentry_filters, + "_GENAI_INTEGRATIONS", + (("app.core.does_not_exist", "MissingIntegration"),), + ): + assert sentry_filters.genai_privacy_integrations() == [] + + +class TestLlmJobKwargsRedaction: + @staticmethod + def _event_with_celery_job( + task_name: str, kwargs: dict[str, Any] + ) -> dict[str, Any]: + return { + "extra": { + "celery-job": { + "task_name": task_name, + "args": [], + "kwargs": kwargs, + } + } + } + + def test_redacts_query_for_llm_job(self) -> None: + event = self._event_with_celery_job( + "app.celery.tasks.job_execution.run_llm_job", + { + "job_id": "b9ce6621-9b5a-45c4-969f-df7613ff7dc4", + "organization_id": 1, + "project_id": 1, + "request_data": { + "callback_url": "https://webhooksite.net/some-id", + "config": {"blob": {"completion": {"provider": "openai"}}}, + "query": { + "input": { + "type": "text", + "content": { + "value": "Amit Gupta phone number is 919611188278" + }, + } + }, + "request_metadata": None, + }, + }, + ) + + result = sentry_filters.before_send_error_filter(event, {}) + + request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] + assert request_data["query"] == sentry_filters._REDACTED + assert request_data["callback_url"] == "https://webhooksite.net/some-id" + assert request_data["config"] == { + "blob": {"completion": {"provider": "openai"}} + } + + def test_redacts_only_instructions_in_call_and_chain_configs(self) -> None: + params = { + "model": "gpt-4o", + "temperature": 0.2, + "instructions": "secret prompt", + } + event = self._event_with_celery_job( + "app.celery.tasks.job_execution.run_llm_chain_job", + { + "request_data": { + "config": { + "blob": { + "completion": {"provider": "openai", "params": dict(params)} + } + }, + "blocks": [ + {"config": {"blob": {"completion": {"params": dict(params)}}}} + ], + } + }, + ) + + result = sentry_filters.before_send_error_filter(event, {}) + + request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] + expected = {**params, "instructions": sentry_filters._REDACTED} + assert request_data["config"]["blob"]["completion"]["params"] == expected + assert request_data["config"]["blob"]["completion"]["provider"] == "openai" + assert ( + request_data["blocks"][0]["config"]["blob"]["completion"]["params"] + == expected + ) + + def test_redacts_query_for_chain_job(self) -> None: + event = self._event_with_celery_job( + "app.celery.tasks.job_execution.run_llm_chain_job", + {"request_data": {"query": {"input": "sensitive text"}}}, + ) + + result = sentry_filters.before_send_error_filter(event, {}) + + request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] + assert request_data["query"] == sentry_filters._REDACTED + + def test_ignores_unrelated_tasks(self) -> None: + event = self._event_with_celery_job( + "app.celery.tasks.job_execution.run_doctransform_job", + {"request_data": {"query": {"input": "not an llm job"}}}, + ) + + result = sentry_filters.before_send_error_filter(event, {}) + + request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] + assert request_data["query"] == {"input": "not an llm job"} + + def test_passes_through_events_without_celery_job(self) -> None: + event = {"message": "some unrelated error"} + + assert sentry_filters.before_send_error_filter(event, {}) is event diff --git a/backend/app/tests/core/telemetry/sentry/test_sentry_init.py b/backend/app/tests/core/telemetry/sentry/test_sentry_init.py new file mode 100644 index 000000000..5b5bea0b3 --- /dev/null +++ b/backend/app/tests/core/telemetry/sentry/test_sentry_init.py @@ -0,0 +1,56 @@ +from unittest.mock import MagicMock, patch + +from sentry_sdk.integrations import Integration + +from app.core.telemetry.sentry import init as sentry_init + + +class _FakeIntegration(Integration): + identifier = "fake" + + @staticmethod + def setup_once() -> None: + return None + + +class TestInitSentry: + def test_noop_without_dsn(self) -> None: + fake = MagicMock() + with ( + patch.object(sentry_init.settings, "SENTRY_DSN", None), + patch.object(sentry_init, "sentry_sdk", fake), + ): + sentry_init.init_sentry(integrations=[], disabled_integrations=[]) + + fake.init.assert_not_called() + + def test_merges_caller_integrations_with_shared_config(self) -> None: + fake = MagicMock() + extra = _FakeIntegration() + disabled = _FakeIntegration() + with ( + patch.object( + sentry_init.settings, "SENTRY_DSN", "https://k@o.ingest.sentry.io/1" + ), + patch.object(sentry_init.settings, "SENTRY_SEND_DEFAULT_PII", False), + patch.object(sentry_init, "sentry_sdk", fake), + patch.object(sentry_init, "genai_privacy_integrations", return_value=[]), + ): + sentry_init.init_sentry( + integrations=[extra], disabled_integrations=[disabled] + ) + + fake.init.assert_called_once() + kwargs = fake.init.call_args.kwargs + assert kwargs["instrumenter"] == "otel" + assert kwargs["send_default_pii"] is False + assert kwargs["include_local_variables"] is False + assert kwargs["max_request_body_size"] == "never" + assert kwargs["before_send"] is sentry_init.before_send_error_filter + assert ( + kwargs["before_send_transaction"] + is sentry_init.before_send_transaction_filter + ) + assert kwargs["before_send_log"] is sentry_init.before_send_log_filter + assert extra in kwargs["integrations"] + assert kwargs["disabled_integrations"] == [disabled] diff --git a/backend/app/tests/core/telemetry/test_telemetry_context.py b/backend/app/tests/core/telemetry/test_telemetry_context.py new file mode 100644 index 000000000..b986f7764 --- /dev/null +++ b/backend/app/tests/core/telemetry/test_telemetry_context.py @@ -0,0 +1,220 @@ +import logging +from unittest.mock import MagicMock, patch + +import pytest + +from app.core.telemetry import context as telemetry + + +def _active_sentry() -> MagicMock: + """A sentry_sdk stand-in whose client reports active.""" + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = True + return fake + + +def _inactive_sentry() -> MagicMock: + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = False + return fake + + +class TestSetRequestLogContext: + @pytest.fixture(autouse=True) + def _clean_log_context(self): + token = telemetry._log_context_var.set(None) + yield + telemetry._log_context_var.reset(token) + + def test_org_and_project_land_in_log_context(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.set_request_log_context(org_id=3, project_id=5) + + assert telemetry._log_context_var.get() == {"org_id": "3", "project_id": "5"} + + def test_org_and_project_set_as_tags(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.set_request_log_context(org_id=3, project_id=5) + + fake.set_tag.assert_any_call("tenant.org_id", "3") + fake.set_tag.assert_any_call("tenant.project_id", "5") + + def test_never_binds_a_sentry_user(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.set_request_log_context(org_id=3, project_id=5) + + fake.set_user.assert_not_called() + + def test_inactive_sentry_still_sets_log_context(self) -> None: + fake = _inactive_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.set_request_log_context(org_id=3, project_id=5) + + assert telemetry._log_context_var.get() == {"org_id": "3", "project_id": "5"} + fake.set_tag.assert_not_called() + + +class TestBindSentryUser: + @pytest.fixture(autouse=True) + def _clean_log_context(self): + token = telemetry._log_context_var.set(None) + yield + telemetry._log_context_var.reset(token) + + def test_binds_all_ids_stringified_to_sentry_user(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.bind_sentry_user(user_id=7, org_id=3, project_id=5) + + fake.set_user.assert_called_once_with( + {"id": "7", "org_id": "3", "project_id": "5"} + ) + + def test_only_present_keys_included_in_sentry_user(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.bind_sentry_user(user_id=7) + + fake.set_user.assert_called_once_with({"id": "7"}) + + def test_all_ids_none_does_not_call_set_user(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.bind_sentry_user() + + fake.set_user.assert_not_called() + + def test_inactive_sentry_does_not_call_set_user(self) -> None: + fake = _inactive_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.bind_sentry_user(user_id=7, org_id=3, project_id=5) + + fake.set_user.assert_not_called() + + def test_ids_never_enter_the_log_context(self) -> None: + fake = _active_sentry() + with patch.object(telemetry, "sentry_sdk", fake): + telemetry.bind_sentry_user(user_id=7, org_id=3, project_id=5) + + assert telemetry._log_context_var.get() is None + + +class TestLogContext: + @pytest.fixture(autouse=True) + def _clean_log_context(self): + token = telemetry._log_context_var.set(None) + yield + telemetry._log_context_var.reset(token) + + def test_sets_tag_system_and_fields_then_resets(self) -> None: + with telemetry.log_context(tag="llm-call", job_id="j1", skipped=None): + assert telemetry._log_context_var.get() == { + "tag": "llm-call", + "system": "llm-call", + "job_id": "j1", + } + assert not telemetry._log_context_var.get() + + def test_nested_context_extends_without_overriding_system(self) -> None: + with telemetry.log_context(tag="collection"): + with telemetry.log_context(tag="inner", step=2): + payload = telemetry._log_context_var.get() or {} + assert payload["tag"] == "inner" + assert payload["system"] == "collection" + assert payload["step"] == "2" + + +class TestLogContextFilter: + @pytest.fixture(autouse=True) + def _clean_log_context(self): + token = telemetry._log_context_var.set(None) + yield + telemetry._log_context_var.reset(token) + + def _record(self, name: str) -> logging.LogRecord: + return logging.LogRecord(name, logging.INFO, __file__, 1, "msg", None, None) + + def test_copies_context_fields_onto_record(self) -> None: + record = self._record("app.anything") + with telemetry.log_context(tag="custom", job_id="j1"): + assert telemetry.LogContextFilter().filter(record) + assert record.tag == "custom" + assert record.job_id == "j1" + + def test_infers_llm_call_tag_from_logger_name(self) -> None: + record = self._record("app.services.llm.jobs") + telemetry.LogContextFilter().filter(record) + assert record.tag == "llm-call" + assert record.system == "llm-call" + + def test_infers_collection_tag_from_logger_name(self) -> None: + record = self._record("app.crud.collection") + telemetry.LogContextFilter().filter(record) + assert record.tag == "collection" + assert record.system == "collection" + + def test_stamps_lifecycle_from_recording_span(self) -> None: + record = self._record("app.other") + span = MagicMock() + span.is_recording.return_value = True + span.name = "run/app.task" + with patch.object(telemetry.trace, "get_current_span", return_value=span): + telemetry.LogContextFilter().filter(record) + assert record.lifecycle == "run/app.task" + + +class TestModuleName: + @pytest.fixture(autouse=True) + def _clean_log_context(self): + token = telemetry._log_context_var.set(None) + yield + telemetry._log_context_var.reset(token) + + def _record(self, logger_name: str) -> logging.LogRecord: + record = logging.LogRecord( + logger_name, logging.INFO, __file__, 1, "msg", None, None, "execute_job" + ) + telemetry.LogContextFilter().filter(record) + return record + + @pytest.mark.parametrize( + ("logger_name", "expected"), + [ + ("app.services.llm.jobs", "llm-call"), + ("app.services.llm.chain.executor", "llm-chain"), + ("app.api.routes.llm_chain", "llm-chain"), + ("app.crud.config.version", "config-version"), + ("app.services.collections.create_collection", "knowledgebase"), + ("app.services.assessment.api.batch", "assessment"), + ("app.crud.evaluations.judge_stage", "evals"), + ("app.crud.evaluations.fast_chunks", "fastevals"), + ], + ) + def test_resolves_module_from_logger_name( + self, logger_name: str, expected: str + ) -> None: + record = self._record(logger_name) + assert getattr(record, telemetry.LOG_MODULE_FIELD) == expected + assert ( + getattr(record, telemetry.LOG_LOCATION_FIELD) + == f"[{expected}] {logger_name}" + ) + + def test_unmapped_logger_has_no_module_and_plain_location(self) -> None: + record = self._record("app.crud.assessment.cron") + assert not hasattr(record, telemetry.LOG_MODULE_FIELD) + assert ( + getattr(record, telemetry.LOG_LOCATION_FIELD) == "app.crud.assessment.cron" + ) + + def test_log_context_module_overrides_logger_name(self) -> None: + with telemetry.log_context(module=telemetry.LogModuleEnum.LLM_CHAIN): + record = self._record("app.services.llm.jobs") + assert getattr(record, telemetry.LOG_MODULE_FIELD) == "llm-chain" + assert ( + getattr(record, telemetry.LOG_LOCATION_FIELD) + == "[llm-chain] app.services.llm.jobs" + ) diff --git a/backend/app/tests/core/telemetry/test_telemetry_db.py b/backend/app/tests/core/telemetry/test_telemetry_db.py new file mode 100644 index 000000000..5fa3a75f4 --- /dev/null +++ b/backend/app/tests/core/telemetry/test_telemetry_db.py @@ -0,0 +1,373 @@ +from unittest.mock import MagicMock, patch + +import pytest +from sqlalchemy import create_engine, text +from sqlalchemy.exc import OperationalError +from sqlalchemy.pool import QueuePool + +from app.core.telemetry import db as telemetry +from app.core.telemetry import metrics + + +def _active_sentry() -> MagicMock: + """A sentry_sdk stand-in whose client reports active.""" + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = True + return fake + + +def _inactive_sentry() -> MagicMock: + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = False + return fake + + +class TestNotableSqlstates: + def test_maps_known_postgres_codes(self) -> None: + assert telemetry.NOTABLE_SQLSTATES["40P01"] == "deadlock_detected" + assert telemetry.NOTABLE_SQLSTATES["57014"] == "query_canceled" + assert telemetry.NOTABLE_SQLSTATES["40001"] == "serialization_failure" + + def test_unknown_code_absent(self) -> None: + assert "99999" not in telemetry.NOTABLE_SQLSTATES + + +class TestRecordDbQueryFailed: + def test_emits_count_with_operation_and_sqlstate(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_query_failed(operation="SELECT", sqlstate="40P01") + + fake.metrics.count.assert_called_once() + kwargs = fake.metrics.count.call_args.kwargs + assert kwargs["name"] == "db.query.failed" + assert kwargs["value"] == 1 + assert kwargs["attributes"]["db.operation"] == "SELECT" + assert kwargs["attributes"]["db.sqlstate"] == "40P01" + + def test_omits_missing_attributes(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_query_failed() + + assert fake.metrics.count.call_args.kwargs["attributes"] == {} + + def test_noop_when_sentry_inactive(self) -> None: + fake = _inactive_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_query_failed(operation="SELECT", sqlstate="40P01") + + fake.metrics.count.assert_not_called() + + +class TestRecordDbSlowQuery: + def test_emits_count_with_operation(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_slow_query("SELECT") + + fake.metrics.count.assert_called_once() + kwargs = fake.metrics.count.call_args.kwargs + assert kwargs["name"] == "db.query.slow" + assert kwargs["value"] == 1 + assert kwargs["attributes"]["db.operation"] == "SELECT" + + +class TestRecordDbConnectionEvent: + def test_known_event_emits_named_metric(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_connection_event("invalidated") + + assert ( + fake.metrics.count.call_args.kwargs["name"] == "db.connection.invalidated" + ) + + def test_unknown_event_is_noop(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_connection_event("teleported") + + fake.metrics.count.assert_not_called() + + +class TestRecordDbTransaction: + @pytest.mark.parametrize( + ("outcome", "metric"), + [ + ("commit", "db.transaction.commit"), + ("rollback", "db.transaction.rollback"), + ], + ) + def test_known_outcome_emits_named_metric(self, outcome, metric): + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_transaction(outcome) + + assert fake.metrics.count.call_args.kwargs["name"] == metric + + def test_unknown_outcome_is_noop(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_transaction("savepoint") + + fake.metrics.count.assert_not_called() + + +class TestTagDbError: + def _recording_span(self) -> MagicMock: + span = MagicMock() + span.is_recording.return_value = True + return span + + def test_known_code_sets_named_tag_and_span_attribute(self) -> None: + fake = _active_sentry() + span = self._recording_span() + with ( + patch.object(telemetry, "sentry_sdk", fake), + patch.object(telemetry.trace, "get_current_span", return_value=span), + ): + telemetry._tag_db_error("40P01") + + fake.set_tag.assert_any_call("db.system", "postgresql") + fake.set_tag.assert_any_call("db.sqlstate", "40P01") + fake.set_tag.assert_any_call("db.error.name", "deadlock_detected") + span.set_attribute.assert_called_once_with("db.sqlstate", "40P01") + + def test_unknown_code_skips_error_name_tag(self) -> None: + fake = _active_sentry() + span = self._recording_span() + with ( + patch.object(telemetry, "sentry_sdk", fake), + patch.object(telemetry.trace, "get_current_span", return_value=span), + ): + telemetry._tag_db_error("99999") + + fake.set_tag.assert_any_call("db.system", "postgresql") + fake.set_tag.assert_any_call("db.sqlstate", "99999") + tag_names = [c.args[0] for c in fake.set_tag.call_args_list] + assert "db.error.name" not in tag_names + + def test_none_sqlstate_is_noop(self) -> None: + fake = _active_sentry() + span = self._recording_span() + with ( + patch.object(telemetry, "sentry_sdk", fake), + patch.object(telemetry.trace, "get_current_span", return_value=span), + ): + telemetry._tag_db_error(None) + + fake.set_tag.assert_not_called() + span.set_attribute.assert_not_called() + + def test_swallows_exceptions(self) -> None: + fake = MagicMock() + fake.get_client.side_effect = RuntimeError("sentry exploded") + span = self._recording_span() + with ( + patch.object(telemetry, "sentry_sdk", fake), + patch.object(telemetry.trace, "get_current_span", return_value=span), + ): + telemetry._tag_db_error("40P01") + + +class TestInstrumentDbEngine: + def _engine(self): + return create_engine("sqlite://", poolclass=QueuePool) + + def test_successful_query_emits_pool_stats(self) -> None: + engine = self._engine() + pool_stats = MagicMock() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", pool_stats), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.execute(text("SELECT 1")) + + pool_stats.assert_called() + kwargs = pool_stats.call_args.kwargs + assert set(kwargs) == {"active", "idle", "total", "overflow"} + + def test_failing_query_fires_error_hook(self) -> None: + engine = self._engine() + query_failed = MagicMock() + tag_error = MagicMock() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + patch.object(telemetry, "record_db_query_failed", query_failed), + patch.object(telemetry, "_tag_db_error", tag_error), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + with pytest.raises(OperationalError): + conn.execute(text("SELECT * FROM does_not_exist")) + + query_failed.assert_called_once() + # SQLite driver errors carry no sqlstate, so the operation is SELECT and + # sqlstate is None — the hook still runs end to end. + assert query_failed.call_args.kwargs["operation"] == "SELECT" + assert query_failed.call_args.kwargs["sqlstate"] is None + tag_error.assert_called_once_with(None) + + def test_second_call_is_idempotent(self) -> None: + engine = self._engine() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor") as instrumentor, + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + ): + telemetry.instrument_db_engine(engine) + assert engine._kaapi_db_telemetry_instrumented is True + instrumentor.return_value.instrument.assert_called_once() + + telemetry.instrument_db_engine(engine) + instrumentor.return_value.instrument.assert_called_once() + + def test_rowcount_attribute_set_on_query_span(self) -> None: + from sqlalchemy import event + + engine = self._engine() + span = MagicMock() + span.is_recording.return_value = True + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + ): + telemetry.instrument_db_engine(engine) + + # The stubbed instrumentor never populates context._otel_span, so stand in + # for it: the rowcount listener reads the span off the execution context. + @event.listens_for(engine, "before_cursor_execute") + def _attach_span( + _conn, _cursor, _statement, _parameters, context, _executemany + ): + context._otel_span = span + + with engine.connect() as conn: + conn.execute(text("CREATE TABLE t (x)")) + conn.execute(text("INSERT INTO t VALUES (1)")) + conn.commit() + + rows_calls = [ + c + for c in span.set_attribute.call_args_list + if c.args[0] == telemetry.DB_ROWS_ATTRIBUTE + ] + assert rows_calls + assert 1 in [c.args[1] for c in rows_calls] + assert all(isinstance(c.args[1], int) for c in rows_calls) + + +class TestInstrumentDbEngineMetrics: + def _engine(self): + return create_engine("sqlite://", poolclass=QueuePool) + + def test_slow_query_counted_when_over_threshold(self) -> None: + engine = self._engine() + slow = MagicMock() + with ( + patch.object(telemetry, "DB_SLOW_QUERY_MS", 0), + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + patch.object(telemetry, "record_db_slow_query", slow), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.execute(text("SELECT 1")) + + slow.assert_called() + assert "SELECT" in [c.args[0] for c in slow.call_args_list] + + def test_fast_query_not_counted_when_under_threshold(self) -> None: + engine = self._engine() + slow = MagicMock() + with ( + patch.object(telemetry, "DB_SLOW_QUERY_MS", 10_000), + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + patch.object(telemetry, "record_db_slow_query", slow), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.execute(text("SELECT 1")) + + slow.assert_not_called() + + def test_connection_open_event_recorded(self) -> None: + engine = self._engine() + conn_event = MagicMock() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + patch.object(telemetry, "record_db_connection_event", conn_event), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.execute(text("SELECT 1")) + + assert "opened" in [c.args[0] for c in conn_event.call_args_list] + + def test_commit_and_rollback_recorded(self) -> None: + engine = self._engine() + txn = MagicMock() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor"), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + patch.object(telemetry, "record_db_transaction", txn), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.execute(text("CREATE TABLE t (x)")) + conn.commit() + with engine.connect() as conn: + conn.execute(text("INSERT INTO t VALUES (1)")) + conn.rollback() + + outcomes = [c.args[0] for c in txn.call_args_list] + assert "commit" in outcomes + assert "rollback" in outcomes + + +class TestRecordDbPoolStats: + def test_emits_four_gauges(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_db_pool_stats(active=1, idle=2, total=3, overflow=0) + names = [c.kwargs["name"] for c in fake.metrics.gauge.call_args_list] + assert names == [ + "db.pool.active", + "db.pool.idle", + "db.pool.total", + "db.pool.overflow", + ] + + +class TestInstrumentDbEngineEdgeCases: + def test_non_queue_pool_skips_pool_metrics(self) -> None: + engine = create_engine("sqlite://") + pool_stats = MagicMock() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor", MagicMock()), + patch.object(telemetry, "record_db_pool_stats", pool_stats), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.execute(text("SELECT 1")) + pool_stats.assert_not_called() + + def test_close_and_invalidate_emit_connection_events(self) -> None: + engine = create_engine("sqlite://", poolclass=QueuePool) + events = MagicMock() + with ( + patch.object(telemetry, "SQLAlchemyInstrumentor", MagicMock()), + patch.object(telemetry, "record_db_pool_stats", MagicMock()), + patch.object(telemetry, "record_db_connection_event", events), + ): + telemetry.instrument_db_engine(engine) + with engine.connect() as conn: + conn.invalidate() + engine.dispose() + emitted = {c.args[0] for c in events.call_args_list} + assert {"opened", "invalidated", "closed"} <= emitted diff --git a/backend/app/tests/core/telemetry/test_telemetry_llm.py b/backend/app/tests/core/telemetry/test_telemetry_llm.py new file mode 100644 index 000000000..16aa496fa --- /dev/null +++ b/backend/app/tests/core/telemetry/test_telemetry_llm.py @@ -0,0 +1,120 @@ +from types import SimpleNamespace +from unittest.mock import MagicMock, patch + +from opentelemetry.instrumentation.utils import is_http_instrumentation_enabled + +from app.core.telemetry import llm as telemetry +from app.core.telemetry import metrics + + +def _active_sentry() -> MagicMock: + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = True + return fake + + +def _metric_calls(fake: MagicMock) -> dict[str, dict]: + calls = fake.metrics.count.call_args_list + fake.metrics.distribution.call_args_list + return {c.kwargs["name"]: c.kwargs for c in calls} + + +class TestRecordLlmCallMetrics: + def test_started_emits_count_with_tenant_attrs(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_llm_call_started( + "openai", "gpt-4o", "chat", organization_id=1, project_id=2 + ) + + attrs = _metric_calls(fake)["llm.call.total"]["attributes"] + assert attrs["gen_ai.system"] == "openai" + assert attrs["kaapi.organization_id"] == "1" + assert attrs["kaapi.project_id"] == "2" + + def test_finished_emits_duration_tokens_and_error(self) -> None: + fake = _active_sentry() + with (patch.object(metrics, "sentry_sdk", fake),): + telemetry.record_llm_call_finished( + "openai", + "gpt-4o", + "chat", + duration_ms=120.5, + input_tokens=10, + output_tokens=20, + total_tokens=30, + error=True, + ) + + names = _metric_calls(fake) + assert names["llm.call.duration"]["value"] == 120.5 + assert names["llm.call.errors"]["value"] == 1 + assert names["llm.tokens.input"]["value"] == 10 + assert names["llm.tokens.output"]["value"] == 20 + assert names["llm.tokens.total"]["value"] == 30 + assert "kaapi.organization_id" not in names["llm.call.duration"]["attributes"] + + +class TestGenAiSpanAttributes: + def test_request_attributes_include_params_and_tools(self) -> None: + span = MagicMock() + telemetry.set_gen_ai_request_attributes( + span, + provider="openai", + model="gpt-4o", + operation="chat", + organization_id=1, + project_id=2, + params={"temperature": 0.2, "max_tokens": None, "tools": [{"name": "t"}]}, + ) + set_calls = {c.args[0]: c.args[1] for c in span.set_attribute.call_args_list} + assert set_calls["gen_ai.request.model"] == "gpt-4o" + assert set_calls["kaapi.organization_id"] == 1 + assert set_calls["gen_ai.request.temperature"] == 0.2 + assert "gen_ai.request.max_tokens" not in set_calls + assert set_calls["gen_ai.request.available_tools"] == '[{"name": "t"}]' + + def test_request_attributes_skip_missing_model_and_tenant(self) -> None: + span = MagicMock() + telemetry.set_gen_ai_request_attributes( + span, + provider="openai", + model="", + operation="chat", + organization_id=None, + project_id=None, + ) + keys = {c.args[0] for c in span.set_attribute.call_args_list} + assert keys == { + "gen_ai.system", + "gen_ai.provider.name", + "gen_ai.operation.name", + } + + def test_response_attributes_with_usage_and_model(self) -> None: + span = MagicMock() + response = SimpleNamespace( + usage=SimpleNamespace( + input_tokens=1, output_tokens=2, total_tokens=3, reasoning_tokens=4 + ), + response=SimpleNamespace(model="gpt-4o-2024"), + ) + telemetry.set_gen_ai_response_attributes(span, response=response) + set_calls = {c.args[0]: c.args[1] for c in span.set_attribute.call_args_list} + assert set_calls["gen_ai.usage.total_tokens"] == 3 + assert set_calls["gen_ai.usage.output_tokens.reasoning"] == 4 + assert set_calls["gen_ai.response.model"] == "gpt-4o-2024" + + def test_response_attributes_without_usage(self) -> None: + span = MagicMock() + telemetry.set_gen_ai_response_attributes( + span, response=SimpleNamespace(usage=None, response=None) + ) + span.set_attribute.assert_not_called() + + +class TestSuppressHttpInstrumentation: + def test_disables_http_instrumentation_inside_block_only(self) -> None: + assert is_http_instrumentation_enabled() + with telemetry.suppress_http_instrumentation(): + assert not is_http_instrumentation_enabled() + assert is_http_instrumentation_enabled() diff --git a/backend/app/tests/core/telemetry/test_telemetry_metrics.py b/backend/app/tests/core/telemetry/test_telemetry_metrics.py new file mode 100644 index 000000000..1d404ff38 --- /dev/null +++ b/backend/app/tests/core/telemetry/test_telemetry_metrics.py @@ -0,0 +1,45 @@ +from unittest.mock import MagicMock, patch + +from app.core.telemetry import metrics + + +def _active_sentry() -> MagicMock: + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = True + return fake + + +class TestRecordStalePendingJobs: + def test_table_level_metrics(self) -> None: + fake = _active_sentry() + with patch.object(metrics, "sentry_sdk", fake): + metrics.record_stale_pending_jobs( + table="batch_job", + status="pending", + stale_count=3, + oldest_age_seconds=90, + ) + names = {c.kwargs["name"]: c.kwargs for c in fake.metrics.gauge.call_args_list} + assert names["jobs.pending.stale.count"]["value"] == 3 + assert names["jobs.pending.oldest_age_seconds"]["unit"] == "second" + assert ( + names["jobs.pending.stale.count"]["attributes"]["job.table"] == "batch_job" + ) + + def test_dimensional_metrics_without_age(self) -> None: + fake = _active_sentry() + with patch.object(metrics, "sentry_sdk", fake): + metrics.record_stale_pending_jobs( + table="job", + status="pending", + stale_count=1, + oldest_age_seconds=None, + job_type="llm", + action_type="call", + dimensional=True, + ) + names = {c.kwargs["name"]: c.kwargs for c in fake.metrics.gauge.call_args_list} + assert list(names) == ["jobs.pending.stale.by_dimension.count"] + attrs = names["jobs.pending.stale.by_dimension.count"]["attributes"] + assert attrs["job.type"] == "llm" + assert attrs["job.action_type"] == "call" diff --git a/backend/app/tests/core/telemetry/test_telemetry_tracing.py b/backend/app/tests/core/telemetry/test_telemetry_tracing.py new file mode 100644 index 000000000..3fcf0e7d5 --- /dev/null +++ b/backend/app/tests/core/telemetry/test_telemetry_tracing.py @@ -0,0 +1,292 @@ +import os +import time +from types import SimpleNamespace +from unittest.mock import MagicMock, patch + +from fastapi import FastAPI +from opentelemetry.trace import SpanKind, StatusCode, format_span_id +from opentelemetry.util.http import ExcludeList +from sentry_sdk.integrations.opentelemetry import SentrySpanProcessor + +from app.core.telemetry import tracing as telemetry + + +class TestSetupTelemetryInstrumentors: + def test_enabled_calls_instrument_on_both(self) -> None: + redis, botocore = MagicMock(), MagicMock() + with ( + patch.object(telemetry.settings, "SENTRY_DSN", None), + patch.object(telemetry, "TracerProvider", MagicMock()), + patch.object(telemetry.trace, "set_tracer_provider", MagicMock()), + patch.object(telemetry, "LoggingInstrumentor", MagicMock()), + patch.object(telemetry, "HTTPXClientInstrumentor", MagicMock()), + patch.object(telemetry, "RequestsInstrumentor", MagicMock()), + patch( + "opentelemetry.instrumentation.celery.CeleryInstrumentor", MagicMock() + ), + patch("opentelemetry.instrumentation.redis.RedisInstrumentor", redis), + patch( + "opentelemetry.instrumentation.botocore.BotocoreInstrumentor", botocore + ), + ): + telemetry.setup_telemetry() + + redis.return_value.instrument.assert_called_once() + botocore.return_value.instrument.assert_called_once() + + def test_redis_failure_does_not_propagate_and_botocore_still_instruments( + self, + ) -> None: + redis = MagicMock() + redis.return_value.instrument.side_effect = RuntimeError("boom") + botocore = MagicMock() + with ( + patch.object(telemetry.settings, "SENTRY_DSN", None), + patch.object(telemetry, "TracerProvider", MagicMock()), + patch.object(telemetry.trace, "set_tracer_provider", MagicMock()), + patch.object(telemetry, "LoggingInstrumentor", MagicMock()), + patch.object(telemetry, "HTTPXClientInstrumentor", MagicMock()), + patch.object(telemetry, "RequestsInstrumentor", MagicMock()), + patch( + "opentelemetry.instrumentation.celery.CeleryInstrumentor", MagicMock() + ), + patch("opentelemetry.instrumentation.redis.RedisInstrumentor", redis), + patch( + "opentelemetry.instrumentation.botocore.BotocoreInstrumentor", botocore + ), + ): + telemetry.setup_telemetry() + + botocore.return_value.instrument.assert_called_once() + + +class TestShouldDropBareHttpTrace: + def test_drops_root_http_span_with_no_children(self) -> None: + assert telemetry._should_drop_bare_http_trace( + is_root=True, + kind=SpanKind.SERVER, + status_code=StatusCode.UNSET, + had_children=False, + ) + + def test_keeps_when_trace_has_children(self) -> None: + assert not telemetry._should_drop_bare_http_trace( + is_root=True, + kind=SpanKind.SERVER, + status_code=StatusCode.UNSET, + had_children=True, + ) + + def test_keeps_error_trace_even_without_children(self) -> None: + assert not telemetry._should_drop_bare_http_trace( + is_root=True, + kind=SpanKind.SERVER, + status_code=StatusCode.ERROR, + had_children=False, + ) + + def test_keeps_non_root_span(self) -> None: + assert not telemetry._should_drop_bare_http_trace( + is_root=False, + kind=SpanKind.SERVER, + status_code=StatusCode.UNSET, + had_children=False, + ) + + def test_keeps_non_server_root(self) -> None: + assert not telemetry._should_drop_bare_http_trace( + is_root=True, + kind=SpanKind.INTERNAL, + status_code=StatusCode.UNSET, + had_children=False, + ) + + +class TestSemconvOptIn: + def test_defaults_to_dup_mode_for_http(self) -> None: + assert os.environ[telemetry.OTEL_SEMCONV_OPT_IN_ENV] == "http/dup" + + +class TestShouldDropUnroutedServerSpan: + def test_drops_root_server_span_without_route(self) -> None: + assert telemetry._should_drop_unrouted_server_span( + is_root=True, kind=SpanKind.SERVER, attributes={"http.method": "PROPFIND"} + ) + + def test_keeps_root_server_span_with_route(self) -> None: + assert not telemetry._should_drop_unrouted_server_span( + is_root=True, kind=SpanKind.SERVER, attributes={"http.route": "/api/v1/x"} + ) + + def test_keeps_non_root_and_non_server_spans(self) -> None: + assert not telemetry._should_drop_unrouted_server_span( + is_root=False, kind=SpanKind.SERVER, attributes={} + ) + assert not telemetry._should_drop_unrouted_server_span( + is_root=True, kind=SpanKind.CONSUMER, attributes={} + ) + + +class TestNoiseFilteringSpanProcessor: + @staticmethod + def _root_server_span(span_id: int, start_time_ns: int) -> MagicMock: + span = MagicMock() + span.parent = None + span.kind = SpanKind.SERVER + span.status.status_code = StatusCode.UNSET + span.start_time = start_time_ns + span.get_span_context.return_value = SimpleNamespace( + trace_id=0xABC, span_id=span_id, is_valid=True + ) + return span + + def test_root_span_attributes_forwarded_to_transaction_data(self) -> None: + processor = telemetry._NoiseFilteringSpanProcessor() + otel_span = MagicMock() + otel_span.attributes = {"http.request.body.size": 4096, "http.method": "POST"} + otel_span.kind = SpanKind.SERVER + transaction = MagicMock() + + with patch.object( + SentrySpanProcessor, "_update_transaction_with_otel_data" + ) as base: + processor._update_transaction_with_otel_data(transaction, otel_span) + + base.assert_called_once_with(transaction, otel_span) + transaction.set_data.assert_any_call("http.request.body.size", 4096) + + def test_dropped_root_span_is_removed_from_open_spans(self) -> None: + processor = telemetry._NoiseFilteringSpanProcessor() + start_time_ns = int(time.time() * 1e9) + span = self._root_server_span(span_id=0x1, start_time_ns=start_time_ns) + span_id = format_span_id(0x1) + started_minute = int(start_time_ns / 1e9 / 60) + processor.otel_span_map[span_id] = MagicMock() + processor.open_spans[started_minute] = {span_id} + + with patch.object(SentrySpanProcessor, "on_end") as base_on_end: + processor.on_end(span) + + base_on_end.assert_not_called() + assert span_id not in processor.otel_span_map + assert all(span_id not in bucket for bucket in processor.open_spans.values()) + + +class TestInstrumentApp: + def _app(self) -> FastAPI: + return FastAPI(openapi_url="/api/v1/openapi.json") + + def _excluded(self) -> ExcludeList: + instrument = MagicMock() + with ( + patch.object(telemetry.FastAPIInstrumentor, "instrument_app", instrument), + ): + telemetry.instrument_app(self._app()) + + excluded_urls = instrument.call_args.kwargs["excluded_urls"] + return ExcludeList(excluded_urls.split(",")) + + def test_health_and_cron_paths_excluded_from_traces(self) -> None: + el = self._excluded() + assert el.url_disabled("/health") + assert el.url_disabled("/api/v1/utils/health") + assert el.url_disabled("/api/v1/cron/run_batches") + + def test_framework_doc_paths_excluded_from_traces(self) -> None: + el = self._excluded() + assert el.url_disabled("/docs") + assert el.url_disabled("/redoc") + assert el.url_disabled("/api/v1/openapi.json") + assert el.url_disabled("/docs/oauth2-redirect") + + def test_real_endpoints_still_traced(self) -> None: + el = self._excluded() + assert not el.url_disabled("/api/v1/llm/generate") + assert not el.url_disabled("/api/v1/cronies") + assert not el.url_disabled("/api/v1/documents") + + def test_asgi_send_receive_spans_excluded_at_source(self) -> None: + instrument = MagicMock() + with ( + patch.object(telemetry.FastAPIInstrumentor, "instrument_app", instrument), + ): + telemetry.instrument_app(self._app()) + + assert instrument.call_args.kwargs["exclude_spans"] == ["receive", "send"] + + +class TestNoiseFilteringSpanProcessorPaths: + def _span( + self, *, parent, kind=SpanKind.INTERNAL, trace_id=0xABC, span_id=0x1 + ) -> MagicMock: + span = MagicMock() + span.parent = parent + span.kind = kind + span.status.status_code = StatusCode.UNSET + span.attributes = {"http.route": "/x"} + span.get_span_context.return_value = SimpleNamespace( + trace_id=trace_id, span_id=span_id, is_valid=True + ) + return span + + def test_child_span_marks_trace_as_having_children(self) -> None: + processor = telemetry._NoiseFilteringSpanProcessor() + child = self._span(parent=SimpleNamespace(is_remote=False)) + with patch.object(SentrySpanProcessor, "on_start") as base: + processor.on_start(child) + base.assert_called_once() + assert 0xABC in processor._traces_with_children + + def test_root_span_with_children_ships(self) -> None: + processor = telemetry._NoiseFilteringSpanProcessor() + processor._traces_with_children.add(0xABC) + root = self._span(parent=None, kind=SpanKind.SERVER) + with patch.object(SentrySpanProcessor, "on_end") as base: + processor.on_end(root) + base.assert_called_once_with(root) + assert 0xABC not in processor._traces_with_children + + +class TestSetupTelemetryWithSentry: + def test_registers_processor_and_propagator(self) -> None: + provider = MagicMock() + set_textmap = MagicMock() + with ( + patch.object( + telemetry.settings, "SENTRY_DSN", "https://k@o.ingest.sentry.io/1" + ), + patch.object(telemetry, "TracerProvider", return_value=provider), + patch.object(telemetry, "_NoiseFilteringSpanProcessor", MagicMock()), + patch.object(telemetry, "set_global_textmap", set_textmap), + patch.object(telemetry.trace, "set_tracer_provider", MagicMock()), + patch.object(telemetry, "LoggingInstrumentor", MagicMock()), + patch.object(telemetry, "HTTPXClientInstrumentor", MagicMock()), + patch.object(telemetry, "RequestsInstrumentor", MagicMock()), + patch( + "opentelemetry.instrumentation.celery.CeleryInstrumentor", MagicMock() + ), + patch("opentelemetry.instrumentation.redis.RedisInstrumentor", MagicMock()), + patch( + "opentelemetry.instrumentation.botocore.BotocoreInstrumentor", + MagicMock(), + ), + ): + telemetry.setup_telemetry() + + provider.add_span_processor.assert_called_once() + set_textmap.assert_called_once() + + +class TestFlushTelemetry: + def test_flushes_provider_and_sentry(self) -> None: + provider = MagicMock() + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = True + with ( + patch.object(telemetry.trace, "get_tracer_provider", return_value=provider), + patch.object(telemetry, "sentry_sdk", fake), + ): + telemetry.flush_telemetry(timeout_millis=2000) + + provider.force_flush.assert_called_once_with(timeout_millis=2000) + fake.flush.assert_called_once_with(timeout=2.0) diff --git a/backend/app/tests/core/test_config.py b/backend/app/tests/core/test_config.py new file mode 100644 index 000000000..4be4e932d --- /dev/null +++ b/backend/app/tests/core/test_config.py @@ -0,0 +1,47 @@ +import pytest +from pydantic import TypeAdapter, ValidationError + +from app.core.config import Settings + + +class TestSentryConfigDefaults: + @pytest.mark.parametrize( + ("field", "expected"), + [ + ("SENTRY_TRACES_SAMPLE_RATE", 1.0), + ("SENTRY_SEND_DEFAULT_PII", False), + ("SENTRY_ERROR_SAMPLE_RATE", 1.0), + ("SENTRY_PROFILE_SESSION_SAMPLE_RATE", 1.0), + ("SENTRY_PROFILE_LIFECYCLE", "trace"), + ], + ) + def test_declared_default( + self, field: str, expected: float | str | bool | None + ) -> None: + assert Settings.model_fields[field].default == expected + + +class TestSentryProfilingValidation: + @staticmethod + def _adapter(field: str) -> TypeAdapter[object]: + return TypeAdapter(Settings.model_fields[field].rebuild_annotation()) + + @pytest.mark.parametrize("value", [0.0, 0.25, 1.0]) + def test_session_sample_rate_accepts_unit_interval(self, value: float) -> None: + assert ( + self._adapter("SENTRY_PROFILE_SESSION_SAMPLE_RATE").validate_python(value) + == value + ) + + @pytest.mark.parametrize("value", [-0.1, 1.5]) + def test_session_sample_rate_rejects_out_of_range(self, value: float) -> None: + with pytest.raises(ValidationError): + self._adapter("SENTRY_PROFILE_SESSION_SAMPLE_RATE").validate_python(value) + + @pytest.mark.parametrize("value", ["manual", "trace"]) + def test_lifecycle_accepts_supported_modes(self, value: str) -> None: + assert self._adapter("SENTRY_PROFILE_LIFECYCLE").validate_python(value) == value + + def test_lifecycle_rejects_unknown_mode(self) -> None: + with pytest.raises(ValidationError): + self._adapter("SENTRY_PROFILE_LIFECYCLE").validate_python("always") diff --git a/backend/app/tests/core/test_exception_handlers.py b/backend/app/tests/core/test_exception_handlers.py index 4955136be..e7ee22a4f 100644 --- a/backend/app/tests/core/test_exception_handlers.py +++ b/backend/app/tests/core/test_exception_handlers.py @@ -1,7 +1,15 @@ +from unittest.mock import patch + +import pytest +from fastapi import FastAPI, HTTPException from fastapi.testclient import TestClient +from pydantic import BaseModel from app.core.config import settings -from app.core.exception_handlers import _sanitize_validation_errors +from app.core.exception_handlers import ( + _sanitize_validation_errors, + register_exception_handlers, +) from app.tests.utils.auth import TestAuthContext @@ -105,6 +113,63 @@ def test_fallback_on_malformed_input(self) -> None: assert result == malformed +class TestSentryCaptureRouting: + """Only the generic 500 handler reports to Sentry; 4xx handlers stay quiet.""" + + @pytest.fixture + def client(self) -> TestClient: + app = FastAPI() + register_exception_handlers(app) + + class Body(BaseModel): + x: int + + @app.get("/boom") + def boom() -> None: + raise ValueError("boom") + + @app.get("/http-error") + def http_error() -> None: + raise HTTPException(status_code=404, detail="nope") + + @app.post("/validate") + def validate(body: Body) -> dict[str, bool]: + return {"ok": True} + + return TestClient(app, raise_server_exceptions=False) + + def test_generic_handler_captures_unhandled_exception( + self, client: TestClient + ) -> None: + with patch( + "app.core.exception_handlers.sentry_sdk.capture_exception" + ) as capture: + response = client.get("/boom") + + assert response.status_code == 500 + capture.assert_called_once() + + def test_http_exception_handler_does_not_capture(self, client: TestClient) -> None: + with patch( + "app.core.exception_handlers.sentry_sdk.capture_exception" + ) as capture: + response = client.get("/http-error") + + assert response.status_code == 404 + capture.assert_not_called() + + def test_validation_error_handler_does_not_capture( + self, client: TestClient + ) -> None: + with patch( + "app.core.exception_handlers.sentry_sdk.capture_exception" + ) as capture: + response = client.post("/validate", json={}) + + assert response.status_code == 422 + capture.assert_not_called() + + class TestValidationErrorResponse: """Integration: structured errors via configs endpoint.""" diff --git a/backend/app/tests/core/test_middleware.py b/backend/app/tests/core/test_middleware.py index e32d9d3b1..6d902300f 100644 --- a/backend/app/tests/core/test_middleware.py +++ b/backend/app/tests/core/test_middleware.py @@ -1,12 +1,136 @@ import logging import re +from types import SimpleNamespace +from unittest.mock import AsyncMock, MagicMock, patch import pytest from fastapi import Response from fastapi.testclient import TestClient from starlette.requests import Request +from app.core import middleware from app.core.middleware import _resolve_request_body_size +from app.core.telemetry import metrics + + +def _active_sentry() -> MagicMock: + fake = MagicMock() + fake.get_client.return_value.is_active.return_value = True + return fake + + +def _request( + path: str, + method: str = "GET", + route: str | None = None, + content_length: str | None = None, +) -> MagicMock: + req = MagicMock() + req.url.path = path + req.method = method + req.scope = {"route": SimpleNamespace(path=route)} if route else {} + req.headers = {"content-length": content_length} if content_length else {} + return req + + +def _metric_names(fake: MagicMock) -> list[str]: + calls = list(fake.metrics.count.call_args_list) + list( + fake.metrics.distribution.call_args_list + ) + return [c.kwargs["name"] for c in calls] + + +@pytest.fixture +def non_recording_span(): + span = MagicMock() + span.is_recording.return_value = False + with patch.object(middleware.trace, "get_current_span", return_value=span): + yield span + + +class TestHttpRequestMetrics: + async def _run(self, request, call_next, fake): + with ( + patch.object(middleware, "sentry_sdk", fake), + patch.object(metrics, "sentry_sdk", fake), + ): + return await middleware._log_http_request(request, call_next) + + @pytest.mark.asyncio + async def test_success_emits_traffic_and_latency(self, non_recording_span): + fake = _active_sentry() + request = _request("/api/v1/items", route="/api/v1/items") + call_next = AsyncMock(return_value=SimpleNamespace(status_code=200)) + + await self._run(request, call_next, fake) + + names = _metric_names(fake) + assert "http.server.request.count" in names + assert "http.server.request.duration" in names + assert "http.server.request.error" not in names + + @pytest.mark.asyncio + async def test_client_error_status_emits_error_metric(self, non_recording_span): + fake = _active_sentry() + request = _request("/api/v1/items", route="/api/v1/items") + call_next = AsyncMock(return_value=SimpleNamespace(status_code=404)) + + await self._run(request, call_next, fake) + + error_calls = [ + c + for c in fake.metrics.count.call_args_list + if c.kwargs["name"] == "http.server.request.error" + ] + assert len(error_calls) == 1 + assert error_calls[0].kwargs["attributes"]["http.status_code"] == "404" + + @pytest.mark.asyncio + async def test_unhandled_exception_counts_500_and_reraises( + self, non_recording_span + ): + fake = _active_sentry() + request = _request("/api/v1/items", route="/api/v1/items") + call_next = AsyncMock(side_effect=ValueError("boom")) + + with pytest.raises(ValueError): + await self._run(request, call_next, fake) + + error_calls = [ + c + for c in fake.metrics.count.call_args_list + if c.kwargs["name"] == "http.server.request.error" + ] + assert len(error_calls) == 1 + assert error_calls[0].kwargs["attributes"]["http.status_code"] == "500" + + @pytest.mark.asyncio + async def test_health_path_excluded_from_metrics(self, non_recording_span): + fake = _active_sentry() + request = _request("/health", route="/health") + call_next = AsyncMock(return_value=SimpleNamespace(status_code=200)) + + await self._run(request, call_next, fake) + + fake.metrics.count.assert_not_called() + fake.metrics.distribution.assert_not_called() + + @pytest.mark.asyncio + async def test_route_template_used_as_metric_tag(self, non_recording_span): + fake = _active_sentry() + request = _request("/api/v1/items/42", route="/api/v1/items/{item_id}") + call_next = AsyncMock(return_value=SimpleNamespace(status_code=200)) + + await self._run(request, call_next, fake) + + count_call = next( + c + for c in fake.metrics.count.call_args_list + if c.kwargs["name"] == "http.server.request.count" + ) + assert ( + count_call.kwargs["attributes"]["http.route"] == "/api/v1/items/{item_id}" + ) def _build_request(headers: dict[str, str] | None = None) -> Request: @@ -25,10 +149,34 @@ def _build_request(headers: dict[str, str] | None = None) -> Request: "query_string": b"", "root_path": "", "headers": raw_headers, + "route": SimpleNamespace(path="/api/v1/probe"), } ) +class TestUnmatchedRoute: + @pytest.mark.asyncio + async def test_unrouted_request_emits_only_unmatched_counter( + self, non_recording_span: MagicMock, caplog: pytest.LogCaptureFixture + ) -> None: + fake = _active_sentry() + request = _request("/wp-admin/setup.php", route=None) + call_next = AsyncMock(return_value=SimpleNamespace(status_code=404)) + + with ( + patch.object(middleware, "sentry_sdk", fake), + patch.object(metrics, "sentry_sdk", fake), + caplog.at_level(logging.INFO, logger="http_request_logger"), + ): + await middleware._log_http_request(request, call_next) + + assert _metric_names(fake) == ["http.server.request.unmatched"] + assert fake.metrics.count.call_args.kwargs["attributes"] == { + "http.method": "GET" + } + assert not [r for r in caplog.records if "_log_http_request" in r.message] + + class TestResolveRequestBodySize: def test_reads_content_length_header(self) -> None: request = _build_request({"content-length": "512"}) @@ -54,15 +202,15 @@ def test_logs_body_size_and_correlation_id( payload = b"0123456789abcdef" with caplog.at_level(logging.INFO, logger="http_request_logger"): - response = client.post("/api/v1/no-such-route", content=payload) + response = client.patch("/api/v1/users/me", content=payload) - assert response.status_code == 404 + assert response.status_code == 401 line = next( record.getMessage() for record in caplog.records if record.name == "http_request_logger" ) - assert "POST /api/v1/no-such-route - 404" in line + assert "PATCH /api/v1/users/me - 401" in line assert "| request_body_size: 16B |" in line assert re.search(r"correlation_id: [0-9a-f]{32}$", line) @@ -70,7 +218,7 @@ def test_logs_zero_for_bodyless_request( self, client: TestClient, caplog: pytest.LogCaptureFixture ) -> None: with caplog.at_level(logging.INFO, logger="http_request_logger"): - client.get("/api/v1/no-such-route") + client.get("/api/v1/users/me") line = next( record.getMessage() diff --git a/backend/app/tests/core/test_rate_monitor.py b/backend/app/tests/core/test_rate_monitor.py index bc15febd2..131ed30cb 100644 --- a/backend/app/tests/core/test_rate_monitor.py +++ b/backend/app/tests/core/test_rate_monitor.py @@ -7,7 +7,8 @@ import redis -from app.core import rate_monitor, telemetry +from app.core import rate_monitor +from app.core.telemetry import metrics as telemetry def _auth_context(project_id: int | None = 1, project_name: str = "Acme"): @@ -164,7 +165,7 @@ def test_emits_warning_message_with_tags(self): with ( patch.object(telemetry.sentry_sdk, "get_client", return_value=client), - patch.object(telemetry.sentry_sdk, "push_scope", return_value=scope_cm), + patch.object(telemetry.sentry_sdk, "new_scope", return_value=scope_cm), patch.object(telemetry.sentry_sdk, "capture_message") as capture, ): telemetry.record_rate_threshold( diff --git a/backend/app/tests/core/test_sentry_filters.py b/backend/app/tests/core/test_sentry_filters.py deleted file mode 100644 index 1873b7368..000000000 --- a/backend/app/tests/core/test_sentry_filters.py +++ /dev/null @@ -1,80 +0,0 @@ -from app.core.sentry_filters import before_send_filter - - -def _event_with_celery_job(task_name: str, kwargs: dict) -> dict: - return { - "extra": { - "celery-job": { - "task_name": task_name, - "args": [], - "kwargs": kwargs, - } - } - } - - -def test_before_send_filter_redacts_query_for_llm_job(): - event = _event_with_celery_job( - "app.celery.tasks.job_execution.run_llm_job", - { - "job_id": "b9ce6621-9b5a-45c4-969f-df7613ff7dc4", - "organization_id": 1, - "project_id": 1, - "request_data": { - "callback_url": "https://webhooksite.net/some-id", - "config": {"blob": {"completion": {"provider": "openai"}}}, - "query": { - "input": { - "type": "text", - "content": {"value": "Amit Gupta phone number is 919611188278"}, - } - }, - "request_metadata": None, - }, - }, - ) - - result = before_send_filter(event, {}) - - request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] - assert request_data["query"] == "[REDACTED]" - # callback_url can carry identifying/credential data and is redacted too. - assert request_data["callback_url"] == "[REDACTED]" - # Non-sensitive fields are left untouched so the trace stays useful. - assert request_data["config"] == {"blob": {"completion": {"provider": "openai"}}} - - -def test_before_send_filter_redacts_query_for_chain_and_response_jobs(): - for task_name in ( - "app.celery.tasks.job_execution.run_llm_chain_job", - "app.celery.tasks.job_execution.run_response_job", - ): - event = _event_with_celery_job( - task_name, - {"request_data": {"query": {"input": "sensitive text"}}}, - ) - - result = before_send_filter(event, {}) - - request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] - assert request_data["query"] == "[REDACTED]" - - -def test_before_send_filter_ignores_unrelated_tasks(): - event = _event_with_celery_job( - "app.celery.tasks.job_execution.run_doctransform_job", - {"request_data": {"query": {"input": "not an llm job"}}}, - ) - - result = before_send_filter(event, {}) - - request_data = result["extra"]["celery-job"]["kwargs"]["request_data"] - assert request_data["query"] == {"input": "not an llm job"} - - -def test_before_send_filter_passes_through_events_without_celery_job(): - event = {"message": "some unrelated error"} - - result = before_send_filter(event, {}) - - assert result == event diff --git a/backend/app/tests/test_utils.py b/backend/app/tests/test_utils.py index 7aac18032..16d666d7d 100644 --- a/backend/app/tests/test_utils.py +++ b/backend/app/tests/test_utils.py @@ -419,6 +419,39 @@ def test_returns_false_for_blocked_url(self, mock_validate) -> None: assert result is False +class TestSendCallbackLogging: + _payload = { + "success": True, + "data": {"output": "model answer for the user"}, + "error": None, + "metadata": {"job_id": "j1", "request_metadata": {"ref": "abc"}}, + } + + @patch("app.utils.validate_callback_url") + @patch("requests.Session") + def test_failure_logs_status_and_payload_without_user_data( + self, mock_session_cls, mock_validate, caplog: pytest.LogCaptureFixture + ) -> None: + mock_session = MagicMock() + error_response = MagicMock(status_code=502) + mock_session.post.return_value.raise_for_status.side_effect = ( + requests.HTTPError("502 Bad Gateway", response=error_response) + ) + mock_session_cls.return_value.__enter__.return_value = mock_session + + with caplog.at_level("ERROR", logger="app.utils"): + assert not send_callback("https://api.example.com/hook", self._payload) + + line = next( + r.getMessage() + for r in caplog.records + if "Callback failed" in r.getMessage() + ) + assert "status=502" in line + assert "'job_id': 'j1'" in line + assert "model answer for the user" not in line + + class TestGenerateEvalCompletionEmail: def test_completed_renders_expected_fields(self) -> None: data = generate_eval_completion_email( diff --git a/backend/app/utils.py b/backend/app/utils.py index 679ecb3cb..a01a342d3 100644 --- a/backend/app/utils.py +++ b/backend/app/utils.py @@ -24,6 +24,7 @@ from langfuse import Langfuse import openai from anthropic import Anthropic +from opentelemetry import trace from openai import OpenAI from pydantic import BaseModel, JsonValue from sqlmodel import Session @@ -550,6 +551,9 @@ def get_webhook_secret( return creds.get("webhook_secret") if isinstance(creds, dict) else None +CALLBACK_USER_DATA_KEY = "data" + + def send_callback( callback_url: str, data: dict[str, Any], @@ -582,14 +586,18 @@ def send_callback( except ValueError as ve: logger.warning(f"[send_callback] Invalid callback URL: {ve}", exc_info=True) return False + log_payload = {k: v for k, v in data.items() if k != CALLBACK_USER_DATA_KEY} + raw_body = json.dumps(data, separators=(",", ":")).encode() + started_at = time.perf_counter() try: - raw_body = json.dumps(data, separators=(",", ":")).encode() headers = {"Content-Type": "application/json"} if webhook_secret: signature, timestamp_ms = sign_webhook_payload(webhook_secret, raw_body) headers["X-Webhook-Signature"] = signature headers["X-Webhook-Timestamp"] = str(timestamp_ms) + span = trace.get_current_span() + span.set_attribute("callback.request.body.size", len(raw_body)) with requests.Session() as session: session.trust_env = False # Ignores environment proxies and other implicit settings for SSRF safety @@ -603,14 +611,23 @@ def send_callback( ), allow_redirects=False, ) + span.set_attribute( + "callback.duration_ms", + round((time.perf_counter() - started_at) * 1000, 2), + ) + span.set_attribute("callback.response.status_code", response.status_code) response.raise_for_status() - - logger.info(f"[send_callback] Callback sent successfully to {callback_url}") return True except requests.RequestException as e: - logger.error(f"[send_callback] Callback failed: {str(e)}", exc_info=True) + status = e.response.status_code if e.response is not None else None + logger.error( + f"[send_callback] Callback failed | url={callback_url} | status={status} " + f"| duration_ms={(time.perf_counter() - started_at) * 1000:.2f} " + f"| bytes={len(raw_body)} | payload={log_payload} | error={e}", + exc_info=True, + ) return False diff --git a/backend/pyproject.toml b/backend/pyproject.toml index caf23c32b..0ca77e4fd 100644 --- a/backend/pyproject.toml +++ b/backend/pyproject.toml @@ -20,7 +20,7 @@ dependencies = [ # Pin bcrypt until passlib supports the latest "bcrypt==4.0.1", "pydantic-settings<3.0.0,>=2.2.1", - "sentry-sdk[fastapi]>=2.20.0", + "sentry-sdk[fastapi]>=2.35.0", "opentelemetry-api>=1.30.0", "opentelemetry-sdk>=1.30.0", "opentelemetry-instrumentation>=0.51b0", @@ -29,6 +29,9 @@ dependencies = [ "opentelemetry-instrumentation-httpx>=0.51b0", "opentelemetry-instrumentation-requests>=0.51b0", "opentelemetry-instrumentation-logging>=0.51b0", + "opentelemetry-instrumentation-sqlalchemy>=0.51b0", + "opentelemetry-instrumentation-redis>=0.51b0", + "opentelemetry-instrumentation-botocore>=0.51b0", "pyjwt>=2.13.0,<3.0.0", "boto3>=1.37.20", "moto[s3]>=5.1.1", diff --git a/backend/uv.lock b/backend/uv.lock index 675933ab5..51a9fce43 100644 --- a/backend/uv.lock +++ b/backend/uv.lock @@ -282,11 +282,14 @@ dependencies = [ { name = "openpyxl" }, { name = "opentelemetry-api" }, { name = "opentelemetry-instrumentation" }, + { name = "opentelemetry-instrumentation-botocore" }, { name = "opentelemetry-instrumentation-celery" }, { name = "opentelemetry-instrumentation-fastapi" }, { name = "opentelemetry-instrumentation-httpx" }, { name = "opentelemetry-instrumentation-logging" }, + { name = "opentelemetry-instrumentation-redis" }, { name = "opentelemetry-instrumentation-requests" }, + { name = "opentelemetry-instrumentation-sqlalchemy" }, { name = "opentelemetry-sdk" }, { name = "pandas" }, { name = "passlib", extra = ["bcrypt"] }, @@ -354,11 +357,14 @@ requires-dist = [ { name = "openpyxl", specifier = ">=3.1.5" }, { name = "opentelemetry-api", specifier = ">=1.30.0" }, { name = "opentelemetry-instrumentation", specifier = ">=0.51b0" }, + { name = "opentelemetry-instrumentation-botocore", specifier = ">=0.51b0" }, { name = "opentelemetry-instrumentation-celery", specifier = ">=0.51b0" }, { name = "opentelemetry-instrumentation-fastapi", specifier = ">=0.51b0" }, { name = "opentelemetry-instrumentation-httpx", specifier = ">=0.51b0" }, { name = "opentelemetry-instrumentation-logging", specifier = ">=0.51b0" }, + { name = "opentelemetry-instrumentation-redis", specifier = ">=0.51b0" }, { name = "opentelemetry-instrumentation-requests", specifier = ">=0.51b0" }, + { name = "opentelemetry-instrumentation-sqlalchemy", specifier = ">=0.51b0" }, { name = "opentelemetry-sdk", specifier = ">=1.30.0" }, { name = "pandas", specifier = ">=2.3.2" }, { name = "passlib", extras = ["bcrypt"], specifier = ">=1.7.4,<2.0.0" }, @@ -373,7 +379,7 @@ requires-dist = [ { name = "redis", specifier = ">=5.0.0,<6.0.0" }, { name = "sarvamai", specifier = ">=0.1.25" }, { name = "scikit-learn", specifier = ">=1.7.1" }, - { name = "sentry-sdk", extras = ["fastapi"], specifier = ">=2.20.0" }, + { name = "sentry-sdk", extras = ["fastapi"], specifier = ">=2.35.0" }, { name = "sqlmodel", specifier = ">=0.0.21,<1.0.0" }, { name = "tenacity", specifier = ">=8.2.3,<9.0.0" }, { name = "whisper-normalizer", specifier = ">=0.1.12" }, @@ -2615,32 +2621,31 @@ wheels = [ [[package]] name = "opentelemetry-api" -version = "1.41.0" +version = "1.44.0" source = { registry = "https://pypi.org/simple" } dependencies = [ - { name = "importlib-metadata" }, { name = "typing-extensions" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/47/8e/3778a7e87801d994869a9396b9fc2a289e5f9be91ff54a27d41eace494b0/opentelemetry_api-1.41.0.tar.gz", hash = "sha256:9421d911326ec12dee8bc933f7839090cad7a3f13fcfb0f9e82f8174dc003c09", size = 71416, upload-time = "2026-04-09T14:38:34.544Z" } +sdist = { url = "https://files.pythonhosted.org/packages/ee/8b/aa9e2d8b8dfa7c946f7dec5d1f8f6ba8eca062f43509a06bdb5ce93d26c0/opentelemetry_api-1.44.0.tar.gz", hash = "sha256:67647e5e9566edcf421166fdf022b3537f818635daa852b289e34604dc6fb33a", size = 72406, upload-time = "2026-07-16T15:25:32.678Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/58/ee/99ab786653b3bda9c37ade7e24a7b607a1b1f696063172768417539d876d/opentelemetry_api-1.41.0-py3-none-any.whl", hash = "sha256:0e77c806e6a89c9e4f8d372034622f3e1418a11bdbe1c80a50b3d3397ad0fa4f", size = 69007, upload-time = "2026-04-09T14:38:11.833Z" }, + { url = "https://files.pythonhosted.org/packages/ca/6f/a04e900f465ff3221ccc395522503e2d10e79fa21f2723c8e177aae1e0d1/opentelemetry_api-1.44.0-py3-none-any.whl", hash = "sha256:94b98c893a91b88657eaac1e3ba89618cdb85be6918196705354f34728b2cdef", size = 60018, upload-time = "2026-07-16T15:25:11.657Z" }, ] [[package]] name = "opentelemetry-exporter-otlp-proto-common" -version = "1.41.0" +version = "1.44.0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-proto" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/8c/28/e8eca94966fe9a1465f6094dc5ddc5398473682180279c94020bc23b4906/opentelemetry_exporter_otlp_proto_common-1.41.0.tar.gz", hash = "sha256:966bbce537e9edb166154779a7c4f8ab6b8654a03a28024aeaf1a3eacb07d6ee", size = 20411, upload-time = "2026-04-09T14:38:36.572Z" } +sdist = { url = "https://files.pythonhosted.org/packages/61/09/4d717852c1cf3f854b76c7110a5d00883bc3c99288b9b0dbcbeb9e306eb6/opentelemetry_exporter_otlp_proto_common-1.44.0.tar.gz", hash = "sha256:dc87a5a5bc58f149a56d1547e4691588fa12994cdc3bc039a694ccb3375862ac", size = 20202, upload-time = "2026-07-16T15:25:37.658Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/26/c4/78b9bf2d9c1d5e494f44932988d9d91c51a66b9a7b48adf99b62f7c65318/opentelemetry_exporter_otlp_proto_common-1.41.0-py3-none-any.whl", hash = "sha256:7a99177bf61f85f4f9ed2072f54d676364719c066f6d11f515acc6c745c7acf0", size = 18366, upload-time = "2026-04-09T14:38:15.135Z" }, + { url = "https://files.pythonhosted.org/packages/5e/71/65fd9d54c10b860f87c045ccee1264cab7011268895d3528818a29c1172a/opentelemetry_exporter_otlp_proto_common-1.44.0-py3-none-any.whl", hash = "sha256:9a9fe61bba73d802904bc989f1d6b4a7b1ee40f06c40e98d6f85af65aaebb694", size = 17045, upload-time = "2026-07-16T15:25:18.201Z" }, ] [[package]] name = "opentelemetry-exporter-otlp-proto-http" -version = "1.41.0" +version = "1.44.0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "googleapis-common-protos" }, @@ -2651,14 +2656,14 @@ dependencies = [ { name = "requests" }, { name = "typing-extensions" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/19/63/d9f43cd75f3fabb7e01148c89cfa9491fc18f6580a6764c554ff7c953c46/opentelemetry_exporter_otlp_proto_http-1.41.0.tar.gz", hash = "sha256:dcd6e0686f56277db4eecbadd5262124e8f2cc739cadbc3fae3d08a12c976cf5", size = 24139, upload-time = "2026-04-09T14:38:38.128Z" } +sdist = { url = "https://files.pythonhosted.org/packages/1a/87/95e2a5aaa795b4e2260d74e16df2d5541deb2ea9de010bcd615f4dee2654/opentelemetry_exporter_otlp_proto_http-1.44.0.tar.gz", hash = "sha256:c633d7270ad6b57cd4cfbe8b0007a9e2e7c0cb50bd6c50fe2a7b245f721a09d8", size = 25806, upload-time = "2026-07-16T15:25:39.162Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/64/b5/a214cd907eedc17699d1c2d602288ae17cb775526df04db3a3b3585329d2/opentelemetry_exporter_otlp_proto_http-1.41.0-py3-none-any.whl", hash = "sha256:a9c4ee69cce9c3f4d7ee736ad1b44e3c9654002c0816900abbafd9f3cf289751", size = 22673, upload-time = "2026-04-09T14:38:18.349Z" }, + { url = "https://files.pythonhosted.org/packages/cd/d0/fdeb1a98d8d3a6205f5f297c51b4a9bfe65126ab60339669bbe3dd54c2e2/opentelemetry_exporter_otlp_proto_http-1.44.0-py3-none-any.whl", hash = "sha256:838592fce774c1c8bb7b9a0a7facbfa82e17be5a8a4e94cef10cb84ae026bae3", size = 21850, upload-time = "2026-07-16T15:25:20.006Z" }, ] [[package]] name = "opentelemetry-instrumentation" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, @@ -2666,14 +2671,14 @@ dependencies = [ { name = "packaging" }, { name = "wrapt" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/f9/fd/b8e90bb340957f059084376f94cff336b0e871a42feba7d3f7342365e987/opentelemetry_instrumentation-0.62b0.tar.gz", hash = "sha256:aa1b0b9ab2e1722c2a8a5384fb016fc28d30bba51826676c8036074790d2861e", size = 34042, upload-time = "2026-04-09T14:40:22.843Z" } +sdist = { url = "https://files.pythonhosted.org/packages/13/91/3c58961cb0360cd60509064734f0be4275383c8681d73c580a40ca83ddce/opentelemetry_instrumentation-0.65b0.tar.gz", hash = "sha256:071d9d9eced9bd6460444ec3b0c77229870ed05a881c22c84fdede58e4eed09b", size = 42689, upload-time = "2026-07-16T15:25:50.275Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/00/b6/3356d2e335e3c449c5183e9b023f30f04f1b7073a6583c68745ea2e704b1/opentelemetry_instrumentation-0.62b0-py3-none-any.whl", hash = "sha256:30d4e76486eae64fb095264a70c2c809c4bed17b73373e53091470661f7d477c", size = 34158, upload-time = "2026-04-09T14:39:21.428Z" }, + { url = "https://files.pythonhosted.org/packages/40/7b/85eab1215f72adf0e68d3dc4a679b9bff993fa679ff34cd8dd378e2659fd/opentelemetry_instrumentation-0.65b0-py3-none-any.whl", hash = "sha256:ea967a72b9939b5fcfdad572753b4306c59dcb99e3f382d95dae04286805e137", size = 36717, upload-time = "2026-07-16T15:24:51.424Z" }, ] [[package]] name = "opentelemetry-instrumentation-asgi" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "asgiref" }, @@ -2682,28 +2687,44 @@ dependencies = [ { name = "opentelemetry-semantic-conventions" }, { name = "opentelemetry-util-http" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/f1/38/999bf777774878971c2716de4b7a03cd57a7decb4af25090e703b79fa0e5/opentelemetry_instrumentation_asgi-0.62b0.tar.gz", hash = "sha256:93cde8c62e5918a3c1ff9ba020518127300e5e0816b7e8b14baf46a26ba619fc", size = 26779, upload-time = "2026-04-09T14:40:26.566Z" } +sdist = { url = "https://files.pythonhosted.org/packages/17/83/8e8e83b7ac285281687c7be2fd305213ccccbb8c0a2dd4fb45a8ccaf12c7/opentelemetry_instrumentation_asgi-0.65b0.tar.gz", hash = "sha256:892bca67c56522ffa85a8a83cf934d7b50b3be2132e45cbee705825f0a5ba426", size = 26140, upload-time = "2026-07-16T15:25:54.544Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/0b/9c/376962840b619d2d55fe8ee2285f8c70971c090e5fff614516fc654a6f3a/opentelemetry_instrumentation_asgi-0.65b0-py3-none-any.whl", hash = "sha256:3a845a8ebd1c4ef0d8263401e6545f5b219b2feee612090d50f578a87e71fd65", size = 15903, upload-time = "2026-07-16T15:24:57.198Z" }, +] + +[[package]] +name = "opentelemetry-instrumentation-botocore" +version = "0.65b0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "opentelemetry-api" }, + { name = "opentelemetry-instrumentation" }, + { name = "opentelemetry-propagator-aws-xray" }, + { name = "opentelemetry-semantic-conventions" }, + { name = "wrapt" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/54/03/a0c6a0f34ba3cacda527317e7f2a5a1fcfd21c9911eee3e6fc2be63d0a93/opentelemetry_instrumentation_botocore-0.65b0.tar.gz", hash = "sha256:64987326ac98a47a85821606a981f5058864de0e98b43c8de892eb0fe625b04e", size = 125099, upload-time = "2026-07-16T15:25:59.335Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/25/cf/29df82f5870178143bdb5c9a7be044b9f78c71e1c5dcf995242e86d80158/opentelemetry_instrumentation_asgi-0.62b0-py3-none-any.whl", hash = "sha256:89b62a6f996b260b162f515c25e6d78e39286e4cbe2f935899e51b32f31027e2", size = 17011, upload-time = "2026-04-09T14:39:27.305Z" }, + { url = "https://files.pythonhosted.org/packages/3f/59/0b51f55d9fb96949674efe895d330506b7b8c1b13a6401f0eec49d1196af/opentelemetry_instrumentation_botocore-0.65b0-py3-none-any.whl", hash = "sha256:a5e80b9423f8369c9bbc27a64b31f02cc44218633028ad8d1ace0a2a7fc8f4cd", size = 36242, upload-time = "2026-07-16T15:25:03.377Z" }, ] [[package]] name = "opentelemetry-instrumentation-celery" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, { name = "opentelemetry-instrumentation" }, { name = "opentelemetry-semantic-conventions" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/01/b4/20a3c8c669dc45aa3703c0370041d67e8be613f1829523cdaf634a5f9626/opentelemetry_instrumentation_celery-0.62b0.tar.gz", hash = "sha256:55e8fa48e5b886bcca448fa32e28a6cc2165157745e8328de479a826d3903095", size = 14808, upload-time = "2026-04-09T14:40:31.603Z" } +sdist = { url = "https://files.pythonhosted.org/packages/b1/ba/c4ef088927a6bf1b75916b3bfca93552526f0e3e85d19557666f858fc5b6/opentelemetry_instrumentation_celery-0.65b0.tar.gz", hash = "sha256:ff4d192b6371cfe06969005862dc558cc8b79b03b0bbdfbf65b9a59e4dcd7fee", size = 16071, upload-time = "2026-07-16T15:26:00.867Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/f6/60/cf951e6bd6ec62ec55bd2384e0ba9841ea38f2d128c773d85dc60da97172/opentelemetry_instrumentation_celery-0.62b0-py3-none-any.whl", hash = "sha256:cadfd3e65287a36099dce5ba7e05d98e4c5f9479a455241e01d140ecc5c10935", size = 13864, upload-time = "2026-04-09T14:39:35.009Z" }, + { url = "https://files.pythonhosted.org/packages/1d/3a/3a53db4c82bd42f67a16c846aa972aef75043557e26e9d6a4ca8ffac9699/opentelemetry_instrumentation_celery-0.65b0-py3-none-any.whl", hash = "sha256:8510357a6a9e2cb1a6485fe98642a39f06c2970eb58656de06260b922ffe7888", size = 13556, upload-time = "2026-07-16T15:25:05.427Z" }, ] [[package]] name = "opentelemetry-instrumentation-fastapi" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, @@ -2712,14 +2733,14 @@ dependencies = [ { name = "opentelemetry-semantic-conventions" }, { name = "opentelemetry-util-http" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/37/09/92740c6d114d1bef392557a03ae6de64065c83c1b331dae9b57fe718497c/opentelemetry_instrumentation_fastapi-0.62b0.tar.gz", hash = "sha256:e4748e4e575077e08beaf2c5d2f369da63dd90882d89d73c4192a97356637dec", size = 25056, upload-time = "2026-04-09T14:40:36.438Z" } +sdist = { url = "https://files.pythonhosted.org/packages/30/23/b057f8196d06efdc1b50e3ff11fbc499a7d96b35c87f217eb7885542f4ea/opentelemetry_instrumentation_fastapi-0.65b0.tar.gz", hash = "sha256:10a3a95486036230413a58fe4fdf4a83fa6bba46918407e527476994bd92bd97", size = 26236, upload-time = "2026-07-16T15:26:05.954Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/64/bb/186ffe0fde0ad33ceb50e1d3596cc849b732d3b825592a6a507a40c8c49b/opentelemetry_instrumentation_fastapi-0.62b0-py3-none-any.whl", hash = "sha256:06d3272ad15f9daea5a0a27c32831aff376110a4b0394197120256ef6d610e6e", size = 13482, upload-time = "2026-04-09T14:39:43.446Z" }, + { url = "https://files.pythonhosted.org/packages/fa/b0/c9b0300d33349ecc3dfd2362516eaffc44877e90970e6a52178ff953fec3/opentelemetry_instrumentation_fastapi-0.65b0-py3-none-any.whl", hash = "sha256:cda2610a0ec1b22d19886f33e4d861e9f5dbb886aeaa3a1263b47aff82c36943", size = 13261, upload-time = "2026-07-16T15:25:12.429Z" }, ] [[package]] name = "opentelemetry-instrumentation-httpx" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, @@ -2728,27 +2749,43 @@ dependencies = [ { name = "opentelemetry-util-http" }, { name = "wrapt" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/77/a7/63e2c6325c8e99cd9b8e0229a8b61c37520ee537214a2c8d514e84486a94/opentelemetry_instrumentation_httpx-0.62b0.tar.gz", hash = "sha256:d865398db3f3c289ba226e355bf4d94460a4301c0c8916e3136caea55ae18000", size = 24182, upload-time = "2026-04-09T14:40:38.719Z" } +sdist = { url = "https://files.pythonhosted.org/packages/61/03/a529140241addd4d0acc73bafbd6f74691651b92fc0ae9b4513cf80f07fa/opentelemetry_instrumentation_httpx-0.65b0.tar.gz", hash = "sha256:4627aa9c6bb99bf4462c8b565b0ef6aeb9ffad95c6c92868be1ef7895de112ee", size = 26309, upload-time = "2026-07-16T15:26:07.973Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/c0/5e/7d5fc28487637871b015128cd5dbb3c36f6d343a9098b893bd803d5a9cca/opentelemetry_instrumentation_httpx-0.62b0-py3-none-any.whl", hash = "sha256:c7660b939c12608fec67743126e9b4dc23dceef0ed631c415924966b0d1579e3", size = 17200, upload-time = "2026-04-09T14:39:46.618Z" }, + { url = "https://files.pythonhosted.org/packages/9d/0f/c6144096b4914bbf44b43ba21c962e8f333ff045770b50a3e79ed8bd455f/opentelemetry_instrumentation_httpx-0.65b0-py3-none-any.whl", hash = "sha256:400f1b78afa4ee2332b5debe58e1ed1b317913d58812c952576be76660aeadb1", size = 17436, upload-time = "2026-07-16T15:25:15.772Z" }, ] [[package]] name = "opentelemetry-instrumentation-logging" -version = "0.62b0" +version = "0.65b0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "opentelemetry-api" }, + { name = "opentelemetry-instrumentation" }, + { name = "opentelemetry-semantic-conventions" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/ed/0a/b70a9cddbc7b314a783e62739dbb1184f8538c1f85e8ded6d340142b9b54/opentelemetry_instrumentation_logging-0.65b0.tar.gz", hash = "sha256:c0a50cade5d54db6c6af12e2c69227ecd26f2b3b779e99ff850561d3d8dd77e3", size = 19783, upload-time = "2026-07-16T15:26:09.853Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/e2/8e/7577914681d77b180f8d6dcbac435be8e4ca6add6315da2d01ac4289eaa3/opentelemetry_instrumentation_logging-0.65b0-py3-none-any.whl", hash = "sha256:68365b31755c844f1e85f07dcd217839ff92f2d278a214bdf02d4dc806f9d915", size = 15727, upload-time = "2026-07-16T15:25:18.774Z" }, +] + +[[package]] +name = "opentelemetry-instrumentation-redis" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, { name = "opentelemetry-instrumentation" }, + { name = "opentelemetry-semantic-conventions" }, + { name = "wrapt" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/b2/47/8b81b7f007addf4dfd2b2f0753326e62822e1fec674605d0ec7c39d479b0/opentelemetry_instrumentation_logging-0.62b0.tar.gz", hash = "sha256:61f23be960e047054b3aa38998e7d1eb1fd9bef6f52097e28bc113af8b6f3bd8", size = 18968, upload-time = "2026-04-09T14:40:40.733Z" } +sdist = { url = "https://files.pythonhosted.org/packages/21/e5/b369897a9ff902eb028f1f999c9f9a4602f0b30fe1e97298d2c15fe5b8b0/opentelemetry_instrumentation_redis-0.65b0.tar.gz", hash = "sha256:f16409f189092984ff922f26939e7be79509365f5c9d202308c13fddf1368147", size = 17218, upload-time = "2026-07-16T15:26:17.243Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/c1/36/135fd0f4a154ea225de0a418d36f8cf9cf273ad31d41a3a2aaa91862b817/opentelemetry_instrumentation_logging-0.62b0-py3-none-any.whl", hash = "sha256:9a27b6c3d419170d96dedcea7d38cc0418f0dd1054365f52499a0a1eb70b8faf", size = 17489, upload-time = "2026-04-09T14:39:49.384Z" }, + { url = "https://files.pythonhosted.org/packages/9d/2a/5b874bf8824e7cb995b22e1e61e1b5bc42810023d81612c44edbfd2c48a3/opentelemetry_instrumentation_redis-0.65b0-py3-none-any.whl", hash = "sha256:7d135f61db9d72416e1f382012fbc13de6f5e726491bebd0344a9c42a60e6769", size = 14658, upload-time = "2026-07-16T15:25:29.146Z" }, ] [[package]] name = "opentelemetry-instrumentation-requests" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, @@ -2756,57 +2793,85 @@ dependencies = [ { name = "opentelemetry-semantic-conventions" }, { name = "opentelemetry-util-http" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/20/77/bbc89f2264e03b53fc3e9462a69415f30c23e88c7f0f5e6ebf594471355e/opentelemetry_instrumentation_requests-0.62b0.tar.gz", hash = "sha256:4534f961729393e8070cd5b779fa42937f5b7380ef481107ffd4042b31816ce2", size = 18398, upload-time = "2026-04-09T14:40:49.615Z" } +sdist = { url = "https://files.pythonhosted.org/packages/c8/84/f46bf7976a81827419b085c9ed14562410c7599e07509786e9f6eb3c5438/opentelemetry_instrumentation_requests-0.65b0.tar.gz", hash = "sha256:1d601548f89236d5ab373c7208a2e1e162a8d6462b5b972f9ad8fb0ed82d7438", size = 18107, upload-time = "2026-07-16T15:26:18.532Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/42/45/6201afe846263d775cd4fc8d6a87dc8c15eb7921cdade4dca1e1227b04b6/opentelemetry_instrumentation_requests-0.65b0-py3-none-any.whl", hash = "sha256:91688ec0d4d1fed75ea8d026ef2c66274ed9868c22b6be211ef85d832d16f957", size = 13386, upload-time = "2026-07-16T15:25:31.093Z" }, +] + +[[package]] +name = "opentelemetry-instrumentation-sqlalchemy" +version = "0.65b0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "opentelemetry-api" }, + { name = "opentelemetry-instrumentation" }, + { name = "opentelemetry-semantic-conventions" }, + { name = "packaging" }, + { name = "wrapt" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/ae/9d/72af21527ce6f286ac78dc2c75ce44b76cc45343a28f0bcbb13f213421fc/opentelemetry_instrumentation_sqlalchemy-0.65b0.tar.gz", hash = "sha256:8ec2e79f1e00808c5dc639ab5b2cfcdf9dcdef55efd6442c6019707fe2894028", size = 18007, upload-time = "2026-07-16T15:26:19.197Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/71/94/3eb3195a60b894cc1852a5657a2b64764a998085c50d7fb3452148af8f18/opentelemetry_instrumentation_sqlalchemy-0.65b0-py3-none-any.whl", hash = "sha256:4d8a2e5afc7b505a48d05cb1fb6db5f8b31681814c1d7767bd6d4b5bdd3a3047", size = 14410, upload-time = "2026-07-16T15:25:32.04Z" }, +] + +[[package]] +name = "opentelemetry-propagator-aws-xray" +version = "1.0.2" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "opentelemetry-api" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/f4/31/40004e9e55b1e5694ef3a7526f0b7637df44196fc68a8b7d248a3684680f/opentelemetry_propagator_aws_xray-1.0.2.tar.gz", hash = "sha256:6b2cee5479d2ef0172307b66ed2ed151f598a0fd29b3c01133ac87ca06326260", size = 10994, upload-time = "2024-08-05T17:45:57.601Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/97/54/a73d688d969283f344de96c43366912addb94bdbef413bcebac22979545e/opentelemetry_instrumentation_requests-0.62b0-py3-none-any.whl", hash = "sha256:edf61785ecb3ec6923e33c24074c82067f286a418f817b2b82546956d120e6d6", size = 14209, upload-time = "2026-04-09T14:40:02.987Z" }, + { url = "https://files.pythonhosted.org/packages/ea/89/849a0847871fd9745315896ad9e23d6479db84d90b8b36c4c26dc46e92b8/opentelemetry_propagator_aws_xray-1.0.2-py3-none-any.whl", hash = "sha256:1c99181ee228e99bddb638a0c911a297fa21f1c3a0af951f841e79919b5f1934", size = 10856, upload-time = "2024-08-05T17:45:56.492Z" }, ] [[package]] name = "opentelemetry-proto" -version = "1.41.0" +version = "1.44.0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "protobuf" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/e0/d9/08e3dc6156878713e8c811682bc76151f5fe1a3cb7f3abda3966fd56e71e/opentelemetry_proto-1.41.0.tar.gz", hash = "sha256:95d2e576f9fb1800473a3e4cfcca054295d06bdb869fda4dc9f4f779dc68f7b6", size = 45669, upload-time = "2026-04-09T14:38:45.978Z" } +sdist = { url = "https://files.pythonhosted.org/packages/64/01/40ac4ae9a149263cc52c2cee200ddd80cb6d8db1a4610abf8eabce0fe771/opentelemetry_proto-1.44.0.tar.gz", hash = "sha256:c547a79c2f8c0c515d31509154682e5921c7cfd5ca67b70e1f9266e2c3e103f3", size = 46488, upload-time = "2026-07-16T15:25:45.34Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/49/8c/65ef7a9383a363864772022e822b5d5c6988e6f9dabeebb9278f5b86ebc3/opentelemetry_proto-1.41.0-py3-none-any.whl", hash = "sha256:b970ab537309f9eed296be482c3e7cca05d8aca8165346e929f658dbe153b247", size = 72074, upload-time = "2026-04-09T14:38:29.38Z" }, + { url = "https://files.pythonhosted.org/packages/d1/7c/8be563d68e93bbefa5c8affb82ddcff91b3ad858ce49957ba7b16fd3e0ab/opentelemetry_proto-1.44.0-py3-none-any.whl", hash = "sha256:898b155a0e1557afd867478fb6158e8122a46329ca0bb8dc53cc55e98f017f56", size = 72483, upload-time = "2026-07-16T15:25:28.429Z" }, ] [[package]] name = "opentelemetry-sdk" -version = "1.41.0" +version = "1.44.0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, { name = "opentelemetry-semantic-conventions" }, { name = "typing-extensions" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/f8/0e/a586df1186f9f56b5a0879d52653effc40357b8e88fc50fe300038c3c08b/opentelemetry_sdk-1.41.0.tar.gz", hash = "sha256:7bddf3961131b318fc2d158947971a8e37e38b1cd23470cfb72b624e7cc108bd", size = 230181, upload-time = "2026-04-09T14:38:47.225Z" } +sdist = { url = "https://files.pythonhosted.org/packages/5d/77/a6592cbc7c8d9bcc9d6757a9df45e04a7c585e3e6e7a13456da522b21109/opentelemetry_sdk-1.44.0.tar.gz", hash = "sha256:cebe7f65dc12f26ead75c6064de12fd2a9052e5060c0272d402cfa203aae123b", size = 208624, upload-time = "2026-07-16T15:25:46.078Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/2c/13/a7825118208cb32e6a4edcd0a99f925cbef81e77b3b0aedfd9125583c543/opentelemetry_sdk-1.41.0-py3-none-any.whl", hash = "sha256:a596f5687964a3e0d7f8edfdcf5b79cbca9c93c7025ebf5fb00f398a9443b0bd", size = 180214, upload-time = "2026-04-09T14:38:30.657Z" }, + { url = "https://files.pythonhosted.org/packages/e7/23/ff077e61886ee020a17ce9c8b6fa11c601c8d8345b09ea24f605445df62a/opentelemetry_sdk-1.44.0-py3-none-any.whl", hash = "sha256:df081c4c6bcfdb1211e3e86140376792643128a25f8d72d1d27675936e7e96ad", size = 137221, upload-time = "2026-07-16T15:25:29.534Z" }, ] [[package]] name = "opentelemetry-semantic-conventions" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } dependencies = [ { name = "opentelemetry-api" }, { name = "typing-extensions" }, ] -sdist = { url = "https://files.pythonhosted.org/packages/a3/b0/c14f723e86c049b7bf8ff431160d982519b97a7be2857ed2247377397a24/opentelemetry_semantic_conventions-0.62b0.tar.gz", hash = "sha256:cbfb3c8fc259575cf68a6e1b94083cc35adc4a6b06e8cf431efa0d62606c0097", size = 145753, upload-time = "2026-04-09T14:38:48.274Z" } +sdist = { url = "https://files.pythonhosted.org/packages/8f/73/0cbdebcb4cf545fdd328da14f5137e37d0770c3f26185e478b0d15d94f50/opentelemetry_semantic_conventions-0.65b0.tar.gz", hash = "sha256:f9b2b81e9d5b64f11bc952075e7e9c7fb0aab075c7fd1c46d597f1b919852d60", size = 148774, upload-time = "2026-07-16T15:25:46.902Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/58/6c/5e86fa1759a525ef91c2d8b79d668574760ff3f900d114297765eb8786cb/opentelemetry_semantic_conventions-0.62b0-py3-none-any.whl", hash = "sha256:0ddac1ce59eaf1a827d9987ab60d9315fb27aea23304144242d1fcad9e16b489", size = 231619, upload-time = "2026-04-09T14:38:32.394Z" }, + { url = "https://files.pythonhosted.org/packages/a6/0e/49df70d9b81fb5cbae4bbf2a49d865b09bcbcbc4eb53f5851b1027738d78/opentelemetry_semantic_conventions-0.65b0-py3-none-any.whl", hash = "sha256:1cacde7b0ad306f84c5ef08c3dbe1bbaf20165bba6f8bff43b670e555a086bcb", size = 204645, upload-time = "2026-07-16T15:25:30.688Z" }, ] [[package]] name = "opentelemetry-util-http" -version = "0.62b0" +version = "0.65b0" source = { registry = "https://pypi.org/simple" } -sdist = { url = "https://files.pythonhosted.org/packages/9b/e7/830f7c57135158eb8a8efd3f94ab191a89e3b8a49bed314a35ee501da3f2/opentelemetry_util_http-0.62b0.tar.gz", hash = "sha256:a62e4b19b8a432c0de657f167dee3455516136bb9c6ed463ca8063019970d835", size = 11393, upload-time = "2026-04-09T14:40:59.442Z" } +sdist = { url = "https://files.pythonhosted.org/packages/32/a9/d7525a59fdd240e69b5af4a6338e78fafa1b4203394122cbd6701fb5f84a/opentelemetry_util_http-0.65b0.tar.gz", hash = "sha256:84f82d826978bba416ab453460ff6a7391cdc3534c93a786595e4068680016b7", size = 11243, upload-time = "2026-07-16T15:26:27.898Z" } wheels = [ - { url = "https://files.pythonhosted.org/packages/3d/7f/5c1b7d4385852b9e5eacd4e7f9d8b565d3d351d17463b24916ad098adf1a/opentelemetry_util_http-0.62b0-py3-none-any.whl", hash = "sha256:c20462808d8cc95b69b0dc4a3e02a9d36beb663347e96c931f51ffd78bd318ad", size = 9294, upload-time = "2026-04-09T14:40:19.014Z" }, + { url = "https://files.pythonhosted.org/packages/23/3f/ab8d29df207ce5f470a07fa96ebb48af4e95b7fab7e7635311b9a32f2fab/opentelemetry_util_http-0.65b0-py3-none-any.whl", hash = "sha256:7553b606f963097cb190536dc30556cce85090692e471a422fff30ca29b04348", size = 8245, upload-time = "2026-07-16T15:25:46.482Z" }, ] [[package]] diff --git a/docs/architecture/kaapi-llm-call-ARCHITECTURE.md b/docs/architecture/kaapi-llm-call-ARCHITECTURE.md index 16fa827a7..92ce5e065 100644 --- a/docs/architecture/kaapi-llm-call-ARCHITECTURE.md +++ b/docs/architecture/kaapi-llm-call-ARCHITECTURE.md @@ -108,7 +108,7 @@ backend/app/ │ └── core/ ├── langfuse/langfuse.py observe_llm_execution decorator - ├── telemetry.py OTel spans, gen_ai metrics, log_context + ├── telemetry/ OTel tracing, gen_ai metrics (llm.py), log_context (context.py) └── cloud/storage.py S3 upload + presigned URLs (STT/TTS audio) ``` @@ -536,9 +536,9 @@ flowchart TD | Layer | What it captures | Where | |---|---|---| -| **OpenTelemetry / Sentry** | Span tree above. The `chat ` span carries `sentry.op = gen_ai.chat` so Sentry **AI Insights** surfaces model, tokens, and latency. | [core/telemetry.py](../../backend/app/core/telemetry.py) | +| **OpenTelemetry / Sentry** | Span tree above. The `chat ` span carries `sentry.op = gen_ai.chat` so Sentry **AI Insights** surfaces model, tokens, and latency. | [core/telemetry/llm.py](../../backend/app/core/telemetry/llm.py) | | **Langfuse** | LLM generations/traces around the actual provider call; `session_id` = `conversation_id` for stateful chats. Enabled per‑project via stored `langfuse` credentials. | [core/langfuse/langfuse.py](../../backend/app/core/langfuse/langfuse.py) | -| **Metrics** | `record_llm_call_started` / `record_llm_call_finished` (provider, model, duration, token counts, error flag). | [core/telemetry.py](../../backend/app/core/telemetry.py) | +| **Metrics** | `record_llm_call_started` / `record_llm_call_finished` (provider, model, duration, token counts, error flag). | [core/telemetry/llm.py](../../backend/app/core/telemetry/llm.py) | | **DB audit** | `job` + `llm_call` rows (see §8). | [crud/llm.py](../../backend/app/crud/llm.py), [crud/jobs.py](../../backend/app/crud/jobs.py) | `flush_telemetry()` is called in a `finally` so spans/metrics ship even on failure. diff --git a/docs/architecture/kaapi-observability-ARCHITECTURE.md b/docs/architecture/kaapi-observability-ARCHITECTURE.md new file mode 100644 index 000000000..25eb4460a --- /dev/null +++ b/docs/architecture/kaapi-observability-ARCHITECTURE.md @@ -0,0 +1,212 @@ +# Kaapi Observability — Architecture Overview + +## Overview + +Kaapi collects **traces, metrics and logs** from both processes, the FastAPI web app and the Celery worker, and sends all of them to **one Sentry project**. Errors, cron check-ins and profiles go to the same place, so one request can be followed from the HTTP call to the Celery task, the provider call and the callback. + +- **OpenTelemetry creates spans, Sentry stores them** (`instrumenter="otel"`). Sentry's own span integrations are off, so nothing is recorded twice. +- **One package, `core/telemetry/`**, holds all of it. API and worker share one `init_sentry()`. +- **User data is redacted before it leaves the process.** Langfuse is the only place message bodies go. +- **Noise is dropped at the source:** bots, health checks and empty traces never reach Sentry. + +```mermaid +flowchart LR + subgraph Web["FastAPI process"] + MW["middleware.py\nHTTP metrics · tags"] + FI["FastAPIInstrumentor"] + SQLW["SQLAlchemy hooks"] + LOGW["logging + LogContextFilter"] + end + + subgraph Worker["Celery worker"] + CI["CeleryInstrumentor +\nSentry CeleryIntegration"] + SQLC["SQLAlchemy hooks"] + LOGC["logging + LogContextFilter"] + LLM["LLM spans · gen_ai attrs\nllm.* metrics"] + end + + subgraph Telemetry["core/telemetry (in each process)"] + TP["TracerProvider\n_NoiseFilteringSpanProcessor"] + FLT["sentry/filters.py\nscrub · drop"] + end + + Sentry[("Sentry project\nIssues · Traces · Logs · Metrics\nProfiles · Crons · Uptime")] + LF[("Langfuse\nmessage bodies only")] + CW[("CloudWatch\nstdout text")] + + FI --> TP + SQLW --> TP + CI --> TP + LLM --> TP + TP --> FLT + MW -- "metrics" --> FLT + LOGW --> FLT + LOGC --> FLT + FLT --> Sentry + LLM -. "separate TracerProvider" .-> LF + LOGW -- "stdout" --> CW + LOGC -- "stdout" --> CW + Web -- "enqueue with trace headers" --> Worker +``` + +--- + +## Setup + +``` +core/telemetry/ +├── __init__.py public API +├── tracing.py tracer provider, span filtering, FastAPI instrumentation, flush +├── context.py log context, per-module context, tenant tags, user binding +├── metrics.py metric emitter, job and rate-threshold monitors +├── http.py HTTP request metrics +├── llm.py gen_ai span attributes, LLM metrics +├── db.py SQLAlchemy spans and DB metrics +└── sentry/ + ├── init.py one sentry_sdk.init() for API and worker + └── filters.py redaction and noise filters +``` + +- **One switch:** `OTEL_ENABLED` is checked only where instrumentation starts (`main.py`, `celery_app.py`, `core/db.py`). The telemetry functions themselves have no flags. +- **No double recording:** Sentry's FastAPI, Starlette, SQLAlchemy, httpx (and, on the API, Celery) integrations are disabled because OTel already covers them. The worker keeps Sentry's Celery integration for task-failure Issues. +- **Sampling and profiling** come from settings, each validated to 0–1: `SENTRY_TRACES_SAMPLE_RATE`, `SENTRY_ERROR_SAMPLE_RATE`, `SENTRY_PROFILE_SESSION_SAMPLE_RATE` (continuous profiling, tied to traces). +- **Environments:** production and staging report to separate Sentry projects (`kaapi-production`, `kaapi-staging`). + +--- + +## 1. Tracing + +**What is traced:** HTTP requests, DB queries, Celery tasks, Redis, S3/KMS (botocore), outbound HTTP, and every LLM call. These feed Sentry's ready-made views: **AI Insights** (LLM calls), **Queries** (DB), **Queues** (Celery), **Caches** (Redis) and **Outbound API Requests**. + +**Waterfall of one `/llm/call`**, as it appears in Sentry: + +```mermaid +flowchart TD + A["POST /api/v1/llm/call (web)"] --> A1["db: INSERT job"] + A --> B["run/app.celery.tasks.job_execution.run_llm_job (worker)"] + B --> C["llm.resolve_config"] + B --> D["llm.guardrails.input"] + B --> E["llm.create_call_record"] + B --> F["chat gpt-4o · sentry.op = gen_ai.chat"] + B --> G["llm.update_call_record"] + B --> H["llm.guardrails.output"] + B --> I["llm.send_callback"] +``` + +**What each span carries:** + +- **LLM (`chat `):** provider, model, operation, request params (temperature, max tokens, top_p, tools), token usage including reasoning tokens, response model, org and project. +- **DB:** parameterised SQL (`db.statement`), rows affected (`db.rows_affected`), and on failure the Postgres SQLSTATE with a readable name for deadlocks, lock timeouts, serialization failures and connection errors. +- **Callback (`llm.send_callback`):** payload size, client HTTP status and duration. +- **HTTP server span:** method, route, status and request body size. + +**How it is done:** + +```mermaid +flowchart LR + I["OTel instrumentors\n+ manual spans"] --> P["_NoiseFilteringSpanProcessor"] + P -- "drop" --> X1["root span without http.route\n(bot / scanner)"] + P -- "drop" --> X2["root span, no children, no error"] + P -- "forward + copy root attributes" --> S["SentrySpanProcessor"] + S --> F["before_send_transaction_filter\nscrub gen_ai content"] + F --> Sentry[("Sentry Traces")] +``` + +- **One trace from API to worker:** the Sentry Celery integration adds trace headers on enqueue, and the task re-attaches the parent. Self re-enqueuing poll loops start a fresh trace so one trace does not span hours. +- **Root attributes are kept:** Sentry's processor copies attributes only for child spans; ours copies root-span attributes too. +- **Provider HTTP spans are suppressed** inside LLM calls, since the `chat ` span already covers the call. +- **Spans are flushed** after every Celery task and in LLM job `finally` blocks, so a recycled worker does not lose them. +- **Langfuse is kept apart:** it runs on its own tracer provider, so LLM message bodies go to Langfuse and never into Sentry traces. + +--- + +## 2. Metrics + +All metrics go through `emit_sentry_metric()`, which never raises and does nothing when Sentry is off. + +| Family | Metrics | +|---|---| +| **HTTP** | `http.server.request.count`, `.duration`, `.body.size`, `.error`, `.unmatched` | +| **DB** | `db.query.failed` (tagged by Postgres SQLSTATE), `db.query.slow` (≥ `DB_SLOW_QUERY_MS`), `db.connection.opened/closed/invalidated`, `db.transaction.commit/rollback` (rollback ratio), `db.pool.active/idle/total/overflow` (pool saturation) | +| **LLM** | `llm.call.total`, `llm.call.duration`, `llm.call.errors`, `llm.tokens.input/output/total` (by provider and model) | +| **Jobs** | `jobs.pending.stale.count`, `jobs.pending.oldest_age_seconds` (table-level and by job type) | + +Metrics use the Sentry SDK directly because Sentry does not ingest OpenTelemetry metrics. + +--- + +## 3. Logs + +Every log line goes to two places with the same content: + +| Sink | What you see | Search | +|---|---|---| +| **Sentry Logs** | structured fields: `message`, `log_module`, `logger.name`, `code.line.number`, tenant tags, link to the trace | `log_module:llm-call` | +| **CloudWatch** | one text line from container stdout | `filter @message like "[llm-call]"` | + +``` +2026-10-11 10:16:57,137 - [kaapi-backend] - [a1b2c3] - INFO - [knowledgebase] app.api.routes.collection_job - [get_collection_job] Fetched job | job_id=8f2c +``` + +**Log context.** `log_context(...)` wraps a request or task and adds fields (`job_id`, `project_id`, `lifecycle`, …) to every log line inside it, including lines from shared helpers. After auth, the org and project ids are added the same way. `LogContextFilter` applies these fields; it is installed with logging, so it works even when tracing is off. + +**Per-module context.** Every line from a known module carries `log_module` (for example `llm-call`), and the CloudWatch line shows it in front of the logger name: + +| Module | Covers | +|---|---| +| `knowledgebase` | collections, documents, doc transformation, RAG | +| `llm-call` | `/llm/call`, `services/llm`, `crud/llm` | +| `llm-chain` | `/llm/chain`, `services/llm/chain`, `crud/llm_chain` | +| `config-version` | config routes and CRUD | +| `assessment` | API-client BATCH path and submissions | +| `evals` | evaluations v2: routes, judge, iteration loop, prompt improvement | +| `fastevals` | fast evaluations | + +- The module comes from a file-to-module map (`_LOGGER_MODULES` in `context.py`). +- When a flow runs another flow's code, it sets the module itself with `log_context(module=LogModuleEnum.X)`: LLM chain jobs and fast-eval tasks do this. +- Files outside these modules have no `log_module`, and their CloudWatch line shows just the logger name. + +--- + +## 4. HTTP + +- **Spans:** `FastAPIInstrumentor` creates one server span per request. Health checks, docs/OpenAPI paths and cron endpoints are excluded, and ASGI `http send` / `http receive` spans are never created. Spans carry both old and stable `http.*` names (`OTEL_SEMCONV_STABILITY_OPT_IN=http/dup`). +- **Middleware (`core/middleware.py`):** times each request, reads the body size from `Content-Length`, tags the Sentry scope with method, route, status and `correlation_id`, and writes one access log line. +- **Metrics:** count, duration, body size and errors per method, route and status. +- **Bots and scanners:** requests that match no route (random paths, `PROPFIND`, `SEARCH`, …) are dropped from traces, get no access log and no per-route metrics; only `http.server.request.unmatched` is counted. + +--- + +## 5. Errors, crons and alerts + +- **Unhandled API errors:** the generic 500 handler reports the exception to Sentry. 4xx responses are not reported. +- **Celery task failures:** become Issues with the task name and (redacted) arguments. +- **Error logs:** any `logger.error` / `logger.exception` becomes a Sentry event. +- **Callbacks:** every callback logs url, status, duration, size and payload (without `data`); failures log at ERROR. +- **Tenant impact:** each Issue is tagged with org and project and bound to the calling user, so it shows which tenants are affected. +- **DB errors:** tagged with the Postgres SQLSTATE and a readable name (`deadlock_detected`, `lock_not_available`, `too_many_connections`, …), so DB Issues can be grouped by cause. +- **Breadcrumbs:** the last 30 log lines and calls before an error are attached to it. +- **Rate threshold:** a project exceeding its per-minute limit raises a warning event tagged `alert.type=threshold_rate_monitor`. +- **Crons:** `evaluation-cron-job`, `pending-jobs-monitor` and `daily-stats-cron-job` check in with `@sentry_sdk.monitor`; a missed or failed run is flagged. +- **Alerts and uptime:** alert rules, uptime monitors (API, console, guardrails) and dashboards are configured in the Sentry UI. + +--- + +## 6. Redaction + +- **Prompts and completions:** `gen_ai.*`, `ai.*` and Langfuse content keys are removed from every event, transaction and log. +- **Request body:** always replaced with `[REDACTED]` on error events, because on LLM routes it is the user's message. +- **Headers, cookies, query string:** `Authorization`, `Cookie`, `X-API-KEY` and the query string are redacted while `SENTRY_SEND_DEFAULT_PII` is off. +- **LLM and chain task arguments:** the user `query` and every config `instructions` value are redacted. Model, params, `request_metadata` and `callback_url` are kept. +- **Callback payload:** the `data` field (LLM output) is left out of callback logs. +- **Stack frames:** local variables are not sent (`include_local_variables=False`). +- **Sentry AI integrations:** pinned to `include_prompts=False`, so the SDK never records prompts on its own. +- **Log lines on LLM paths:** by convention they log ids, lengths and types, never prompt or response text. + +--- + +## Where to start reading + +1. [core/telemetry/__init__.py](../../backend/app/core/telemetry/__init__.py) — the public surface. +2. [core/telemetry/sentry/](../../backend/app/core/telemetry/sentry/) — `init.py` (what is sent) and `filters.py` (what is redacted). +3. [core/telemetry/tracing.py](../../backend/app/core/telemetry/tracing.py) and [context.py](../../backend/app/core/telemetry/context.py) — span filtering, log context and modules. diff --git a/docs/wiki/cross-cutting/observability.md b/docs/wiki/cross-cutting/observability.md index ab55c8b5a..b60d5c93b 100644 --- a/docs/wiki/cross-cutting/observability.md +++ b/docs/wiki/cross-cutting/observability.md @@ -10,8 +10,23 @@ All paths relative to `backend/app/`. - `core/logger.py`. Convention (CLAUDE.md): every log line starts with the function name in brackets — `logger.info(f"[function_name] Message | key: {value}")`. ## Sentry -- `core/sentry_filters.py` — event filtering before send. +OTel-first, Sentry as sole in-process sink (`instrumenter="otel"`). Init at `main.py` (web) and `celery/celery_app.py` (worker), kept in sync. +- `core/telemetry/sentry/filters.py` — `before_send_transaction_filter` (drops probe transactions, scrubs genai content; DB spans are kept so Sentry Queries has data) and `before_send_error_filter` (drops probe events, always drops the request body, scrubs headers/cookies/query when `SENTRY_SEND_DEFAULT_PII` off, redacts LLM task kwargs). +- GenAI content never reaches Sentry, in either PII mode. Four locks in `core/telemetry/sentry/filters.py`, wired by `init_sentry()` in `core/telemetry/sentry/init.py` for both API and worker: `scrub_genai_content` strips `_GENAI_CONTENT_KEYS` (prompt/completion span+log attributes) from every event, `before_send_log_filter` does the same for logs, `genai_privacy_integrations()` pins Sentry's auto-enabled AI integrations to `include_prompts=False`, and `include_local_variables=False` / `max_request_body_size="never"` keep prompts out of stack frames and request bodies. Langfuse (isolated tracer provider, `core/langfuse/langfuse.py`) stays the only sink for message bodies. +- Corollary for log lines on LLM paths: log lengths/ids/types, never prompt or response text — `enable_logs=True` ships every INFO record to Sentry. +- Sampling/profiling/PII: `SENTRY_TRACES_SAMPLE_RATE`, `SENTRY_PROFILE_SESSION_SAMPLE_RATE`, `SENTRY_PROFILE_LIFECYCLE`, `SENTRY_SEND_DEFAULT_PII`, `SENTRY_ERROR_SAMPLE_RATE` (config.py; defaults preserve current behavior). +- Trace propagation: `CeleryIntegration(propagate_traces=True)` links API to worker as one trace; poll-loop re-enqueues pass `SENTRY_NO_PROPAGATE_HEADERS` (`celery/tasks/job_execution.py`) to start a fresh trace. +- Error capture: generic handler in `core/exception_handlers.py` calls `capture_exception`. +- Tenant impact (both in `core/telemetry/context.py`, called from `api/deps.py`): `set_request_log_context` puts org/project in the log context + Sentry tags; `bind_sentry_user` binds user/org/project via `sentry_sdk.set_user` so issues report users/orgs affected. The user binding is scope-only — ids in the log context would stamp per-user cardinality on every INFO record `enable_logs` ships. Per-request identity is the `correlation_id` tag (`core/middleware.py`), not the user binding. +- Crons: `@sentry_sdk.monitor` on `/cron/*` endpoints (`api/routes/cron.py`). +- Runbook (alerts/dashboards/debugging): `features/sentry-utilization/SENTRY-RUNBOOK.md`. ## Telemetry / misc -- `core/telemetry.py` +- `core/telemetry/` package, public API re-exported from `__init__.py`: `tracing.py` (OTel tracer provider, span noise filter, FastAPI instrumentation with `exclude_spans` for ASGI send/receive, `OTEL_SEMCONV_STABILITY_OPT_IN=http/dup` default so server spans carry both old and stable `http.*` names, root-span attributes forwarded into Sentry transaction data, root server spans without `http.route` dropped as scanner/bot traffic, flush), `context.py` (log context, tenant tags, user binding), `metrics.py` (Sentry metric emit, stale-job and rate-threshold monitors), `http.py` (HTTP request metrics, called from `core/middleware.py`; unrouted requests emit only `http.server.request.unmatched` with no route label and no access log), `llm.py` (gen_ai span attributes, LLM call metrics), `db.py` (SQLAlchemy engine hooks, DB spans `db.statement` / `db.rows_affected`, pool/slow-query/transaction metrics). +- Log records carry `module_name` = `[] .` (modules: knowledgebase, llm-call, llm-chain, config-version, assessment (API path), evals (2.0), fastevals). Module names are `LogModuleEnum`; `core/telemetry/context.py::_LOGGER_MODULES` maps each logging file's exact logger name (`__name__`) to its module, so a new logging file must be added there. A flow that runs another flow's code sets `log_context(module=LogModuleEnum.X)` at its entry (LLM chain jobs, fast-eval Celery tasks). Unmapped loggers (legacy assessment, shared eval helpers outside a fast-eval task) get `.` without the `[]` prefix. +- Example, one log line in both sinks: + - Sentry Logs: `module_name: [knowledgebase] app.api.routes.collection_job.get_collection_job`, `logger.name: app.api.routes.collection_job`, `code.line.number: 58`; filter with `module_name:[knowledgebase]*`. + - CloudWatch (stdout format puts `module_name` where the logger name was): `2026-10-11 10:16:57,137 - [kaapi-backend] - [a1b2c3] - INFO - [knowledgebase] app.api.routes.collection_job.get_collection_job - [get_collection_job] Fetched job | job_id=8f2c`; Logs Insights `filter @message like "[knowledgebase]"`. +- `OTEL_ENABLED` is checked only at the entry points (`main.py`, `celery/celery_app.py`, `core/db.py`), which decide whether to call `setup_telemetry` / `instrument_app` / `instrument_db_engine`; the telemetry functions themselves are unconditional. `LogContextFilter` is installed by `configure_logging`, so log context works with OTel off. +- OTel auto-instrumentation (in `setup_telemetry`): FastAPI, SQLAlchemy, httpx, requests, logging, Celery (Queues insight), Redis (Caches insight), botocore (S3/KMS spans). - `core/rate_monitor.py` — provider rate tracking diff --git a/docs/wiki/services.md b/docs/wiki/services.md index 09e9c936b..3c868f672 100644 --- a/docs/wiki/services.md +++ b/docs/wiki/services.md @@ -13,7 +13,7 @@ FastAPI (backend/app/main.py, api/routes/*) │ └── app/celery/tasks/job_execution.py, priority queues ├── Object storage core/cloud/storage.py ├── Langfuse core/langfuse/langfuse.py (traces, scores) - ├── Sentry core/sentry_filters.py + ├── Sentry core/telemetry/sentry/ (init.py, filters.py) └── Providers ├── OpenAI (llm calls, embeddings, batch, vector stores, responses API) ├── Gemini (llm calls, batch: core/batch/gemini.py)