diff --git a/app/exceptions/base.py b/app/exceptions/base.py index 5b583bf..e67f74b 100644 --- a/app/exceptions/base.py +++ b/app/exceptions/base.py @@ -1,12 +1,11 @@ from http import HTTPStatus +import logfire from fastapi import Request from fastapi.exceptions import RequestValidationError from fastapi.responses import JSONResponse, Response from starlette.exceptions import HTTPException -from app.logger import logger - _PROBLEM_JSON_MEDIA_TYPE = "application/problem+json" @@ -69,10 +68,10 @@ def base_exception_handler(request: Request, exc: Exception) -> Response: media_type=_PROBLEM_JSON_MEDIA_TYPE, ) case _: - logger.exception( - "Unhandled exception while processing %s", - request.url, - exc=exc, + logfire.exception( + "Unhandled exception while processing {url}", + url=str(request.url), + _exc_info=exc, ) return JSONResponse( status_code=500, diff --git a/app/logger/__init__.py b/app/logger/__init__.py index 5bde31a..b806d2e 100644 --- a/app/logger/__init__.py +++ b/app/logger/__init__.py @@ -1,3 +1,3 @@ -from app.logger.logger import debug, error, exception, info, setup_logging, warning +from app.logger.configuration import setup_logging -__all__ = ["debug", "error", "exception", "info", "setup_logging", "warning"] +__all__ = ["setup_logging"] diff --git a/app/logger/configuration.py b/app/logger/configuration.py index f1a6d06..7de92cb 100644 --- a/app/logger/configuration.py +++ b/app/logger/configuration.py @@ -3,7 +3,6 @@ from logging import Handler, Logger from app.logger.handlers import LOG_LEVEL -from app.settings import app_settings from app.telemetry import get_otel_log_handler LogHandlerFactory = Callable[[], Handler] @@ -11,7 +10,6 @@ __all__ = ["LogHandlerFactory", "configure_logger", "setup_logging"] _CONFIGURED_LOGGER_NAMES = ( - app_settings.app_name, "uvicorn", "uvicorn.access", "uvicorn.error", diff --git a/app/logger/formatters.py b/app/logger/formatters.py deleted file mode 100644 index 0a4b2d2..0000000 --- a/app/logger/formatters.py +++ /dev/null @@ -1,117 +0,0 @@ -import json -import logging -import os -import threading -import time -from logging import Formatter -from typing import Any - -from app.settings import app_settings - -__all__ = ["JsonFormatter"] - -_STANDARD_LOG_RECORD_ATTRIBUTES = { - "args", - "asctime", - "created", - "exc_info", - "exc_text", - "filename", - "funcName", - "levelname", - "levelno", - "lineno", - "message", - "module", - "msecs", - "msg", - "name", - "pathname", - "process", - "processName", - "relativeCreated", - "stack_info", - "thread", - "threadName", - "taskName", - "_app_json_log_payload", -} - - -def _json_safe(value: Any) -> Any: - if value is None or isinstance(value, str | int | float | bool): - return value - - if isinstance(value, dict): - return {str(key): _json_safe(item) for key, item in value.items()} - - if isinstance(value, list | tuple | set | frozenset): - return [_json_safe(item) for item in value] - - return str(value) - - -class JsonFormatter(Formatter): - def _severity_number(self, level: int) -> int: - if level >= logging.CRITICAL: - return 21 - if level >= logging.ERROR: - return 17 - if level >= logging.WARNING: - return 13 - if level >= logging.INFO: - return 9 - if level >= logging.DEBUG: - return 5 - return 1 - - def _attributes(self, record: logging.LogRecord) -> dict[str, Any]: - attributes: dict[str, Any] = { - "logger.name": record.name, - "code.filepath": record.pathname, - "code.function": record.funcName, - "code.lineno": record.lineno, - "process.pid": os.getpid(), - "thread.id": threading.get_ident(), - "thread.name": record.threadName, - } - - attributes.update( - { - key: _json_safe(value) - for key, value in record.__dict__.items() - if key not in _STANDARD_LOG_RECORD_ATTRIBUTES - } - ) - - if record.exc_info: - exception = record.exc_info[1] - attributes["exception.type"] = type(exception).__name__ - attributes["exception.message"] = str(exception) - attributes["exception.stacktrace"] = self.formatException(record.exc_info) - - return attributes - - def format(self, record: logging.LogRecord) -> str: - attributes = self._attributes(record) - log_object: dict[str, Any] = { - "time_unix_nano": int(record.created * 1_000_000_000), - "observed_time_unix_nano": time.time_ns(), - "severity_text": record.levelname, - "severity_number": self._severity_number(record.levelno), - "body": record.getMessage(), - "resource": { - "service.name": app_settings.app_name, - }, - "scope": { - "name": record.name, - }, - "attributes": attributes, - "timestamp": self.formatTime(record, self.datefmt), - "name": record.name, - "level": record.levelname, - "message": record.getMessage(), - } - if record.exc_info: - log_object["exception"] = attributes["exception.stacktrace"] - return json.dumps(log_object) diff --git a/app/logger/handlers.py b/app/logger/handlers.py index 293a23e..114dcc0 100644 --- a/app/logger/handlers.py +++ b/app/logger/handlers.py @@ -1,69 +1,20 @@ import logging -import sys -from logging import Formatter, Handler -from typing import TextIO import logfire from app.logger.filters import HealthEndpointFilter -from app.logger.formatters import JsonFormatter LOG_LEVEL = logging.INFO -JSON_LOG_ATTRIBUTE = "app.log.json" -_JSON_PAYLOAD_RECORD_ATTRIBUTE = "_app_json_log_payload" __all__ = [ - "JSON_LOG_ATTRIBUTE", "LOG_LEVEL", - "JsonPayloadLogfireLoggingHandler", - "formatter", "get_logfire_handler", ] -formatter: Formatter = JsonFormatter() - - -def _json_payload(record: logging.LogRecord) -> str: - payload = getattr(record, _JSON_PAYLOAD_RECORD_ATTRIBUTE, None) - if isinstance(payload, str): - return payload - - payload = formatter.format(record) - setattr(record, _JSON_PAYLOAD_RECORD_ATTRIBUTE, payload) - return payload - - -class JsonPayloadLogfireLoggingHandler(logfire.LogfireLoggingHandler): - terminator = "\n" - - def __init__( - self, - level: int | str = LOG_LEVEL, - *, - stream: TextIO | None = None, - ) -> None: - super().__init__(level=level, fallback=logging.NullHandler()) - self.stream = stream or sys.stdout - self.addFilter(HealthEndpointFilter()) - - def fill_attributes(self, record: logging.LogRecord) -> dict[str, object]: - attributes = super().fill_attributes(record) - attributes[JSON_LOG_ATTRIBUTE] = _json_payload(record) - return attributes - - def emit(self, record: logging.LogRecord) -> None: - try: - payload = _json_payload(record) - super().emit(record) - self.stream.write(payload + self.terminator) - self.flush() - except Exception: # noqa: BLE001 - self.handleError(record) - - def flush(self) -> None: - if hasattr(self.stream, "flush"): - self.stream.flush() - - -def get_logfire_handler() -> Handler: - return JsonPayloadLogfireLoggingHandler(level=LOG_LEVEL) +def get_logfire_handler() -> logfire.LogfireLoggingHandler: + handler = logfire.LogfireLoggingHandler( + level=LOG_LEVEL, + fallback=logging.NullHandler(), + ) + handler.addFilter(HealthEndpointFilter()) + return handler diff --git a/app/logger/logger.py b/app/logger/logger.py deleted file mode 100644 index 08ebf7b..0000000 --- a/app/logger/logger.py +++ /dev/null @@ -1,51 +0,0 @@ -import logging -from logging import Logger - -from app.logger.configuration import setup_logging as _setup_logging -from app.logger.formatters import JsonFormatter -from app.logger.handlers import LOG_LEVEL, formatter -from app.settings import app_settings -from app.telemetry import get_otel_log_handler - -__all__ = [ - "JsonFormatter", - "debug", - "error", - "exception", - "formatter", - "info", - "logger", - "setup_logging", - "warning", -] - -logger: Logger = logging.getLogger(app_settings.app_name) -logger.setLevel(LOG_LEVEL) - - -def setup_logging() -> None: - _setup_logging(otel_handler_factory=get_otel_log_handler) - - -def info(msg: str, *args: object) -> None: - logger.info(msg, *args) - - -def error(msg: str, *args: object) -> None: - logger.error(msg, *args) - - -def exception(msg: str, *args: object, exc: BaseException) -> None: - logger.error( - msg, - *args, - exc_info=(type(exc), exc, exc.__traceback__), - ) - - -def warning(msg: str, *args: object) -> None: - logger.warning(msg, *args) - - -def debug(msg: str, *args: object) -> None: - logger.debug(msg, *args) diff --git a/app/main.py b/app/main.py index 58ca744..0f83f3e 100644 --- a/app/main.py +++ b/app/main.py @@ -1,6 +1,7 @@ from collections.abc import AsyncGenerator from contextlib import asynccontextmanager +import logfire import uvicorn from fastapi import FastAPI from fastapi.exceptions import RequestValidationError @@ -26,12 +27,16 @@ async def lifespan(_app: FastAPI) -> AsyncGenerator[None]: ) _app.openapi_schema = None telemetry.instrument_sqlalchemy(get_engine()) - logger.info(f"Starting up {app_settings.app_name} on port {app_settings.port}") + logfire.info( + "Starting up {service_name} on port {port}", + service_name=app_settings.app_name, + port=app_settings.port, + ) try: yield finally: await get_engine().dispose() - logger.info("Application shutdown") + logfire.info("Application shutdown") app = OIDCOpenAPIFastAPI( diff --git a/app/telemetry.py b/app/telemetry.py index 32dc1da..cca96bf 100644 --- a/app/telemetry.py +++ b/app/telemetry.py @@ -23,7 +23,7 @@ def configure_otel() -> None: logfire.configure( service_name=app_settings.app_name, send_to_logfire="if-token-present", - console=False, + console=logfire.ConsoleOptions(colors="never", show_project_link=False), ) _configured = True diff --git a/reports/open-github-issues-audit.html b/reports/open-github-issues-audit.html index 833bb8a..54bfcac 100644 --- a/reports/open-github-issues-audit.html +++ b/reports/open-github-issues-audit.html @@ -5,11 +5,11 @@ Open GitHub Issues Audit — FastAPI Template
-
Live issue audit · main @ 9e5b527 · updated 11 July 2026

GitHub issues: implementation status

Evidence-based review of the 26 issues originally audited in Subhransu-De/FastAPI-Template. Seven completed issues have since been closed, leaving 19 open. “Partially done” means meaningful criteria are present; “Still to work on” means no substantive issue-level implementation was found.

+
Live issue audit · main @ 6f0b6dc · updated 12 July 2026

GitHub issues: implementation status

Evidence-based review of the 26 issues originally audited in Subhransu-De/FastAPI-Template. Seven completed issues have since been closed, leaving 19 open. “Partially done” means meaningful criteria or reusable prerequisites are present; actionable remaining lists exclude documentation-only work.

19issues still open
7closed as done
3partially done
16still to work on

Done

@@ -22,9 +22,9 @@
#27
Reproducible local Keycloak
Done · closed
Committed realm exports are mounted by Compose, exact Swagger callbacks are configured automatically, and an isolated fresh-stack test verified the API, OIDC discovery, imported user, clients, migrations, and one-shot configuration. docs/local-keycloak.md documents identities, clients, reset behavior, internal/public URLs, and local-only quirks; docs/local-development.md explains the rest of the local stack.

Partially done

-
#19
Observability expectations
Partial
app/telemetry.py instruments FastAPI and SQLAlchemy, excludes health traffic, and JSON logging exists.
-
#25
Expand README into production documentation
Partial
README covers local/Docker setup, tests, migrations, OIDC basics, and the real CI badge.
-
#67
Full ECS Fargate Terraform deployment
Partial
A generic API image, migration image, health endpoint, and brief ECS migration note are reusable prerequisites.
+
#19
Observability expectations
Implementation complete on branch
2 of 2 non-documentation criteria complete on issue-19-observability-correlation

Done / available foundation

  • Application lifecycle and exception events use Logfire's direct structured logging API.
  • The stock LogfireLoggingHandler bridges Uvicorn and third-party standard-library logs into the same telemetry pipeline without a project-owned handler subclass or duplicate JSON payload.
  • Logfire automatically correlates logs emitted within active OpenTelemetry traces; focused tests verify shared trace context.
  • app/telemetry.py instruments FastAPI and SQLAlchemy; request spans include route/status data plus filtered client and OIDC attributes.
  • Sensitive request values are dropped, and unit/integration tests exercise telemetry behavior.
  • /health spans and access logs are intentionally excluded and covered by tests, fully satisfying the noise-reduction criterion.

Remaining implementation work

  • None. Both non-documentation acceptance criteria are implemented on the issue branch.
+
#25
Expand README into production documentation
Documentation only
Excluded from the implementation backlog

Current foundation

  • README covers installation, host and Docker Compose startup, tests, migrations, and the application architecture.
  • Production image and migration-image responsibilities are documented, including the ECS/EKS pre-deployment migration flow.
  • The CI/CD badge points to the existing workflow.
  • Local Keycloak, Swagger PKCE, and browser-secret safety are introduced; detailed environment and local identity references exist under docs/.

Remaining implementation work

  • None. The open acceptance criteria for this issue are documentation-only.
+
#67
Full ECS Fargate Terraform deployment
Prerequisites only
0 of 7 non-documentation criteria complete

Done / reusable prerequisites

  • A generic runtime Dockerfile and separate one-shot Dockerfile.migration are ready to publish.
  • The application exposes GET /health for a future load-balancer target.
  • Application configuration already uses environment variables.
  • README briefly explains running the migration image as an ECS one-off task before service rollout.

Remaining implementation work

  • Create infra/ and Terraform for VPC networking and security groups.
  • Provision the ECS cluster, Fargate task definition, and ECS service.
  • Provision the ALB, target group, listener, and working health check; verify the API through the ALB.
  • Wire application configuration and secrets through Secrets Manager or SSM Parameter Store.
  • Configure a CloudWatch log group and ECS task logging.
  • Add least-privilege task execution and application task IAM roles.
  • Output the ALB DNS name, cluster name, service name, and log-group name.

Still to be worked on

#14
Production server and reverse-proxy guidance
Still to work on
Only basic host/port/reload Uvicorn settings exist. Worker/replica strategy, trusted forwarded headers, HTTPS termination, graceful shutdown, and timeout guidance are absent.
@@ -44,5 +44,5 @@
#71
Elastic Beanstalk Docker Terraform
Still to work on
No EB Terraform, source bundle/Dockerrun setup, configurable environment, outputs, or deployment/verification guide exists.
#77
Actuator-style health and build information
Still to work on
Only lowercase {"status":"up"} at /health exists. All four Actuator routes, readiness dependency checks, package metadata, OCI build provenance, policies, tests, and docs remain absent.
- -
\ No newline at end of file + + diff --git a/tests/unit/exceptions/test_exceptions.py b/tests/unit/exceptions/test_exceptions.py index e557309..0382278 100644 --- a/tests/unit/exceptions/test_exceptions.py +++ b/tests/unit/exceptions/test_exceptions.py @@ -121,7 +121,7 @@ def test_base_exception_handler_for_unexpected_error(monkeypatch): def capture_log(*args, **kwargs): logged.append((args, kwargs)) - monkeypatch.setattr("app.exceptions.base.logger.exception", capture_log) + monkeypatch.setattr("app.exceptions.base.logfire.exception", capture_log) response = base_exception_handler(request, error) body = load_json_body(response) @@ -129,8 +129,8 @@ def capture_log(*args, **kwargs): assert response.status_code == 500 assert logged == [ ( - ("Unhandled exception while processing %s", request.url), - {"exc": error}, + ("Unhandled exception while processing {url}",), + {"url": str(request.url), "_exc_info": error}, ) ] assert body == { diff --git a/tests/unit/logger/test_logger.py b/tests/unit/logger/test_logger.py index dc59409..51986e1 100644 --- a/tests/unit/logger/test_logger.py +++ b/tests/unit/logger/test_logger.py @@ -1,200 +1,54 @@ -import json import logging -import sys -from datetime import UTC, datetime -from io import StringIO from unittest.mock import Mock -from uuid import UUID +import logfire import pytest -import app.logger.formatters as formatter_module -import app.logger.logger as logger_module -from app.logger.handlers import ( - JSON_LOG_ATTRIBUTE, - JsonPayloadLogfireLoggingHandler, -) +from app.logger import configuration +from app.logger.handlers import get_logfire_handler pytestmark = pytest.mark.unit -def _raise_value_error() -> None: - message = "boom" - raise ValueError(message) - - -def test_json_formatter_formats_record_without_exception(): - formatter = logger_module.JsonFormatter() - record = logging.LogRecord( - name="test.logger", - level=logging.INFO, - pathname=__file__, - lineno=10, - msg="hello world", - args=(), - exc_info=None, - ) - - payload = json.loads(formatter.format(record)) - - assert payload["name"] == "test.logger" - assert payload["level"] == "INFO" - assert payload["message"] == "hello world" - assert payload["severity_text"] == "INFO" - assert payload["severity_number"] == 9 - assert payload["body"] == "hello world" - assert payload["resource"]["service.name"] == logger_module.app_settings.app_name - assert payload["scope"]["name"] == "test.logger" - assert payload["attributes"]["logger.name"] == "test.logger" - assert payload["attributes"]["code.lineno"] == 10 - assert "timestamp" in payload - assert "time_unix_nano" in payload - assert "observed_time_unix_nano" in payload - assert "exception" not in payload - - -def test_json_formatter_formats_record_with_exception(): - formatter = logger_module.JsonFormatter() - - try: - _raise_value_error() - except ValueError: - exc_info = sys.exc_info() - - record = logging.LogRecord( - name="test.logger", - level=logging.ERROR, - pathname=__file__, - lineno=20, - msg="failure", - args=(), - exc_info=exc_info, - ) - - payload = json.loads(formatter.format(record)) - - assert payload["level"] == "ERROR" - assert payload["message"] == "failure" - assert payload["severity_text"] == "ERROR" - assert payload["severity_number"] == 17 - assert "ValueError: boom" in payload["exception"] - assert payload["attributes"]["exception.type"] == "ValueError" - assert payload["attributes"]["exception.message"] == "boom" - assert "ValueError: boom" in payload["attributes"]["exception.stacktrace"] - - -def test_setup_logging_reconfigures_uvicorn_loggers(monkeypatch: pytest.MonkeyPatch): - logger_names = [ - logger_module.app_settings.app_name, - "uvicorn", - "uvicorn.access", - "uvicorn.error", - ] +def test_setup_logging_reconfigures_uvicorn_loggers( + monkeypatch: pytest.MonkeyPatch, +) -> None: + logger_names = ["uvicorn", "uvicorn.access", "uvicorn.error"] otel_handler = logging.NullHandler() - monkeypatch.setattr(logger_module, "get_otel_log_handler", lambda: otel_handler) root = logging.getLogger() monkeypatch.setattr(root, "handlers", [logging.NullHandler()]) monkeypatch.setattr(root, "level", logging.WARNING) for logger_name in logger_names: - log = logging.getLogger(logger_name) + logger = logging.getLogger(logger_name) monkeypatch.setattr( - log, "handlers", [logging.NullHandler(), logging.NullHandler()] + logger, + "handlers", + [logging.NullHandler(), logging.NullHandler()], ) - monkeypatch.setattr(log, "level", logging.WARNING) - monkeypatch.setattr(log, "propagate", True) + monkeypatch.setattr(logger, "level", logging.WARNING) + monkeypatch.setattr(logger, "propagate", True) - logger_module.setup_logging() + configuration.setup_logging(otel_handler_factory=lambda: otel_handler) assert root.handlers == [otel_handler] assert root.level == logging.INFO assert root.disabled is False for logger_name in logger_names: - log = logging.getLogger(logger_name) - assert log.handlers == [otel_handler] - assert log.level == logging.INFO - assert log.disabled is False - assert log.propagate is False - - -def test_logfire_handler_preserves_json_formatter_payload( - monkeypatch: pytest.MonkeyPatch, -) -> None: - monkeypatch.setattr(formatter_module.time, "time_ns", lambda: 123456789) - record = logging.LogRecord( - name="test.logger", - level=logging.WARNING, - pathname=__file__, - lineno=30, - msg="hello %s", - args=("logfire",), - exc_info=None, - ) - record.component = "unit-test" - - handler = JsonPayloadLogfireLoggingHandler() - - attributes = handler.fill_attributes(record) - - assert attributes[JSON_LOG_ATTRIBUTE] == logger_module.formatter.format(record) + logger = logging.getLogger(logger_name) + assert logger.handlers == [otel_handler] + assert logger.level == logging.INFO + assert logger.disabled is False + assert logger.propagate is False -def test_logfire_handler_writes_otel_json_to_stdout( - monkeypatch: pytest.MonkeyPatch, -) -> None: - monkeypatch.setattr(formatter_module.time, "time_ns", lambda: 123456789) - record = logging.LogRecord( - name="test.logger", - level=logging.INFO, - pathname=__file__, - lineno=40, - msg="stdout %s", - args=("otel",), - exc_info=None, - ) - record.component = "unit-test" - stream = StringIO() - handler = JsonPayloadLogfireLoggingHandler(stream=stream) - logfire_instance = Mock() - handler.logfire_instance = logfire_instance - - handler.emit(record) - - stdout_payload = stream.getvalue().strip() - exported_attributes = logfire_instance.log.call_args.kwargs["attributes"] - parsed = json.loads(stdout_payload) - - assert stdout_payload == exported_attributes[JSON_LOG_ATTRIBUTE] - assert parsed["message"] == "stdout otel" - assert parsed["severity_text"] == "INFO" - assert parsed["severity_number"] == 9 - assert parsed["attributes"]["component"] == "unit-test" - - -def test_json_formatter_stringifies_non_json_extra_attributes() -> None: - formatter = logger_module.JsonFormatter() - record = logging.LogRecord( - name="test.logger", - level=logging.INFO, - pathname=__file__, - lineno=45, - msg="extra payload", - args=(), - exc_info=None, - ) - record.request_id = UUID("00000000-0000-0000-0000-000000000001") - record.started_at = datetime(2026, 6, 21, tzinfo=UTC) - record.context = {"items": {1, 2}} +def test_logfire_handler_uses_stock_handler_with_null_fallback() -> None: + handler = get_logfire_handler() - payload = json.loads(formatter.format(record)) - - assert payload["attributes"]["request_id"] == ( - "00000000-0000-0000-0000-000000000001" - ) - assert payload["attributes"]["started_at"] == "2026-06-21 00:00:00+00:00" - assert sorted(payload["attributes"]["context"]["items"]) == [1, 2] + assert type(handler) is logfire.LogfireLoggingHandler + assert isinstance(handler.fallback, logging.NullHandler) def test_logfire_handler_filters_health_endpoint_access_logs() -> None: @@ -207,45 +61,11 @@ def test_logfire_handler_filters_health_endpoint_access_logs() -> None: args=("127.0.0.1:50000", "GET", "/health", "1.1", 200), exc_info=None, ) - stream = StringIO() - handler = JsonPayloadLogfireLoggingHandler(stream=stream) + handler = get_logfire_handler() logfire_instance = Mock() handler.logfire_instance = logfire_instance handled = handler.handle(record) assert handled is False - assert stream.getvalue() == "" logfire_instance.log.assert_not_called() - - -@pytest.mark.parametrize( - ("wrapper", "method_name"), - [ - ("info", "info"), - ("error", "error"), - ("warning", "warning"), - ("debug", "debug"), - ], -) -def test_log_wrappers_delegate(monkeypatch, wrapper, method_name): - method = Mock() - monkeypatch.setattr(logger_module.logger, method_name, method) - - getattr(logger_module, wrapper)("message %s", "value") - - method.assert_called_once_with("message %s", "value") - - -def test_exception_wrapper_preserves_stack_trace(monkeypatch): - method = Mock() - monkeypatch.setattr(logger_module.logger, "error", method) - error = RuntimeError("boom") - - logger_module.exception("request failed: %s", "/failure", exc=error) - - method.assert_called_once_with( - "request failed: %s", - "/failure", - exc_info=(RuntimeError, error, error.__traceback__), - ) diff --git a/tests/unit/logger/test_otel_logging.py b/tests/unit/logger/test_otel_logging.py index 20c0ddf..810f303 100644 --- a/tests/unit/logger/test_otel_logging.py +++ b/tests/unit/logger/test_otel_logging.py @@ -1,20 +1,17 @@ -import json import logging import logfire import pytest from logfire.testing import TestExporter +from opentelemetry import trace from opentelemetry.sdk.trace.export import SimpleSpanProcessor -import app.logger.logger as logger_module -from app.logger.handlers import JSON_LOG_ATTRIBUTE, JsonPayloadLogfireLoggingHandler +from app.logger import configuration pytestmark = pytest.mark.unit -def test_setup_logging_exports_app_and_uvicorn_logs_to_otel( - monkeypatch: pytest.MonkeyPatch, -) -> None: +def test_setup_logging_exports_stdlib_logs_to_otel() -> None: exporter = TestExporter() logfire.configure( send_to_logfire=False, @@ -22,46 +19,37 @@ def test_setup_logging_exports_app_and_uvicorn_logs_to_otel( service_name="fastapi-template-test", additional_span_processors=[SimpleSpanProcessor(exporter)], ) - def get_test_otel_log_handler() -> logging.Handler: - return JsonPayloadLogfireLoggingHandler() - monkeypatch.setattr( - logger_module, - "get_otel_log_handler", - get_test_otel_log_handler, + configuration.setup_logging( + otel_handler_factory=lambda: logfire.LogfireLoggingHandler( + fallback=logging.NullHandler() + ) ) - logger_module.setup_logging() - - logging.getLogger(logger_module.app_settings.app_name).info( - "app log %s", - "captured", - extra={"component": "unit-test"}, - ) + with trace.get_tracer(__name__).start_as_current_span("correlated request") as span: + span_context = span.get_span_context() + logging.getLogger("third.party").info( + "third-party log captured", + extra={"component": "unit-test"}, + ) logging.getLogger("uvicorn.access").warning("uvicorn access captured") - logging.getLogger("third.party").error("third-party propagated captured") exported = exporter.exported_spans_as_dict(parse_json_attributes=True) - messages = [span["attributes"].get("logfire.msg") for span in exported] - app_log = next( - span - for span in exported - if span["attributes"].get("logfire.msg") == "app log captured" + logs = [ + record + for record in exported + if record["attributes"].get("logfire.span_type") == "log" + ] + messages = [record["attributes"].get("logfire.msg") for record in logs] + third_party_log = next( + record + for record in logs + if record["attributes"].get("logfire.msg") == "third-party log captured" ) - json_payload = app_log["attributes"][JSON_LOG_ATTRIBUTE] - if isinstance(json_payload, str): - json_payload = json.loads(json_payload) - assert "app log captured" in messages + assert "third-party log captured" in messages assert "uvicorn access captured" in messages - assert "third-party propagated captured" in messages - assert all( - span["attributes"].get("logfire.span_type") == "log" for span in exported - ) - assert any( - span["attributes"].get("component") == "unit-test" for span in exported - ) - assert json_payload["message"] == "app log captured" - assert json_payload["severity_text"] == "INFO" - assert json_payload["severity_number"] == 9 - assert json_payload["attributes"]["component"] == "unit-test" + assert third_party_log["attributes"].get("component") == "unit-test" + assert third_party_log["context"]["trace_id"] == span_context.trace_id + assert third_party_log["context"]["span_id"] != span_context.span_id + assert third_party_log["parent"]["span_id"] == span_context.span_id diff --git a/tests/unit/test_main.py b/tests/unit/test_main.py index 53dbfec..7acfe53 100644 --- a/tests/unit/test_main.py +++ b/tests/unit/test_main.py @@ -77,7 +77,7 @@ async def test_lifespan_runs_startup_and_shutdown(monkeypatch): access_token_validator_class = Mock(return_value=access_token_validator) monkeypatch.setattr(module.logger, "setup_logging", setup_logging) - monkeypatch.setattr(module.logger, "info", info) + monkeypatch.setattr(module.logfire, "info", info) monkeypatch.setattr(module, "resolve_oidc_metadata", resolve_oidc_metadata) monkeypatch.setattr( module, @@ -88,7 +88,9 @@ async def test_lifespan_runs_startup_and_shutdown(monkeypatch): async with module.lifespan(module.app): setup_logging.assert_called_once_with() info.assert_called_once_with( - f"Starting up {module.app_settings.app_name} on port {module.app_settings.port}" + "Starting up {service_name} on port {port}", + service_name=module.app_settings.app_name, + port=module.app_settings.port, ) assert module.app.state.oidc_metadata is metadata assert module.app.state.access_token_validator is access_token_validator diff --git a/tests/unit/test_telemetry.py b/tests/unit/test_telemetry.py index 563efbc..ab4f9d8 100644 --- a/tests/unit/test_telemetry.py +++ b/tests/unit/test_telemetry.py @@ -30,7 +30,10 @@ def configure(**kwargs: object) -> None: { "service_name": telemetry.app_settings.app_name, "send_to_logfire": "if-token-present", - "console": False, + "console": telemetry.logfire.ConsoleOptions( + colors="never", + show_project_link=False, + ), } ]