feat[logging]: Replacement API for get_correlation_ids (#2654) (#2797)

* Replacement API for get_correlation_ids to match logging integration

* Changed helper name, added release note.

* Moved helper to be a tracer instance method, added to opentracer as well.

* Spelling fix

* Ensure get_log_correlation_context always returns a DDLogRecord

* Replaced DDLogRecord with dictionary result

* Updated docstrings

* Update ddtrace/opentracer/tracer.py

Co-authored-by: Brett Langdon <[email protected]>
Co-authored-by: Brett Langdon <[email protected]>
Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com>
(cherry picked from commit 65f0634)

Co-authored-by: Yun Kim <[email protected]>

Author: mergify[bot]

ddtrace/opentracer/tracer.py

@@ -364,3 +364,12 @@ def extract(self, format, carrier):  # noqa: A002
         dd_span_ctx = ot_span_ctx._dd_context
         self._dd_tracer.context_provider.activate(dd_span_ctx)
         return ot_span_ctx
+
+    def get_log_correlation_context(self):
+        # type: () -> Dict[str, str]
+        """Retrieves the data used to correlate a log with the current active trace.
+        Generates a dictionary for custom logging instrumentation including the trace id and
+        span id of the current active span, as well as the configured service, version, and environment names.
+        If there is no active span, a dictionary with an empty string for each value will be returned.
+        """
+        return self._dd_tracer.get_log_correlation_context()

ddtrace/tracer.py

@@ -246,6 +246,25 @@ def current_trace_context(self, *args, **kwargs):
             return active.context
         return None
 
+    def get_log_correlation_context(self):
+        # type: () -> Dict[str, str]
+        """Retrieves the data used to correlate a log with the current active trace.
+        Generates a dictionary for custom logging instrumentation including the trace id and
+        span id of the current active span, as well as the configured service, version, and environment names.
+        If there is no active span, a dictionary with an empty string for each value will be returned.
+        """
+        span = None
+        if self.enabled:
+            span = self.current_span()
+
+        return {
+            "trace_id": str(span.trace_id) if span else "0",
+            "span_id": str(span.span_id) if span else "0",
+            "service": config.service or "",
+            "version": config.version or "",
+            "env": config.env or "",
+        }
+
     # TODO: deprecate this method and make sure users create a new tracer if they need different parameters
     def configure(
         self,

releasenotes/notes/log-correlation-context-22d56ee0b5cc9cfa.yaml

@@ -0,0 +1,6 @@
+---
+features:
+  - |
+    The ``ddtrace.Tracer.get_log_correlation_context`` method has been added to replace
+    ``ddtrace.helpers.get_correlation_ids``. It now returns a dictionary which includes the current span's
+    trace and span ids, as well as the configured service, version, and environment names.

riotfile.py

@@ -195,6 +195,7 @@ def select_pys(min_version=MIN_PYTHON_VERSION, max_version=MAX_PYTHON_VERSION):
                         "msgpack": latest,
                         "attrs": ["==19.2.0", latest],
                         "packaging": ["==17.1", latest],
+                        "structlog": latest,
                     },
                 )
             ],

tests/tracer/test_correlation_log_context.py

