feat(observability): Add comprehensive monitoring with Prometheus and OpenTelemetry
- Add Prometheus metrics for HTTP, MCP tools, Nextcloud API, OAuth, vector sync, and DB operations - Add OpenTelemetry distributed tracing with OTLP export - Add structured JSON logging with trace context correlation - Add ObservabilityMiddleware for automatic HTTP instrumentation - Add app_name attribute to all client classes for per-app metrics - Add configuration for metrics, tracing, and logging via environment variables - Add documentation in docs/observability.md - Fix graceful degradation when tracing is disabled (default state) - Fix uvicorn logging configuration to use observability formatters 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
Chris Coutinho
@@ -0,0 +1,35 @@
|
||||
"""
|
||||
Observability module for the Nextcloud MCP Server.
|
||||
|
||||
This module provides:
|
||||
- Prometheus metrics collection
|
||||
- OpenTelemetry distributed tracing
|
||||
- Enhanced structured logging with trace correlation
|
||||
- Monitoring middleware for Starlette/FastAPI
|
||||
|
||||
Usage:
|
||||
from nextcloud_mcp_server.observability import setup_observability
|
||||
|
||||
# In app.py lifespan
|
||||
setup_observability(app, config)
|
||||
"""
|
||||
|
||||
from nextcloud_mcp_server.observability.logging_config import (
|
||||
get_uvicorn_logging_config,
|
||||
setup_logging,
|
||||
)
|
||||
from nextcloud_mcp_server.observability.metrics import (
|
||||
get_metrics_handler,
|
||||
setup_metrics,
|
||||
)
|
||||
from nextcloud_mcp_server.observability.middleware import ObservabilityMiddleware
|
||||
from nextcloud_mcp_server.observability.tracing import setup_tracing
|
||||
|
||||
__all__ = [
|
||||
"setup_logging",
|
||||
"get_uvicorn_logging_config",
|
||||
"setup_metrics",
|
||||
"setup_tracing",
|
||||
"get_metrics_handler",
|
||||
"ObservabilityMiddleware",
|
||||
]
|
||||
@@ -0,0 +1,290 @@
|
||||
"""
|
||||
Enhanced logging configuration for the Nextcloud MCP Server.
|
||||
|
||||
This module provides:
|
||||
- Structured JSON logging with python-json-logger
|
||||
- Trace context injection (trace_id, span_id) for correlation with distributed traces
|
||||
- Configurable log formats (JSON or text)
|
||||
- Log level configuration per component
|
||||
"""
|
||||
|
||||
import logging
|
||||
import sys
|
||||
from typing import Any
|
||||
|
||||
from pythonjsonlogger import jsonlogger
|
||||
|
||||
from nextcloud_mcp_server.observability.tracing import get_trace_context
|
||||
|
||||
|
||||
class TraceContextFormatter(jsonlogger.JsonFormatter):
|
||||
"""
|
||||
JSON formatter that injects OpenTelemetry trace context into log records.
|
||||
|
||||
This allows logs to be correlated with distributed traces by including
|
||||
trace_id and span_id in each log entry.
|
||||
"""
|
||||
|
||||
def add_fields(
|
||||
self,
|
||||
log_record: dict[str, Any],
|
||||
record: logging.LogRecord,
|
||||
message_dict: dict[str, Any],
|
||||
) -> None:
|
||||
"""
|
||||
Add custom fields to the log record, including trace context.
|
||||
|
||||
Args:
|
||||
log_record: Dictionary to be serialized as JSON
|
||||
record: LogRecord instance
|
||||
message_dict: Dictionary of extra fields from log call
|
||||
"""
|
||||
# Call parent to add standard fields
|
||||
super().add_fields(log_record, record, message_dict)
|
||||
|
||||
# Add trace context if available
|
||||
trace_context = get_trace_context()
|
||||
if trace_context:
|
||||
log_record["trace_id"] = trace_context.get("trace_id")
|
||||
log_record["span_id"] = trace_context.get("span_id")
|
||||
|
||||
# Add standard fields with consistent naming
|
||||
log_record["timestamp"] = self.formatTime(record)
|
||||
log_record["level"] = record.levelname
|
||||
log_record["logger"] = record.name
|
||||
log_record["message"] = record.getMessage()
|
||||
|
||||
# Include exception info if present
|
||||
if record.exc_info:
|
||||
log_record["exception"] = self.formatException(record.exc_info)
|
||||
|
||||
|
||||
class TraceContextTextFormatter(logging.Formatter):
|
||||
"""
|
||||
Text formatter that includes OpenTelemetry trace context.
|
||||
|
||||
Format: [LEVEL] [timestamp] logger - message [trace_id=xxx span_id=yyy]
|
||||
"""
|
||||
|
||||
def format(self, record: logging.LogRecord) -> str:
|
||||
"""
|
||||
Format log record with trace context.
|
||||
|
||||
Args:
|
||||
record: LogRecord instance
|
||||
|
||||
Returns:
|
||||
Formatted log string
|
||||
"""
|
||||
# Format base message
|
||||
base_message = super().format(record)
|
||||
|
||||
# Add trace context if available
|
||||
trace_context = get_trace_context()
|
||||
if trace_context:
|
||||
trace_id = trace_context.get("trace_id", "")
|
||||
span_id = trace_context.get("span_id", "")
|
||||
return f"{base_message} [trace_id={trace_id} span_id={span_id}]"
|
||||
|
||||
return base_message
|
||||
|
||||
|
||||
def setup_logging(
|
||||
log_format: str = "json",
|
||||
log_level: str = "INFO",
|
||||
include_trace_context: bool = True,
|
||||
) -> None:
|
||||
"""
|
||||
Configure logging for the Nextcloud MCP Server.
|
||||
|
||||
Args:
|
||||
log_format: "json" for JSON logging, "text" for human-readable text (default: "json")
|
||||
log_level: Minimum log level (DEBUG, INFO, WARNING, ERROR, CRITICAL) (default: "INFO")
|
||||
include_trace_context: Whether to include trace context in logs (default: True)
|
||||
"""
|
||||
# Get root logger
|
||||
root_logger = logging.getLogger()
|
||||
root_logger.setLevel(getattr(logging, log_level.upper(), logging.INFO))
|
||||
|
||||
# Remove existing handlers
|
||||
root_logger.handlers.clear()
|
||||
|
||||
# Create console handler
|
||||
console_handler = logging.StreamHandler(sys.stdout)
|
||||
console_handler.setLevel(getattr(logging, log_level.upper(), logging.INFO))
|
||||
|
||||
# Configure formatter based on format preference
|
||||
if log_format.lower() == "json":
|
||||
if include_trace_context:
|
||||
formatter = TraceContextFormatter(
|
||||
"%(timestamp)s %(level)s %(name)s %(message)s",
|
||||
datefmt="%Y-%m-%dT%H:%M:%S",
|
||||
)
|
||||
else:
|
||||
formatter = jsonlogger.JsonFormatter(
|
||||
"%(timestamp)s %(level)s %(name)s %(message)s",
|
||||
datefmt="%Y-%m-%dT%H:%M:%S",
|
||||
)
|
||||
else: # text format
|
||||
if include_trace_context:
|
||||
formatter = TraceContextTextFormatter(
|
||||
"%(levelname)s [%(asctime)s] %(name)s - %(message)s",
|
||||
datefmt="%Y-%m-%d %H:%M:%S",
|
||||
)
|
||||
else:
|
||||
formatter = logging.Formatter(
|
||||
"%(levelname)s [%(asctime)s] %(name)s - %(message)s",
|
||||
datefmt="%Y-%m-%d %H:%M:%S",
|
||||
)
|
||||
|
||||
console_handler.setFormatter(formatter)
|
||||
root_logger.addHandler(console_handler)
|
||||
|
||||
# Configure specific logger levels
|
||||
configure_component_loggers(log_level)
|
||||
|
||||
root_logger.info(
|
||||
f"Logging configured: format={log_format}, level={log_level}, "
|
||||
f"trace_context={include_trace_context}"
|
||||
)
|
||||
|
||||
|
||||
def configure_component_loggers(default_level: str = "INFO") -> None:
|
||||
"""
|
||||
Configure log levels for specific components.
|
||||
|
||||
This allows fine-grained control over logging verbosity for different
|
||||
parts of the application.
|
||||
|
||||
Args:
|
||||
default_level: Default log level for most components
|
||||
"""
|
||||
# Map of logger names to log levels
|
||||
logger_levels = {
|
||||
# Application loggers
|
||||
"nextcloud_mcp_server": default_level,
|
||||
"nextcloud_mcp_server.server": default_level,
|
||||
"nextcloud_mcp_server.client": default_level,
|
||||
"nextcloud_mcp_server.auth": default_level,
|
||||
"nextcloud_mcp_server.observability": default_level,
|
||||
# HTTP client loggers (less verbose by default)
|
||||
"httpx": "WARNING",
|
||||
"httpcore": "WARNING",
|
||||
# Server loggers
|
||||
"uvicorn": "INFO",
|
||||
"uvicorn.access": "INFO",
|
||||
"uvicorn.error": "INFO",
|
||||
# MCP framework
|
||||
"mcp": "INFO",
|
||||
# OpenTelemetry (less verbose)
|
||||
"opentelemetry": "WARNING",
|
||||
}
|
||||
|
||||
for logger_name, level in logger_levels.items():
|
||||
logger = logging.getLogger(logger_name)
|
||||
logger.setLevel(getattr(logging, level.upper(), logging.INFO))
|
||||
|
||||
|
||||
def get_logger(name: str) -> logging.Logger:
|
||||
"""
|
||||
Get a logger instance for a specific module.
|
||||
|
||||
This is a convenience function that wraps logging.getLogger()
|
||||
to ensure consistent logger configuration.
|
||||
|
||||
Args:
|
||||
name: Logger name (typically __name__)
|
||||
|
||||
Returns:
|
||||
Logger instance
|
||||
"""
|
||||
return logging.getLogger(name)
|
||||
|
||||
|
||||
def get_uvicorn_logging_config(
|
||||
log_format: str = "json",
|
||||
log_level: str = "INFO",
|
||||
include_trace_context: bool = True,
|
||||
) -> dict:
|
||||
"""
|
||||
Get uvicorn-compatible logging configuration.
|
||||
|
||||
This creates a logging config dict that uvicorn can use while maintaining
|
||||
our observability setup (JSON format, trace context, etc.).
|
||||
|
||||
Args:
|
||||
log_format: "json" or "text"
|
||||
log_level: Minimum log level
|
||||
include_trace_context: Whether to include trace IDs in logs
|
||||
|
||||
Returns:
|
||||
Logging config dict compatible with uvicorn's log_config parameter
|
||||
"""
|
||||
# Determine formatter class based on format and trace context
|
||||
if log_format.lower() == "json":
|
||||
if include_trace_context:
|
||||
formatter_class = "nextcloud_mcp_server.observability.logging_config.TraceContextFormatter"
|
||||
else:
|
||||
formatter_class = "pythonjsonlogger.jsonlogger.JsonFormatter"
|
||||
format_string = "%(timestamp)s %(level)s %(name)s %(message)s"
|
||||
else:
|
||||
if include_trace_context:
|
||||
formatter_class = "nextcloud_mcp_server.observability.logging_config.TraceContextTextFormatter"
|
||||
else:
|
||||
formatter_class = "logging.Formatter"
|
||||
format_string = "%(levelname)s [%(asctime)s] %(name)s - %(message)s"
|
||||
|
||||
return {
|
||||
"version": 1,
|
||||
"disable_existing_loggers": False,
|
||||
"formatters": {
|
||||
"default": {
|
||||
"()": formatter_class,
|
||||
"format": format_string,
|
||||
"datefmt": "%Y-%m-%d %H:%M:%S",
|
||||
},
|
||||
},
|
||||
"handlers": {
|
||||
"default": {
|
||||
"formatter": "default",
|
||||
"class": "logging.StreamHandler",
|
||||
"stream": "ext://sys.stdout",
|
||||
},
|
||||
},
|
||||
"loggers": {
|
||||
"": {
|
||||
"handlers": ["default"],
|
||||
"level": log_level.upper(),
|
||||
},
|
||||
"uvicorn": {
|
||||
"handlers": ["default"],
|
||||
"level": "INFO",
|
||||
"propagate": False,
|
||||
},
|
||||
"uvicorn.access": {
|
||||
"handlers": ["default"],
|
||||
"level": "INFO",
|
||||
"propagate": False,
|
||||
},
|
||||
"uvicorn.error": {
|
||||
"handlers": ["default"],
|
||||
"level": "INFO",
|
||||
"propagate": False,
|
||||
},
|
||||
"httpx": {
|
||||
"handlers": ["default"],
|
||||
"level": "WARNING",
|
||||
"propagate": False,
|
||||
},
|
||||
"httpcore": {
|
||||
"handlers": ["default"],
|
||||
"level": "WARNING",
|
||||
"propagate": False,
|
||||
},
|
||||
"opentelemetry": {
|
||||
"handlers": ["default"],
|
||||
"level": "WARNING",
|
||||
"propagate": False,
|
||||
},
|
||||
},
|
||||
}
|
||||
@@ -0,0 +1,355 @@
|
||||
"""
|
||||
Prometheus metrics for the Nextcloud MCP Server.
|
||||
|
||||
This module defines all Prometheus metrics for monitoring server health, performance,
|
||||
and resource usage. Metrics are organized by category:
|
||||
|
||||
- HTTP Server Metrics (RED: Rate, Errors, Duration)
|
||||
- MCP Tool Metrics (per-tool invocation tracking)
|
||||
- MCP Resource Metrics
|
||||
- Nextcloud API Client Metrics
|
||||
- OAuth Flow Metrics
|
||||
- Vector Sync Metrics (conditional on feature flag)
|
||||
- Database Operation Metrics
|
||||
- External Dependency Health Metrics
|
||||
"""
|
||||
|
||||
import logging
|
||||
|
||||
from prometheus_client import (
|
||||
CONTENT_TYPE_LATEST,
|
||||
REGISTRY,
|
||||
Counter,
|
||||
Gauge,
|
||||
Histogram,
|
||||
generate_latest,
|
||||
)
|
||||
from starlette.requests import Request
|
||||
from starlette.responses import Response
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
# =============================================================================
|
||||
# HTTP Server Metrics (RED + System)
|
||||
# =============================================================================
|
||||
|
||||
http_requests_total = Counter(
|
||||
"mcp_http_requests_total",
|
||||
"Total HTTP requests received",
|
||||
["method", "endpoint", "status_code"],
|
||||
)
|
||||
|
||||
http_request_duration_seconds = Histogram(
|
||||
"mcp_http_request_duration_seconds",
|
||||
"HTTP request latency in seconds",
|
||||
["method", "endpoint"],
|
||||
buckets=(0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0, 10.0),
|
||||
)
|
||||
|
||||
http_requests_in_progress = Gauge(
|
||||
"mcp_http_requests_in_progress",
|
||||
"Number of HTTP requests currently being processed",
|
||||
["method", "endpoint"],
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# MCP Tool Metrics
|
||||
# =============================================================================
|
||||
|
||||
mcp_tool_calls_total = Counter(
|
||||
"mcp_tool_calls_total",
|
||||
"Total MCP tool invocations",
|
||||
["tool_name", "status"], # status: success | error
|
||||
)
|
||||
|
||||
mcp_tool_duration_seconds = Histogram(
|
||||
"mcp_tool_duration_seconds",
|
||||
"MCP tool execution duration in seconds",
|
||||
["tool_name"],
|
||||
buckets=(0.01, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0, 10.0, 30.0),
|
||||
)
|
||||
|
||||
mcp_tool_errors_total = Counter(
|
||||
"mcp_tool_errors_total",
|
||||
"Total MCP tool errors by type",
|
||||
["tool_name", "error_type"],
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# MCP Resource Metrics
|
||||
# =============================================================================
|
||||
|
||||
mcp_resource_requests_total = Counter(
|
||||
"mcp_resource_requests_total",
|
||||
"Total MCP resource requests",
|
||||
["resource_uri", "status"],
|
||||
)
|
||||
|
||||
mcp_resource_duration_seconds = Histogram(
|
||||
"mcp_resource_duration_seconds",
|
||||
"MCP resource request duration in seconds",
|
||||
["resource_uri"],
|
||||
buckets=(0.01, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5),
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# Nextcloud API Client Metrics
|
||||
# =============================================================================
|
||||
|
||||
nextcloud_api_requests_total = Counter(
|
||||
"mcp_nextcloud_api_requests_total",
|
||||
"Total Nextcloud API requests",
|
||||
["app", "method", "status_code"], # app: notes, calendar, contacts, etc.
|
||||
)
|
||||
|
||||
nextcloud_api_duration_seconds = Histogram(
|
||||
"mcp_nextcloud_api_duration_seconds",
|
||||
"Nextcloud API request duration in seconds",
|
||||
["app", "method"],
|
||||
buckets=(0.01, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5, 5.0, 10.0),
|
||||
)
|
||||
|
||||
nextcloud_api_retries_total = Counter(
|
||||
"mcp_nextcloud_api_retries_total",
|
||||
"Total Nextcloud API retries",
|
||||
["app", "reason"], # reason: 429 | timeout | connection_error
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# OAuth Flow Metrics
|
||||
# =============================================================================
|
||||
|
||||
oauth_token_validations_total = Counter(
|
||||
"mcp_oauth_token_validations_total",
|
||||
"Total OAuth token validation attempts",
|
||||
["method", "result"], # method: introspect | jwt; result: valid | invalid | error
|
||||
)
|
||||
|
||||
oauth_token_exchange_total = Counter(
|
||||
"mcp_oauth_token_exchange_total",
|
||||
"Total OAuth token exchange operations (RFC 8693)",
|
||||
["status"], # status: success | error
|
||||
)
|
||||
|
||||
oauth_token_cache_hits_total = Counter(
|
||||
"mcp_oauth_token_cache_hits_total",
|
||||
"Total OAuth token cache lookups",
|
||||
["hit"], # hit: true | false
|
||||
)
|
||||
|
||||
oauth_refresh_token_operations_total = Counter(
|
||||
"mcp_oauth_refresh_token_operations_total",
|
||||
"Total refresh token storage operations",
|
||||
[
|
||||
"operation",
|
||||
"status",
|
||||
], # operation: store | retrieve | delete; status: success | error
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# Vector Sync Metrics (optional feature)
|
||||
# =============================================================================
|
||||
|
||||
vector_sync_documents_scanned_total = Counter(
|
||||
"mcp_vector_sync_documents_scanned_total",
|
||||
"Total documents scanned for vector sync",
|
||||
)
|
||||
|
||||
vector_sync_documents_processed_total = Counter(
|
||||
"mcp_vector_sync_documents_processed_total",
|
||||
"Total documents processed for vector sync",
|
||||
["status"], # status: success | error
|
||||
)
|
||||
|
||||
vector_sync_processing_duration_seconds = Histogram(
|
||||
"mcp_vector_sync_processing_duration_seconds",
|
||||
"Document processing duration in seconds",
|
||||
buckets=(0.1, 0.5, 1.0, 2.5, 5.0, 10.0, 30.0, 60.0),
|
||||
)
|
||||
|
||||
vector_sync_queue_size = Gauge(
|
||||
"mcp_vector_sync_queue_size",
|
||||
"Current number of documents in processing queue",
|
||||
)
|
||||
|
||||
qdrant_operations_total = Counter(
|
||||
"mcp_qdrant_operations_total",
|
||||
"Total Qdrant vector database operations",
|
||||
[
|
||||
"operation",
|
||||
"status",
|
||||
], # operation: upsert | search | delete; status: success | error
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# Database Metrics
|
||||
# =============================================================================
|
||||
|
||||
db_operations_total = Counter(
|
||||
"mcp_db_operations_total",
|
||||
"Total database operations",
|
||||
["db", "operation", "status"], # db: sqlite | qdrant; operation varies
|
||||
)
|
||||
|
||||
db_operation_duration_seconds = Histogram(
|
||||
"mcp_db_operation_duration_seconds",
|
||||
"Database operation duration in seconds",
|
||||
["db", "operation"],
|
||||
buckets=(0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1.0),
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# External Dependency Health Metrics
|
||||
# =============================================================================
|
||||
|
||||
dependency_health = Gauge(
|
||||
"mcp_dependency_health",
|
||||
"External dependency health status (1=up, 0=down)",
|
||||
["dependency"], # dependency: nextcloud | keycloak | qdrant | unstructured
|
||||
)
|
||||
|
||||
dependency_check_duration_seconds = Histogram(
|
||||
"mcp_dependency_check_duration_seconds",
|
||||
"Dependency health check duration in seconds",
|
||||
["dependency"],
|
||||
buckets=(0.01, 0.05, 0.1, 0.25, 0.5, 1.0, 2.5),
|
||||
)
|
||||
|
||||
# =============================================================================
|
||||
# Metrics Setup and HTTP Handler
|
||||
# =============================================================================
|
||||
|
||||
|
||||
def setup_metrics() -> None:
|
||||
"""
|
||||
Initialize Prometheus metrics collection.
|
||||
|
||||
This function should be called once during application startup.
|
||||
It currently doesn't require any initialization beyond module-level
|
||||
metric definitions, but is provided for consistency and future extensibility.
|
||||
"""
|
||||
logger.info("Prometheus metrics initialized")
|
||||
|
||||
|
||||
async def get_metrics_handler(request: Request) -> Response:
|
||||
"""
|
||||
HTTP handler for the /metrics endpoint.
|
||||
|
||||
Args:
|
||||
request: Starlette request object (unused, but required by signature)
|
||||
|
||||
Returns:
|
||||
Response containing Prometheus metrics in text format
|
||||
"""
|
||||
metrics_data = generate_latest(REGISTRY)
|
||||
return Response(content=metrics_data, media_type=CONTENT_TYPE_LATEST)
|
||||
|
||||
|
||||
# =============================================================================
|
||||
# Convenience Functions for Common Metric Updates
|
||||
# =============================================================================
|
||||
|
||||
|
||||
def record_tool_call(tool_name: str, duration: float, status: str = "success") -> None:
|
||||
"""
|
||||
Record metrics for an MCP tool call.
|
||||
|
||||
Args:
|
||||
tool_name: Name of the MCP tool
|
||||
duration: Execution duration in seconds
|
||||
status: "success" or "error"
|
||||
"""
|
||||
mcp_tool_calls_total.labels(tool_name=tool_name, status=status).inc()
|
||||
mcp_tool_duration_seconds.labels(tool_name=tool_name).observe(duration)
|
||||
|
||||
|
||||
def record_tool_error(tool_name: str, error_type: str) -> None:
|
||||
"""
|
||||
Record an MCP tool error.
|
||||
|
||||
Args:
|
||||
tool_name: Name of the MCP tool
|
||||
error_type: Type of error (e.g., "HTTPStatusError", "ValueError")
|
||||
"""
|
||||
mcp_tool_errors_total.labels(tool_name=tool_name, error_type=error_type).inc()
|
||||
|
||||
|
||||
def record_nextcloud_api_call(
|
||||
app: str,
|
||||
method: str,
|
||||
status_code: int,
|
||||
duration: float,
|
||||
) -> None:
|
||||
"""
|
||||
Record metrics for a Nextcloud API call.
|
||||
|
||||
Args:
|
||||
app: Nextcloud app name (notes, calendar, contacts, etc.)
|
||||
method: HTTP method (GET, POST, PUT, DELETE, PROPFIND, etc.)
|
||||
status_code: HTTP status code
|
||||
duration: Request duration in seconds
|
||||
"""
|
||||
nextcloud_api_requests_total.labels(
|
||||
app=app, method=method, status_code=str(status_code)
|
||||
).inc()
|
||||
nextcloud_api_duration_seconds.labels(app=app, method=method).observe(duration)
|
||||
|
||||
|
||||
def record_nextcloud_api_retry(app: str, reason: str) -> None:
|
||||
"""
|
||||
Record a Nextcloud API retry.
|
||||
|
||||
Args:
|
||||
app: Nextcloud app name
|
||||
reason: Retry reason (429, timeout, connection_error)
|
||||
"""
|
||||
nextcloud_api_retries_total.labels(app=app, reason=reason).inc()
|
||||
|
||||
|
||||
def record_oauth_token_validation(method: str, result: str) -> None:
|
||||
"""
|
||||
Record an OAuth token validation.
|
||||
|
||||
Args:
|
||||
method: Validation method ("introspect" or "jwt")
|
||||
result: Validation result ("valid", "invalid", or "error")
|
||||
"""
|
||||
oauth_token_validations_total.labels(method=method, result=result).inc()
|
||||
|
||||
|
||||
def record_db_operation(
|
||||
db: str, operation: str, duration: float, status: str = "success"
|
||||
) -> None:
|
||||
"""
|
||||
Record a database operation.
|
||||
|
||||
Args:
|
||||
db: Database type ("sqlite" or "qdrant")
|
||||
operation: Operation type (e.g., "insert", "select", "upsert", "search")
|
||||
duration: Operation duration in seconds
|
||||
status: "success" or "error"
|
||||
"""
|
||||
db_operations_total.labels(db=db, operation=operation, status=status).inc()
|
||||
db_operation_duration_seconds.labels(db=db, operation=operation).observe(duration)
|
||||
|
||||
|
||||
def set_dependency_health(dependency: str, is_healthy: bool) -> None:
|
||||
"""
|
||||
Update external dependency health status.
|
||||
|
||||
Args:
|
||||
dependency: Dependency name (nextcloud, keycloak, qdrant, unstructured)
|
||||
is_healthy: True if dependency is healthy, False otherwise
|
||||
"""
|
||||
dependency_health.labels(dependency=dependency).set(1 if is_healthy else 0)
|
||||
|
||||
|
||||
def record_dependency_check(dependency: str, duration: float) -> None:
|
||||
"""
|
||||
Record a dependency health check duration.
|
||||
|
||||
Args:
|
||||
dependency: Dependency name
|
||||
duration: Check duration in seconds
|
||||
"""
|
||||
dependency_check_duration_seconds.labels(dependency=dependency).observe(duration)
|
||||
@@ -0,0 +1,200 @@
|
||||
"""
|
||||
Observability middleware for the Nextcloud MCP Server.
|
||||
|
||||
This module provides Starlette middleware that automatically instruments
|
||||
HTTP requests with:
|
||||
- Prometheus metrics (request count, latency, in-flight requests)
|
||||
- OpenTelemetry distributed tracing
|
||||
- Request/response timing and error tracking
|
||||
"""
|
||||
|
||||
import logging
|
||||
import time
|
||||
from typing import Callable
|
||||
|
||||
from starlette.middleware.base import BaseHTTPMiddleware
|
||||
from starlette.requests import Request
|
||||
from starlette.responses import Response
|
||||
|
||||
from nextcloud_mcp_server.observability.metrics import (
|
||||
http_request_duration_seconds,
|
||||
http_requests_in_progress,
|
||||
http_requests_total,
|
||||
)
|
||||
from nextcloud_mcp_server.observability.tracing import (
|
||||
add_span_attribute,
|
||||
trace_operation,
|
||||
)
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class ObservabilityMiddleware(BaseHTTPMiddleware):
|
||||
"""
|
||||
Starlette middleware for automatic HTTP request instrumentation.
|
||||
|
||||
This middleware:
|
||||
- Records Prometheus metrics for each request (RED metrics)
|
||||
- Creates OpenTelemetry spans for distributed tracing
|
||||
- Tracks request timing and errors
|
||||
- Handles in-flight request counting
|
||||
"""
|
||||
|
||||
async def dispatch(
|
||||
self,
|
||||
request: Request,
|
||||
call_next: Callable,
|
||||
) -> Response:
|
||||
"""
|
||||
Process HTTP request with observability instrumentation.
|
||||
|
||||
Args:
|
||||
request: Starlette request object
|
||||
call_next: Next middleware or route handler
|
||||
|
||||
Returns:
|
||||
Response from downstream handler
|
||||
"""
|
||||
# Extract request details
|
||||
method = request.method
|
||||
path = request.url.path
|
||||
endpoint = self._get_endpoint_label(path)
|
||||
|
||||
# Increment in-flight requests counter
|
||||
http_requests_in_progress.labels(method=method, endpoint=endpoint).inc()
|
||||
|
||||
# Record start time
|
||||
start_time = time.time()
|
||||
|
||||
try:
|
||||
# Create span for request (OpenTelemetry auto-instrumentation will create parent span)
|
||||
with trace_operation(
|
||||
f"HTTP {method} {endpoint}",
|
||||
attributes={
|
||||
"http.method": method,
|
||||
"http.path": path,
|
||||
"http.scheme": request.url.scheme,
|
||||
"http.host": request.url.hostname,
|
||||
},
|
||||
):
|
||||
# Process request
|
||||
response = await call_next(request)
|
||||
|
||||
# Add response status to span
|
||||
add_span_attribute("http.status_code", response.status_code)
|
||||
|
||||
# Record metrics
|
||||
duration = time.time() - start_time
|
||||
self._record_request_metrics(
|
||||
method=method,
|
||||
endpoint=endpoint,
|
||||
status_code=response.status_code,
|
||||
duration=duration,
|
||||
)
|
||||
|
||||
return response
|
||||
|
||||
except Exception:
|
||||
# Record error metrics
|
||||
duration = time.time() - start_time
|
||||
self._record_request_metrics(
|
||||
method=method,
|
||||
endpoint=endpoint,
|
||||
status_code=500, # Internal server error
|
||||
duration=duration,
|
||||
)
|
||||
|
||||
logger.error(
|
||||
f"Request failed: {method} {path}",
|
||||
exc_info=True,
|
||||
extra={
|
||||
"method": method,
|
||||
"path": path,
|
||||
"duration_seconds": duration,
|
||||
},
|
||||
)
|
||||
|
||||
# Re-raise exception to be handled by error middleware
|
||||
raise
|
||||
|
||||
finally:
|
||||
# Decrement in-flight requests counter
|
||||
http_requests_in_progress.labels(method=method, endpoint=endpoint).dec()
|
||||
|
||||
def _get_endpoint_label(self, path: str) -> str:
|
||||
"""
|
||||
Get endpoint label for metrics, normalizing dynamic path segments.
|
||||
|
||||
This prevents metric cardinality explosion by grouping similar paths.
|
||||
|
||||
Args:
|
||||
path: Request path
|
||||
|
||||
Returns:
|
||||
Normalized endpoint label
|
||||
"""
|
||||
# Health check endpoints
|
||||
if path.startswith("/health/"):
|
||||
return "/health/*"
|
||||
|
||||
# Metrics endpoint
|
||||
if path == "/metrics":
|
||||
return "/metrics"
|
||||
|
||||
# MCP protocol endpoints
|
||||
if path == "/sse" or path.startswith("/sse/"):
|
||||
return "/sse"
|
||||
|
||||
if path == "/messages" or path.startswith("/messages/"):
|
||||
return "/messages"
|
||||
|
||||
# OAuth/OIDC endpoints
|
||||
if path.startswith("/oauth/"):
|
||||
return "/oauth/*"
|
||||
|
||||
if path.startswith("/oidc/"):
|
||||
return "/oidc/*"
|
||||
|
||||
# Catch-all for other paths
|
||||
return path
|
||||
|
||||
def _record_request_metrics(
|
||||
self,
|
||||
method: str,
|
||||
endpoint: str,
|
||||
status_code: int,
|
||||
duration: float,
|
||||
) -> None:
|
||||
"""
|
||||
Record Prometheus metrics for an HTTP request.
|
||||
|
||||
Args:
|
||||
method: HTTP method
|
||||
endpoint: Normalized endpoint label
|
||||
status_code: HTTP status code
|
||||
duration: Request duration in seconds
|
||||
"""
|
||||
# Record request count
|
||||
http_requests_total.labels(
|
||||
method=method,
|
||||
endpoint=endpoint,
|
||||
status_code=str(status_code),
|
||||
).inc()
|
||||
|
||||
# Record request duration
|
||||
http_request_duration_seconds.labels(
|
||||
method=method,
|
||||
endpoint=endpoint,
|
||||
).observe(duration)
|
||||
|
||||
# Log slow requests (>1 second)
|
||||
if duration > 1.0:
|
||||
logger.warning(
|
||||
f"Slow request: {method} {endpoint} took {duration:.3f}s",
|
||||
extra={
|
||||
"method": method,
|
||||
"endpoint": endpoint,
|
||||
"status_code": status_code,
|
||||
"duration_seconds": duration,
|
||||
},
|
||||
)
|
||||
@@ -0,0 +1,363 @@
|
||||
"""
|
||||
OpenTelemetry distributed tracing for the Nextcloud MCP Server.
|
||||
|
||||
This module provides:
|
||||
- OpenTelemetry SDK initialization with OTLP exporter
|
||||
- Auto-instrumentation for ASGI (Starlette/FastAPI) and httpx
|
||||
- Helper functions for creating custom spans
|
||||
- Context propagation utilities
|
||||
- Span attribute standardization
|
||||
"""
|
||||
|
||||
import logging
|
||||
from contextlib import contextmanager
|
||||
from typing import Any
|
||||
|
||||
from opentelemetry import trace
|
||||
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
|
||||
from opentelemetry.instrumentation.httpx import HTTPXClientInstrumentor
|
||||
from opentelemetry.instrumentation.logging import LoggingInstrumentor
|
||||
from opentelemetry.sdk.resources import Resource
|
||||
from opentelemetry.sdk.trace import TracerProvider
|
||||
from opentelemetry.sdk.trace.export import BatchSpanProcessor
|
||||
from opentelemetry.trace import Status, StatusCode, Tracer
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
# Global tracer instance (initialized in setup_tracing)
|
||||
_tracer: Tracer | None = None
|
||||
|
||||
|
||||
def setup_tracing(
|
||||
service_name: str = "nextcloud-mcp-server",
|
||||
otlp_endpoint: str | None = None,
|
||||
sampling_rate: float = 1.0,
|
||||
) -> Tracer:
|
||||
"""
|
||||
Initialize OpenTelemetry tracing with OTLP exporter.
|
||||
|
||||
Args:
|
||||
service_name: Service name for traces (default: "nextcloud-mcp-server")
|
||||
otlp_endpoint: OTLP gRPC endpoint (e.g., "http://otel-collector:4317")
|
||||
If None, tracing is initialized but no exporter is configured
|
||||
sampling_rate: Sampling rate (0.0-1.0). Default 1.0 (100% sampling)
|
||||
|
||||
Returns:
|
||||
Tracer instance for creating custom spans
|
||||
"""
|
||||
global _tracer
|
||||
|
||||
# Create resource with service name
|
||||
resource = Resource.create(
|
||||
{
|
||||
"service.name": service_name,
|
||||
"service.version": "0.27.2", # TODO: Extract from pyproject.toml
|
||||
}
|
||||
)
|
||||
|
||||
# Create tracer provider
|
||||
provider = TracerProvider(resource=resource)
|
||||
|
||||
# Configure OTLP exporter if endpoint is provided
|
||||
if otlp_endpoint:
|
||||
try:
|
||||
otlp_exporter = OTLPSpanExporter(endpoint=otlp_endpoint, insecure=True)
|
||||
span_processor = BatchSpanProcessor(otlp_exporter)
|
||||
provider.add_span_processor(span_processor)
|
||||
logger.info(
|
||||
f"OpenTelemetry tracing enabled with OTLP endpoint: {otlp_endpoint}"
|
||||
)
|
||||
except Exception as e:
|
||||
logger.warning(
|
||||
f"Failed to initialize OTLP exporter: {e}. Continuing without trace export."
|
||||
)
|
||||
else:
|
||||
logger.info(
|
||||
"OpenTelemetry tracing initialized without OTLP exporter (traces will be generated but not exported)"
|
||||
)
|
||||
|
||||
# Set global tracer provider
|
||||
trace.set_tracer_provider(provider)
|
||||
|
||||
# Auto-instrument httpx for Nextcloud API calls
|
||||
HTTPXClientInstrumentor().instrument()
|
||||
|
||||
# Auto-instrument logging to inject trace context
|
||||
LoggingInstrumentor().instrument(set_logging_format=True)
|
||||
|
||||
# Get and store tracer
|
||||
_tracer = trace.get_tracer(__name__)
|
||||
|
||||
logger.info(f"OpenTelemetry tracing initialized for service: {service_name}")
|
||||
return _tracer
|
||||
|
||||
|
||||
def get_tracer() -> Tracer | None:
|
||||
"""
|
||||
Get the global tracer instance.
|
||||
|
||||
Returns:
|
||||
Tracer instance for creating custom spans, or None if tracing is not enabled
|
||||
|
||||
Note:
|
||||
Returns None if setup_tracing() was never called (tracing disabled).
|
||||
Calling code should handle None gracefully.
|
||||
"""
|
||||
return _tracer
|
||||
|
||||
|
||||
@contextmanager
|
||||
def trace_operation(
|
||||
operation_name: str,
|
||||
attributes: dict[str, Any] | None = None,
|
||||
record_exception: bool = True,
|
||||
):
|
||||
"""
|
||||
Context manager for tracing an operation with automatic error handling.
|
||||
|
||||
Usage:
|
||||
with trace_operation("mcp.tool.nc_notes_create_note", {"note.title": "My Note"}):
|
||||
# Your code here
|
||||
pass
|
||||
|
||||
Args:
|
||||
operation_name: Name of the operation (span name)
|
||||
attributes: Optional attributes to add to the span
|
||||
record_exception: Whether to record exceptions in the span (default: True)
|
||||
|
||||
Yields:
|
||||
Span instance for adding additional attributes (or None if tracing disabled)
|
||||
"""
|
||||
tracer = get_tracer()
|
||||
|
||||
# If tracing is not enabled, just yield without creating a span
|
||||
if tracer is None:
|
||||
yield None
|
||||
return
|
||||
|
||||
with tracer.start_as_current_span(operation_name) as span:
|
||||
# Set initial attributes
|
||||
if attributes:
|
||||
for key, value in attributes.items():
|
||||
span.set_attribute(key, value)
|
||||
|
||||
try:
|
||||
yield span
|
||||
span.set_status(Status(StatusCode.OK))
|
||||
except Exception as e:
|
||||
if record_exception:
|
||||
span.record_exception(e)
|
||||
span.set_status(Status(StatusCode.ERROR, str(e)))
|
||||
raise
|
||||
|
||||
|
||||
def trace_mcp_tool(tool_name: str, tool_args: dict[str, Any] | None = None):
|
||||
"""
|
||||
Create a span for an MCP tool invocation.
|
||||
|
||||
Usage:
|
||||
with trace_mcp_tool("nc_notes_create_note", {"title": "My Note"}):
|
||||
# Tool implementation
|
||||
pass
|
||||
|
||||
Args:
|
||||
tool_name: Name of the MCP tool
|
||||
tool_args: Optional tool arguments (sensitive data will be sanitized)
|
||||
|
||||
Returns:
|
||||
Context manager for the span
|
||||
"""
|
||||
attributes = {
|
||||
"mcp.tool.name": tool_name,
|
||||
}
|
||||
|
||||
# Add sanitized tool args (avoid logging sensitive data)
|
||||
if tool_args:
|
||||
# Only include non-sensitive arguments
|
||||
safe_args = {
|
||||
k: v
|
||||
for k, v in tool_args.items()
|
||||
if k not in ("password", "token", "secret", "api_key", "etag")
|
||||
}
|
||||
if safe_args:
|
||||
attributes["mcp.tool.args"] = str(safe_args)
|
||||
|
||||
return trace_operation(f"mcp.tool.{tool_name}", attributes)
|
||||
|
||||
|
||||
def trace_nextcloud_api_call(
|
||||
app: str,
|
||||
method: str,
|
||||
path: str | None = None,
|
||||
):
|
||||
"""
|
||||
Create a span for a Nextcloud API call.
|
||||
|
||||
Usage:
|
||||
with trace_nextcloud_api_call("notes", "POST", "/apps/notes/api/v1/notes"):
|
||||
# API call implementation
|
||||
pass
|
||||
|
||||
Args:
|
||||
app: Nextcloud app name (notes, calendar, contacts, etc.)
|
||||
method: HTTP method (GET, POST, PUT, DELETE, etc.)
|
||||
path: Optional API path
|
||||
|
||||
Returns:
|
||||
Context manager for the span
|
||||
"""
|
||||
attributes = {
|
||||
"nextcloud.app": app,
|
||||
"http.method": method,
|
||||
}
|
||||
|
||||
if path:
|
||||
attributes["http.path"] = path
|
||||
|
||||
return trace_operation(f"nextcloud.api.{app}.{method}", attributes)
|
||||
|
||||
|
||||
def trace_oauth_operation(operation: str, details: dict[str, Any] | None = None):
|
||||
"""
|
||||
Create a span for an OAuth operation.
|
||||
|
||||
Usage:
|
||||
with trace_oauth_operation("token.validate", {"method": "jwt"}):
|
||||
# OAuth validation logic
|
||||
pass
|
||||
|
||||
Args:
|
||||
operation: OAuth operation name (e.g., "token.validate", "token.exchange")
|
||||
details: Optional operation details (sensitive data will be sanitized)
|
||||
|
||||
Returns:
|
||||
Context manager for the span
|
||||
"""
|
||||
attributes = {"oauth.operation": operation}
|
||||
|
||||
if details:
|
||||
# Only include non-sensitive details
|
||||
safe_details = {
|
||||
k: v
|
||||
for k, v in details.items()
|
||||
if k not in ("token", "refresh_token", "access_token", "client_secret")
|
||||
}
|
||||
if safe_details:
|
||||
attributes.update(safe_details)
|
||||
|
||||
return trace_operation(f"oauth.{operation}", attributes)
|
||||
|
||||
|
||||
def trace_vector_sync_operation(
|
||||
operation: str,
|
||||
document_count: int | None = None,
|
||||
):
|
||||
"""
|
||||
Create a span for a vector sync operation.
|
||||
|
||||
Usage:
|
||||
with trace_vector_sync_operation("scan", document_count=10):
|
||||
# Vector sync logic
|
||||
pass
|
||||
|
||||
Args:
|
||||
operation: Operation name (scan, process, embed, upsert)
|
||||
document_count: Optional number of documents being processed
|
||||
|
||||
Returns:
|
||||
Context manager for the span
|
||||
"""
|
||||
attributes = {"vector_sync.operation": operation}
|
||||
|
||||
if document_count is not None:
|
||||
attributes["vector_sync.document_count"] = document_count
|
||||
|
||||
return trace_operation(f"vector_sync.{operation}", attributes)
|
||||
|
||||
|
||||
def trace_db_operation(
|
||||
db: str,
|
||||
operation: str,
|
||||
table: str | None = None,
|
||||
):
|
||||
"""
|
||||
Create a span for a database operation.
|
||||
|
||||
Usage:
|
||||
with trace_db_operation("sqlite", "insert", "refresh_tokens"):
|
||||
# Database operation
|
||||
pass
|
||||
|
||||
Args:
|
||||
db: Database type (sqlite, qdrant)
|
||||
operation: Operation type (insert, select, update, delete, upsert, search)
|
||||
table: Optional table/collection name
|
||||
|
||||
Returns:
|
||||
Context manager for the span
|
||||
"""
|
||||
attributes = {
|
||||
"db.system": db,
|
||||
"db.operation": operation,
|
||||
}
|
||||
|
||||
if table:
|
||||
attributes["db.table"] = table
|
||||
|
||||
return trace_operation(f"db.{db}.{operation}", attributes)
|
||||
|
||||
|
||||
def add_span_attribute(key: str, value: Any) -> None:
|
||||
"""
|
||||
Add an attribute to the current span (if any).
|
||||
|
||||
Args:
|
||||
key: Attribute key
|
||||
value: Attribute value
|
||||
|
||||
Note:
|
||||
This is a no-op if tracing is not enabled or there's no active span.
|
||||
"""
|
||||
if _tracer is None:
|
||||
return # Tracing not enabled
|
||||
span = trace.get_current_span()
|
||||
if span.is_recording():
|
||||
span.set_attribute(key, value)
|
||||
|
||||
|
||||
def add_span_event(name: str, attributes: dict[str, Any] | None = None) -> None:
|
||||
"""
|
||||
Add an event to the current span (if any).
|
||||
|
||||
Args:
|
||||
name: Event name
|
||||
attributes: Optional event attributes
|
||||
|
||||
Note:
|
||||
This is a no-op if tracing is not enabled or there's no active span.
|
||||
"""
|
||||
if _tracer is None:
|
||||
return # Tracing not enabled
|
||||
span = trace.get_current_span()
|
||||
if span.is_recording():
|
||||
span.add_event(name, attributes=attributes or {})
|
||||
|
||||
|
||||
def get_trace_context() -> dict[str, str]:
|
||||
"""
|
||||
Get current trace context as a dictionary.
|
||||
|
||||
Returns:
|
||||
Dictionary with trace_id and span_id (or empty dict if tracing disabled or no active span)
|
||||
"""
|
||||
if _tracer is None:
|
||||
return {} # Tracing not enabled
|
||||
|
||||
span = trace.get_current_span()
|
||||
if span.is_recording():
|
||||
span_context = span.get_span_context()
|
||||
return {
|
||||
"trace_id": format(span_context.trace_id, "032x"),
|
||||
"span_id": format(span_context.span_id, "016x"),
|
||||
}
|
||||
return {}
|
||||
Reference in New Issue
Block a user