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 93087e9867..509006bc4a 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py +++ b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py @@ -9,7 +9,7 @@ You can disable this setting `OTEL_PYTHON_LOG_AUTO_INSTRUMENTATION` to `false`. Trace context injection is opt-in. Pass ``inject_trace_context=True`` to add -``otelSpanID``, ``otelTraceID``, ``otelTraceSampled``, and ``otelServiceName`` +``span_id``, ``trace_id``, ``trace_flags``, and ``otelServiceName`` to every log record without changing the logging format: .. code-block:: python @@ -40,7 +40,7 @@ :: - 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 + 2025-03-05 09:40:04,398 WARNING [root] [example.py:7] [trace_id=0 span_id=0 resource.service.name= trace_flags=00] - OTel test """ @@ -182,9 +182,9 @@ def record_factory(*args, **kwargs): return record if inject_context: - record.otelSpanID = "0" - record.otelTraceID = "0" - record.otelTraceSampled = False + record.span_id = "0" + record.trace_id = "0" + record.trace_flags = "00" nonlocal service_name if service_name is None: @@ -203,9 +203,9 @@ def record_factory(*args, **kwargs): ctx = span.get_span_context() if ctx != INVALID_SPAN_CONTEXT: if inject_context: - record.otelSpanID = format(ctx.span_id, "016x") - record.otelTraceID = format(ctx.trace_id, "032x") - record.otelTraceSampled = ctx.trace_flags.sampled + record.span_id = format(ctx.span_id, "016x") + record.trace_id = format(ctx.trace_id, "032x") + record.trace_flags = format(ctx.trace_flags, "02x") 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 f787184cad..2f37aa4a45 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/constants.py +++ b/instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/constants.py @@ -1,7 +1,7 @@ # Copyright The OpenTelemetry Authors # SPDX-License-Identifier: Apache-2.0 -DEFAULT_LOGGING_FORMAT = "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s resource.service.name=%(otelServiceName)s trace_sampled=%(otelTraceSampled)s] - %(message)s" +DEFAULT_LOGGING_FORMAT = "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] [trace_id=%(trace_id)s span_id=%(span_id)s resource.service.name=%(otelServiceName)s trace_flags=%(trace_flags)s] - %(message)s" _MODULE_DOC = """ @@ -24,14 +24,14 @@ The integration registers a custom log record factory with the the standard library logging module that automatically inject tracing context into log record objects. Optionally, the integration can also call ``logging.basicConfig()`` to set a logging -format with placeholders for span ID, trace ID and service name. +format with placeholders for span ID, trace ID, trace flags and service name. The following keys are injected into log record objects by the factory: -- ``otelSpanID`` -- ``otelTraceID`` +- ``span_id`` +- ``trace_id`` - ``otelServiceName`` -- ``otelTraceSampled`` +- ``trace_flags`` The integration uses the following logging format by default: @@ -43,7 +43,7 @@ - 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. + ``span_id``, ``trace_id``, ``trace_flags``, 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. @@ -144,7 +144,7 @@ .. code-block:: - %(otelSpanID)s %(otelTraceID)s %(otelServiceName)s %(otelTraceSampled)s + %(span_id)s %(trace_id)s %(otelServiceName)s %(trace_flags)s @@ -169,7 +169,7 @@ Note ----- -If you set a logging format with trace context placeholders (e.g. ``%(otelSpanID)s``) but do not enable +If you set a logging format with trace context placeholders (e.g. ``%(span_id)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 diff --git a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py index 7ad851d3fa..a7e9aa6e88 100644 --- a/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py +++ b/instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py @@ -53,10 +53,10 @@ def test_trace_context_injection(self): logger.info("hello") self.assertEqual(len(self.caplog.records), 1) record = self.caplog.records[0] - self.assertEqual(record.otelSpanID, "0") - self.assertEqual(record.otelTraceID, "0") + self.assertEqual(record.span_id, "0") + self.assertEqual(record.trace_id, "0") self.assertEqual(record.otelServiceName, "") - self.assertEqual(record.otelTraceSampled, False) + self.assertEqual(record.trace_flags, "00") def log_hook(span, record): @@ -77,15 +77,15 @@ def tearDown(self): super().tearDown() LoggingInstrumentor().uninstrument() - def assert_trace_context_injected(self, span_id, trace_id, trace_sampled): + def assert_trace_context_injected(self, span_id, trace_id, trace_flags): 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.span_id, span_id) + self.assertEqual(record.trace_id, trace_id) + self.assertEqual(record.trace_flags, trace_flags) self.assertEqual(record.otelServiceName, "unknown_service") @mock.patch.dict("os.environ", {"OTEL_PYTHON_LOG_CORRELATION": "true"}) @@ -102,10 +102,8 @@ def test_trace_context_injection_with_log_correlation_from_env_var( 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 - ) + trace_flags = format(span_ctx.trace_flags, "02x") + self.assert_trace_context_injected(span_id, trace_id, trace_flags) @mock.patch("logging.basicConfig") def test_trace_context_injection_with_log_correlation_instrument_arg( @@ -120,10 +118,8 @@ def test_trace_context_injection_with_log_correlation_instrument_arg( 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 - ) + trace_flags = format(span_ctx.trace_flags, "02x") + self.assert_trace_context_injected(span_id, trace_id, trace_flags) def test_no_trace_context_injection_by_default(self): with self.tracer.start_as_current_span("s1"): @@ -133,9 +129,9 @@ def test_no_trace_context_injection_by_default(self): 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.assertFalse(hasattr(record, "span_id")) + self.assertFalse(hasattr(record, "trace_id")) + self.assertFalse(hasattr(record, "trace_flags")) @mock.patch("logging.basicConfig") def test_inject_trace_context_arg(self, basic_config_mock): @@ -146,17 +142,41 @@ def test_inject_trace_context_arg(self, basic_config_mock): 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 - ) + trace_flags = format(span_ctx.trace_flags, "02x") + self.assert_trace_context_injected(span_id, trace_id, trace_flags) + + def test_log_record_dict_uses_spec_trace_context_names(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() + 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].__dict__ + self.assertEqual( + record["span_id"], format(span_ctx.span_id, "016x") + ) + self.assertEqual( + record["trace_id"], format(span_ctx.trace_id, "032x") + ) + self.assertEqual( + record["trace_flags"], format(span_ctx.trace_flags, "02x") + ) + self.assertIs(type(record["span_id"]), str) + self.assertIs(type(record["trace_id"]), str) + self.assertIs(type(record["trace_flags"]), str) + self.assertNotIn("otelSpanID", record) + self.assertNotIn("otelTraceID", record) + self.assertNotIn("otelTraceSampled", record) @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) + self.assert_trace_context_injected("0", "0", "00") @mock.patch("logging.basicConfig") def test_trace_context_injection_without_span(self, basic_config_mock): @@ -165,7 +185,7 @@ def test_trace_context_injection_without_span(self, basic_config_mock): basic_config_mock.assert_called_once_with( format=DEFAULT_LOGGING_FORMAT, level=logging.INFO ) - self.assert_trace_context_injected("0", "0", False) + self.assert_trace_context_injected("0", "0", "00") @mock.patch("logging.basicConfig") def test_basic_config_called(self, basic_config_mock): @@ -193,13 +213,13 @@ def test_custom_format_and_level_env(self, basic_config_mock): "os.environ", { "OTEL_PYTHON_LOG_CORRELATION": "true", - "OTEL_PYTHON_LOG_FORMAT": "%(message)s %(otelSpanID)s", + "OTEL_PYTHON_LOG_FORMAT": "%(message)s %(span_id)s", "OTEL_PYTHON_LOG_LEVEL": "error", }, ): LoggingInstrumentor().instrument() basic_config_mock.assert_called_with( - format="%(message)s %(otelSpanID)s", level=logging.ERROR + format="%(message)s %(span_id)s", level=logging.ERROR ) @mock.patch("logging.basicConfig") @@ -207,11 +227,11 @@ def test_custom_format_and_level_api(self, basic_config_mock): # pylint: disabl LoggingInstrumentor().uninstrument() LoggingInstrumentor().instrument( set_logging_format=True, - logging_format="%(message)s span_id=%(otelSpanID)s", + logging_format="%(message)s span_id=%(span_id)s", log_level=logging.WARNING, ) basic_config_mock.assert_called_with( - format="%(message)s span_id=%(otelSpanID)s", level=logging.WARNING + format="%(message)s span_id=%(span_id)s", level=logging.WARNING ) def test_log_hook(self): @@ -226,9 +246,9 @@ def test_log_hook(self): 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.assertFalse(hasattr(record, "span_id")) + self.assertFalse(hasattr(record, "trace_id")) + self.assertFalse(hasattr(record, "trace_flags")) self.assertEqual( record.custom_user_attribute_from_log_hook, "some-value" ) @@ -247,16 +267,16 @@ def test_log_hook_with_set_logging_format(self, basic_config_mock): 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 + trace_flags = format(span_ctx.trace_flags, "02x") 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.span_id, span_id) + self.assertEqual(record.trace_id, trace_id) self.assertEqual(record.otelServiceName, "unknown_service") - self.assertEqual(record.otelTraceSampled, trace_sampled) + self.assertEqual(record.trace_flags, trace_flags) self.assertEqual( record.custom_user_attribute_from_log_hook, "some-value" ) @@ -270,9 +290,9 @@ def test_uninstrumented(self): 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.assertFalse(hasattr(record, "span_id")) + self.assertFalse(hasattr(record, "trace_id")) + self.assertFalse(hasattr(record, "trace_flags")) root_logger = logging.getLogger() logging_handler_instances = [ @@ -298,10 +318,10 @@ def test_no_op_tracer_provider(self, basic_config_mock): self.assertEqual(len(self.caplog.records), 1) record = self.caplog.records[0] - self.assertEqual(record.otelSpanID, "0") - self.assertEqual(record.otelTraceID, "0") + self.assertEqual(record.span_id, "0") + self.assertEqual(record.trace_id, "0") self.assertEqual(record.otelServiceName, "") - self.assertEqual(record.otelTraceSampled, False) + self.assertEqual(record.trace_flags, "00") @mock.patch.dict( "os.environ",