From aa8dcc66b84276be968e4ddbd225333fc648b29d Mon Sep 17 00:00:00 2001 From: "Nikhil Chitlur Navakiran (from Dev Box)" Date: Wed, 27 May 2026 11:04:01 -0600 Subject: [PATCH] fix: use get_span_context() to handle NonRecordingSpan When the token resolver returns None on the first turn, the TracerProvider produces a NonRecordingSpan. The .context attribute only exists on concrete ReadableSpan implementations, causing AttributeError crashes on the first agent message. Replace all span.context accesses with the public get_span_context() interface method, which is available on all Span types including NonRecordingSpan. Also guard the .name access in _end() with getattr() since NonRecordingSpan lacks that attribute as well. Changes: - opentelemetry_scope.py: use get_span_context() in span start/end logging - enriched_span.py: delegate context property via get_span_context() - agent365_exporter.py: use get_span_context() in _map_span() - Update test mocks to set get_span_context() return value - Add test_nonrecording_span.py with 6 targeted tests Ported from: https://github.com/microsoft/opentelemetry-distro-python/pull/168 Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../core/exporters/agent365_exporter.py | 2 +- .../core/exporters/enriched_span.py | 2 +- .../observability/core/opentelemetry_scope.py | 9 +- .../core/exporters/test_enriched_span.py | 1 + .../test_enriching_span_processor.py | 3 + .../core/exporters/test_payload_chunking.py | 1 + .../core/test_agent365_exporter.py | 1 + .../core/test_nonrecording_span.py | 192 ++++++++++++++++++ 8 files changed, 206 insertions(+), 5 deletions(-) create mode 100644 tests/observability/core/test_nonrecording_span.py diff --git a/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/agent365_exporter.py b/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/agent365_exporter.py index 698c6c9f..1acbee61 100644 --- a/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/agent365_exporter.py +++ b/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/agent365_exporter.py @@ -330,7 +330,7 @@ def _build_envelope( } def _map_span(self, sp: ReadableSpan) -> dict[str, Any]: - ctx = sp.context + ctx = sp.get_span_context() parent_span_id = None if sp.parent is not None and sp.parent.span_id != 0: diff --git a/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/enriched_span.py b/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/enriched_span.py index a6b4e8c1..678e4000 100644 --- a/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/enriched_span.py +++ b/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/exporters/enriched_span.py @@ -54,7 +54,7 @@ def name(self): @property def context(self): """Return the span context.""" - return self._span.context + return self._span.get_span_context() @property def parent(self): diff --git a/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/opentelemetry_scope.py b/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/opentelemetry_scope.py index 73474cf1..ff40360f 100644 --- a/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/opentelemetry_scope.py +++ b/libraries/microsoft-agents-a365-observability-core/microsoft_agents_a365/observability/core/opentelemetry_scope.py @@ -158,7 +158,8 @@ def __init__( # Log span creation if self._span: - span_id = f"{self._span.context.span_id:016x}" if self._span.context else "unknown" + sc = self._span.get_span_context() + span_id = f"{sc.span_id:016x}" if sc else "unknown" logger.info(f"Span started: '{activity_name}' ({span_id})") else: logger.error(f"Failed to create span: '{activity_name}' - tracer returned None") @@ -267,8 +268,10 @@ def _end(self) -> None: """End the span and record metrics.""" if self._span and self._is_telemetry_enabled() and not self._has_ended: self._has_ended = True - span_id = f"{self._span.context.span_id:016x}" if self._span.context else "unknown" - logger.info(f"Span ended: '{self._span.name}' ({span_id})") + sc = self._span.get_span_context() + span_id = f"{sc.span_id:016x}" if sc else "unknown" + span_name = getattr(self._span, "name", "unknown") + logger.info(f"Span ended: '{span_name}' ({span_id})") # Convert custom end time to OTel-compatible format (nanoseconds since epoch) otel_end_time = self._datetime_to_ns(self._custom_end_time) diff --git a/tests/observability/core/exporters/test_enriched_span.py b/tests/observability/core/exporters/test_enriched_span.py index 1c4e1f48..f9d0e3ee 100644 --- a/tests/observability/core/exporters/test_enriched_span.py +++ b/tests/observability/core/exporters/test_enriched_span.py @@ -34,6 +34,7 @@ def test_delegates_all_properties_to_wrapped_span(self): mock_span = Mock() mock_span.name = "test-span" mock_span.context = Mock(trace_id=123, span_id=456) + mock_span.get_span_context.return_value = mock_span.context mock_span.parent = Mock(span_id=789) mock_span.start_time = 1000000000 mock_span.end_time = 2000000000 diff --git a/tests/observability/core/exporters/test_enriching_span_processor.py b/tests/observability/core/exporters/test_enriching_span_processor.py index 759a07a4..40e3e334 100644 --- a/tests/observability/core/exporters/test_enriching_span_processor.py +++ b/tests/observability/core/exporters/test_enriching_span_processor.py @@ -99,6 +99,7 @@ def enricher(span): original_span.context = Mock() original_span.context.trace_id = 123 original_span.context.span_id = 456 + original_span.get_span_context.return_value = original_span.context # Call on_end processor.on_end(original_span) @@ -125,6 +126,7 @@ def failing_enricher(span): original_span.context = Mock() original_span.context.trace_id = 123 original_span.context.span_id = 456 + original_span.get_span_context.return_value = original_span.context # Should not raise despite failing enricher processor.on_end(original_span) @@ -142,6 +144,7 @@ def test_on_end_works_without_enricher(self): original_span.context = Mock() original_span.context.trace_id = 123 original_span.context.span_id = 456 + original_span.get_span_context.return_value = original_span.context # Should not raise processor.on_end(original_span) diff --git a/tests/observability/core/exporters/test_payload_chunking.py b/tests/observability/core/exporters/test_payload_chunking.py index 6ed9ba9f..87095f09 100644 --- a/tests/observability/core/exporters/test_payload_chunking.py +++ b/tests/observability/core/exporters/test_payload_chunking.py @@ -151,6 +151,7 @@ def _make_span(self, span_id: int, attribute_size: int) -> ReadableSpan: ctx.trace_id = 0x1 ctx.span_id = span_id mock_span.context = ctx + mock_span.get_span_context.return_value = ctx mock_span.parent = None mock_span.start_time = 1640995200000000000 mock_span.end_time = 1640995260000000000 diff --git a/tests/observability/core/test_agent365_exporter.py b/tests/observability/core/test_agent365_exporter.py index 32ef426f..f3d80ebe 100644 --- a/tests/observability/core/test_agent365_exporter.py +++ b/tests/observability/core/test_agent365_exporter.py @@ -70,6 +70,7 @@ def _create_mock_span( mock_context.trace_id = trace_id mock_context.span_id = span_id mock_span.context = mock_context + mock_span.get_span_context.return_value = mock_context mock_span.parent = Mock() if parent_id else None if parent_id: diff --git a/tests/observability/core/test_nonrecording_span.py b/tests/observability/core/test_nonrecording_span.py new file mode 100644 index 00000000..452d510f --- /dev/null +++ b/tests/observability/core/test_nonrecording_span.py @@ -0,0 +1,192 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Tests that observability code handles NonRecordingSpan gracefully. + +When the TracerProvider has no valid exporter (e.g. token resolver returns +None on the first turn), it produces NonRecordingSpan instances. These only +expose get_span_context() — the .context attribute does not exist. The code +must use get_span_context() everywhere to avoid AttributeError crashes. +""" + +import os +import unittest +from unittest.mock import MagicMock, patch + +from microsoft_agents_a365.observability.core.exporters.enriched_span import ( + EnrichedReadableSpan, +) +from microsoft_agents_a365.observability.core.opentelemetry_scope import ( + OpenTelemetryScope, +) +from opentelemetry.trace import NonRecordingSpan, SpanContext, TraceFlags + + +def _make_non_recording_span(trace_id: int = 0, span_id: int = 0) -> NonRecordingSpan: + """Create a NonRecordingSpan with the given trace/span IDs.""" + return NonRecordingSpan( + SpanContext( + trace_id=trace_id, + span_id=span_id, + is_remote=False, + trace_flags=TraceFlags(0), + ) + ) + + +class TestOpenTelemetryScopeNonRecordingSpan(unittest.TestCase): + """Verify OpenTelemetryScope works when the tracer returns a NonRecordingSpan.""" + + @patch.dict(os.environ, {"ENABLE_OBSERVABILITY": "true"}) + @patch.object(OpenTelemetryScope, "_get_tracer") + def test_init_with_non_recording_span(self, mock_get_tracer: MagicMock) -> None: + """__init__ must not crash when tracer.start_span returns NonRecordingSpan.""" + mock_tracer = MagicMock() + nr_span = _make_non_recording_span(trace_id=0xABCD, span_id=0x1234) + mock_tracer.start_span.return_value = nr_span + mock_get_tracer.return_value = mock_tracer + + # Should not raise AttributeError + scope = OpenTelemetryScope( + operation_name="invoke_agent", + activity_name="test_activity", + ) + + self.assertIs(scope._span, nr_span) + + @patch.dict(os.environ, {"ENABLE_OBSERVABILITY": "true"}) + @patch.object(OpenTelemetryScope, "_get_tracer") + def test_end_with_non_recording_span(self, mock_get_tracer: MagicMock) -> None: + """_end() must not crash when the span is a NonRecordingSpan.""" + mock_tracer = MagicMock() + nr_span = _make_non_recording_span(trace_id=0xABCD, span_id=0x1234) + mock_tracer.start_span.return_value = nr_span + mock_get_tracer.return_value = mock_tracer + + scope = OpenTelemetryScope( + operation_name="invoke_agent", + activity_name="test_activity", + ) + + # Should not raise AttributeError + scope._end() + + @patch.dict(os.environ, {"ENABLE_OBSERVABILITY": "true"}) + @patch.object(OpenTelemetryScope, "_get_tracer") + def test_dispose_with_non_recording_span(self, mock_get_tracer: MagicMock) -> None: + """Full dispose lifecycle must not crash with NonRecordingSpan.""" + mock_tracer = MagicMock() + nr_span = _make_non_recording_span(trace_id=0xABCD, span_id=0x1234) + mock_tracer.start_span.return_value = nr_span + mock_get_tracer.return_value = mock_tracer + + scope = OpenTelemetryScope( + operation_name="invoke_agent", + activity_name="test_activity", + ) + + # Context manager exit should not raise + scope.__exit__(None, None, None) + + +class TestEnrichedReadableSpanNonRecordingSpan(unittest.TestCase): + """Verify EnrichedReadableSpan delegates context via get_span_context().""" + + def test_context_property_uses_get_span_context(self) -> None: + """EnrichedReadableSpan.context must call get_span_context(), not .context.""" + mock_span = MagicMock() + expected_ctx = SpanContext( + trace_id=0xFF, + span_id=0xAA, + is_remote=False, + trace_flags=TraceFlags(0), + ) + mock_span.get_span_context.return_value = expected_ctx + # Ensure .context attribute is NOT used + del mock_span.context + + enriched = EnrichedReadableSpan(mock_span, extra_attributes={"key": "val"}) + + result = enriched.context + self.assertIs(result, expected_ctx) + mock_span.get_span_context.assert_called_once() + + def test_to_json_with_non_recording_span_context(self) -> None: + """to_json() must not crash when wrapped span uses get_span_context().""" + mock_span = MagicMock() + mock_span.name = "test" + mock_span.get_span_context.return_value = SpanContext( + trace_id=0x1234, + span_id=0x5678, + is_remote=False, + trace_flags=TraceFlags(0), + ) + del mock_span.context + mock_span.attributes = {"key": "value"} + mock_span.kind = "INTERNAL" + mock_span.parent = None + mock_span.start_time = 1000000000 + mock_span.end_time = 2000000000 + mock_span.status = None + mock_span.events = [] + mock_span.links = [] + mock_span.resource = None + + enriched = EnrichedReadableSpan(mock_span, extra_attributes={}) + + # Should not raise + json_str = enriched.to_json() + self.assertIn("test", json_str) + self.assertIn("0x00000000000000000000000000001234", json_str) + + +class TestAgent365ExporterMapSpanGetSpanContext(unittest.TestCase): + """Verify _map_span uses get_span_context() instead of .context.""" + + @patch.dict(os.environ, {}, clear=True) + def test_map_span_calls_get_span_context(self) -> None: + """_map_span must use get_span_context(), not .context attribute.""" + from microsoft_agents_a365.observability.core.exporters.agent365_exporter import ( + _Agent365Exporter, + ) + + exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + + span = MagicMock() + span.name = "test_span" + span.attributes = {"gen_ai.operation.name": "invoke_agent"} + + expected_ctx = SpanContext( + trace_id=0xABCD, + span_id=0x1234, + is_remote=False, + trace_flags=TraceFlags(0), + ) + span.get_span_context.return_value = expected_ctx + # Remove .context so it would fail if accessed + del span.context + + span.parent = None + span.kind = MagicMock() + span.start_time = 1000000000 + span.end_time = 2000000000 + span.status = MagicMock() + span.status.status_code = MagicMock() + span.status.description = "" + span.events = [] + span.links = [] + span.instrumentation_scope = MagicMock() + span.instrumentation_scope.name = "test" + span.instrumentation_scope.version = "1.0" + + # Should not raise AttributeError + mapped = exporter._map_span(span) + + span.get_span_context.assert_called_once() + self.assertIn("traceId", mapped) + self.assertIn("spanId", mapped) + exporter.shutdown() + + +if __name__ == "__main__": + unittest.main()