diff --git a/README.md b/README.md index c615664..b713f97 100644 --- a/README.md +++ b/README.md @@ -27,6 +27,7 @@ This template provides out of the box some commonly used functionalities: * Database migrations using [Alembic](https://alembic.sqlalchemy.org/en/latest/) (configured supporting both sync and async SQLAlchemy engines) * Database fixtures support using customized [Alembic](https://alembic.sqlalchemy.org/en/latest/) configuration * Authentication and Identity Provider using [ORY Zero Trust architecture](https://www.ory.sh/docs/kratos/guides/zero-trust-iap-proxy-identity-access-proxy) +* Full observability setup using [OpenTelemetry](https://opentelemetry.io/) (Metrics, Traces and Logs) * Example CI/CD deployment pipeline for GitLab (The focus for this repository is still GitHub but, in case you want to use GitLab 🤷) * [TODO] Producer and consumer to emit and consume events using [CloudEvents](https://cloudevents.io/) format using HTTP, to be used with [Knative Eventing](https://knative.dev/docs/eventing/) diff --git a/config.alloy b/config.alloy new file mode 100644 index 0000000..51ad59e --- /dev/null +++ b/config.alloy @@ -0,0 +1,29 @@ +otelcol.exporter.otlp "jaeger" { + client { + endpoint = "jaeger:4317" + + tls { + insecure = true + } + } +} + +otelcol.exporter.debug "console" { + verbosity = "Detailed" +} + +otelcol.processor.batch "default" { + output { + traces = [otelcol.exporter.otlp.jaeger.input] + } +} + +otelcol.receiver.otlp "default" { + grpc { } + + output { + metrics = [otelcol.exporter.debug.console.input] + logs = [otelcol.exporter.debug.console.input] + traces = [otelcol.processor.batch.default.input] + } +} diff --git a/docker-compose.yaml b/docker-compose.yaml index 1a3d747..e89b4b4 100644 --- a/docker-compose.yaml +++ b/docker-compose.yaml @@ -59,11 +59,19 @@ services: - "14268:14268" # HTTP port for spans otel-collector: - image: otel/opentelemetry-collector-contrib + image: grafana/alloy:latest depends_on: - jaeger + ports: + - "12345:12345" volumes: - - ./otel-collector-config.yaml:/etc/otelcol-contrib/config.yaml + - ./config.alloy:/etc/alloy/config.alloy + command: + - run + - --server.http.listen-addr=0.0.0.0:12345 + - --stability.level=experimental +# - --stability.level=public-preview + - /etc/alloy/config.alloy redis: image: redis diff --git a/local.env b/local.env index 1f196a8..9fccb2e 100644 --- a/local.env +++ b/local.env @@ -2,3 +2,4 @@ ENVIRONMENT: "local" AUTH__JWKS_URL: "http://oathkeeper:4456/.well-known/jwks.json" #DRAMATIQ__REDIS_URL: "redis://redis:6379/0" OTEL_EXPORTER_OTLP_ENDPOINT: "http://otel-collector:4317" +OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED: "true" diff --git a/otel-collector-config.yaml b/otel-collector-config.yaml deleted file mode 100644 index d767dd0..0000000 --- a/otel-collector-config.yaml +++ /dev/null @@ -1,26 +0,0 @@ -receivers: - otlp: - protocols: - grpc: - endpoint: 0.0.0.0:4317 - -exporters: - debug: - verbosity: detailed - otlp/jaeger: - endpoint: jaeger:4317 - tls: - insecure: true - -processors: - batch: - -service: - pipelines: - metrics: - receivers: [otlp] - exporters: [debug] - traces: - receivers: [otlp] - exporters: [otlp/jaeger] - processors: [batch] diff --git a/src/common/logs/__init__.py b/src/common/logs/__init__.py index 1e2ed3a..302ee81 100644 --- a/src/common/logs/__init__.py +++ b/src/common/logs/__init__.py @@ -2,6 +2,7 @@ from typing import List import structlog +from opentelemetry.sdk._logs import LoggingHandler from structlog.typing import Processor from ..config import AppConfig @@ -14,11 +15,22 @@ def init_logger(config: AppConfig) -> None: """ - Configure structlog and stdlib logging with shared handler and formatter. + Function to initialize logging configuration using `structlog` and Python's standard + logging module. It supports dynamic log level adjustment, shared processors for + structlog and standard loggers, and tailored configurations for different environments + (local, test, or production). Ensures consistent formatting across application logs + and integrates handlers for OpenTelemetry logs if present. + + Args: + config (AppConfig): Configuration object containing application-wide settings + such as DEBUG flag and environment status. + + Raises: + None + + Returns: + None - :param config: The app configuration - :type config: AppConfig - :return: """ # Strongly inspired by https://gist.github.com/nymous/f138c7f06062b7c43c060bf03759c29e @@ -76,9 +88,17 @@ def init_logger(config: AppConfig) -> None: ) ) - # Use structlog to format logs coming from stdlib logger + # Get root logger stdlib_logger = logging.getLogger() - stdlib_logger.handlers.clear() + + # In case there's a OTEL handler we keep it but remove all the others, + # in case this function is called multiple times. + # NOTE all the processors are not applied to OTEL logs! + for handler in stdlib_logger.handlers: + if not isinstance(handler, LoggingHandler): + stdlib_logger.removeHandler(handler) + + # Use structlog to format logs coming from stdlib logger stdlib_logger.addHandler(stdlib_handler) stdlib_logger.setLevel(log_level) diff --git a/src/domains/books/_service.py b/src/domains/books/_service.py index c78b688..2c927e4 100644 --- a/src/domains/books/_service.py +++ b/src/domains/books/_service.py @@ -1,8 +1,8 @@ +import logging from collections.abc import Iterable from anyio import to_thread from dependency_injector.wiring import Provide, inject -from structlog import get_logger from common.tracing import trace_function from common.utils import apply_decorator_to_methods @@ -58,8 +58,12 @@ async def book_created_event_handler( book_id: int, ) -> None: # pragma: no cover # This is just an example placeholder, there's nothing to test. - logger = get_logger() - await logger.ainfo(f"Processed book crated event for id `{book_id}`") + logging.info( + "Processed book crated event`", + extra={ + "book_id": book_id, + }, + ) def _some_cpu_intensive_blocking_task(self, book: dict) -> dict: # This is just an example placeholder, diff --git a/src/gateways/event.py b/src/gateways/event.py index c641a5d..0ae1ee9 100644 --- a/src/gateways/event.py +++ b/src/gateways/event.py @@ -1,11 +1,8 @@ +import logging + from cloudevents_pydantic.events import CloudEvent -from structlog import get_logger class NullEventGateway: async def emit(self, event: CloudEvent) -> None: # pragma: no cover # No need to test this - logger = get_logger() - await logger.ainfo( - "Event emitted", - cloudevent=event.model_dump(), - ) + logging.info("Event emitted", extra={"cloudevent": event.model_dump()}) diff --git a/src/http_app/__init__.py b/src/http_app/__init__.py index 74166c5..ec45759 100644 --- a/src/http_app/__init__.py +++ b/src/http_app/__init__.py @@ -1,10 +1,10 @@ +import logging from typing import Union from fastapi import FastAPI, Request from opentelemetry.instrumentation.asgi import OpenTelemetryMiddleware from starlette.responses import JSONResponse from starlette_prometheus import PrometheusMiddleware, metrics -from structlog import get_logger from common import AppConfig, application_init from http_app import context @@ -62,6 +62,5 @@ async def add_exception_middleware(request: Request, call_next): try: return await call_next(request) except Exception as e: - logger = get_logger(__name__) - await logger.aexception(e) + logging.exception(e) return JSONResponse({"error": "Internal server error"}, status_code=500) diff --git a/tests/http_app/test_exception_handlers.py b/tests/http_app/test_exception_handlers.py index 01ef644..fda870b 100644 --- a/tests/http_app/test_exception_handlers.py +++ b/tests/http_app/test_exception_handlers.py @@ -1,12 +1,12 @@ -from unittest.mock import AsyncMock, MagicMock, patch +from unittest.mock import MagicMock, patch from fastapi import FastAPI from fastapi.testclient import TestClient -@patch("http_app.get_logger") +@patch("logging.exception") async def test_exception_is_logged_handler_returns_500( - mocked_get_logger: MagicMock, + mocked_logging_exception: MagicMock, testapp: FastAPI, ): my_exc = Exception("Some random exception") @@ -15,12 +15,9 @@ async def test_exception_is_logged_handler_returns_500( async def fake_endpoint(): raise my_exc - mocked_get_logger.return_value.aexception = AsyncMock(return_value=None) - ac = TestClient(app=testapp, base_url="http://test") response = ac.get("/ppp") assert response.status_code == 500 assert response.json() == {"error": "Internal server error"} - mocked_get_logger.assert_called_once() - mocked_get_logger.return_value.aexception.assert_called_once_with(my_exc) + mocked_logging_exception.assert_called_once_with(my_exc)