diff --git a/CHANGELOG.md b/CHANGELOG.md index 2c693841fc7..ec1aba73ef9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - docs: Added sqlcommenter example ([#4734](https://github.com/open-telemetry/opentelemetry-python/pull/4734)) +- feat: implement on ending in span processor + ([#4775](https://github.com/open-telemetry/opentelemetry-python/pull/4775)) ## Version 1.38.0/0.59b0 (2025-10-16) diff --git a/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py b/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py index a1c0576520e..18ed76d6ad0 100644 --- a/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py +++ b/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py @@ -113,6 +113,16 @@ def on_start( parent_context: The parent context of the span that just started. """ + def _on_ending(self, span: "Span") -> None: + """Called when a :class:`opentelemetry.trace.Span` is ending. + + This method is called synchronously on the thread that ends the + span, therefore it should not block or throw an exception. + + Args: + span: The :class:`opentelemetry.trace.Span` that is ending. + """ + def on_end(self, span: "ReadableSpan") -> None: """Called when a :class:`opentelemetry.trace.Span` is ended. @@ -170,6 +180,10 @@ def on_start( for sp in self._span_processors: sp.on_start(span, parent_context=parent_context) + def _on_ending(self, span: "Span") -> None: + for sp in self._span_processors: + sp._on_ending(span) + def on_end(self, span: "ReadableSpan") -> None: for sp in self._span_processors: sp.on_end(span) @@ -254,6 +268,9 @@ def on_start( lambda sp: sp.on_start, span, parent_context=parent_context ) + def _on_ending(self, span: "Span") -> None: + self._submit_and_await(lambda sp: sp._on_ending, span) + def on_end(self, span: "ReadableSpan") -> None: self._submit_and_await(lambda sp: sp.on_end, span) @@ -945,6 +962,7 @@ def end(self, end_time: Optional[int] = None) -> None: self._end_time = end_time if end_time is not None else time_ns() + self._span_processor._on_ending(self) self._span_processor.on_end(self._readable_span()) @_check_span_ended diff --git a/opentelemetry-sdk/tests/trace/test_span_processor.py b/opentelemetry-sdk/tests/trace/test_span_processor.py index c672d4ce102..bd188432646 100644 --- a/opentelemetry-sdk/tests/trace/test_span_processor.py +++ b/opentelemetry-sdk/tests/trace/test_span_processor.py @@ -32,6 +32,10 @@ def span_event_start_fmt(span_processor_name, span_name): return span_processor_name + ":" + span_name + ":start" +def span_event_ending_fmt(span_processor_name, span_name): + return span_processor_name + ":" + span_name + ":ending" + + def span_event_end_fmt(span_processor_name, span_name): return span_processor_name + ":" + span_name + ":end" @@ -50,6 +54,11 @@ def on_end(self, span: "trace.Span") -> None: self.span_list.append(span_event_end_fmt(self.name, span.name)) +class MyExtendedSpanProcessor(MySpanProcessor): + def _on_ending(self, span: "trace.Span") -> None: + self.span_list.append(span_event_ending_fmt(self.name, span.name)) + + class TestSpanProcessor(unittest.TestCase): def test_span_processor(self): tracer_provider = trace.TracerProvider() @@ -120,6 +129,84 @@ def test_span_processor(self): # compare if two lists are the same self.assertListEqual(spans_calls_list, expected_list) + def test_span_processor_with_on_ending(self): + tracer_provider = trace.TracerProvider() + tracer = tracer_provider.get_tracer(__name__) + + spans_calls_list = [] # filled by MySpanProcessor + expected_list = [] # filled by hand + + # Span processors are created but not added to the tracer yet + sp1 = MyExtendedSpanProcessor("SP1", spans_calls_list) + sp2 = MyExtendedSpanProcessor("SP2", spans_calls_list) + + with tracer.start_as_current_span("foo"): + with tracer.start_as_current_span("bar"): + with tracer.start_as_current_span("baz"): + pass + + # at this point lists must be empty + self.assertEqual(len(spans_calls_list), 0) + + # add single span processor + tracer_provider.add_span_processor(sp1) + + with tracer.start_as_current_span("foo"): + expected_list.append(span_event_start_fmt("SP1", "foo")) + + with tracer.start_as_current_span("bar"): + expected_list.append(span_event_start_fmt("SP1", "bar")) + + with tracer.start_as_current_span("baz"): + expected_list.append(span_event_start_fmt("SP1", "baz")) + + expected_list.append(span_event_ending_fmt("SP1", "baz")) + expected_list.append(span_event_end_fmt("SP1", "baz")) + + expected_list.append(span_event_ending_fmt("SP1", "bar")) + expected_list.append(span_event_end_fmt("SP1", "bar")) + + expected_list.append(span_event_ending_fmt("SP1", "foo")) + expected_list.append(span_event_end_fmt("SP1", "foo")) + + self.assertListEqual(spans_calls_list, expected_list) + + spans_calls_list.clear() + expected_list.clear() + + # go for multiple span processors + tracer_provider.add_span_processor(sp2) + + with tracer.start_as_current_span("foo"): + expected_list.append(span_event_start_fmt("SP1", "foo")) + expected_list.append(span_event_start_fmt("SP2", "foo")) + + with tracer.start_as_current_span("bar"): + expected_list.append(span_event_start_fmt("SP1", "bar")) + expected_list.append(span_event_start_fmt("SP2", "bar")) + + with tracer.start_as_current_span("baz"): + expected_list.append(span_event_start_fmt("SP1", "baz")) + expected_list.append(span_event_start_fmt("SP2", "baz")) + + expected_list.append(span_event_ending_fmt("SP1", "baz")) + expected_list.append(span_event_ending_fmt("SP2", "baz")) + expected_list.append(span_event_end_fmt("SP1", "baz")) + expected_list.append(span_event_end_fmt("SP2", "baz")) + + expected_list.append(span_event_ending_fmt("SP1", "bar")) + expected_list.append(span_event_ending_fmt("SP2", "bar")) + expected_list.append(span_event_end_fmt("SP1", "bar")) + expected_list.append(span_event_end_fmt("SP2", "bar")) + + expected_list.append(span_event_ending_fmt("SP1", "foo")) + expected_list.append(span_event_ending_fmt("SP2", "foo")) + expected_list.append(span_event_end_fmt("SP1", "foo")) + expected_list.append(span_event_end_fmt("SP2", "foo")) + + # compare if two lists are the same + self.assertListEqual(spans_calls_list, expected_list) + def test_add_span_processor_after_span_creation(self): tracer_provider = trace.TracerProvider() tracer = tracer_provider.get_tracer(__name__) @@ -176,6 +263,20 @@ def test_on_start(self): ) multi_processor.shutdown() + def test_on_ending(self): + multi_processor = self.create_multi_span_processor() + + mocks = [mock.Mock(spec=trace.SpanProcessor) for _ in range(0, 5)] + for mock_processor in mocks: + multi_processor.add_span_processor(mock_processor) + + span = self.create_default_span() + multi_processor._on_ending(span) + + for mock_processor in mocks: + mock_processor._on_ending.assert_called_once_with(span) + multi_processor.shutdown() + def test_on_end(self): multi_processor = self.create_multi_span_processor() diff --git a/opentelemetry-sdk/tests/trace/test_trace.py b/opentelemetry-sdk/tests/trace/test_trace.py index 7b23c11fa1f..43f08cb3c5a 100644 --- a/opentelemetry-sdk/tests/trace/test_trace.py +++ b/opentelemetry-sdk/tests/trace/test_trace.py @@ -1428,6 +1428,10 @@ def span_event_start_fmt(span_processor_name, span_name): return span_processor_name + ":" + span_name + ":start" +def span_event_ending_fmt(span_processor_name, span_name): + return span_processor_name + ":" + span_name + ":ending" + + def span_event_end_fmt(span_processor_name, span_name): return span_processor_name + ":" + span_name + ":end" @@ -1442,6 +1446,9 @@ def on_start( ) -> None: self.span_list.append(span_event_start_fmt(self.name, span.name)) + def _on_ending(self, span: "trace.ReadableSpan") -> None: + self.span_list.append(span_event_ending_fmt(self.name, span.name)) + def on_end(self, span: "trace.ReadableSpan") -> None: self.span_list.append(span_event_end_fmt(self.name, span.name)) @@ -1478,10 +1485,13 @@ def test_span_processor(self): with tracer.start_as_current_span("baz"): expected_list.append(span_event_start_fmt("SP1", "baz")) + expected_list.append(span_event_ending_fmt("SP1", "baz")) expected_list.append(span_event_end_fmt("SP1", "baz")) + expected_list.append(span_event_ending_fmt("SP1", "bar")) expected_list.append(span_event_end_fmt("SP1", "bar")) + expected_list.append(span_event_ending_fmt("SP1", "foo")) expected_list.append(span_event_end_fmt("SP1", "foo")) self.assertListEqual(spans_calls_list, expected_list) @@ -1504,12 +1514,18 @@ def test_span_processor(self): expected_list.append(span_event_start_fmt("SP1", "baz")) expected_list.append(span_event_start_fmt("SP2", "baz")) + expected_list.append(span_event_ending_fmt("SP1", "baz")) + expected_list.append(span_event_ending_fmt("SP2", "baz")) expected_list.append(span_event_end_fmt("SP1", "baz")) expected_list.append(span_event_end_fmt("SP2", "baz")) + expected_list.append(span_event_ending_fmt("SP1", "bar")) + expected_list.append(span_event_ending_fmt("SP2", "bar")) expected_list.append(span_event_end_fmt("SP1", "bar")) expected_list.append(span_event_end_fmt("SP2", "bar")) + expected_list.append(span_event_ending_fmt("SP1", "foo")) + expected_list.append(span_event_ending_fmt("SP2", "foo")) expected_list.append(span_event_end_fmt("SP1", "foo")) expected_list.append(span_event_end_fmt("SP2", "foo")) @@ -1532,10 +1548,13 @@ def test_add_span_processor_after_span_creation(self): # add span processor after spans have been created tracer_provider.add_span_processor(sp) + expected_list.append(span_event_ending_fmt("SP1", "baz")) expected_list.append(span_event_end_fmt("SP1", "baz")) + expected_list.append(span_event_ending_fmt("SP1", "bar")) expected_list.append(span_event_end_fmt("SP1", "bar")) + expected_list.append(span_event_ending_fmt("SP1", "foo")) expected_list.append(span_event_end_fmt("SP1", "foo")) self.assertListEqual(spans_calls_list, expected_list)