chore: default variables IDs to 128-bit (#180)

Author: dmehala

doc/API.md

@@ -443,24 +443,26 @@ The Datadog nginx module defines additional variables that provide information
 about the currently active trace.
 
 ### `datadog_trace_id`
-`$datadog_trace_id` expands to the decimal representation of the unsigned
-64-bit ID of the currently active trace. If there is no currently active
+`$datadog_trace_id` expands to the hexadecimal representation of the unsigned
+128-bit ID of the currently active trace. If there is no currently active
 trace, then the variable expands to a hyphen character (`-`) instead.
 
 ### `datadog_span_id`
-`$datadog_span_id` expands to the decimal representation of the unsigned 64-bit
+`$datadog_span_id` expands to the hexadecimal representation of the unsigned 128-bit
 ID of the currently active span.If there is no currently active span, then
 the variable expands to a hyphen character (`-`) instead.
 
 Note that if `datadog_trace_locations` is `on`, then `$datadog_span_id` will
 refer to the span associated with the location (outbound request), not its
 parent (inbound request).
 
-### `datadog_trace_id_hex`
-Same as `$datadog_trace_id`, but is the hexadecimal representation of the 128-bit ID. 
+### `datadog_trace_id_64bits_base10`  
+This reflects the legacy behavior prior to `v1.6.0`, where `$datadog_trace_id` evaluated to the decimal representation of the 64-bit trace ID.  
+If there is no currently active span, then the variable expands to a hyphen character (`-`) instead.
 
-### `datadog_span_id_hex`
-Same as `$datadog_span_id`, but is the hexadecimal representation.
+### `datadog_span_id_64bits_base10`  
+This reflects the legacy behavior prior to `v1.6.0`, where `$datadog_span_id` evaluated to the decimal representation of the 64-bit span ID.
+If there is no currently active span, then the variable expands to a hyphen character (`-`) instead.
 
 ### `datadog_location`
 `$datadog_location` expands to the name or pattern of the `location` block that

src/datadog_variable.cpp

@@ -274,9 +274,6 @@ ngx_int_t add_variables(ngx_conf_t* cf) noexcept {
   variable->get_handler = expand_location_variable;
   variable->data = 0;
 
-  ngx_log_error(NGX_LOG_WARN, cf->log, 0,
-                "In the next release, $datadog_trace_id and $datadog_span_id "
-                "will return their values in hexadecimal format.");
   return NGX_OK;
 }
 }  // namespace nginx

src/tracing_library.cpp

