Sanic: capture responseHeadersOnEntrySpans

instana/instrumentation/sanic_inst.py

@@ -44,6 +44,7 @@ def response_details(span, response):
                 span.set_tag('http.status_code', status_code)
 
             if response.headers is not None:
+                extract_custom_headers(span, response.headers)
                 async_tracer.inject(span.context, opentracing.Format.HTTP_HEADERS, response.headers)
             response.headers['Server-Timing'] = "intid;desc=%s" % span.context.trace_id
         except Exception:
@@ -124,7 +125,7 @@ async def handle_request_with_instana(wrapped, instance, args, kwargs):
                     scope.span.set_tag("http.params", scrubbed_params)
 
                 if agent.options.extra_http_headers is not None:
-                    extract_custom_headers(scope, headers)
+                    extract_custom_headers(scope.span, headers)
                 await wrapped(*args, **kwargs)
                 if hasattr(request, "uri_template") and request.uri_template:
                     scope.span.set_tag("http.path_tpl", request.uri_template)

instana/util/traceutils.py

@@ -5,13 +5,13 @@
 from ..log import logger
 
 
-def extract_custom_headers(tracing_scope, headers):
+def extract_custom_headers(tracing_span, headers):
     try:
         for custom_header in agent.options.extra_http_headers:
             # Headers are in the following format: b'x-header-1'
             for header_key, value in headers.items():
                 if header_key.lower() == custom_header.lower():
-                    tracing_scope.span.set_tag("http.header.%s" % custom_header, value)
+                    tracing_span.set_tag("http.header.%s" % custom_header, value)
     except Exception:
         logger.debug("extract_custom_headers: ", exc_info=True)
 

tests/apps/sanic_app/__init__.py

@@ -3,6 +3,7 @@
 
 
 import uvicorn
+
 from ...helpers import testenv
 from instana.log import logger
 
@@ -15,6 +16,16 @@ def launch_sanic():
     from instana.singletons import agent
 
     # Hack together a manual custom headers list; We'll use this in tests
-    agent.options.extra_http_headers = [u'X-Capture-This', u'X-Capture-That']
+    agent.options.extra_http_headers = [
+        "X-Capture-This",
+        "X-Capture-That",
+        "X-Capture-This-Too",
+        "X-Capture-That-Too",
+    ]
 
-    uvicorn.run(app, host='127.0.0.1', port=testenv['sanic_port'], log_level="critical")
+    uvicorn.run(
+        app,
+        host="127.0.0.1",
+        port=testenv["sanic_port"],
+        log_level="critical",
+    )

tests/apps/sanic_app/server.py

@@ -5,16 +5,24 @@
 
 from sanic import Sanic
 from sanic.exceptions import SanicException
+from sanic.response import text
+
 from tests.apps.sanic_app.simpleview import SimpleView
 from tests.apps.sanic_app.name import NameView
-from sanic.response import text
 
 app = Sanic('test')
 
 @app.get("/foo/<foo_id:int>")
 async def uuid_handler(request, foo_id: int):
     return text("INT - {}".format(foo_id))
 
+@app.route("/response_headers")
+async def response_headers(request):
+    headers = {
+        'X-Capture-This-Too': 'this too',
+        'X-Capture-That-Too': 'that too'
+    }
+    return text("Stan wuz here with headers!", headers=headers)
 
 @app.route("/test_request_args")
 async def test_request_args(request):

tests/frameworks/test_sanic.py

@@ -37,7 +37,6 @@ def test_vanilla_get(self):
         self.assertEqual(spans[0].n, 'asgi')
 
     def test_basic_get(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/')
 
@@ -71,16 +70,15 @@ def test_basic_get(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/')
-        assert (asgi_span.data['http']['path_tpl'] == '/')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 200)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 200)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
 
     def test_404(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/foo/not_an_int')
 
@@ -114,16 +112,15 @@ def test_404(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/foo/not_an_int')
-        assert (asgi_span.data['http']['path_tpl'] is None)
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 404)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/foo/not_an_int')
+        self.assertIsNone(asgi_span.data['http']['path_tpl'])
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 404)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
 
     def test_sanic_exception(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/wrong')
 
@@ -157,16 +154,15 @@ def test_sanic_exception(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/wrong')
-        assert (asgi_span.data['http']['path_tpl'] == '/wrong')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 400)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/wrong')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/wrong')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 400)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
 
     def test_500_instana_exception(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/instana_exception')
 
@@ -200,16 +196,15 @@ def test_500_instana_exception(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertEqual(asgi_span.ec, 1)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/instana_exception')
-        assert (asgi_span.data['http']['path_tpl'] == '/instana_exception')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 500)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/instana_exception')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/instana_exception')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 500)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
 
     def test_500(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/test_request_args')
 
@@ -243,16 +238,15 @@ def test_500(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertEqual(asgi_span.ec, 1)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/test_request_args')
-        assert (asgi_span.data['http']['path_tpl'] == '/test_request_args')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 500)
-        assert (asgi_span.data['http']['error'] == 'Something went wrong.')
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/test_request_args')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/test_request_args')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 500)
+        self.assertEqual(asgi_span.data['http']['error'], 'Something went wrong.')
+        self.assertIsNone(asgi_span.data['http']['params'])
 
     def test_path_templates(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/foo/1')
 
@@ -286,16 +280,15 @@ def test_path_templates(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/foo/1')
-        assert (asgi_span.data['http']['path_tpl'] == '/foo/<foo_id:int>')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 200)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/foo/1')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/foo/<foo_id:int>')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 200)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
 
     def test_secret_scrubbing(self):
