open-telemetry / open-telemetry/opentelemetry-python

Flaky opentelemetry-sdk tests

Open
#5,113 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Python
Stars
2.6k
Forks
1k
Avg merge
4d 15h
Merged PRs (30d)
19

Description

It looks like there something off regarding the shutdown of a span processor and some issues with the metric exporter as seen in the following logs. The failures and the errors we have below looks unrelated though.

=================================== FAILURES ===================================
__________ TestEventLoggerProvider.test_event_logger_provider_default __________

self = <tests.events.test_events.TestEventLoggerProvider testMethod=test_event_logger_provider_default>

    def test_event_logger_provider_default(self):
        logger_provider = LoggerProvider()
        set_logger_provider(logger_provider)
        event_logger_provider = EventLoggerProvider()
    
>       self.assertEqual(
            event_logger_provider._logger_provider,
            logger_provider,
        )
E       AssertionError: <opentelemetry.sdk._logs._internal.LoggerProvider object at 0x7f4f07441690> != <opentelemetry.sdk._logs._internal.LoggerProvider object at 0x7f4f075e3070>

opentelemetry-sdk/tests/events/test_events.py:45: AssertionError
------------------------------ Captured log call -------------------------------
WARNING  opentelemetry._logs._internal:__init__.py:425 Overriding of current LoggerProvider is not allowed
________ TestParentChildSpanException.test_child_parent_span_exception _________

self = <tests.trace.test_trace.TestParentChildSpanException testMethod=test_child_parent_span_exception>

    def test_child_parent_span_exception(self):
        """
        Tests that a child span does not have its status set to ERROR when a
        parent span raises an exception and the parent span has its
        ``record_exception`` and ``set_status_on_exception`` attributes
        set to ``False``.
        """
    
        set_tracer_provider(TracerProvider())
        tracer = get_tracer(__name__)
    
        exception = Exception("exception")
    
        child_span = None
        try:
            with tracer.start_as_current_span(
                "parent",
                record_exception=False,
                set_status_on_exception=False,
            ) as parent_span:
                with tracer.start_as_current_span(
                    "child",
                ) as child_span:
                    pass
                raise exception
    
        except Exception:  # pylint: disable=broad-exception-caught
            pass
    
>       self.assertIsNotNone(child_span)
E       AssertionError: unexpectedly None

opentelemetry-sdk/tests/trace/test_trace.py:2297: AssertionError
------------------------------ Captured log call -------------------------------
WARNING  opentelemetry.trace:__init__.py:567 Overriding of current TracerProvider is not allowed
________ TestParentChildSpanException.test_parent_child_span_exception _________

self = <tests.trace.test_trace.TestParentChildSpanException testMethod=test_parent_child_span_exception>

    def test_parent_child_span_exception(self):
        """
        Tests that a parent span has its status set to ERROR when a child span
        raises an exception even when the child span has its
        ``record_exception`` and ``set_status_on_exception`` attributes
        set to ``False``.
        """
    
        set_tracer_provider(TracerProvider())
        tracer = get_tracer(__name__)
    
        exception = Exception("exception")
    
        exception_type = exception.__class__.__name__
        exception_message = exception.args[0]
    
        child_span = None
        try:
            with tracer.start_as_current_span(
                "parent",
            ) as parent_span:
                with tracer.start_as_current_span(
                    "child",
                    record_exception=False,
                    set_status_on_exception=False,
                ) as child_span:
                    raise exception
    
        except Exception:  # pylint: disable=broad-exception-caught
            pass
    
>       self.assertIsNotNone(child_span)
E       AssertionError: unexpectedly None

opentelemetry-sdk/tests/trace/test_trace.py:2249: AssertionError

=========================== short test summary info ============================
FAILED opentelemetry-sdk/tests/events/test_events.py::TestEventLoggerProvider::test_event_logger_provider_default
FAILED opentelemetry-sdk/tests/trace/test_trace.py::TestParentChildSpanException::test_child_parent_span_exception
FAILED opentelemetry-sdk/tests/trace/test_trace.py::TestParentChildSpanException::test_parent_child_span_exception
================= 3 failed, 960 passed, 84 warnings in 24.26s ==================
Exception ignored in atexit callback: <bound method TracerProvider.shutdown of <opentelemetry.sdk.trace.TracerProvider object at 0x7f4ef4c2be50>>
Traceback (most recent call last):
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 1443, in shutdown
    self._active_span_processor.shutdown()
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 200, in shutdown
    sp.shutdown()
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 302, in shutdown
    self._submit_and_await(lambda sp: sp.shutdown)
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 279, in _submit_and_await
    future = self._executor.submit(func(sp), *args, **kwargs)
  File "/opt/hostedtoolcache/Python/3.10.20/x64/lib/python3.10/concurrent/futures/thread.py", line 167, in submit
Error:     raise RuntimeError('cannot schedule new futures after shutdown')
RuntimeError: cannot schedule new futures after shutdown
Exception ignored in atexit callback: <bound method TracerProvider.shutdown of <opentelemetry.sdk.trace.TracerProvider object at 0x7f4ef4c50160>>
Traceback (most recent call last):
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 1443, in shutdown
    self._active_span_processor.shutdown()
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 200, in shutdown
    sp.shutdown()
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 302, in shutdown
    self._submit_and_await(lambda sp: sp.shutdown)
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/trace/__init__.py", line 279, in _submit_and_await
    future = self._executor.submit(func(sp), *args, **kwargs)
  File "/opt/hostedtoolcache/Python/3.10.20/x64/lib/python3.10/concurrent/futures/thread.py", line 167, in submit
Error:     raise RuntimeError('cannot schedule new futures after shutdown')
RuntimeError: cannot schedule new futures after shutdown
Can't shutdown multiple times
Can't shutdown multiple times
Exception while exporting metrics
Traceback (most recent call last):
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/metrics/_internal/export/__init__.py", line 575, in _receive_metrics
    self._exporter.export(
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/metrics/_internal/export/__init__.py", line 176, in export
    self.out.write(self.formatter(metrics_data))
ValueError: I/O operation on closed file.
Exception while exporting metrics
Traceback (most recent call last):
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/metrics/_internal/export/__init__.py", line 575, in _receive_metrics
    self._exporter.export(
  File "/home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/src/opentelemetry/sdk/metrics/_internal/export/__init__.py", line 176, in export
    self.out.write(self.formatter(metrics_data))
ValueError: I/O operation on closed file.
py310-test-opentelemetry-sdk: exit 1 (24.96 seconds) /home/runner/work/opentelemetry-python/opentelemetry-python> pytest /home/runner/work/opentelemetry-python/opentelemetry-python/opentelemetry-sdk/tests -ra pid=2423
  py310-test-opentelemetry-sdk: FAIL code 1 (26.39=setup[1.43]+cmd[24.96] seconds)
  evaluation failed :( (27.37 seconds)

Example run https://github.com/open-telemetry/opentelemetry-python/actions/runs/24402949044/job/71282531351?pr=4646

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by running the opentelemetry-sdk pytest command from the report and inspect opentelemetry-sdk/tests/events/test_events.py and opentelemetry-sdk/tests/trace/test_trace.py. Reproduce the three named failures and compare them with the TracerProvider shutdown and metrics exporter errors in the logs. Done means the SDK tests pass reliably without these shutdown or closed-output errors.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
observability-sre, testing-qa
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.