diff --git a/lite_bootstrap/bootstraps/base.py b/lite_bootstrap/bootstraps/base.py index e37d446..fe8a37f 100644 --- a/lite_bootstrap/bootstraps/base.py +++ b/lite_bootstrap/bootstraps/base.py @@ -13,10 +13,10 @@ class BaseBootstrap(abc.ABC, typing.Generic[ApplicationT]): def bootstrap(self) -> None: for one_instrument in self.instruments: - if one_instrument.is_ready(): + if one_instrument.is_ready(self.service_config): one_instrument.bootstrap(self.service_config, self.application) def teardown(self) -> None: for one_instrument in self.instruments: - if one_instrument.is_ready(): + if one_instrument.is_ready(self.service_config): one_instrument.teardown(self.application) diff --git a/lite_bootstrap/bootstraps/fastapi_bootstrap/__init__.py b/lite_bootstrap/bootstraps/fastapi_bootstrap/__init__.py index a94e117..6911a1c 100644 --- a/lite_bootstrap/bootstraps/fastapi_bootstrap/__init__.py +++ b/lite_bootstrap/bootstraps/fastapi_bootstrap/__init__.py @@ -5,6 +5,7 @@ from lite_bootstrap.bootstraps.base import BaseBootstrap from lite_bootstrap.bootstraps.fastapi_bootstrap.healthchecks_instrument import FastAPIHealthChecksInstrument +from lite_bootstrap.bootstraps.fastapi_bootstrap.logging_instrument import FastAPILoggingInstrument from lite_bootstrap.bootstraps.fastapi_bootstrap.opentelemetry_instrument import FastAPIOpenTelemetryInstrument from lite_bootstrap.bootstraps.fastapi_bootstrap.sentry_instrument import FastAPISentryInstrument @@ -12,6 +13,7 @@ __all__ = [ "FastAPIBootstrap", "FastAPIHealthChecksInstrument", + "FastAPILoggingInstrument", "FastAPIOpenTelemetryInstrument", "FastAPISentryInstrument", ] @@ -23,6 +25,9 @@ class FastAPIBootstrap(BaseBootstrap[fastapi.FastAPI]): application: fastapi.FastAPI instruments: typing.Sequence[ - FastAPIOpenTelemetryInstrument | FastAPISentryInstrument | FastAPIHealthChecksInstrument + FastAPIOpenTelemetryInstrument + | FastAPISentryInstrument + | FastAPIHealthChecksInstrument + | FastAPILoggingInstrument ] service_config: ServiceConfig diff --git a/lite_bootstrap/bootstraps/fastapi_bootstrap/logging_instrument.py b/lite_bootstrap/bootstraps/fastapi_bootstrap/logging_instrument.py new file mode 100644 index 0000000..e527490 --- /dev/null +++ b/lite_bootstrap/bootstraps/fastapi_bootstrap/logging_instrument.py @@ -0,0 +1,7 @@ +import dataclasses + +from lite_bootstrap.instruments.logging_instrument import LoggingInstrument + + +@dataclasses.dataclass(kw_only=True, frozen=True) +class FastAPILoggingInstrument(LoggingInstrument): ... diff --git a/lite_bootstrap/bootstraps/fastapi_bootstrap/opentelemetry_instrument.py b/lite_bootstrap/bootstraps/fastapi_bootstrap/opentelemetry_instrument.py index 6247879..f22e187 100644 --- a/lite_bootstrap/bootstraps/fastapi_bootstrap/opentelemetry_instrument.py +++ b/lite_bootstrap/bootstraps/fastapi_bootstrap/opentelemetry_instrument.py @@ -2,6 +2,7 @@ import dataclasses import fastapi +from opentelemetry.trace import get_tracer_provider from lite_bootstrap.instruments.opentelemetry_instrument import OpenTelemetryInstrument from lite_bootstrap.service_config import ServiceConfig @@ -11,7 +12,7 @@ from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor -@dataclasses.dataclass(kw_only=True) +@dataclasses.dataclass(kw_only=True, frozen=True) class FastAPIOpenTelemetryInstrument(OpenTelemetryInstrument): excluded_urls: list[str] = dataclasses.field(default_factory=list) @@ -19,7 +20,7 @@ def bootstrap(self, service_config: ServiceConfig, application: fastapi.FastAPI super().bootstrap(service_config, application) FastAPIInstrumentor.instrument_app( app=application, - tracer_provider=self.tracer_provider, + tracer_provider=get_tracer_provider(), excluded_urls=",".join(self.excluded_urls), ) diff --git a/lite_bootstrap/instruments/base.py b/lite_bootstrap/instruments/base.py index 2a08ad1..01462a2 100644 --- a/lite_bootstrap/instruments/base.py +++ b/lite_bootstrap/instruments/base.py @@ -10,4 +10,4 @@ def bootstrap(self, service_config: ServiceConfig, application: ApplicationT | N def teardown(self, application: ApplicationT | None = None) -> None: ... # noqa: B027 @abc.abstractmethod - def is_ready(self) -> bool: ... + def is_ready(self, service_config: ServiceConfig) -> bool: ... diff --git a/lite_bootstrap/instruments/healthchecks_instrument.py b/lite_bootstrap/instruments/healthchecks_instrument.py index 2675325..dee87ce 100644 --- a/lite_bootstrap/instruments/healthchecks_instrument.py +++ b/lite_bootstrap/instruments/healthchecks_instrument.py @@ -18,7 +18,7 @@ class HealthChecksInstrument(BaseInstrument): path: str = "/health/" include_in_schema: bool = False - def is_ready(self) -> bool: + def is_ready(self, _: ServiceConfig) -> bool: return self.enabled @staticmethod diff --git a/lite_bootstrap/instruments/logging_instrument.py b/lite_bootstrap/instruments/logging_instrument.py new file mode 100644 index 0000000..2919e3a --- /dev/null +++ b/lite_bootstrap/instruments/logging_instrument.py @@ -0,0 +1,133 @@ +import contextlib +import dataclasses +import logging +import logging.handlers +import typing + +from lite_bootstrap.instruments.base import BaseInstrument +from lite_bootstrap.service_config import ServiceConfig +from lite_bootstrap.types import ApplicationT + + +if typing.TYPE_CHECKING: + from structlog.typing import EventDict, WrappedLogger + + +with contextlib.suppress(ImportError): + import structlog + + +ScopeType = typing.MutableMapping[str, typing.Any] + + +class AddressProtocol(typing.Protocol): + host: str + port: int + + +class RequestProtocol(typing.Protocol): + client: AddressProtocol + scope: ScopeType + method: str + + +def tracer_injection(_: "WrappedLogger", __: str, event_dict: "EventDict") -> "EventDict": + try: + from opentelemetry import trace + except ImportError: # pragma: no cover + return event_dict + + event_dict["tracing"] = {} + current_span = trace.get_current_span() + if current_span == trace.INVALID_SPAN: + return event_dict + + span_context = current_span.get_span_context() + if span_context == trace.INVALID_SPAN_CONTEXT: # pragma: no cover + return event_dict + + event_dict["tracing"]["trace_id"] = format(span_context.span_id, "016x") + event_dict["tracing"]["span_id"] = format(span_context.trace_id, "032x") + + return event_dict + + +DEFAULT_STRUCTLOG_PROCESSORS: typing.Final[list[typing.Any]] = [ + structlog.stdlib.filter_by_level, + structlog.stdlib.add_log_level, + structlog.stdlib.add_logger_name, + tracer_injection, + structlog.stdlib.PositionalArgumentsFormatter(), + structlog.processors.TimeStamper(fmt="%Y-%m-%d %H:%M:%S"), + structlog.processors.StackInfoRenderer(), + structlog.processors.format_exc_info, + structlog.processors.UnicodeDecoder(), +] +DEFAULT_STRUCTLOG_FORMATTER_PROCESSOR: typing.Final = structlog.processors.JSONRenderer() + + +class MemoryLoggerFactory(structlog.stdlib.LoggerFactory): + def __init__( + self, + *args: typing.Any, # noqa: ANN401 + logging_buffer_capacity: int, + logging_flush_level: int, + logging_log_level: int, + log_stream: typing.Any = None, # noqa: ANN401 + **kwargs: typing.Any, # noqa: ANN401 + ) -> None: + super().__init__(*args, **kwargs) + self.logging_buffer_capacity = logging_buffer_capacity + self.logging_flush_level = logging_flush_level + self.logging_log_level = logging_log_level + self.log_stream = log_stream + + def __call__(self, *args: typing.Any) -> logging.Logger: # noqa: ANN401 + logger: typing.Final = super().__call__(*args) + stream_handler: typing.Final = logging.StreamHandler(stream=self.log_stream) + handler: typing.Final = logging.handlers.MemoryHandler( + capacity=self.logging_buffer_capacity, + flushLevel=self.logging_flush_level, + target=stream_handler, + ) + logger.addHandler(handler) + logger.setLevel(self.logging_log_level) + logger.propagate = False + return logger + + +@dataclasses.dataclass(kw_only=True, slots=True, frozen=True) +class LoggingInstrument(BaseInstrument): + logging_log_level: int = logging.INFO + logging_flush_level: int = logging.ERROR + logging_buffer_capacity: int = 10 + logging_extra_processors: list[typing.Any] = dataclasses.field(default_factory=list) + logging_unset_handlers: list[str] = dataclasses.field( + default_factory=list, + ) + + def is_ready(self, service_config: ServiceConfig) -> bool: + return not service_config.service_debug + + def bootstrap(self, _: ServiceConfig, __: ApplicationT | None = None) -> None: + for unset_handlers_logger in self.logging_unset_handlers: + logging.getLogger(unset_handlers_logger).handlers = [] + + structlog.configure( + processors=[ + *DEFAULT_STRUCTLOG_PROCESSORS, + *self.logging_extra_processors, + DEFAULT_STRUCTLOG_FORMATTER_PROCESSOR, + ], + context_class=dict, + logger_factory=MemoryLoggerFactory( + logging_buffer_capacity=self.logging_buffer_capacity, + logging_flush_level=self.logging_flush_level, + logging_log_level=self.logging_log_level, + ), + wrapper_class=structlog.stdlib.BoundLogger, + cache_logger_on_first_use=True, + ) + + def teardown(self, _: ApplicationT | None = None) -> None: + structlog.reset_defaults() diff --git a/lite_bootstrap/instruments/opentelemetry_instrument.py b/lite_bootstrap/instruments/opentelemetry_instrument.py index 2002334..36b781b 100644 --- a/lite_bootstrap/instruments/opentelemetry_instrument.py +++ b/lite_bootstrap/instruments/opentelemetry_instrument.py @@ -2,6 +2,8 @@ import dataclasses import typing +from opentelemetry.trace import set_tracer_provider + from lite_bootstrap.instruments.base import BaseInstrument from lite_bootstrap.service_config import ServiceConfig from lite_bootstrap.types import ApplicationT @@ -21,7 +23,7 @@ class InstrumentorWithParams: additional_params: dict[str, typing.Any] = dataclasses.field(default_factory=dict) -@dataclasses.dataclass(kw_only=True, slots=True) +@dataclasses.dataclass(kw_only=True, slots=True, frozen=True) class OpenTelemetryInstrument(BaseInstrument): container_name: str | None = None endpoint: str | None = None @@ -30,9 +32,7 @@ class OpenTelemetryInstrument(BaseInstrument): instrumentors: list[InstrumentorWithParams | BaseInstrumentor] = dataclasses.field(default_factory=list) span_exporter: SpanExporter | None = None - tracer_provider: TracerProvider = dataclasses.field(init=False) - - def is_ready(self) -> bool: + def is_ready(self, _: ServiceConfig) -> bool: return bool(self.endpoint) def bootstrap(self, service_config: ServiceConfig, _: ApplicationT | None = None) -> None: @@ -46,8 +46,8 @@ def bootstrap(self, service_config: ServiceConfig, _: ApplicationT | None = None resource: typing.Final = resources.Resource.create( attributes={k: v for k, v in attributes.items() if v}, ) - self.tracer_provider = TracerProvider(resource=resource) - self.tracer_provider.add_span_processor( + tracer_provider = TracerProvider(resource=resource) + tracer_provider.add_span_processor( BatchSpanProcessor( self.span_exporter or OTLPSpanExporter( @@ -59,11 +59,12 @@ def bootstrap(self, service_config: ServiceConfig, _: ApplicationT | None = None for one_instrumentor in self.instrumentors: if isinstance(one_instrumentor, InstrumentorWithParams): one_instrumentor.instrumentor.instrument( - tracer_provider=self.tracer_provider, + tracer_provider=tracer_provider, **one_instrumentor.additional_params, ) else: - one_instrumentor.instrument(tracer_provider=self.tracer_provider) + one_instrumentor.instrument(tracer_provider=tracer_provider) + set_tracer_provider(tracer_provider) def teardown(self, _: ApplicationT | None = None) -> None: for one_instrumentor in self.instrumentors: diff --git a/lite_bootstrap/instruments/sentry_instrument.py b/lite_bootstrap/instruments/sentry_instrument.py index 8bdd020..4660b18 100644 --- a/lite_bootstrap/instruments/sentry_instrument.py +++ b/lite_bootstrap/instruments/sentry_instrument.py @@ -24,7 +24,7 @@ class SentryInstrument(BaseInstrument): additional_params: dict[str, typing.Any] = dataclasses.field(default_factory=dict) tags: dict[str, str] | None = None - def is_ready(self) -> bool: + def is_ready(self, _: ServiceConfig) -> bool: return bool(self.dsn) def bootstrap(self, service_config: ServiceConfig, _: ApplicationT | None = None) -> None: diff --git a/lite_bootstrap/service_config.py b/lite_bootstrap/service_config.py index 028037d..fe82f9c 100644 --- a/lite_bootstrap/service_config.py +++ b/lite_bootstrap/service_config.py @@ -6,3 +6,4 @@ class ServiceConfig: service_name: str = "micro-service" service_version: str = "1.0.0" service_environment: str | None = None + service_debug: bool = True diff --git a/pyproject.toml b/pyproject.toml index 1d9f64c..460cec1 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -43,12 +43,18 @@ otl = [ "opentelemetry-exporter-otlp", "opentelemetry-instrumentation", ] +logging = [ + "structlog", +] fastapi = [ "fastapi", ] fastapi-otl = [ "opentelemetry-instrumentation-fastapi", ] +fastapi-all = [ + "lite-bootstrap[sentry,otl,logging,fastapi,fastapi-otl]" +] [dependency-groups] dev = [ diff --git a/tests/conftest.py b/tests/conftest.py index 1f2a3de..2174238 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -1,4 +1,5 @@ import typing +from unittest.mock import Mock import pytest from fastapi import FastAPI @@ -26,4 +27,10 @@ def service_config() -> ServiceConfig: service_name="microservice", service_version="2.0.0", service_environment="test", + service_debug=False, ) + + +@pytest.fixture(autouse=True) +def mock_sentry_init(monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.setattr("sentry_sdk.init", Mock) diff --git a/tests/instruments/test_logging_instrument.py b/tests/instruments/test_logging_instrument.py new file mode 100644 index 0000000..28d291c --- /dev/null +++ b/tests/instruments/test_logging_instrument.py @@ -0,0 +1,83 @@ +import logging +from io import StringIO + +import structlog +from opentelemetry.sdk.trace.export import ConsoleSpanExporter +from opentelemetry.trace import get_tracer + +from lite_bootstrap.instruments.logging_instrument import LoggingInstrument, MemoryLoggerFactory +from lite_bootstrap.instruments.opentelemetry_instrument import OpenTelemetryInstrument +from lite_bootstrap.service_config import ServiceConfig + + +logger = structlog.getLogger(__name__) + + +def test_logging_instrument(service_config: ServiceConfig) -> None: + logging_instrument = LoggingInstrument(logging_unset_handlers=["uvicorn"], logging_buffer_capacity=0) + try: + logging_instrument.bootstrap(service_config) + logger.info("testing logging", key="value") + finally: + logging_instrument.teardown() + + +def test_logging_instrument_tracer_injection(service_config: ServiceConfig) -> None: + logging_instrument = LoggingInstrument(logging_unset_handlers=["uvicorn"], logging_buffer_capacity=0) + opentelemetry_instrument = OpenTelemetryInstrument( + endpoint="otl", + span_exporter=ConsoleSpanExporter(), + ) + try: + logging_instrument.bootstrap(service_config) + opentelemetry_instrument.bootstrap(service_config) + tracer = get_tracer(__name__) + logger.info("testing tracer injection without spans") + with tracer.start_as_current_span("my_fake_span") as span: + logger.info("testing tracer injection without span attributes") + span.set_attribute("example_attribute", "value") + span.add_event("example_event", {"event_attr": 1}) + logger.info("testing tracer injection with span attributes") + finally: + logging_instrument.teardown() + opentelemetry_instrument.teardown() + + +def test_memory_logger_factory_info() -> None: + test_capacity = 10 + test_flush_level = logging.ERROR + test_stream = StringIO() + + logger_factory = MemoryLoggerFactory( + logging_buffer_capacity=test_capacity, + logging_flush_level=test_flush_level, + logging_log_level=logging.INFO, + log_stream=test_stream, + ) + test_logger = logger_factory() + test_message = "test message" + + for current_log_index in range(test_capacity): + test_logger.info(test_message) + log_contents = test_stream.getvalue() + if current_log_index == test_capacity - 1: + assert test_message in log_contents + else: + assert not log_contents + + +def test_memory_logger_factory_error() -> None: + test_capacity = 10 + test_flush_level = logging.ERROR + test_stream = StringIO() + + logger_factory = MemoryLoggerFactory( + logging_buffer_capacity=test_capacity, + logging_flush_level=test_flush_level, + logging_log_level=logging.INFO, + log_stream=test_stream, + ) + test_logger = logger_factory() + error_message = "error message" + test_logger.error(error_message) + assert error_message in test_stream.getvalue() diff --git a/tests/instruments/test_opentelemetry_instrument.py b/tests/instruments/test_opentelemetry_instrument.py index 3464a23..740dcf4 100644 --- a/tests/instruments/test_opentelemetry_instrument.py +++ b/tests/instruments/test_opentelemetry_instrument.py @@ -6,7 +6,7 @@ def test_opentelemetry_instrument(service_config: ServiceConfig) -> None: - opentelemetry = OpenTelemetryInstrument( + opentelemetry_instrument = OpenTelemetryInstrument( endpoint="otl", instrumentors=[ InstrumentorWithParams(instrumentor=CustomInstrumentor(), additional_params={"key": "value"}), @@ -15,17 +15,17 @@ def test_opentelemetry_instrument(service_config: ServiceConfig) -> None: span_exporter=ConsoleSpanExporter(), ) try: - opentelemetry.bootstrap(service_config) + opentelemetry_instrument.bootstrap(service_config) finally: - opentelemetry.teardown() + opentelemetry_instrument.teardown() def test_opentelemetry_instrument_empty_instruments(service_config: ServiceConfig) -> None: - opentelemetry = OpenTelemetryInstrument( + opentelemetry_instrument = OpenTelemetryInstrument( endpoint="otl", span_exporter=ConsoleSpanExporter(), ) try: - opentelemetry.bootstrap(service_config) + opentelemetry_instrument.bootstrap(service_config) finally: - opentelemetry.teardown() + opentelemetry_instrument.teardown() diff --git a/tests/test_fastapi_bootstrap.py b/tests/test_fastapi_bootstrap.py index 8194e40..c45a5fb 100644 --- a/tests/test_fastapi_bootstrap.py +++ b/tests/test_fastapi_bootstrap.py @@ -1,3 +1,4 @@ +import structlog from fastapi import FastAPI from opentelemetry.sdk.trace.export import ConsoleSpanExporter from starlette import status @@ -6,6 +7,7 @@ from lite_bootstrap.bootstraps.fastapi_bootstrap import ( FastAPIBootstrap, FastAPIHealthChecksInstrument, + FastAPILoggingInstrument, FastAPIOpenTelemetryInstrument, FastAPISentryInstrument, ) @@ -13,6 +15,9 @@ from tests.conftest import CustomInstrumentor +logger = structlog.getLogger(__name__) + + def test_fastapi_bootstrap(fastapi_app: FastAPI, service_config: ServiceConfig) -> None: fastapi_bootstrap = FastAPIBootstrap( application=fastapi_app, @@ -29,9 +34,11 @@ def test_fastapi_bootstrap(fastapi_app: FastAPI, service_config: ServiceConfig) FastAPIHealthChecksInstrument( path="/health/", ), + FastAPILoggingInstrument(logging_buffer_capacity=0), ], ) fastapi_bootstrap.bootstrap() + logger.info("testing logging", key="value") try: response = TestClient(fastapi_app).get("/health/")