@@ -0,0 +1,149 @@
+import pytest
+import structlog
+
+from ddtrace import Tracer
+from ddtrace import config
+from ddtrace import tracer
+from ddtrace.opentracer.tracer import Tracer as OT_Tracer
+from tests.utils import override_global_config
+
+
+@pytest.fixture
+def global_config():
+    config.service = "test-service"
+    config.env = "test-env"
+    config.version = "test-version"
+    yield
+    config.service = config.env = config.version = None
+
+
+def tracer_injection(logger, log_method, event_dict):
+    """Inject tracer information into custom structlog log"""
+    correlation_log_context = tracer.get_log_correlation_context()
+    # add ids and configs to structlog event dictionary
+    event_dict["dd"] = correlation_log_context
+    return event_dict
+
+
+class TestCorrelationLogsContext(object):
+    def test_get_log_correlation_context(self, global_config):
+        """Ensure expected DDLogRecord is generated via get_correlation_log_record."""
+        with tracer.trace("test-span-1") as span1:
+            dd_log_record = tracer.get_log_correlation_context()
+        assert dd_log_record == {
+            "span_id": str(span1.span_id),
+            "trace_id": str(span1.trace_id),
+            "service": "test-service",
+            "env": "test-env",
+            "version": "test-version",
+        }
+        test_tracer = Tracer()
+        with test_tracer.trace("test-span-2") as span2:
+            dd_log_record = test_tracer.get_log_correlation_context()
+        assert dd_log_record == {
+            "span_id": str(span2.span_id),
+            "trace_id": str(span2.trace_id),
+            "service": "test-service",
+            "env": "test-env",
+            "version": "test-version",
+        }
+
+    def test_get_log_correlation_context_opentracer(self, global_config):
+        """Ensure expected DDLogRecord generated via get_correlation_log_record with an opentracing Tracer."""
+        ot_tracer = OT_Tracer()
+        with ot_tracer.start_active_span("operation") as scope:
+            dd_span = scope._span._dd_span
+            dd_log_record = ot_tracer.get_log_correlation_context()
+        assert dd_log_record == {
+            "span_id": str(dd_span.span_id),
+            "trace_id": str(dd_span.trace_id),
+            "service": "test-service",
+            "env": "test-env",
+            "version": "test-version",
+        }
+
+    def test_get_log_correlation_context_no_active_span(self):
+        """Ensure empty DDLogRecord generated if no active span."""
+        dd_log_record = tracer.get_log_correlation_context()
+        assert dd_log_record == {
+            "span_id": "0",
+            "trace_id": "0",
+            "service": "",
+            "env": "",
+            "version": "",
+        }
+
+    def test_get_log_correlation_context_disabled_tracer(self):
+        """Ensure get_correlation_log_record returns None if tracer is disabled."""
+        tracer = Tracer()
+        tracer.enabled = False
+        with tracer.trace("test-span"):
+            dd_log_record = tracer.get_log_correlation_context()
+        assert dd_log_record == {
+            "span_id": "0",
+            "trace_id": "0",
+            "service": "",
+            "env": "",
+            "version": "",
+        }
+
+    def test_custom_logging_injection(self):
+        """Ensure custom log injection via get_correlation_log_record returns proper active span information."""
+        capture_log = structlog.testing.LogCapture()
+        structlog.configure(processors=[tracer_injection, capture_log, structlog.processors.JSONRenderer()])
+        logger = structlog.get_logger()
+
+        with tracer.trace("test span") as span:
+            logger.msg("Hello!")
+
+        assert len(capture_log.entries) == 1
+        assert capture_log.entries[0]["event"] == "Hello!"
+        dd_log_record = capture_log.entries[0]["dd"]
+        assert dd_log_record == {
+            "span_id": str(span.span_id),
+            "trace_id": str(span.trace_id),
+            "service": "",
+            "env": "",
+            "version": "",
+        }
+
+    def test_custom_logging_injection_global_config(self):
+        """Ensure custom log injection via get_correlation_log_record returns proper tracer information."""
+        capture_log = structlog.testing.LogCapture()
+        structlog.configure(processors=[tracer_injection, capture_log, structlog.processors.JSONRenderer()])
+        logger = structlog.get_logger()
+
+        with override_global_config(dict(version="global-version", env="global-env", service="global-service")):
+            with tracer.trace("test span") as span:
+                logger.msg("Hello!")
+
+        assert len(capture_log.entries) == 1
+        assert capture_log.entries[0]["event"] == "Hello!"
+        dd_log_record = capture_log.entries[0]["dd"]
+        assert dd_log_record == {
+            "span_id": str(span.span_id),
+            "trace_id": str(span.trace_id),
+            "service": "global-service",
+            "env": "global-env",
+            "version": "global-version",
+        }
+
+    def test_custom_logging_injection_no_span(self):
+        """Ensure custom log injection via get_correlation_log_record with no active span returns empty record."""
+        capture_log = structlog.testing.LogCapture()
+        structlog.configure(processors=[tracer_injection, capture_log, structlog.processors.JSONRenderer()])
+        logger = structlog.get_logger()
+
+        with override_global_config(dict(version="global-version", env="global-env", service="global-service")):
+            logger.msg("No Span!")
+
+        assert len(capture_log.entries) == 1
+        assert capture_log.entries[0]["event"] == "No Span!"
+        dd_log_record = capture_log.entries[0]["dd"]
+        assert dd_log_record == {
+            "span_id": "0",
+            "trace_id": "0",
+            "service": "global-service",
+            "env": "global-env",
+            "version": "global-version",
+        }