opentelemetry-python icon indicating copy to clipboard operation
opentelemetry-python copied to clipboard

ConcurrentMultiSpanProcessor: cannot schedule new futures after shutdown

Open helderco opened this issue 9 months ago • 2 comments

Describe your environment

OS: macOS 15.2 Python version: 3.13.0

Dependencies from pip install opentelemetry-sdk:

deprecated==1.2.18
importlib-metadata==8.5.0
opentelemetry-api==1.30.0
opentelemetry-sdk==1.30.0
opentelemetry-semantic-conventions==0.51b0
typing-extensions==4.12.2
wrapt==1.17.2
zipp==3.21.0

What happened?

I tried to use the opentelemetry.sdk.trace.ConcurrentMultiSpanProcessor for a library but get an error on shutdown.

Steps to Reproduce

Based on the basic_trace.py example:

from opentelemetry import trace
from opentelemetry.sdk.trace import (
    ConcurrentMultiSpanProcessor,
    TracerProvider,
)
from opentelemetry.sdk.trace.export import (
    BatchSpanProcessor,
    ConsoleSpanExporter,
)

span_proc = ConcurrentMultiSpanProcessor()
span_proc.add_span_processor(BatchSpanProcessor(ConsoleSpanExporter()))

trace.set_tracer_provider(TracerProvider())
trace.get_tracer_provider().add_span_processor(span_proc)

tracer = trace.get_tracer(__name__)
with tracer.start_as_current_span("foo"):
    print("Hello world!")

Running with:

python basic_trace.py

Expected Result

Hello world!
{
    "name": "foo",
    "context": {
        "trace_id": "0xcfd5173b1021291f64aaf996aa5a653c",
        "span_id": "0x4b7f1558bcce9066",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": null,
    "start_time": "2025-03-05T13:33:42.622950Z",
    "end_time": "2025-03-05T13:33:42.623034Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {},
    "events": [],
    "links": [],
    "resource": {
        "attributes": {
            "telemetry.sdk.language": "python",
            "telemetry.sdk.name": "opentelemetry",
            "telemetry.sdk.version": "1.30.0",
            "service.name": "unknown_service"
        },
        "schema_url": ""
    }
}

Actual Result

Hello world!
Exception ignored in atexit callback <bound method TracerProvider.shutdown of <opentelemetry.sdk.trace.TracerProvider object at 0x100ae74d0>>:
Traceback (most recent call last):
  File "/Users/helder/Projects/opentelemetry-python/docs/examples/basic_tracer/.venv/lib/python3.13/site-packages/opentelemetry/sdk/trace/__init__.py", line 1282, in shutdown
    self._active_span_processor.shutdown()
  File "/Users/helder/Projects/opentelemetry-python/docs/examples/basic_tracer/.venv/lib/python3.13/site-packages/opentelemetry/sdk/trace/__init__.py", line 180, in shutdown
    sp.shutdown()
  File "/Users/helder/Projects/opentelemetry-python/docs/examples/basic_tracer/.venv/lib/python3.13/site-packages/opentelemetry/sdk/trace/__init__.py", line 262, in shutdown
    self._submit_and_await(lambda sp: sp.shutdown)
  File "/Users/helder/Projects/opentelemetry-python/docs/examples/basic_tracer/.venv/lib/python3.13/site-packages/opentelemetry/sdk/trace/__init__.py", line 243, in _submit_and_await
    future = self._executor.submit(func(sp), *args, **kwargs)
  File "/Users/helder/Library/Application Support/uv/python/cpython-3.13.0-macos-aarch64-none/lib/python3.13/concurrent/futures/thread.py", line 170, in submit
    raise RuntimeError('cannot schedule new futures after shutdown')
RuntimeError: cannot schedule new futures after shutdown

Additional context

I can avoid the error by manually shutting down in the end of the script:

trace.get_tracer_provider().shutdown()

But since the tracer provider already calls shutdown on exit, can't this be handled automatically without the manual shutdown?

Would you like to implement a fix?

None

helderco avatar Mar 05 '25 13:03 helderco

I'll try the reproducer out myself next week, but it seems like an issue with the atexit handler since you're not calling shutdown on your own. I don't see that obviously in your stack trace though.

Possibly related to https://github.com/python/cpython/issues/86813

aabmass avatar Apr 04 '25 16:04 aabmass

I'm not sure exactly when this broke, but it works on 3.8.

Details

uv run --python 3.8  --script repro_4461.py
Installed 8 packages in 33ms
Hello world!
{
    "name": "foo",
    "context": {
        "trace_id": "0x4b4f33eb7c838b9252507b810c02353c",
        "span_id": "0x4928274a3ff5400c",
        "trace_state": "[]"
    },
    "kind": "SpanKind.INTERNAL",
    "parent_id": null,
    "start_time": "2025-04-07T21:11:20.918046Z",
    "end_time": "2025-04-07T21:11:20.918492Z",
    "status": {
        "status_code": "UNSET"
    },
    "attributes": {},
    "events": [],
    "links": [],
    "resource": {
        "attributes": {
            "telemetry.sdk.language": "python",
            "telemetry.sdk.name": "opentelemetry",
            "telemetry.sdk.version": "1.31.1",
            "service.name": "unknown_service"
        },
        "schema_url": ""
    }
}

Ultimately, it seems like python considers atexit a finalizer and we need a different hook for shutting down the SDK if using multiple threads.

aabmass avatar Apr 07 '25 21:04 aabmass