feat(telemetry): add OTel standard logs as third signal (#239)

Co-authored-by: Lucas Soares <lucas.soares@sap.com>

Author: jeanscherf

pyproject.toml

@@ -1,6 +1,6 @@
 [project]
 name = "sap-cloud-sdk"
-version = "0.43.2"
+version = "0.44.0"
 description = "SAP Cloud SDK for Python"
 readme = "README.md"
 license = "Apache-2.0"

src/sap_cloud_sdk/core/telemetry/_provider.py

@@ -1,16 +1,26 @@
-"""Internal module for setting up OpenTelemetry meter provider."""
+"""Internal module for setting up OpenTelemetry meter and logger providers."""
 
 import logging
 import os
-from typing import Optional
+from typing import Optional, cast
 
 from opentelemetry import metrics
+from opentelemetry._logs import get_logger_provider, set_logger_provider
+from opentelemetry.exporter.otlp.proto.grpc._log_exporter import (
+    OTLPLogExporter as GRPCLogExporter,
+)
 from opentelemetry.exporter.otlp.proto.grpc.metric_exporter import (
     OTLPMetricExporter as GRPCMetricExporter,
 )
+from opentelemetry.exporter.otlp.proto.http._log_exporter import (
+    OTLPLogExporter as HTTPLogExporter,
+)
 from opentelemetry.exporter.otlp.proto.http.metric_exporter import (
     OTLPMetricExporter as HTTPMetricExporter,
 )
+from opentelemetry.instrumentation.logging.handler import LoggingHandler
+from opentelemetry.sdk._logs import LoggerProvider
+from opentelemetry.sdk._logs.export import BatchLogRecordProcessor
 from opentelemetry.sdk.metrics import (
     MeterProvider,
     Counter,
@@ -36,10 +46,38 @@
 
 logger = logging.getLogger(__name__)
 
+
+def _merge_sdk_resource_into_log_provider(
+    provider: LoggerProvider, sdk_resource: Resource
+) -> None:
+    """OTel SDK has no public API to swap a LoggerProvider's Resource after construction."""
+    provider._resource = provider.resource.merge(sdk_resource)
+    with provider._active_loggers_lock:
+        for logger_instance in provider._active_loggers:
+            logger_instance._resource = provider._resource
+    logger.info(
+        "Merged sap-cloud-sdk resource attrs onto wrapper-installed LoggerProvider"
+    )
+
+
+def _root_logger_has_otel_handler() -> bool:
+    # sitecustomize.py installs sdk._logs.LoggingHandler, not the instrumentation-layer one — check both.
+    try:
+        from opentelemetry.sdk._logs import LoggingHandler as _SDKLoggingHandler
+
+        handler_types: tuple[type, ...] = (LoggingHandler, _SDKLoggingHandler)
+    except ImportError:
+        handler_types = (LoggingHandler,)
+    return any(isinstance(h, handler_types) for h in logging.getLogger().handlers)
+
+
 # Global meter provider
 _meter_provider: Optional[MeterProvider] = None
 _meter: Optional[metrics.Meter] = None
 
+# Global logger provider
+_log_provider: Optional[LoggerProvider] = None
+
 
 def get_meter() -> metrics.Meter:
     """Get or create the global meter instance.
@@ -76,6 +114,70 @@ def shutdown() -> None:
         _meter_provider = None
 
 
+def setup_log_provider() -> Optional[LoggerProvider]:
+    """Set up the global OTel LoggerProvider using the shared resource attributes.
+
+    Installs a LoggingHandler on the root stdlib logger so all existing
+    logging.getLogger(...) calls in the app flow through OTel automatically.
+    No-op when telemetry is disabled.
+    """
+    global _log_provider
+
+    if _log_provider is not None:
+        return _log_provider
+
+    config = get_config()
+    if not config.enabled:
+        return None
+
+    try:
+        resource = Resource.create(create_resource_attributes_from_env())
+        existing = cast(LoggerProvider, get_logger_provider())
+
+        if isinstance(existing, LoggerProvider):
+            # Never add a second BatchLogRecordProcessor — the platform's provider
+            # already has one, and a second processor doubles every exported log record.
+            logger.warning(
+                "Global LoggerProvider was already set by another library. "
+                "Merging sap.cloud_sdk.* resource attributes into the existing provider."
+            )
+            _merge_sdk_resource_into_log_provider(existing, resource)
+            if not _root_logger_has_otel_handler():
+                logging.getLogger().addHandler(LoggingHandler(logger_provider=existing))
+            _log_provider = existing
+        else:
+            provider = LoggerProvider(resource=resource)
+            provider.add_log_record_processor(
+                BatchLogRecordProcessor(_create_log_exporter())
+            )
+            set_logger_provider(provider)
+            logging.getLogger().addHandler(LoggingHandler(logger_provider=provider))
+            _log_provider = provider
+
+        logger.info(
+            f"OpenTelemetry log provider initialized. "
+            f"Service: {config.service_name}, "
+            f"Endpoint: {config.otlp_endpoint}"
+        )
+        return _log_provider
+
+    except Exception as e:
+        logger.error(f"Failed to initialize OpenTelemetry log provider: {e}")
+        return None
+
+
+def _create_log_exporter():
+    protocol = os.getenv(ENV_OTLP_PROTOCOL, "grpc").lower()
+    exporter_classes = {"grpc": GRPCLogExporter, "http/protobuf": HTTPLogExporter}
+
+    if protocol not in exporter_classes:
+        raise ValueError(
+            f"Unsupported OTEL_EXPORTER_OTLP_PROTOCOL: '{protocol}'. "
+            "Supported values are 'grpc' and 'http/protobuf'."
+        )
+    return exporter_classes[protocol]()
+
+
 def _create_metric_exporter():
     protocol = os.getenv(ENV_OTLP_PROTOCOL, "grpc").lower()
     exporter_classes = {"grpc": GRPCMetricExporter, "http/protobuf": HTTPMetricExporter}

src/sap_cloud_sdk/core/telemetry/auto_instrument.py

@@ -20,6 +20,7 @@
 from opentelemetry.sdk.trace.export import ConsoleSpanExporter, SpanExporter
 from traceloop.sdk import Traceloop
 
+from sap_cloud_sdk.core.telemetry._provider import setup_log_provider
 from sap_cloud_sdk.core.telemetry.module import Module
 from sap_cloud_sdk.core.telemetry.operation import Operation
 from sap_cloud_sdk.core.telemetry.config import (
@@ -97,6 +98,8 @@ def auto_instrument(
     _set_propagated_attributes_processor()
     _set_runtime_context_processor()
 
+    setup_log_provider()
+
     if middlewares:
         _register_middleware_processors(middlewares)
 

src/sap_cloud_sdk/core/telemetry/instrumentation/instrumentors/logging.py

@@ -1,11 +1,29 @@
+import logging as stdlib_logging
+
 from opentelemetry.instrumentation.logging import LoggingInstrumentor
+from opentelemetry.instrumentation.logging.handler import (
+    LoggingHandler as _InstrumentationHandler,
+)
 
 from sap_cloud_sdk.core.telemetry.instrumentation.base import LibraryInstrumentor
 from sap_cloud_sdk.core.telemetry.instrumentation._registry import register
 
 _instrumentor = LoggingInstrumentor()
 
 
+def _has_otel_handler_on_root() -> bool:
+    # sitecustomize.py installs sdk._logs.LoggingHandler, not the instrumentation-layer one — check both.
+    try:
+        from opentelemetry.sdk._logs import LoggingHandler as _SDKHandler
+
+        handler_types: tuple[type, ...] = (_InstrumentationHandler, _SDKHandler)
+    except ImportError:
+        handler_types = (_InstrumentationHandler,)
+    return any(
+        isinstance(h, handler_types) for h in stdlib_logging.getLogger().handlers
+    )
+
+
 class LoggingInstrumentorWrapper(LibraryInstrumentor):
     """Injects trace_id and span_id into every stdlib log record for log-trace correlation."""
 
@@ -15,7 +33,11 @@ def is_instrumented(self) -> bool:
         return _instrumentor.is_instrumented_by_opentelemetry
 
     def _instrument(self, **kwargs) -> None:
-        _instrumentor.instrument(set_logging_format=True)
+        kwargs.setdefault("set_logging_format", True)
+        if _has_otel_handler_on_root():
+            # Already have a handler — adding another duplicates every log record.
+            kwargs = {**kwargs, "enable_log_auto_instrumentation": False}
+        _instrumentor.instrument(**kwargs)
 
     def _uninstrument(self) -> None:
         _instrumentor.uninstrument()

src/sap_cloud_sdk/core/telemetry/user-guide.md

@@ -176,6 +176,54 @@ GenAIOperation.INVOKE_AGENT
 
 ---
 
+## Logging
+
+`auto_instrument()` sets up OTel logs alongside traces and metrics. It installs a handler on the root stdlib logger so all existing `logging.getLogger(...)` calls in your app automatically ship log records to the OTel backend with the same resource attributes (service name, region, subaccount, etc.).
+
+No changes to your logging code are needed:
+
+```python
+import logging
+
+logger = logging.getLogger(__name__)
+
+logger.info("Destination fetched")
+logger.warning("Retrying request, attempt %d", attempt)
+logger.error("Failed to connect", exc_info=True)
+```
+
+### Structured fields
+
+Use `extra={}` to attach structured attributes to a log record:
+
+```python
+logger.info("Request completed", extra={"tenant_id": tid, "duration_ms": 120})
+```
+
+### Log level filtering
+
+By default all levels (`DEBUG` and above) flow through OTel. To restrict what gets exported, set the level on the root logger or any specific logger:
+
+```python
+# Only WARNING and above to OTel
+logging.getLogger().setLevel(logging.WARNING)
+
+# Or scope it to your app's logger tree
+logging.getLogger("my_app").setLevel(logging.INFO)
+```
+
+### Correlation with traces
+
+OTel logs emitted inside an active span are automatically correlated — the `trace_id` and `span_id` are injected into the log record. No extra work needed.
+
+### Third-party logging libraries
+
+The OTel handler is installed on the root stdlib `logging` logger. Any library that propagates to stdlib works automatically.
+
+Libraries that bypass stdlib entirely need a custom sink that forwards records to `logging.getLogger(...).log(...)`. The OTel handler then picks them up from there.
+
+---
+
 ## Adding attributes
 
 ### To the current span
@@ -232,6 +280,7 @@ Propagation is scoped: once the parent span exits, its attributes stop propagati
 ## Complete example
 
 ```python
+import logging
 from sap_cloud_sdk.core.telemetry import (
     auto_instrument,
     invoke_agent_span,
@@ -244,17 +293,21 @@ auto_instrument()
 
 from litellm import completion
 
+logger = logging.getLogger(__name__)
 
 async def handle_request(query: str, user_id: str):
     set_tenant_id("bh7sjh...")
 
+    logger.info("Handling request", extra={"user_id": user_id})
+
     # Parent span carries business context for the whole agent turn.
     # Autoinstrumentation creates the child LLM span automatically.
     with invoke_agent_span(
         provider="openai", agent_name="SupportBot", attributes={"user.id": user_id}
     ):
         documents = await retrieve_knowledge_base(query)
         add_span_attribute("documents.retrieved", len(documents))
+        logger.debug("Retrieved %d documents", len(documents))
 
         response = completion(
             model="gpt-4",
@@ -345,7 +398,7 @@ export OTEL_EXPORTER_OTLP_ENDPOINT="https://otel-collector.example.com"
 
 ### Transport protocol
 
-Both traces and metrics use gRPC by default. Switch to HTTP/protobuf by setting:
+Traces, metrics, and logs all use gRPC by default. Switch to HTTP/protobuf by setting:
 
 ```bash
 export OTEL_EXPORTER_OTLP_PROTOCOL="http/protobuf"

tests/core/unit/telemetry/test_auto_instrument.py

@@ -25,6 +25,7 @@ def mock_traceloop_components():
             'get_tracer_provider': stack.enter_context(patch('sap_cloud_sdk.core.telemetry.auto_instrument.trace.get_tracer_provider', return_value=create_autospec(SDKTracerProvider))),
             'create_resource': stack.enter_context(patch('sap_cloud_sdk.core.telemetry.auto_instrument.create_resource_attributes_from_env')),
             'get_app_name': stack.enter_context(patch('sap_cloud_sdk.core.telemetry.auto_instrument._get_app_name')),
+            'setup_log_provider': stack.enter_context(patch('sap_cloud_sdk.core.telemetry.auto_instrument.setup_log_provider')),
         }
         yield mocks
 
@@ -405,3 +406,29 @@ def test_baggage_and_middleware_processors_both_added(self, mock_traceloop_compo
 
         # add_span_processor called 4 times: baggage, propagated attributes, runtime context, middleware
         assert mock_traceloop_components['get_tracer_provider'].return_value.add_span_processor.call_count == 4
+
+
+class TestAutoInstrumentLogging:
+    def test_setup_log_provider_called_on_instrument(self, mock_traceloop_components):
+        mock_traceloop_components['get_app_name'].return_value = 'test-app'
+        mock_traceloop_components['create_resource'].return_value = {}
+
+        with patch.dict('os.environ', {'OTEL_EXPORTER_OTLP_ENDPOINT': 'http://localhost:4317'}, clear=True):
+            auto_instrument()
+
+            mock_traceloop_components['setup_log_provider'].assert_called_once()
+
+    def test_setup_log_provider_not_called_when_no_endpoint(self):
+        with patch.dict('os.environ', {}, clear=True):
+            with patch('sap_cloud_sdk.core.telemetry.auto_instrument.setup_log_provider') as mock_log:
+                auto_instrument()
+                mock_log.assert_not_called()
+
+    def test_setup_log_provider_called_with_console_exporter(self, mock_traceloop_components):
+        mock_traceloop_components['get_app_name'].return_value = 'test-app'
+        mock_traceloop_components['create_resource'].return_value = {}
+
+        with patch.dict('os.environ', {'OTEL_TRACES_EXPORTER': 'console'}, clear=True):
+            auto_instrument()
+
+            mock_traceloop_components['setup_log_provider'].assert_called_once()