Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

instrumentation: fastapi prometheus middleware #1007

Open
wants to merge 1 commit into
base: jjaakola-aiven-fastapi
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 4 additions & 4 deletions container/prometheus/prometheus.yml
Original file line number Diff line number Diff line change
Expand Up @@ -8,17 +8,17 @@ rule_files:

# A scrape configuration
scrape_configs:
- job_name: karapace-registry
- job_name: karapace-schema-registry
metrics_path: /metrics
static_configs:
- targets:
- karapace-registry:8081
- karapace-schema-registry:8081

- job_name: karapace-rest
- job_name: karapace-rest-proxy
metrics_path: /metrics
static_configs:
- targets:
- karapace-rest:8082
- karapace-rest-proxy:8082

- job_name: statsd-exporter
metrics_path: /metrics
Expand Down
2 changes: 2 additions & 0 deletions src/schema_registry/__main__.py
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
from schema_registry.factory import create_karapace_application, karapace_schema_registry_lifespan

import schema_registry.factory
import schema_registry.middlewares.prometheus
import schema_registry.routers.compatibility
import schema_registry.routers.config
import schema_registry.routers.health
Expand All @@ -32,6 +33,7 @@
schema_registry_container.wire(
modules=[
__name__,
schema_registry.middlewares.prometheus,
schema_registry.factory,
schema_registry.user,
schema_registry.routers.health,
Expand Down
3 changes: 3 additions & 0 deletions src/schema_registry/middlewares/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
from fastapi import FastAPI, HTTPException, Request, Response
from fastapi.responses import JSONResponse
from karapace.content_type import check_schema_headers
from schema_registry.middlewares.prometheus import setup_prometheus_middleware


def setup_middlewares(app: FastAPI) -> None:
Expand All @@ -32,3 +33,5 @@ async def set_content_types(request: Request, call_next: Callable[[Request], Awa
response = await call_next(request)
response.headers["Content-Type"] = response_content_type
return response

setup_prometheus_middleware(app=app)
53 changes: 53 additions & 0 deletions src/schema_registry/middlewares/prometheus.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,53 @@
"""
Copyright (c) 2024 Aiven Ltd
See LICENSE for details
"""

from collections.abc import Awaitable, Callable
from dependency_injector.wiring import inject, Provide
from fastapi import Depends, FastAPI, Request, Response
from karapace.instrumentation.prometheus import PrometheusInstrumentation
from schema_registry.container import SchemaRegistryContainer

import logging
import time

LOG = logging.getLogger(__name__)


@inject
async def prometheus_middleware(
request: Request,
call_next: Callable[[Request], Awaitable[Response]],
prometheus: PrometheusInstrumentation = Depends(Provide[SchemaRegistryContainer.karapace_container.prometheus]),
) -> Response:
# Set start time for request
setattr(request.state, prometheus.START_TIME_REQUEST_KEY, time.monotonic())

# Extract request labels
path = request.url.path
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This can cause quite high cardinality, can we align this with the path template. E.g. /subjects/<subject>/versions?

Copy link
Contributor Author

@nosahama nosahama Dec 17, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes I can think around it, it was similar thought I had on the tracing PR #1009, where I extract the resource from the path as I didn't find a way to get the template, as this was the traces, it looked fine to trace the resource, as further spans contain relevant information and this reduces the trace cardinality.

In prometheus tho, I do not think this should be a problem, major cardinality issues arise with too many labels. To instrument, might be necessary to see exactly the path that's being checked, but I also get your point. Let me reason around it and get back.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looking at this discussion - fastapi/fastapi#12975, the route template is only accessed after a successful response, I do need the path already to instrument the requests in progress.
Unless we want to fallback and extract the base resource, i.e. resource = request.url.path.split("/")[1]. From a template like /subjects/{subject}/versions and a request for /subjects/test-topic-value/versions, this will yield subjects.

method = request.method

# Increment requests in progress before response handler
prometheus.karapace_http_requests_in_progress.labels(method=method, path=path).inc()

# Call request handler
response: Response = await call_next(request)

# Instrument request duration
prometheus.karapace_http_requests_duration_seconds.labels(method=method, path=path).observe(
time.monotonic() - getattr(request.state, prometheus.START_TIME_REQUEST_KEY)
)

# Instrument total requests
prometheus.karapace_http_requests_total.labels(method=method, path=path, status=response.status_code).inc()

# Decrement requests in progress after response handler
prometheus.karapace_http_requests_in_progress.labels(method=method, path=path).dec()

return response


def setup_prometheus_middleware(app: FastAPI) -> None:
LOG.info("Setting up prometheus middleware for metrics")
app.middleware("http")(prometheus_middleware)
4 changes: 4 additions & 0 deletions tests/unit/schema_registry/__init__.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
"""
Copyright (c) 2024 Aiven Ltd
See LICENSE for details
"""
4 changes: 4 additions & 0 deletions tests/unit/schema_registry/middlewares/__init__.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
"""
Copyright (c) 2024 Aiven Ltd
See LICENSE for details
"""
80 changes: 80 additions & 0 deletions tests/unit/schema_registry/middlewares/test_prometheus.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,80 @@
"""
schema_registry - prometheus instrumentation middleware tests

Copyright (c) 2024 Aiven Ltd
See LICENSE for details
"""

from _pytest.logging import LogCaptureFixture
from fastapi import FastAPI, Request, Response
from karapace.instrumentation.prometheus import PrometheusInstrumentation
from schema_registry.middlewares.prometheus import prometheus_middleware, setup_prometheus_middleware
from starlette.datastructures import State
from unittest.mock import AsyncMock, call, MagicMock, patch

import logging


def test_setup_prometheus_middleware(caplog: LogCaptureFixture) -> None:
app = AsyncMock(spec=FastAPI)
with caplog.at_level(logging.INFO, logger="schema_registry.middlewares.prometheus"):
setup_prometheus_middleware(app=app)

for log in caplog.records:
assert log.name == "schema_registry.middlewares.prometheus"
assert log.levelname == "INFO"
assert log.message == "Setting up prometheus middleware for metrics"

app.middleware.assert_called_once_with("http")
app.middleware.return_value.assert_called_once_with(prometheus_middleware)


async def test_prometheus_middleware() -> None:
response_mock = AsyncMock(spec=Response)
response_mock.status_code = 200

call_next = AsyncMock()
call_next.return_value = response_mock

request = AsyncMock(spec=Request)
request.state = MagicMock(spec=State)

prometheus = MagicMock(spec=PrometheusInstrumentation, START_TIME_REQUEST_KEY="start_time")

with patch("schema_registry.middlewares.prometheus.time.monotonic", return_value=1):
response = await prometheus_middleware(request=request, call_next=call_next, prometheus=prometheus)

# Check that the `start_time` for the request is set
assert hasattr(request.state, "start_time")
assert getattr(request.state, "start_time") == 1

# Check that `karapace_http_requests_in_progress` metric is incremented/decremented
prometheus.karapace_http_requests_in_progress.labels.assert_has_calls(
[
call(method=request.method, path=request.url.path),
call().inc(),
call(method=request.method, path=request.url.path),
call().dec(),
]
)

# Check that `karapace_http_requests_duration_seconds` metric is observed
prometheus.karapace_http_requests_duration_seconds.labels.assert_has_calls(
[
call(method=request.method, path=request.url.path),
call().observe(0),
]
)

# Check that the request handler is called
call_next.assert_awaited_once_with(request)

# Check that `karapace_http_requests_total` metric is incremented/decremented
prometheus.karapace_http_requests_total.labels.assert_has_calls(
[
call(method=request.method, path=request.url.path, status=response.status_code),
call().inc(),
]
)

assert response == response_mock
Loading