added context processors and docs for RUM correlation (#322)

closes #322
fixes #318

Author: beniwohli

docs/django.asciidoc

@@ -114,6 +114,48 @@ ELASTIC_APM['TRANSACTIONS_IGNORE_PATTERNS'] = ['^OPTIONS ', 'views.api.v2']
 
 This example ignores any requests using the `OPTIONS` method and any requests containing `views.api.v2`.
 
+[float]
+[[django-integrating-with-the-rum-agent]]
+==== Integrating with the RUM agent
+
+To correlate performance measurement in the browser with measurements in your Django app,
+you can help the RUM (Real User Monitoring) agent by configuring it with the Trace ID and Span ID of the backend request.
+We provide a handy template context processor which adds all the necessary bits into the context of your templates.
+
+To enable this feature, first add the `rum_tracing` context processor to your `TEMPLATES` setting.
+You most likely already have a list of `context_processors`, in which case you can simply append ours to the list.
+
+[source,python]
+----
+TEMPLATES = [
+    {
+        'BACKEND': 'django.template.backends.django.DjangoTemplates',
+        'OPTIONS': {
+            'context_processors': [
+                # ...
+                'elasticapm.contrib.django.context_processors.rum_tracing',
+            ],
+        },
+    },
+]
+
+----
+
+Then, update the call to initialize the RUM agent (which probably happens in your base template) like this:
+
+[source,javascript]
+----
+elasticApm.init({
+    serviceName: "my-frontend-service",
+    pageLoadTraceId: "{{ apm.trace_id }}",
+    pageLoadSpanId: "{{ apm.span_id }}",
+    pageLoadSampled: {{ apm.is_sampled_js }}
+})
+
+----
+
+See the {apm-rum-ref}[JavaScript RUM agent documentation] for more information.
+
 [float]
 [[django-enabling-and-disabling-the-agent]]
 === Enabling and disabling the agent

docs/flask.asciidoc

@@ -232,3 +232,28 @@ app.config['ELASTIC_APM'] = {
 
 This would ignore any requests using the `OPTIONS` method
 and any requests containing `/api/`.
+
+
+[float]
+[[flask-integrating-with-the-rum-agent]]
+==== Integrating with the RUM agent
+
+To correlate performance measurement in the browser with measurements in your Flask app,
+you can help the RUM (Real User Monitoring) agent by configuring it with the Trace ID and Span ID of the backend request.
+We provide a handy template context processor which adds all the necessary bits into the context of your templates.
+
+The context processor is installed automatically when you initialize `ElasticAPM`.
+All that is left to do is to update the call to initialize the RUM agent (which probably happens in your base template) like this:
+
+[source,javascript]
+----
+elasticApm.init({
+    serviceName: "my-frontend-service",
+    pageLoadTraceId: "{{ apm["trace_id"] }}",
+    pageLoadSpanId: "{{ apm["span_id"]() }}",
+    pageLoadSampled: {{ apm["is_sampled_js"] }}
+})
+
+----
+
+See the {apm-rum-ref}[JavaScript RUM agent documentation] for more information.

elasticapm/contrib/django/apps.py

@@ -1,3 +1,4 @@
+import logging
 from functools import partial
 
 from django.apps import AppConfig
@@ -7,6 +8,8 @@
 from elasticapm.contrib.django.client import get_client
 from elasticapm.utils.disttracing import TraceParent
 
+logger = logging.getLogger("elasticapm.traces")
+
 ERROR_DISPATCH_UID = "elasticapm-exceptions"
 REQUEST_START_DISPATCH_UID = "elasticapm-request-start"
 REQUEST_FINISH_DISPATCH_UID = "elasticapm-request-stop"
@@ -77,6 +80,7 @@ def _request_started_handler(client, sender, *args, **kwargs):
         traceparent_header = None
     if traceparent_header:
         trace_parent = TraceParent.from_string(traceparent_header)
+        logger.debug("Read traceparent header %s", traceparent_header)
     else:
         trace_parent = None
     client.begin_transaction("request", trace_parent=trace_parent)

elasticapm/contrib/django/context_processors.py

@@ -0,0 +1,17 @@
+from elasticapm.traces import get_transaction
+
+
+def rum_tracing(request):
+    transaction = get_transaction()
+    if transaction and transaction.trace_parent:
+        return {
+            "apm": {
+                "trace_id": transaction.trace_parent.trace_id,
+                # only put the callable into the context to ensure that we only change the span_id if the value
+                # is rendered
+                "span_id": transaction.ensure_parent_id,
+                "is_sampled": transaction.is_sampled,
+                "is_sampled_js": "true" if transaction.is_sampled else "false",
+            }
+        }
+    return {}

elasticapm/contrib/flask/__init__.py

@@ -22,6 +22,7 @@
 from elasticapm.conf import constants, setup_logging
 from elasticapm.contrib.flask.utils import get_data_from_request, get_data_from_response
 from elasticapm.handlers.logging import LoggingHandler
+from elasticapm.traces import get_transaction
 from elasticapm.utils import build_name_with_http_method_prefix
 from elasticapm.utils.disttracing import TraceParent
 
@@ -131,6 +132,23 @@ def init_app(self, app, **defaults):
         else:
             logger.debug("Skipping instrumentation. INSTRUMENT is set to False.")
 
+        @app.context_processor
+        def rum_tracing():
+            """
+            Adds APM related IDs to the context used for correlating the backend transaction with the RUM transaction
+            """
+            transaction = get_transaction()
+            if transaction and transaction.trace_parent:
+                return {
+                    "apm": {
+                        "trace_id": transaction.trace_parent.trace_id,
+                        "span_id": lambda: transaction.ensure_parent_id(),
+                        "is_sampled": transaction.is_sampled,
+                        "is_sampled_js": "true" if transaction.is_sampled else "false",
+                    }
+                }
+            return {}
+
     def request_started(self, app):
         if not self.app.debug or self.client.config.debug:
             if constants.TRACEPARENT_HEADER_NAME in request.headers:

elasticapm/traces.py

@@ -13,6 +13,7 @@
 __all__ = ("capture_span", "tag", "set_transaction_name", "set_custom_context", "set_user_context")
 
 error_logger = logging.getLogger("elasticapm.errors")
+logger = logging.getLogger("elasticapm.traces")
 
 _time_func = timeit.default_timer
 
@@ -84,6 +85,17 @@ def end_span(self, skip_frames):
         self._tracer.queue_func(SPAN, span.to_dict())
         return span
 
+    def ensure_parent_id(self):
+        """If current trace_parent has no span_id, generate one, then return it
+
+        This is used to generate a span ID which the RUM agent will use to correlate
+        the RUM transaction with the backend transaction.
+        """
+        if self.trace_parent.span_id == self.id:
+            self.trace_parent.span_id = "%016x" % random.getrandbits(64)
+            logger.debug("Set parent id to generated %s", self.trace_parent.span_id)
+        return self.trace_parent.span_id
+
     def to_dict(self):
         self.context["tags"] = self.tags
         result = {

tests/DockerfileDocs

@@ -9,7 +9,7 @@ RUN for server in $(shuf -e ha.pool.sks-keyservers.net \
                             hkp://p80.pool.sks-keyservers.net:80 \
                             keyserver.ubuntu.com \
                             hkp://keyserver.ubuntu.com:80 \
-                            pgp.mit.edu) ; do echo "Trying $server"; gpg --keyserver "$server" --recv-keys B42F6819007F00F88E364FD4036A9C25BF357DD4 && s=0 && break || s=$?; done; (exit $s)
+                            pgp.mit.edu) ; do echo "Trying $server"; gpg --no-tty --keyserver "$server" --recv-keys B42F6819007F00F88E364FD4036A9C25BF357DD4 && s=0 && break || s=$?; done; (exit $s)
 
 RUN curl -o /usr/local/bin/gosu -SL "https://github.com/tianon/gosu/releases/download/1.10/gosu-$(dpkg --print-architecture)" \
     && curl -o /usr/local/bin/gosu.asc -SL "https://github.com/tianon/gosu/releases/download/1.10/gosu-$(dpkg --print-architecture).asc" \

tests/client/client_tests.py

@@ -784,3 +784,18 @@ def test_trace_parent_not_set(elasticapm_client):
     data = transaction.to_dict()
     assert data["trace_id"] is not None
     assert "parent_id" not in data
+
+
+def test_ensure_parent_sets_new_id(elasticapm_client):
+    transaction = elasticapm_client.begin_transaction("test", trace_parent=None)
+    assert transaction.id == transaction.trace_parent.span_id
+    span_id = transaction.ensure_parent_id()
+    assert span_id == transaction.trace_parent.span_id
+
+
+def test_ensure_parent_doesnt_change_existing_id(elasticapm_client):
+    transaction = elasticapm_client.begin_transaction("test", trace_parent=None)
+    assert transaction.id == transaction.trace_parent.span_id
+    span_id = transaction.ensure_parent_id()
+    span_id_2 = transaction.ensure_parent_id()
+    assert span_id == span_id_2

tests/contrib/django/django_tests.py

@@ -24,6 +24,7 @@
 
 import mock
 
+from conftest import BASE_TEMPLATE_DIR
 from elasticapm.base import Client
 from elasticapm.conf import constants
 from elasticapm.conf.constants import ERROR, SPAN, TRANSACTION
@@ -1351,3 +1352,29 @@ def test_options_request(client, django_elasticapm_client):
         client.options("/")
     transactions = django_elasticapm_client.events[TRANSACTION]
     assert transactions[0]["context"]["request"]["method"] == "OPTIONS"
+
+
+def test_rum_tracing_context_processor(client, django_elasticapm_client):
+    with override_settings(
+        TEMPLATES=[
+            {
+                "BACKEND": "django.template.backends.django.DjangoTemplates",
+                "DIRS": [BASE_TEMPLATE_DIR],
+                "OPTIONS": {
+                    "context_processors": [
+                        "django.contrib.auth.context_processors.auth",
+                        "elasticapm.contrib.django.context_processors.rum_tracing",
+                    ],
+                    "loaders": ["django.template.loaders.filesystem.Loader"],
+                    "debug": False,
+                },
+            }
+        ],
+        **middleware_setting(django.VERSION, ["elasticapm.contrib.django.middleware.TracingMiddleware"])
+    ):
+        response = client.get(reverse("render-heavy-template"))
+        transactions = django_elasticapm_client.events[TRANSACTION]
+        assert response.context["apm"]["trace_id"] == transactions[0]["trace_id"]
+        assert response.context["apm"]["is_sampled"]
+        assert response.context["apm"]["is_sampled_js"] == "true"
+        assert callable(response.context["apm"]["span_id"])

tests/contrib/flask/flask_tests.py

@@ -8,6 +8,7 @@
 from elasticapm.conf.constants import ERROR, TRANSACTION
 from elasticapm.contrib.flask import ElasticAPM
 from elasticapm.utils import compat
+from tests.contrib.flask.utils import captured_templates
 
 try:
     from urllib.request import urlopen
@@ -284,3 +285,15 @@ def test_set_transaction_name(flask_apm_client):
     transaction = flask_apm_client.client.events[TRANSACTION][0]
     assert transaction["name"] == "foo"
     assert transaction["result"] == "okydoky"
+
+
+def test_rum_tracing_context_processor(flask_apm_client):
+    with captured_templates(flask_apm_client.app) as templates:
+        resp = flask_apm_client.app.test_client().post("/users/", data={"foo": "bar"})
+        resp.close()
+        transaction = flask_apm_client.client.events[TRANSACTION][0]
+        template, context = templates[0]
+        assert context["apm"]["trace_id"] == transaction["trace_id"]
+        assert context["apm"]["is_sampled"]
+        assert context["apm"]["is_sampled_js"] == "true"
+        assert callable(context["apm"]["span_id"])