Skip to content
This repository was archived by the owner on Feb 26, 2026. It is now read-only.

fix: 16-bit hexadecimal formatting for XCTC span IDs #946

Merged
gkevinzheng merged 5 commits into from
Oct 15, 2024
Merged

fix: 16-bit hexadecimal formatting for XCTC span IDs #946

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
162af3e
fix: 16-bit hexadecimal formatting for XCTC span IDs
gkevinzheng Oct 11, 2024
b5b6265
🦉 Updates from OwlBot post-processor
gcf-owl-bot[bot] Oct 11, 2024
18d029e
addressed nit
gkevinzheng Oct 14, 2024
f94d288
🦉 Updates from OwlBot post-processor
gcf-owl-bot[bot] Oct 14, 2024
3491f48
Fixed test + docstring
gkevinzheng Oct 15, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 23 additions & 2 deletions google/cloud/logging_v2/handlers/_helpers.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -174,20 +174,41 @@ 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, 32-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))?"
match = re.match(regex, 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
if span_id is not None:
try:
Copy link
Copy Markdown

@michaelsafyan michaelsafyan Oct 14, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You have a lot of layers of nesting here... consider splitting this up into multiple smaller helper functions. For example:

   xctc_trace_id, xctc_span_id, xctc_options = _parse_xct_header(header)
   trace_id = _validate_and_normalize_xctc_trace_id(xctc_trace_id)
   span_id = _validate_and_normalize_xctc_span_id(xctc_span_id)
   sampled = _extract_should_sample_from_xctc_option(xctc_options)

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
Copy link
Copy Markdown
Contributor

@daniel-sanche daniel-sanche Oct 11, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: maybe raise an exception here, since we already have the try/catch?

try:
    span_id_int = int(span_id)
    if span_id_int < 0 or span_id_int > 2**64:
        raise ValueError("span_id outside valid range")
    span_id = f"{span_id_int:016x}"
except ValueError:
    span_id = None

Copy link
Copy Markdown

@michaelsafyan michaelsafyan Oct 14, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If parts of the header fail to validate, you may want to consider making it more obvious that this has happened. Consider some form of debug logging or other tracking if not propagated an error to the caller.

except ValueError:
span_id = None

except IndexError:
pass
return trace_id, span_id, trace_sampled
Expand Down
53 changes: 39 additions & 14 deletions tests/unit/handlers/test__helpers.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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/"}


Expand Down Expand Up @@ -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(
Expand Down Expand Up @@ -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}
Expand Down Expand Up @@ -501,43 +507,62 @@ 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"
input_span = "67890"
expected_span = "10932".zfill(16)
Copy link
Copy Markdown

@michaelsafyan michaelsafyan Oct 14, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is this the expected span when the input span is invalid? Shouldn't the expected span be None?

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_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)
self.assertEqual(sampled, False)

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)
self.assertEqual(sampled, False)

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)
Expand Down
7 changes: 4 additions & 3 deletions tests/unit/handlers/test_handlers.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
"""
Expand All @@ -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,
Expand Down
7 changes: 4 additions & 3 deletions tests/unit/handlers/test_structured_log.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand All @@ -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,
Expand Down