Add LogRecord serialized_context for to_json of arbitrary objects

Author: tammy-baylis-swi

opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py

@@ -235,6 +235,19 @@ def __eq__(self, other: object) -> bool:
             return NotImplemented
         return self.__dict__ == other.__dict__
 
+    def serialized_context(self) -> dict:
+        """Returns JSON-serializable copy of stored Context"""
+        context_dict = {}
+        if self.context is not None:
+            for key, value in self.context.items():
+                try:
+                    json.dumps(value)
+                    context_dict[key] = value
+                except TypeError:
+                    # If not JSON-serializable, use string representation
+                    context_dict[key] = str(value)
+            return context_dict
+
     def to_json(self, indent: int | None = 4) -> str:
         return json.dumps(
             {
@@ -249,9 +262,7 @@ def to_json(self, indent: int | None = 4) -> str:
                 "dropped_attributes": self.dropped_attributes,
                 "timestamp": ns_to_iso_str(self.timestamp),
                 "observed_timestamp": ns_to_iso_str(self.observed_timestamp),
-                "context": (
-                    dict(self.context) if self.context is not None else ""
-                ),
+                "context": self.serialized_context(),
                 "trace_id": (
                     f"0x{format_trace_id(self.trace_id)}"
                     if self.trace_id is not None

opentelemetry-sdk/tests/logs/test_log_record.py

@@ -13,17 +13,30 @@
 # limitations under the License.
 
 import json
+import logging
 import unittest
 import warnings
+from unittest.mock import patch
 
 from opentelemetry._logs.severity import SeverityNumber
 from opentelemetry.attributes import BoundedAttributes
+from opentelemetry.sdk import trace
 from opentelemetry.sdk._logs import (
+    LogData,
     LogDroppedAttributesWarning,
+    LoggerProvider,
+    LoggingHandler,
     LogLimits,
     LogRecord,
+    LogRecordProcessor,
 )
 from opentelemetry.sdk.resources import Resource
+from opentelemetry.trace import (
+    INVALID_SPAN,
+    format_span_id,
+    format_trace_id,
+    set_span_in_context,
+)
 
 
 class TestLogRecord(unittest.TestCase):
@@ -42,7 +55,7 @@ def test_log_record_to_json(self):
                 "dropped_attributes": 0,
                 "timestamp": "1970-01-01T00:00:00.000000Z",
                 "observed_timestamp": "1970-01-01T00:00:00.000000Z",
-                "context": "",
+                "context": None,
                 "trace_id": "",
                 "span_id": "",
                 "trace_flags": None,
@@ -69,9 +82,99 @@ def test_log_record_to_json(self):
         self.assertEqual(expected, actual.to_json(indent=4))
         self.assertEqual(
             actual.to_json(indent=None),
-            '{"body": "a log line", "severity_number": null, "severity_text": null, "attributes": {"mapping": {"key": "value"}, "none": null, "sequence": [1, 2], "str": "string"}, "dropped_attributes": 0, "timestamp": "1970-01-01T00:00:00.000000Z", "observed_timestamp": "1970-01-01T00:00:00.000000Z", "context": "", "trace_id": "", "span_id": "", "trace_flags": null, "resource": {"attributes": {"service.name": "foo"}, "schema_url": ""}}',
+            '{"body": "a log line", "severity_number": null, "severity_text": null, "attributes": {"mapping": {"key": "value"}, "none": null, "sequence": [1, 2], "str": "string"}, "dropped_attributes": 0, "timestamp": "1970-01-01T00:00:00.000000Z", "observed_timestamp": "1970-01-01T00:00:00.000000Z", "context": null, "trace_id": "", "span_id": "", "trace_flags": null, "resource": {"attributes": {"service.name": "foo"}, "schema_url": ""}}',
         )
 
+    @patch("opentelemetry.sdk._logs._internal.get_current_span")
+    @patch("opentelemetry.trace.propagation.set_value")
+    @patch("opentelemetry.sdk.trace.RandomIdGenerator.generate_span_id")
+    @patch("opentelemetry.sdk.trace.RandomIdGenerator.generate_trace_id")
+    def test_log_record_to_json_with_span_correlation(
+        self,
+        mock_generate_trace_id,
+        mock_generate_span_id,
+        mock_set_value,
+        mock_get_current_span,
+    ):
+        trace_id = 0x000000000000000000000000DEADBEEF
+        span_id = 0x00000000DEADBEF0
+        fixed_key = "current-span-test"
+
+        mock_generate_trace_id.return_value = trace_id
+        mock_generate_span_id.return_value = span_id
+
+        def mock_set_value_impl(key, value, context=None):
+            if context is None:
+                context = {}
+            context[fixed_key] = value
+            return context
+
+        mock_set_value.side_effect = mock_set_value_impl
+
+        def mock_get_span_impl(context=None):
+            if context is None or fixed_key not in context:
+                return INVALID_SPAN
+            return context[fixed_key]
+
+        mock_get_current_span.side_effect = mock_get_span_impl
+
+        _, _ = set_up_test_logging(logging.WARNING)
+        tracer = trace.TracerProvider().get_tracer(__name__)
+
+        with tracer.start_as_current_span("test") as span:
+            context = set_span_in_context(span)
+            span_context = span.get_span_context()
+
+            expected = json.dumps(
+                {
+                    "body": "a log line",
+                    "severity_number": None,
+                    "severity_text": None,
+                    "attributes": {
+                        "mapping": {"key": "value"},
+                        "none": None,
+                        "sequence": [1, 2],
+                        "str": "string",
+                    },
+                    "dropped_attributes": 0,
+                    "timestamp": "1970-01-01T00:00:00.000000Z",
+                    "observed_timestamp": "1970-01-01T00:00:00.000000Z",
+                    "context": {
+                        fixed_key: f'_Span(name="test", context=SpanContext(trace_id=0x{format_trace_id(trace_id)}, '
+                        f"span_id=0x{format_span_id(span_id)}, "
+                        f"trace_flags=0x01, trace_state=[], is_remote=False))"
+                    },
+                    "trace_id": f"0x{format_trace_id(span_context.trace_id)}",
+                    "span_id": f"0x{format_span_id(span_context.span_id)}",
+                    "trace_flags": span_context.trace_flags,
+                    "resource": {
+                        "attributes": {"service.name": "foo"},
+                        "schema_url": "",
+                    },
+                },
+                indent=4,
+            )
+
+            actual = LogRecord(
+                timestamp=0,
+                observed_timestamp=0,
+                context=context,
+                body="a log line",
+                resource=Resource({"service.name": "foo"}),
+                attributes={
+                    "mapping": {"key": "value"},
+                    "none": None,
+                    "sequence": [1, 2],
+                    "str": "string",
+                },
+            )
+
+            self.assertEqual(expected, actual.to_json(indent=4))
+            self.assertEqual(
+                '{"body": "a log line", "severity_number": null, "severity_text": null, "attributes": {"mapping": {"key": "value"}, "none": null, "sequence": [1, 2], "str": "string"}, "dropped_attributes": 0, "timestamp": "1970-01-01T00:00:00.000000Z", "observed_timestamp": "1970-01-01T00:00:00.000000Z", "context": {"current-span-test": "_Span(name=\\"test\\", context=SpanContext(trace_id=0x000000000000000000000000deadbeef, span_id=0x00000000deadbef0, trace_flags=0x01, trace_state=[], is_remote=False))"}, "trace_id": "0x000000000000000000000000deadbeef", "span_id": "0x00000000deadbef0", "trace_flags": 1, "resource": {"attributes": {"service.name": "foo"}, "schema_url": ""}}',
+                actual.to_json(indent=None),
+            )
+
     def test_log_record_to_json_serializes_severity_number_as_int(self):
         actual = LogRecord(
             timestamp=0,
@@ -169,3 +272,35 @@ def test_log_record_dropped_attributes_unset_limits(self):
         )
         self.assertTrue(result.dropped_attributes == 0)
         self.assertEqual(attr, result.attributes)
+
+
+def set_up_test_logging(level, formatter=None, root_logger=False):
+    logger_provider = LoggerProvider()
+    processor = FakeProcessor()
+    logger_provider.add_log_record_processor(processor)
+    logger = logging.getLogger(None if root_logger else "foo")
+    handler = LoggingHandler(level=level, logger_provider=logger_provider)
+    if formatter:
+        handler.setFormatter(formatter)
+    logger.addHandler(handler)
+    return processor, logger
+
+
+class FakeProcessor(LogRecordProcessor):
+    def __init__(self):
+        self.log_data_emitted = []
+
+    def emit(self, log_data: LogData):
+        self.log_data_emitted.append(log_data)
+
+    def shutdown(self):
+        pass
+
+    def force_flush(self, timeout_millis: int = 30000):
+        pass
+
+    def emit_count(self):
+        return len(self.log_data_emitted)
+
+    def get_log_record(self, i):
+        return self.log_data_emitted[i].log_record