@@ -147,17 +147,17 @@ class SpanContextJSONWriter : public dd::DictWriter {
 std::string span_property(std::string_view key, const dd::Span &span) {
   const auto not_found = "-";
 
-  if (key == "trace_id_hex") {
+  if (key == "trace_id_hex" || key == "trace_id") {
     return span.trace_id().hex_padded();
-  } else if (key == "span_id_hex") {
+  } else if (key == "span_id_hex" || key == "span_id") {
     char buffer[17];
     int written =
         std::snprintf(buffer, sizeof(buffer), "%016" PRIx64, span.id());
     assert(written == 16);
     return {buffer, static_cast<size_t>(written)};
-  } else if (key == "trace_id") {
+  } else if (key == "trace_id_64bits_base10") {
     return std::to_string(span.trace_id().low);
-  } else if (key == "span_id") {
+  } else if (key == "span_id_64bits_base10") {
     return std::to_string(span.id());
   } else if (key == "json") {
     SpanContextJSONWriter writer;

test/cases/variables/conf/in_access_log_format.conf

@@ -10,12 +10,17 @@ events {
 http {
     datadog_agent_url http://agent:8126;
 
-    log_format wild_and_crazy escape=none "here is your access record: [$datadog_trace_id, $datadog_span_id, $datadog_json, \"$datadog_location\"]";
+    # Enforce tracecontext propagation style to facilitate 128-bit IDs comparison.
+    # Since, Datadog propagation context set the higher bytes in `x-datadog-trace-id` and the lower part 
+    # in `_dd.p.tid`.
+    datadog_propagation_styles "tracecontext";
+
+    log_format wild_and_crazy_128bits escape=none "here is your access record: [\"$datadog_trace_id\", \"$datadog_span_id\", $datadog_json, \"$datadog_location\"]";
 
     server {
         listen       80;
 
-        access_log /dev/stdout wild_and_crazy;
+        access_log /dev/stdout wild_and_crazy_128bits;
 
         location ~ /https?[0-9]* {
             proxy_pass http://http:8080;

test/cases/variables/conf/in_access_log_format_legacy.conf

@@ -0,0 +1,30 @@
+# "/datadog-tests" is a directory created by the docker build
+# of the nginx test image. It contains the module, the
+# nginx config, and "index.html".
+load_module /datadog-tests/ngx_http_datadog_module.so;
+
+events {
+    worker_connections  1024;
+}
+
+http {
+    datadog_agent_url http://agent:8126;
+
+    log_format wild_and_crazy_64bits escape=none "here is your access record: [\"$datadog_trace_id_64bits_base10\", \"$datadog_span_id_64bits_base10\", $datadog_json, \"$datadog_location\"]";
+
+    server {
+        listen       80;
+
+        access_log /dev/stdout wild_and_crazy_64bits;
+
+        location ~ /https?[0-9]* {
+            proxy_pass http://http:8080;
+        }
+
+        location /sync {
+            # access log in the default format (so we can use it to sync)
+            access_log /dev/stdout;
+            return 200;
+        }
+    }
+}

test/cases/variables/conf/in_request_headers.conf

@@ -10,11 +10,15 @@ events {
 http {
     datadog_agent_url http://agent:8126;
 
+    # Enforce tracecontext propagation style
+    # because Datadog 128-bit trace ID is the composition of the header + `_dd.p.tid`
+    datadog_propagation_styles "tracecontext";
+
     server {
         listen       80;
 
         location ~ /https?[0-9]* {
-            proxy_set_header x-datadog-test-thingy "[$datadog_trace_id, $datadog_span_id, $datadog_json, \"$datadog_location\"]";
+            proxy_set_header x-datadog-test-thingy "[\"$datadog_trace_id\", \"$datadog_span_id\", $datadog_json, \"$datadog_location\"]";
             proxy_pass http://http:8080;
         }
     }

test/cases/variables/conf/which_span_id_in_access_log_format.conf

@@ -10,7 +10,7 @@ events {
 http {
     datadog_agent_url http://agent:8126;
 
-    log_format wild_and_crazy escape=none "here is your span ID: $datadog_span_id";
+    log_format wild_and_crazy escape=none "here is your span ID: \"$datadog_span_id\"";
 
     server {
         listen       80;

test/cases/variables/test_variables.py

@@ -8,7 +8,7 @@
 class TestVariables(case.TestCase):
 
     def test_in_access_log_format(self):
-        conf_path = Path(__file__).parent / './conf/in_access_log_format.conf'
+        conf_path = Path(__file__).parent / "./conf/in_access_log_format.conf"
         conf_text = conf_path.read_text()
 
         status, log_lines = self.orch.nginx_replace_config(
@@ -18,16 +18,17 @@ def test_in_access_log_format(self):
         # Drain any old nginx log lines.
         self.orch.sync_nginx_access_log()
 
-        status, _, body = self.orch.send_nginx_http_request('/http')
+        status, _, body = self.orch.send_nginx_http_request("/http")
         self.assertEqual(200, status, body)
         response = json.loads(body)
-        headers = response['headers']
-        trace_id, span_id = int(headers['x-datadog-trace-id']), int(
-            headers['x-datadog-parent-id'])
+        headers = response["headers"]
+        traceparent = headers["traceparent"]
+        assert traceparent
+        _, trace_id, span_id, _ = traceparent.split("-")
 
         log_lines = self.orch.sync_nginx_access_log()
         num_matching_lines = 0
-        prefix = 'here is your access record: '
+        prefix = "here is your access record: "
         for line in log_lines:
             if not line.startswith(prefix):
                 continue
@@ -37,36 +38,73 @@ def test_in_access_log_format(self):
             self.assertEqual(trace_id, log_trace_id, line)
             self.assertEqual(span_id, log_span_id, line)
             self.assertEqual(dict, type(propagation))
-            self.assertEqual('/https?[0-9]*', location)
+            self.assertEqual("/https?[0-9]*", location)
+
+        self.assertEqual(1, num_matching_lines)
+
+    def test_in_access_log_format_legacy(self):
+        """Using the legacy 64bits trace ID and span ID"""
+        conf_path = Path(
+            __file__).parent / "./conf/in_access_log_format_legacy.conf"
+        conf_text = conf_path.read_text()
+
+        status, log_lines = self.orch.nginx_replace_config(
+            conf_text, conf_path.name)
+        self.assertEqual(0, status, log_lines)
+
+        # Drain any old nginx log lines.
+        self.orch.sync_nginx_access_log()
+
+        status, _, body = self.orch.send_nginx_http_request("/http")
+        self.assertEqual(200, status, body)
+        response = json.loads(body)
+        headers = response["headers"]
+        trace_id = headers["x-datadog-trace-id"]
+        span_id = headers["x-datadog-parent-id"]
+
+        log_lines = self.orch.sync_nginx_access_log()
+        num_matching_lines = 0
+        prefix = "here is your access record: "
+        for line in log_lines:
+            if not line.startswith(prefix):
+                continue
+            num_matching_lines += 1
+            log_trace_id, log_span_id, propagation, location = json.loads(
+                line[len(prefix):])
+            self.assertEqual(trace_id, log_trace_id, line)
+            self.assertEqual(span_id, log_span_id, line)
+            self.assertEqual(dict, type(propagation))
+            self.assertEqual("/https?[0-9]*", location)
 
         self.assertEqual(1, num_matching_lines)
 
     def test_in_request_headers(self):
-        conf_path = Path(__file__).parent / './conf/in_request_headers.conf'
+        conf_path = Path(__file__).parent / "./conf/in_request_headers.conf"
         conf_text = conf_path.read_text()
 
         status, log_lines = self.orch.nginx_replace_config(
             conf_text, conf_path.name)
         self.assertEqual(0, status, log_lines)
 
-        status, _, body = self.orch.send_nginx_http_request('/http')
+        status, _, body = self.orch.send_nginx_http_request("/http")
         self.assertEqual(200, status)
         response = json.loads(body)
-        headers = response['headers']
-        trace_id, span_id = int(headers['x-datadog-trace-id']), int(
-            headers['x-datadog-parent-id'])
+        headers = response["headers"]
+        traceparent = headers["traceparent"]
+        assert traceparent
+        _, trace_id, span_id, _ = traceparent.split("-")
 
         # The service being reverse proxied by nginx returns a JSON response
         # containing the request headers.  By instructing nginx to add headers
         # whose values depend on the variables, we can extract the values of
         # the variables from the response.
-        self.assertIn('x-datadog-test-thingy', headers)
+        self.assertIn("x-datadog-test-thingy", headers)
         header_trace_id, header_span_id, propagation, location = json.loads(
-            headers['x-datadog-test-thingy'])
+            headers["x-datadog-test-thingy"])
         self.assertEqual(trace_id, header_trace_id)
         self.assertEqual(span_id, header_span_id)
         self.assertEqual(dict, type(propagation))
-        self.assertEqual('/https?[0-9]*', location)
+        self.assertEqual("/https?[0-9]*", location)
 
     def test_which_span_id_in_headers(self):
         """Verify that when `datadog_trace_locations` is `on`, the span
@@ -83,31 +121,31 @@ def test_which_span_id_in_headers(self):
           nginx.
         """
         conf_path = Path(
-            __file__).parent / './conf/which_span_id_in_headers.conf'
+            __file__).parent / "./conf/which_span_id_in_headers.conf"
         conf_text = conf_path.read_text()
 
         status, log_lines = self.orch.nginx_replace_config(
             conf_text, conf_path.name)
         self.assertEqual(0, status, log_lines)
 
-        self.orch.sync_service('agent')
+        self.orch.sync_service("agent")
 
         headers = {
-            'X-Datadog-Trace-ID': 123,
-            'X-Datadog-Parent-ID': 456,
-            'X-Datadog-Sampling-Priority': 2  # manual keep
+            "X-Datadog-Trace-ID": 123,
+            "X-Datadog-Parent-ID": 456,
+            "X-Datadog-Sampling-Priority": 2,  # manual keep
         }
-        status, _, body = self.orch.send_nginx_http_request('/http',
+        status, _, body = self.orch.send_nginx_http_request("/http",
                                                             headers=headers)
         self.assertEqual(200, status)
         response = json.loads(body)
-        headers = response['headers']
+        headers = response["headers"]
 
-        self.assertIn('x-datadog-test-thingy', headers)
-        variable_span_id = int(json.loads(headers['x-datadog-test-thingy']))
+        self.assertIn("x-datadog-test-thingy", headers)
+        variable_span_id = headers["x-datadog-test-thingy"]
 
         self.orch.reload_nginx()
-        log_lines = self.orch.sync_service('agent')
+        log_lines = self.orch.sync_service("agent")
 
         # Map {span ID -> parent ID} for each span sent to the agent by nginx.
         # This will allow us to check that $datadog_span_id is the _location_
@@ -122,10 +160,12 @@ def test_which_span_id_in_headers(self):
                 continue
             for chunk in trace:
                 first, *rest = chunk
-                if first['service'] == 'nginx':
+                if first["service"] == "nginx":
                     nginx_sent_a_trace = True
                     for span in chunk:
-                        parent_by_span_id[span['span_id']] = span['parent_id']
+                        parent_by_span_id[format(span["span_id"],
+                                                 "016x")] = format(
+                                                     span["parent_id"], "016x")
 
         self.assertTrue(nginx_sent_a_trace)
         self.assertIn(variable_span_id, parent_by_span_id)
@@ -138,45 +178,45 @@ def test_which_span_id_in_access_log_format(self):
         referred to by the `$datadog_span_id` variable in an access log format
         string is the location span, not the request span.
         """
-        conf_path = Path(
-            __file__).parent / './conf/which_span_id_in_access_log_format.conf'
+        conf_path = (Path(__file__).parent /
+                     "./conf/which_span_id_in_access_log_format.conf")
         conf_text = conf_path.read_text()
 
         status, log_lines = self.orch.nginx_replace_config(
             conf_text, conf_path.name)
         self.assertEqual(0, status, log_lines)
 
-        self.orch.sync_service('agent')
+        self.orch.sync_service("agent")
 
         # Drain any old nginx log lines.
         self.orch.sync_nginx_access_log()
 
         headers = {
-            'X-Datadog-Trace-ID': 123,
-            'X-Datadog-Parent-ID': 456,
-            'X-Datadog-Sampling-Priority': 2  # manual keep
+            "X-Datadog-Trace-ID": 123,
+            "X-Datadog-Parent-ID": 456,
+            "X-Datadog-Sampling-Priority": 2,  # manual keep
         }
-        status, _, body = self.orch.send_nginx_http_request('/http',
+        status, _, body = self.orch.send_nginx_http_request("/http",
                                                             headers=headers)
         self.assertEqual(200, status, body)
         response = json.loads(body)
-        headers = response['headers']
+        headers = response["headers"]
 
         log_lines = self.orch.sync_nginx_access_log()
-        prefix = 'here is your span ID: '
+        prefix = "here is your span ID: "
         logged_span_id = None
         for line in log_lines:
             if not line.startswith(prefix):
                 continue
-            logged_span_id = int(line[len(prefix):])
+            logged_span_id = line[len(prefix) + 1:-1]
 
         self.assertNotEqual(None, logged_span_id)
 
         # Now look at the agent's logs to see the spans actually sent, and
         # verify that `logged_span_id` is the _location_ span, not the request
         # span.
         self.orch.reload_nginx()
-        log_lines = self.orch.sync_service('agent')
+        log_lines = self.orch.sync_service("agent")
 
         parent_by_span_id = {}
         nginx_sent_a_trace = False
@@ -187,10 +227,12 @@ def test_which_span_id_in_access_log_format(self):
                 continue
             for chunk in trace:
                 first, *rest = chunk
-                if first['service'] == 'nginx':
+                if first["service"] == "nginx":
                     nginx_sent_a_trace = True
                     for span in chunk:
-                        parent_by_span_id[span['span_id']] = span['parent_id']
+                        parent_by_span_id[format(span["span_id"],
+                                                 "016x")] = format(
+                                                     span["parent_id"], "016x")
 
         self.assertTrue(nginx_sent_a_trace)
         self.assertIn(logged_span_id, parent_by_span_id)