diff --git a/google/cloud/logging_v2/handlers/_helpers.py b/google/cloud/logging_v2/handlers/_helpers.py index 98bf0cd29..ff5838e05 100644 --- a/google/cloud/logging_v2/handlers/_helpers.py +++ b/google/cloud/logging_v2/handlers/_helpers.py @@ -174,13 +174,22 @@ def _parse_xcloud_trace(header): Args: header (str): the string extracted from the X_CLOUD_TRACE header Returns: - Tuple[Optional[dict], Optional[str], bool]: + Tuple[Optional[str], Optional[str], bool]: The trace_id, span_id and trace_sampled extracted from the header Each field will be None if not found. """ trace_id = span_id = None trace_sampled = False - # see https://cloud.google.com/trace/docs/setup for X-Cloud-Trace_Context format + + # As per the format described at https://cloud.google.com/trace/docs/trace-context#legacy-http-header + # "X-Cloud-Trace-Context: TRACE_ID[/SPAN_ID][;o=OPTIONS]" + # for example: + # "X-Cloud-Trace-Context: 105445aa7843bc8bf206b12000100000/1;o=1" + # + # We expect: + # * trace_id (optional, 128-bit hex string): "105445aa7843bc8bf206b12000100000" + # * span_id (optional, 16-bit hex string): "0000000000000001" (needs to be converted into 16 bit hex string) + # * trace_sampled (optional, bool): true if header: try: regex = r"([\w-]+)?(\/?([\w-]+))?(;?o=(\d))?" @@ -188,6 +197,17 @@ def _parse_xcloud_trace(header): trace_id = match.group(1) span_id = match.group(3) trace_sampled = match.group(5) == "1" + + # Convert the span ID to 16-bit hexadecimal instead of decimal + try: + span_id_int = int(span_id) + if span_id_int > 0 and span_id_int < 2**64: + span_id = f"{span_id_int:016x}" + else: + span_id = None + except (ValueError, TypeError): + span_id = None + except IndexError: pass return trace_id, span_id, trace_sampled diff --git a/tests/unit/handlers/test__helpers.py b/tests/unit/handlers/test__helpers.py index b8c8fc99d..d0577cf22 100644 --- a/tests/unit/handlers/test__helpers.py +++ b/tests/unit/handlers/test__helpers.py @@ -25,9 +25,13 @@ _FLASK_TRACE_ID = "flask0id" _FLASK_SPAN_ID = "span0flask" +_FLASK_SPAN_ID_XCTC_DEC = "12345" +_FLASK_SPAN_ID_XCTC_HEX = "3039".zfill(16) _FLASK_HTTP_REQUEST = {"requestUrl": "https://flask.palletsprojects.com/en/1.1.x/"} _DJANGO_TRACE_ID = "django0id" _DJANGO_SPAN_ID = "span0django" +_DJANGO_SPAN_ID_XCTC_DEC = "54321" +_DJANGO_SPAN_ID_XCTC_HEX = "d431".zfill(16) _DJANGO_HTTP_REQUEST = {"requestUrl": "https://www.djangoproject.com/"} @@ -64,8 +68,9 @@ def test_no_context_header(self): def test_xcloud_header(self): flask_trace_header = "X_CLOUD_TRACE_CONTEXT" expected_trace_id = _FLASK_TRACE_ID - expected_span_id = _FLASK_SPAN_ID - flask_trace_id = f"{expected_trace_id}/{expected_span_id};o=1" + input_span_id = _FLASK_SPAN_ID_XCTC_DEC + expected_span_id = _FLASK_SPAN_ID_XCTC_HEX + flask_trace_id = f"{expected_trace_id}/{input_span_id};o=1" app = self.create_app() context = app.test_request_context( @@ -173,9 +178,10 @@ def test_xcloud_header(self): from google.cloud.logging_v2.handlers.middleware import request django_trace_header = "HTTP_X_CLOUD_TRACE_CONTEXT" - expected_span_id = _DJANGO_SPAN_ID + input_span_id = _DJANGO_SPAN_ID_XCTC_DEC + expected_span_id = _DJANGO_SPAN_ID_XCTC_HEX expected_trace_id = _DJANGO_TRACE_ID - django_trace_id = f"{expected_trace_id}/{expected_span_id};o=1" + django_trace_id = f"{expected_trace_id}/{input_span_id};o=1" django_request = RequestFactory().get( "/", **{django_trace_header: django_trace_id} @@ -501,25 +507,40 @@ def test_no_span(self): self.assertEqual(sampled, False) def test_no_trace(self): - header = "/12345" + input_span = "12345" + expected_span = "3039".zfill(16) + header = f"/{input_span}" trace_id, span_id, sampled = self._call_fut(header) self.assertIsNone(trace_id) - self.assertEqual(span_id, "12345") + self.assertEqual(span_id, expected_span) self.assertEqual(sampled, False) def test_with_span(self): expected_trace = "12345" - expected_span = "67890" - header = f"{expected_trace}/{expected_span}" + input_span = "67890" + expected_span = "10932".zfill(16) + header = f"{expected_trace}/{input_span}" trace_id, span_id, sampled = self._call_fut(header) self.assertEqual(trace_id, expected_trace) self.assertEqual(span_id, expected_span) self.assertEqual(sampled, False) + def test_with_span_decimal_not_in_bounds(self): + input_spans = ["0", "9" * 100] + + for input_span in input_spans: + expected_trace = "12345" + header = f"{expected_trace}/{input_span}" + trace_id, span_id, sampled = self._call_fut(header) + self.assertEqual(trace_id, expected_trace) + self.assertIsNone(span_id) + self.assertEqual(sampled, False) + def test_with_extra_characters(self): expected_trace = "12345" - expected_span = "67890" - header = f"{expected_trace}/{expected_span};abc" + input_span = "67890" + expected_span = "10932".zfill(16) + header = f"{expected_trace}/{input_span};abc" trace_id, span_id, sampled = self._call_fut(header) self.assertEqual(trace_id, expected_trace) self.assertEqual(span_id, expected_span) @@ -527,8 +548,9 @@ def test_with_extra_characters(self): def test_with_explicit_no_sampled(self): expected_trace = "12345" - expected_span = "67890" - header = f"{expected_trace}/{expected_span};o=0" + input_span = "67890" + expected_span = "10932".zfill(16) + header = f"{expected_trace}/{input_span};o=0" trace_id, span_id, sampled = self._call_fut(header) self.assertEqual(trace_id, expected_trace) self.assertEqual(span_id, expected_span) @@ -536,8 +558,9 @@ def test_with_explicit_no_sampled(self): def test_with__sampled(self): expected_trace = "12345" - expected_span = "67890" - header = f"{expected_trace}/{expected_span};o=1" + input_span = "67890" + expected_span = "10932".zfill(16) + header = f"{expected_trace}/{input_span};o=1" trace_id, span_id, sampled = self._call_fut(header) self.assertEqual(trace_id, expected_trace) self.assertEqual(span_id, expected_span) diff --git a/tests/unit/handlers/test_handlers.py b/tests/unit/handlers/test_handlers.py index 535c1f4b1..14b2e5cba 100644 --- a/tests/unit/handlers/test_handlers.py +++ b/tests/unit/handlers/test_handlers.py @@ -140,7 +140,7 @@ def test_minimal_record(self): self.assertIsNone(record._labels) self.assertEqual(record._labels_str, "{}") - def test_record_with_request(self): + def test_record_with_xctc_request(self): """ test filter adds http request data when available """ @@ -161,8 +161,9 @@ def test_record_with_request(self): expected_path = "http://testserver/123" expected_agent = "Mozilla/5.0" expected_trace = "123" - expected_span = "456" - combined_trace = f"{expected_trace}/{expected_span};o=1" + input_span = "456" + expected_span = "1c8".zfill(16) + combined_trace = f"{expected_trace}/{input_span};o=1" expected_request = { "requestMethod": "GET", "requestUrl": expected_path, diff --git a/tests/unit/handlers/test_structured_log.py b/tests/unit/handlers/test_structured_log.py index 920ca15ea..908758749 100644 --- a/tests/unit/handlers/test_structured_log.py +++ b/tests/unit/handlers/test_structured_log.py @@ -382,7 +382,7 @@ def test_format_with_arguments(self): result = handler.format(record) self.assertIn(expected_result, result) - def test_format_with_request(self): + def test_format_with_xctc_request(self): import logging import json @@ -393,8 +393,9 @@ def test_format_with_request(self): expected_path = "http://testserver/123" expected_agent = "Mozilla/5.0" expected_trace = "123" - expected_span = "456" - trace_header = f"{expected_trace}/{expected_span};o=1" + input_span = "456" + expected_span = "1c8".zfill(16) + trace_header = f"{expected_trace}/{input_span};o=1" expected_payload = { "logging.googleapis.com/trace": expected_trace, "logging.googleapis.com/spanId": expected_span,