-        result = None
         with tracer.start_active_span('test'):
             result = requests.get(testenv["sanic_server"] + '/?secret=shhh')
 
@@ -329,13 +322,13 @@ def test_secret_scrubbing(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/')
-        assert (asgi_span.data['http']['path_tpl'] == '/')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 200)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] == 'secret=<redacted>')
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 200)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertEqual(asgi_span.data['http']['params'], 'secret=<redacted>')
 
     def test_synthetic_request(self):
         request_headers = {
@@ -374,19 +367,19 @@ def test_synthetic_request(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/')
-        assert (asgi_span.data['http']['path_tpl'] == '/')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 200)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 200)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
 
         self.assertIsNotNone(asgi_span.sy)
         self.assertIsNone(urllib3_span.sy)
         self.assertIsNone(test_span.sy)
 
-    def test_custom_header_capture(self):
+    def test_request_header_capture(self):
         request_headers = {
             'X-Capture-This': 'this',
             'X-Capture-That': 'that'
@@ -424,15 +417,63 @@ def test_custom_header_capture(self):
         self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
 
         self.assertIsNone(asgi_span.ec)
-        assert (asgi_span.data['http']['host'] == '127.0.0.1:1337')
-        assert (asgi_span.data['http']['path'] == '/')
-        assert (asgi_span.data['http']['path_tpl'] == '/')
-        assert (asgi_span.data['http']['method'] == 'GET')
-        assert (asgi_span.data['http']['status'] == 200)
-        assert (asgi_span.data['http']['error'] is None)
-        assert (asgi_span.data['http']['params'] is None)
-
-        assert ("X-Capture-This" in asgi_span.data["http"]["header"])
-        assert ("this" == asgi_span.data["http"]["header"]["X-Capture-This"])
-        assert ("X-Capture-That" in asgi_span.data["http"]["header"])
-        assert ("that" == asgi_span.data["http"]["header"]["X-Capture-That"])
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data['http']['path'], '/')
+        self.assertEqual(asgi_span.data['http']['path_tpl'], '/')
+        self.assertEqual(asgi_span.data['http']['method'], 'GET')
+        self.assertEqual(asgi_span.data['http']['status'], 200)
+        self.assertIsNone(asgi_span.data['http']['error'])
+        self.assertIsNone(asgi_span.data['http']['params'])
+
+        self.assertIn("X-Capture-This", asgi_span.data["http"]["header"])
+        self.assertEqual("this", asgi_span.data["http"]["header"]["X-Capture-This"])
+        self.assertIn("X-Capture-That", asgi_span.data["http"]["header"])
+        self.assertEqual("that", asgi_span.data["http"]["header"]["X-Capture-That"])
+
+    def test_response_header_capture(self):
+        with tracer.start_active_span("test"):
+            result = requests.get(testenv["sanic_server"] + "/response_headers")
+
+        self.assertEqual(result.status_code, 200)
+
+        spans = tracer.recorder.queued_spans()
+        self.assertEqual(len(spans), 3)
+
+        span_filter = lambda span: span.n == "sdk" and span.data['sdk']['name'] == 'test'
+        test_span = get_first_span_by_filter(spans, span_filter)
+        self.assertIsNotNone(test_span)
+
+        span_filter = lambda span: span.n == "urllib3"
+        urllib3_span = get_first_span_by_filter(spans, span_filter)
+        self.assertIsNotNone(urllib3_span)
+
+        span_filter = lambda span: span.n == 'asgi'
+        asgi_span = get_first_span_by_filter(spans, span_filter)
+        self.assertIsNotNone(asgi_span)
+
+        self.assertTraceContextPropagated(test_span, urllib3_span)
+        self.assertTraceContextPropagated(urllib3_span, asgi_span)
+
+        self.assertIn("X-INSTANA-T", result.headers)
+        self.assertEqual(result.headers["X-INSTANA-T"], asgi_span.t)
+        self.assertIn("X-INSTANA-S", result.headers)
+        self.assertEqual(result.headers["X-INSTANA-S"], asgi_span.s)
+        self.assertIn("X-INSTANA-L", result.headers)
+        self.assertEqual(result.headers["X-INSTANA-L"], '1')
+        self.assertIn("Server-Timing", result.headers)
+        self.assertEqual(result.headers["Server-Timing"], ("intid;desc=%s" % asgi_span.t))
+
+        self.assertIsNone(asgi_span.ec)
+        self.assertEqual(asgi_span.data['http']['host'], '127.0.0.1:1337')
+        self.assertEqual(asgi_span.data["http"]["path"], "/response_headers")
+        self.assertEqual(asgi_span.data["http"]["path_tpl"], "/response_headers")
+        self.assertEqual(asgi_span.data["http"]["method"], "GET")
+        self.assertEqual(asgi_span.data["http"]["status"], 200)
+
+        self.assertIsNone(asgi_span.data["http"]["error"])
+        self.assertIsNone(asgi_span.data["http"]["params"])
+
+        self.assertIn("X-Capture-This-Too", asgi_span.data["http"]["header"])
+        self.assertEqual("this too", asgi_span.data["http"]["header"]["X-Capture-This-Too"])
+        self.assertIn("X-Capture-That-Too", asgi_span.data["http"]["header"])
+        self.assertEqual("that too", asgi_span.data["http"]["header"]["X-Capture-That-Too"])