Skip to content

celery: wait for exported spans instead of result.ready() in tests - #5015

Open
aniketwaghh wants to merge 1 commit into
open-telemetry:mainfrom
aniketwaghh:fix/celery-test-span-wait
Open

celery: wait for exported spans instead of result.ready() in tests#5015
aniketwaghh wants to merge 1 commit into
open-telemetry:mainfrom
aniketwaghh:fix/celery-test-span-wait

Conversation

@aniketwaghh

Copy link
Copy Markdown

Description

The celery tests wait on result.ready() before asserting on spans, but Celery stores the task result before it dispatches task_postrun, and CeleryInstrumentor ends the run span from its task_postrun receiver. So the result can be ready while the run span has not been ended and exported yet, and the assertion runs against an incomplete exporter. That is the 1 != 2 in the issue.

These now wait for the expected number of exported spans instead. test_task_clears_start_time_cache also waits for the start-time cache to drain, because that pop happens a few statements after the span is ended in the same receiver. test_baggage and test_uninstrument keep result.ready(), which is the right thing for them to wait on.

Test-only change, no instrumentation code touched.

Two things worth flagging:

  • The old loops break on timeout and fall through into the assertion, so a genuine hang showed up as a confusing span-count mismatch. These raise with the reason instead.
  • test_metrics.py waits the same way and has the same race. I left it alone to keep this to one logical change, but it is the same fix if you want it. It already carries a skipif(PyPy, reason="Fails randomly in pypy"), which looks like this race showing up there.

Prior analysis of this race in the docker suite is in #4964 by @Pissinatti-py, for #653. Different file and different issue, so no overlap with this change, but they described the cause first and it is worth reading alongside.

Fixes #5009

Type of change

  • Bug fix (non-breaking change which fixes an issue)

How Has This Been Tested?

Ordering measured on macOS arm64 against f1b9368aa, showing the result landing before the span ends:

   34.304 ms  task_prerun
   35.232 ms  backend.mark_as_failure ENTER
   35.302 ms  task_failure
   35.446 ms  task_postrun          <- run span ends here
   36.029 ms  result.ready() == True
AT result.ready(): ['apply_async/celery_test_tasks.task_raises']
ONE SECOND LATER : ['apply_async/...', 'run/celery_test_tasks.task_raises']

To make it deterministic rather than waiting for a loaded runner, I connected a 0.5s task_postrun receiver ahead of the instrumentor's, which widens the real window without touching any source:

from celery import signals
signals.task_postrun.connect(lambda *a, **k: time.sleep(0.5), weak=False)

With that loaded, on main:

8 failed, 22 passed
FAILED test_tasks.py::TestCeleryInstrumentation::test_task
FAILED test_tasks.py::TestCeleryInstrumentation::test_task_clears_start_time_cache
FAILED test_tasks.py::TestCeleryInstrumentation::test_task_not_instrumented_does_not_raise
FAILED test_tasks.py::TestCeleryInstrumentation::test_task_raises
FAILED test_tasks.py::TestCeleryInstrumentation::test_task_use_span_links
FAILED test_tasks.py::TestCelerySignatureTask::test_hidden_task
FAILED test_metrics.py::TestMetrics::test_basic_metric
FAILED test_metrics.py::TestMetrics::test_metric_uninstrument

test_task_raises fails with AssertionError: 1 != 2 at test_tasks.py:123, the error and line from the CI traceback in the issue.

With this change, same widened window:

2 failed, 28 passed

The six in test_tasks.py are gone. The two remaining are test_metrics.py, which this PR does not touch.

Unmodified suite:

uvx --from tox --with tox-uv tox -e py312-test-instrumentation-celery   ->  30 passed
uvx --from tox --with tox-uv tox -e lint-instrumentation-celery         ->  10.00/10
ruff check / ruff format --check                                        ->  clean
  • Reproduced the race on main and confirmed the fix removes it
  • Full celery suite green on py3.12 and py3.14

Does This PR Require a Core Repo Change?

  • Yes. - Link to PR:
  • No.

Checklist:

  • Followed the style guidelines of this project
  • Changelogs have been updated - test-only, so I believe this needs the Skip Changelog label rather than a fragment. Happy to add one if you would rather have it.
  • Unit tests have been added - existing tests made deterministic
  • Documentation has been updated - not applicable

Celery stores the task result before it dispatches task_postrun, and
CeleryInstrumentor ends the run span from its task_postrun receiver. So an
AsyncResult can be ready while the run span has not been ended and exported
yet, and the span assertions run against an incomplete exporter.

Wait for the expected number of exported spans instead. The window is a
fraction of a millisecond on an idle machine and unbounded on a loaded CI
runner, which is what makes test_task_raises fail with 1 != 2.

test_task_clears_start_time_cache also waits for the start-time cache to
drain, since that pop happens a few statements after the span is ended in the
same receiver. test_baggage and test_uninstrument keep result.ready(), which
is the right thing for them to wait on.
@linux-foundation-easycla

linux-foundation-easycla Bot commented Aug 30, 2026

Copy link
Copy Markdown

CLA Signed
The committers listed above are authorized under a signed CLA.

  • ✅ login: aniketwaghh / name: aniketwaghh (810703d)

@opentelemetry-pr-dashboard

Copy link
Copy Markdown

Pull request dashboard status

Waiting on reviewers · refreshed 2026-08-30 07:23 UTC

Review the latest changes.

Status above doesn't look right?
  • Just replied or pushed? Anything around or after the refresh time above may not be picked up yet — give it a few minutes.
  • Anything look wrong? Report it with what you expected; it helps us improve the dashboard.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

Status: No status

Development

Successfully merging this pull request may close these issues.

Flaky celery test

1 participant