From d9275751222ffca1cafc156edb79dd51bc1bde3e Mon Sep 17 00:00:00 2001 From: Lukas Hering Date: Mon, 25 May 2026 19:16:49 -0400 Subject: [PATCH 1/4] update logging instrumentation to always inject trace context --- .../instrumentation/logging/__init__.py | 73 ++++++++----------- .../tests/test_logging.py | 30 +++++--- 2 files changed, 49 insertions(+), 54 deletions(-) diff --git a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py index 528ed39f3c..05a524ab51 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py +++ b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py @@ -8,9 +8,9 @@ system with an handler to convert log messages into OpenTelemetry logs. You can disable this setting `OTEL_PYTHON_LOG_AUTO_INSTRUMENTATION` to `false`. -The OpenTelemetry `logging` integration can inject tracing context into -log statements, though it is opt-in and must be enabled explicitly by setting the -environment variable `OTEL_PYTHON_LOG_CORRELATION` to `true`. +The OpenTelemetry `logging` integration always injects tracing context attributes +(``otelSpanID``, ``otelTraceID``, ``otelTraceSampled``, ``otelServiceName``) into +every log record, making them available for custom formatters and filters. .. code-block:: python @@ -22,19 +22,9 @@ logging.warning('OTel test') -When running the above example you will see the following output: - -:: - - 2025-03-05 09:40:04,398 WARNING [root] [example.py:7] [trace_id=0 span_id=0 resource.service.name= trace_sampled=False] - OTel test - -The environment variable `OTEL_PYTHON_LOG_CORRELATION` must be set to `true` -in order to enable trace context injection into logs by calling -`logging.basicConfig()` and setting a logging format that makes use of the -injected tracing variables. - -Alternatively, `set_logging_format` argument can be set to `True` when -initializing the `LoggingInstrumentor` class to achieve the same effect: +Setting the environment variable `OTEL_PYTHON_LOG_CORRELATION` to `true` (or +passing ``set_logging_format=True``) additionally calls ``logging.basicConfig()`` +with a format string that includes the injected tracing attributes: .. code-block:: python @@ -46,6 +36,12 @@ logging.warning('OTel test') +When running the above example you will see the following output: + +:: + + 2025-03-05 09:40:04,398 WARNING [root] [example.py:7] [trace_id=0 span_id=0 resource.service.name= trace_sampled=False] - OTel test + """ import logging # pylint: disable=import-self @@ -171,38 +167,29 @@ def _instrument(self, **kwargs): def record_factory(*args, **kwargs): record = old_factory(*args, **kwargs) - # this factory is a no-op if log correlation or log hook are not set - if not set_logging_format and not callable( - LoggingInstrumentor._log_hook - ): - return record - - # out of spec attributes are added to the log record only if log correlation is set - if set_logging_format: - record.otelSpanID = "0" - record.otelTraceID = "0" - record.otelTraceSampled = False - - nonlocal service_name - if service_name is None: - resource = getattr(provider, "resource", None) - if resource: - service_name = ( - resource.attributes.get("service.name") or "" - ) - else: - service_name = "" - - record.otelServiceName = service_name + record.otelSpanID = "0" + record.otelTraceID = "0" + record.otelTraceSampled = False + + nonlocal service_name + if service_name is None: + resource = getattr(provider, "resource", None) + if resource: + service_name = ( + resource.attributes.get("service.name") or "" + ) + else: + service_name = "" + + record.otelServiceName = service_name span = get_current_span() if span != INVALID_SPAN: ctx = span.get_span_context() if ctx != INVALID_SPAN_CONTEXT: - if set_logging_format: - record.otelSpanID = format(ctx.span_id, "016x") - record.otelTraceID = format(ctx.trace_id, "032x") - record.otelTraceSampled = ctx.trace_flags.sampled + record.otelSpanID = format(ctx.span_id, "016x") + record.otelTraceID = format(ctx.trace_id, "032x") + record.otelTraceSampled = ctx.trace_flags.sampled if callable(LoggingInstrumentor._log_hook): try: diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py index 6ad3bbe626..79b651f5b5 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py @@ -113,17 +113,21 @@ def test_trace_context_injection_with_log_correlation_instrument_arg(self): span_id, trace_id, trace_sampled ) - def test_no_trace_context_injection_by_default(self): - with self.tracer.start_as_current_span("s1"): + def test_trace_context_injection_by_default(self): + with self.tracer.start_as_current_span("s1") as span: + span_ctx = span.get_span_context() + span_id = format(span_ctx.span_id, "016x") + trace_id = format(span_ctx.trace_id, "032x") + trace_sampled = span_ctx.trace_flags.sampled with self.caplog.at_level(level=logging.INFO): logger = logging.getLogger("test logger") logger.info("hello") self.assertEqual(len(self.caplog.records), 1) record = self.caplog.records[0] - self.assertFalse(hasattr(record, "otelServiceName")) - self.assertFalse(hasattr(record, "otelSpanID")) - self.assertFalse(hasattr(record, "otelTraceID")) - self.assertFalse(hasattr(record, "otelTraceSampled")) + self.assertEqual(record.otelSpanID, span_id) + self.assertEqual(record.otelTraceID, trace_id) + self.assertEqual(record.otelTraceSampled, trace_sampled) + self.assertEqual(record.otelServiceName, "unknown_service") def test_trace_context_injection_without_span(self): LoggingInstrumentor().uninstrument() @@ -182,16 +186,20 @@ def test_log_hook(self): LoggingInstrumentor().instrument( log_hook=log_hook, ) - with self.tracer.start_as_current_span("s1"): + with self.tracer.start_as_current_span("s1") as span: + span_ctx = span.get_span_context() + span_id = format(span_ctx.span_id, "016x") + trace_id = format(span_ctx.trace_id, "032x") + trace_sampled = span_ctx.trace_flags.sampled with self.caplog.at_level(level=logging.INFO): logger = logging.getLogger("test logger") logger.info("hello") self.assertEqual(len(self.caplog.records), 1) record = self.caplog.records[0] - self.assertFalse(hasattr(record, "otelServiceName")) - self.assertFalse(hasattr(record, "otelSpanID")) - self.assertFalse(hasattr(record, "otelTraceID")) - self.assertFalse(hasattr(record, "otelTraceSampled")) + self.assertEqual(record.otelSpanID, span_id) + self.assertEqual(record.otelTraceID, trace_id) + self.assertEqual(record.otelTraceSampled, trace_sampled) + self.assertEqual(record.otelServiceName, "unknown_service") self.assertEqual( record.custom_user_attribute_from_log_hook, "some-value" ) From ffca6610869225274615fa1793abaf711de6cdfd Mon Sep 17 00:00:00 2001 From: Lukas Hering Date: Mon, 25 May 2026 19:57:56 -0400 Subject: [PATCH 2/4] add optional 'inject_trace_context' argument --- .../instrumentation/logging/__init__.py | 80 +++++++++++-------- .../instrumentation/logging/constants.py | 28 +++++-- .../tests/test_logging.py | 47 ++++++----- 3 files changed, 96 insertions(+), 59 deletions(-) diff --git a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py index 05a524ab51..93087e9867 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py +++ b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py @@ -8,9 +8,9 @@ system with an handler to convert log messages into OpenTelemetry logs. You can disable this setting `OTEL_PYTHON_LOG_AUTO_INSTRUMENTATION` to `false`. -The OpenTelemetry `logging` integration always injects tracing context attributes -(``otelSpanID``, ``otelTraceID``, ``otelTraceSampled``, ``otelServiceName``) into -every log record, making them available for custom formatters and filters. +Trace context injection is opt-in. Pass ``inject_trace_context=True`` to add +``otelSpanID``, ``otelTraceID``, ``otelTraceSampled``, and ``otelServiceName`` +to every log record without changing the logging format: .. code-block:: python @@ -18,13 +18,13 @@ from opentelemetry.instrumentation.logging import LoggingInstrumentor - LoggingInstrumentor().instrument() + LoggingInstrumentor().instrument(inject_trace_context=True) logging.warning('OTel test') -Setting the environment variable `OTEL_PYTHON_LOG_CORRELATION` to `true` (or -passing ``set_logging_format=True``) additionally calls ``logging.basicConfig()`` -with a format string that includes the injected tracing attributes: +Alternatively, set ``set_logging_format=True`` (or the environment variable +``OTEL_PYTHON_LOG_CORRELATION=true``) to inject those same attributes and +call ``logging.basicConfig()`` with a format string that includes them: .. code-block:: python @@ -116,7 +116,10 @@ def log_hook(span: Span, record: LogRecord): Args: tracer_provider: Tracer provider instance that can be used to fetch a tracer. - set_logging_format: When set to True, it calls logging.basicConfig() and sets a logging format. + set_logging_format: When set to True, injects trace context attributes into log records + and calls logging.basicConfig() with a format string that includes those attributes. + inject_trace_context: When set to True, injects trace context attributes + into every log record without modifying the logging format. logging_format: Accepts a string and sets it as the logging format when set_logging_format is set to True. log_level: Accepts one of the following values and sets the logging level to it. @@ -152,44 +155,57 @@ def _instrument(self, **kwargs): ) if set_logging_format: - log_format = kwargs.get( - "logging_format", environ.get(OTEL_PYTHON_LOG_FORMAT, None) + log_format = ( + kwargs.get( + "logging_format", environ.get(OTEL_PYTHON_LOG_FORMAT, None) + ) + or DEFAULT_LOGGING_FORMAT ) - log_format = log_format or DEFAULT_LOGGING_FORMAT - - log_level = kwargs.get( - "log_level", LEVELS.get(environ.get(OTEL_PYTHON_LOG_LEVEL)) + log_level = ( + kwargs.get( + "log_level", LEVELS.get(environ.get(OTEL_PYTHON_LOG_LEVEL)) + ) + or logging.INFO ) - log_level = log_level or logging.INFO - logging.basicConfig(format=log_format, level=log_level) + inject_context = set_logging_format or kwargs.get( + "inject_trace_context", False + ) + def record_factory(*args, **kwargs): record = old_factory(*args, **kwargs) - record.otelSpanID = "0" - record.otelTraceID = "0" - record.otelTraceSampled = False + if not inject_context and not callable( + LoggingInstrumentor._log_hook + ): + return record + + if inject_context: + record.otelSpanID = "0" + record.otelTraceID = "0" + record.otelTraceSampled = False - nonlocal service_name - if service_name is None: - resource = getattr(provider, "resource", None) - if resource: - service_name = ( - resource.attributes.get("service.name") or "" - ) - else: - service_name = "" + nonlocal service_name + if service_name is None: + resource = getattr(provider, "resource", None) + if resource: + service_name = ( + resource.attributes.get("service.name") or "" + ) + else: + service_name = "" - record.otelServiceName = service_name + record.otelServiceName = service_name span = get_current_span() if span != INVALID_SPAN: ctx = span.get_span_context() if ctx != INVALID_SPAN_CONTEXT: - record.otelSpanID = format(ctx.span_id, "016x") - record.otelTraceID = format(ctx.trace_id, "032x") - record.otelTraceSampled = ctx.trace_flags.sampled + if inject_context: + record.otelSpanID = format(ctx.span_id, "016x") + record.otelTraceID = format(ctx.trace_id, "032x") + record.otelTraceSampled = ctx.trace_flags.sampled if callable(LoggingInstrumentor._log_hook): try: diff --git a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/constants.py b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/constants.py index 6070601649..f787184cad 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/constants.py +++ b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/constants.py @@ -39,9 +39,13 @@ {default_logging_format} -The integration is opt-in and must be enabled explicitly by setting the environment variable ``OTEL_PYTHON_LOG_CORRELATION`` to ``true``. -Setting ``OTEL_PYTHON_LOG_CORRELATION`` to ``true`` calls ``logging.basicConfig()`` to set a logging format that actually makes -use of the injected variables. +Trace context injection is opt-in and can be enabled in two ways: + +- Pass ``inject_trace_context=True`` to inject trace context attributes into every log record without modifying + the logging format. Use this when you manage the logging format yourself but still want + ``otelSpanID``, ``otelTraceID``, ``otelTraceSampled``, and ``otelServiceName`` available on each record. +- Set ``OTEL_PYTHON_LOG_CORRELATION`` to ``true`` (or pass ``set_logging_format=True``) to inject the same + trace context attributes and call ``logging.basicConfig()`` with a format string that includes them. Environment variables --------------------- @@ -151,15 +155,23 @@ from opentelemetry.instrumentation.logging import LoggingInstrumentor + # inject trace context attributes only (manage your own format) + LoggingInstrumentor().instrument(inject_trace_context=True) + +.. code-block:: python + + from opentelemetry.instrumentation.logging import LoggingInstrumentor + + # inject trace context attributes and set the logging format LoggingInstrumentor().instrument(set_logging_format=True) Note ----- -If you do not set ``OTEL_PYTHON_LOG_CORRELATION`` to ``true`` but instead set the logging format manually or through your framework, you must ensure that this -integration is enabled before you set the logging format. This is important because unless the integration is enabled, the tracing context variables -are not injected into the log record objects. This means any attempted log statements made after setting the logging format and before enabling this integration -will result in KeyError exceptions. Such exceptions are automatically swallowed by the logging module and do not result in crashes but you may still lose out -on important log messages. +If you set a logging format with trace context placeholders (e.g. ``%(otelSpanID)s``) but do not enable +trace context injection via ``inject_trace_context=True`` or ``set_logging_format=True``, the placeholders +will not be populated. Any log statements emitted before injection is enabled will result in ``KeyError`` +exceptions, which the logging module silently swallows. Enable this integration as early as possible to +avoid these issues. """.format(default_logging_format=DEFAULT_LOGGING_FORMAT) diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py index 79b651f5b5..5bcc1fba9f 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py @@ -113,21 +113,34 @@ def test_trace_context_injection_with_log_correlation_instrument_arg(self): span_id, trace_id, trace_sampled ) - def test_trace_context_injection_by_default(self): - with self.tracer.start_as_current_span("s1") as span: - span_ctx = span.get_span_context() - span_id = format(span_ctx.span_id, "016x") - trace_id = format(span_ctx.trace_id, "032x") - trace_sampled = span_ctx.trace_flags.sampled + def test_no_trace_context_injection_by_default(self): + with self.tracer.start_as_current_span("s1"): with self.caplog.at_level(level=logging.INFO): logger = logging.getLogger("test logger") logger.info("hello") self.assertEqual(len(self.caplog.records), 1) record = self.caplog.records[0] - self.assertEqual(record.otelSpanID, span_id) - self.assertEqual(record.otelTraceID, trace_id) - self.assertEqual(record.otelTraceSampled, trace_sampled) - self.assertEqual(record.otelServiceName, "unknown_service") + self.assertFalse(hasattr(record, "otelServiceName")) + self.assertFalse(hasattr(record, "otelSpanID")) + self.assertFalse(hasattr(record, "otelTraceID")) + self.assertFalse(hasattr(record, "otelTraceSampled")) + + def test_inject_trace_context_arg(self): + LoggingInstrumentor().uninstrument() + LoggingInstrumentor().instrument(inject_trace_context=True) + with self.tracer.start_as_current_span("s1") as span: + span_ctx = span.get_span_context() + span_id = format(span_ctx.span_id, "016x") + trace_id = format(span_ctx.trace_id, "032x") + trace_sampled = span_ctx.trace_flags.sampled + self.assert_trace_context_injected( + span_id, trace_id, trace_sampled + ) + + def test_inject_trace_context_arg_without_span(self): + LoggingInstrumentor().uninstrument() + LoggingInstrumentor().instrument(inject_trace_context=True) + self.assert_trace_context_injected("0", "0", False) def test_trace_context_injection_without_span(self): LoggingInstrumentor().uninstrument() @@ -186,20 +199,16 @@ def test_log_hook(self): LoggingInstrumentor().instrument( log_hook=log_hook, ) - with self.tracer.start_as_current_span("s1") as span: - span_ctx = span.get_span_context() - span_id = format(span_ctx.span_id, "016x") - trace_id = format(span_ctx.trace_id, "032x") - trace_sampled = span_ctx.trace_flags.sampled + with self.tracer.start_as_current_span("s1"): with self.caplog.at_level(level=logging.INFO): logger = logging.getLogger("test logger") logger.info("hello") self.assertEqual(len(self.caplog.records), 1) record = self.caplog.records[0] - self.assertEqual(record.otelSpanID, span_id) - self.assertEqual(record.otelTraceID, trace_id) - self.assertEqual(record.otelTraceSampled, trace_sampled) - self.assertEqual(record.otelServiceName, "unknown_service") + self.assertFalse(hasattr(record, "otelServiceName")) + self.assertFalse(hasattr(record, "otelSpanID")) + self.assertFalse(hasattr(record, "otelTraceID")) + self.assertFalse(hasattr(record, "otelTraceSampled")) self.assertEqual( record.custom_user_attribute_from_log_hook, "some-value" ) From f3d99719c95cd14a0a4b0521a8de55eb2cd1c89b Mon Sep 17 00:00:00 2001 From: Lukas Hering Date: Mon, 25 May 2026 20:03:28 -0400 Subject: [PATCH 3/4] add changelog fragment --- .changelog/4626.added | 1 + 1 file changed, 1 insertion(+) create mode 100644 .changelog/4626.added diff --git a/.changelog/4626.added b/.changelog/4626.added new file mode 100644 index 0000000000..27f51f9169 --- /dev/null +++ b/.changelog/4626.added @@ -0,0 +1 @@ +`opentelemetry-instrumentation-logging`: add optional `inject_trace_context` argument for injecting trace context attributes From 75d8c3560c462877878bc5f3eb82cea8750c98f8 Mon Sep 17 00:00:00 2001 From: Lukas Hering Date: Mon, 25 May 2026 22:49:56 -0400 Subject: [PATCH 4/4] update unit tests to validate calls to logging.basicConfig --- .../tests/test_logging.py | 42 +++++++++++++++---- 1 file changed, 35 insertions(+), 7 deletions(-) diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py index 5bcc1fba9f..7ad851d3fa 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py @@ -89,9 +89,15 @@ def assert_trace_context_injected(self, span_id, trace_id, trace_sampled): self.assertEqual(record.otelServiceName, "unknown_service") @mock.patch.dict("os.environ", {"OTEL_PYTHON_LOG_CORRELATION": "true"}) - def test_trace_context_injection_with_log_correlation_from_env_var(self): + @mock.patch("logging.basicConfig") + def test_trace_context_injection_with_log_correlation_from_env_var( + self, basic_config_mock + ): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument() + basic_config_mock.assert_called_once_with( + format=DEFAULT_LOGGING_FORMAT, level=logging.INFO + ) with self.tracer.start_as_current_span("s1") as span: span_ctx = span.get_span_context() span_id = format(span_ctx.span_id, "016x") @@ -101,9 +107,15 @@ def test_trace_context_injection_with_log_correlation_from_env_var(self): span_id, trace_id, trace_sampled ) - def test_trace_context_injection_with_log_correlation_instrument_arg(self): + @mock.patch("logging.basicConfig") + def test_trace_context_injection_with_log_correlation_instrument_arg( + self, basic_config_mock + ): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument(set_logging_format=True) + basic_config_mock.assert_called_once_with( + format=DEFAULT_LOGGING_FORMAT, level=logging.INFO + ) with self.tracer.start_as_current_span("s1") as span: span_ctx = span.get_span_context() span_id = format(span_ctx.span_id, "016x") @@ -125,9 +137,11 @@ def test_no_trace_context_injection_by_default(self): self.assertFalse(hasattr(record, "otelTraceID")) self.assertFalse(hasattr(record, "otelTraceSampled")) - def test_inject_trace_context_arg(self): + @mock.patch("logging.basicConfig") + def test_inject_trace_context_arg(self, basic_config_mock): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument(inject_trace_context=True) + basic_config_mock.assert_not_called() with self.tracer.start_as_current_span("s1") as span: span_ctx = span.get_span_context() span_id = format(span_ctx.span_id, "016x") @@ -137,14 +151,20 @@ def test_inject_trace_context_arg(self): span_id, trace_id, trace_sampled ) - def test_inject_trace_context_arg_without_span(self): + @mock.patch("logging.basicConfig") + def test_inject_trace_context_arg_without_span(self, basic_config_mock): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument(inject_trace_context=True) + basic_config_mock.assert_not_called() self.assert_trace_context_injected("0", "0", False) - def test_trace_context_injection_without_span(self): + @mock.patch("logging.basicConfig") + def test_trace_context_injection_without_span(self, basic_config_mock): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument(set_logging_format=True) + basic_config_mock.assert_called_once_with( + format=DEFAULT_LOGGING_FORMAT, level=logging.INFO + ) self.assert_trace_context_injected("0", "0", False) @mock.patch("logging.basicConfig") @@ -213,12 +233,16 @@ def test_log_hook(self): record.custom_user_attribute_from_log_hook, "some-value" ) - def test_log_hook_with_set_logging_format(self): + @mock.patch("logging.basicConfig") + def test_log_hook_with_set_logging_format(self, basic_config_mock): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument( set_logging_format=True, log_hook=log_hook, ) + basic_config_mock.assert_called_once_with( + format=DEFAULT_LOGGING_FORMAT, level=logging.INFO + ) with self.tracer.start_as_current_span("s1") as span: span_ctx = span.get_span_context() span_id = format(span_ctx.span_id, "016x") @@ -258,11 +282,15 @@ def test_uninstrumented(self): ] self.assertEqual(logging_handler_instances, []) - def test_no_op_tracer_provider(self): + @mock.patch("logging.basicConfig") + def test_no_op_tracer_provider(self, basic_config_mock): LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument( tracer_provider=NoOpTracerProvider(), set_logging_format=True ) + basic_config_mock.assert_called_once_with( + format=DEFAULT_LOGGING_FORMAT, level=logging.INFO + ) with self.caplog.at_level(level=logging.INFO): logger = logging.getLogger("test logger")