DiamondLightSource / DiamondLightSource/dodal
Flakey test_xspress3.py `test_stage_fail_on_detector_not_busy_state` occasionally fails
- Dominant language
- Python
- Stars
- 5
- Forks
- 13
- Avg merge
- 3d 2h
- Merged PRs (30d)
- 10
Description
The folloing test sometimes fails. Example https://github.com/DiamondLightSource/dodal/actions/runs/34215378487/job/102025783196?pr=2050
```
=================================== FAILURES ===================================
__________________ test_stage_fail_on_detector_not_busy_state __________________
Traceback (most recent call last):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/runner.py", line 353, in from_call
result: TResult | None = func()
^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/runner.py", line 245, in
lambda: runtest_hook(item=item, **kwds),
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 167, in _multicall
raise exception
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 139, in _multicall
teardown.throw(exception)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/logging.py", line 850, in pytest_runtest_call
yield
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 139, in _multicall
teardown.throw(exception)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 53, in run_old_style_hookwrapper
return result.get_result()
^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_result.py", line 103, in get_result
raise exc.with_traceback(tb)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 38, in run_old_style_hookwrapper
res = yield
^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 139, in _multicall
teardown.throw(exception)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/capture.py", line 900, in pytest_runtest_call
return (yield)
^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 139, in _multicall
teardown.throw(exception)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 53, in run_old_style_hookwrapper
return result.get_result()
^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_result.py", line 103, in get_result
raise exc.with_traceback(tb)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 38, in run_old_style_hookwrapper
res = yield
^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 139, in _multicall
teardown.throw(exception)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/skipping.py", line 268, in pytest_runtest_call
return (yield)
^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/runner.py", line 179, in pytest_runtest_call
item.runtest()
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pytest_asyncio/plugin.py", line 469, in runtest
super().runtest()
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/python.py", line 1720, in runtest
self.ihook.pytest_pyfunc_call(pyfuncitem=self)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 167, in _multicall
raise exception
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 139, in _multicall
teardown.throw(exception)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 53, in run_old_style_hookwrapper
return result.get_result()
^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_result.py", line 103, in get_result
raise exc.with_traceback(tb)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 38, in run_old_style_hookwrapper
res = yield
^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/python.py", line 166, in pytest_pyfunc_call
result = testfunction(**testargs)
^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pytest_asyncio/plugin.py", line 716, in inner
runner.run(coro, context=context)
File "/usr/lib/python3.12/asyncio/runners.py", line 118, in run
return self._loop.run_until_complete(task)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/asyncio/base_events.py", line 674, in run_until_complete
self.run_forever()
File "/usr/lib/python3.12/asyncio/base_events.py", line 641, in run_forever
self._run_once()
File "/usr/lib/python3.12/asyncio/base_events.py", line 1949, in _run_once
event_list = self._selector.select(timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/selectors.py", line 468, in select
fd_event_list = self._selector.poll(timeout, max_ev)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pytest_timeout.py", line 317, in handler
timeout_sigalrm(item, settings)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/pytest_timeout.py", line 502, in timeout_sigalrm
pytest.fail(PYTEST_FAILURE_MESSAGE % settings.timeout)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/_pytest/outcomes.py", line 163, in __call__
raise Failed(msg=reason, pytrace=pytrace)
Failed: Timeout (>1.0s) from pytest-timeout.
----------------------------- Captured stdout call -----------------------------
+++++++++++++++++++++++++++++++++++ Timeout ++++++++++++++++++++++++++++++++++++
~~~~~~~~~~~~ Stack of Thread-597 (_run_callbacks) (140472207013568) ~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/status.py", line 247, in _run_callbacks
if not self._settled_event.wait(timeout):
File "/usr/lib/python3.12/threading.py", line 655, in wait
signaled = self._cond.wait(timeout)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~ Stack of Thread-594 (_run_callbacks) (140472525776576) ~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/status.py", line 247, in _run_callbacks
if not self._settled_event.wait(timeout):
File "/usr/lib/python3.12/threading.py", line 655, in wait
signaled = self._cond.wait(timeout)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~ Stack of Thread-234 (_run_callbacks) (140472542557888) ~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/status.py", line 247, in _run_callbacks
if not self._settled_event.wait(timeout):
File "/usr/lib/python3.12/threading.py", line 655, in wait
signaled = self._cond.wait(timeout)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~ Stack of Thread-232 (_run_callbacks) (140473106683584) ~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/status.py", line 247, in _run_callbacks
if not self._settled_event.wait(timeout):
File "/usr/lib/python3.12/threading.py", line 655, in wait
signaled = self._cond.wait(timeout)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~ Stack of Thread-229 (_run_callbacks) (140472763803328) ~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/status.py", line 247, in _run_callbacks
if not self._settled_event.wait(timeout):
File "/usr/lib/python3.12/threading.py", line 655, in wait
signaled = self._cond.wait(timeout)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~ Stack of Thread-225 (_run_callbacks) (140472810993344) ~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/status.py", line 247, in _run_callbacks
if not self._settled_event.wait(timeout):
File "/usr/lib/python3.12/threading.py", line 655, in wait
signaled = self._cond.wait(timeout)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~~~~~ Stack of bluesky-run-engine (140473273763520) ~~~~~~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/usr/lib/python3.12/asyncio/base_events.py", line 641, in run_forever
self._run_once()
File "/usr/lib/python3.12/asyncio/base_events.py", line 1949, in _run_once
event_list = self._selector.select(timeout)
File "/usr/lib/python3.12/selectors.py", line 468, in select
fd_event_list = self._selector.poll(timeout, max_ev)
~~~~~~~~~~~~~~~~ Stack of bluesky-run-engine (140474136389312) ~~~~~~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/usr/lib/python3.12/asyncio/base_events.py", line 641, in run_forever
self._run_once()
File "/usr/lib/python3.12/asyncio/base_events.py", line 1949, in _run_once
event_list = self._selector.select(timeout)
File "/usr/lib/python3.12/selectors.py", line 468, in select
fd_event_list = self._selector.poll(timeout, max_ev)
~~~~~~~~~~~~~~~~~~~ Stack of debug_monitor (140474153170624) ~~~~~~~~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/usr/lib/python3.12/threading.py", line 1010, in run
self._target(*self._args, **self._kwargs)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/_dispatch.py", line 164, in _debug_monitor
time.sleep(self.debug_monitor_interval)
~~~~~~~~~~~~~~~~~~~~~~~ Stack of util3 (140474388043456) ~~~~~~~~~~~~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/_dispatch.py", line 46, in run
callback, args, kwargs = self.queue.get(True, self.timeout)
File "/usr/lib/python3.12/queue.py", line 180, in get
self.not_empty.wait(remaining)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~~~~~~~~~~~~ Stack of util2 (140474404824768) ~~~~~~~~~~~~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/_dispatch.py", line 46, in run
callback, args, kwargs = self.queue.get(True, self.timeout)
File "/usr/lib/python3.12/queue.py", line 180, in get
self.not_empty.wait(remaining)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
~~~~~~~~~~~~~~~~~~~~~~~ Stack of util1 (140474421606080) ~~~~~~~~~~~~~~~~~~~~~~~
File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap
self._bootstrap_inner()
File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
self.run()
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd/_dispatch.py", line 46, in run
callback, args, kwargs = self.queue.get(True, self.timeout)
File "/usr/lib/python3.12/queue.py", line 180, in get
self.not_empty.wait(remaining)
File "/usr/lib/python3.12/threading.py", line 359, in wait
gotit = waiter.acquire(True, timeout)
----------------------------- Captured stderr call -----------------------------
I 260908 10:28:34.138 xspress3:123] Arming Xspress3 detector...
I 260908 10:28:34.243 xspress3:123] Arming Xspress3 detector...
I 260908 10:28:34.358 xspress3:138] unstaging Xspress3 detector...
------------------------------ Captured log call -------------------------------
INFO Dodal:xspress3.py:123 Arming Xspress3 detector...
INFO Dodal:xspress3.py:123 Arming Xspress3 detector...
ERROR bluesky:run_engine.py:1761 Run aborted
Traceback (most recent call last):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 565, in observe_signals_value
item = await asyncio.wait_for(q.get(), iteration_timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
return await fut
^^^^^^^^^
File "/usr/lib/python3.12/asyncio/queues.py", line 158, in get
await getter
asyncio.exceptions.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 617, in wait_for_value
await self._wait_for_value(signal)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 606, in _wait_for_value
async for value in observe_value(signal):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 483, in observe_value
async for _, value in observe_signals_value(
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 573, in observe_signals_value
raise asyncio.CancelledError(
asyncio.exceptions.CancelledError: Cancelled Error while waiting Nones to update ['mock+ca://BLXX-EA-DET-007:DetectorState_RBV']. Last observed signal and value were (, )
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 616, in wait_for_value
async with asyncio.timeout(timeout):
File "/usr/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
raise TimeoutError from exc_val
TimeoutError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_status.py", line 41, in wait_with_error_message
return await awaitable
^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/src/dodal/devices/xspress3/xspress3.py", line 125, in stage
await wait_for_value(
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 647, in wait_for_value
await _ValueChecker(match).wait_for_value(signal, timeout)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/ophyd_async/core/_signal.py", line 619, in wait_for_value
raise TimeoutError(
TimeoutError: Xspress3Mini-detector_state didn't match in 0.1s, last value
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/bluesky/run_engine.py", line 1591, in _run
msg = self._plan_stack[-1].throw(stashed_exception or resp)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/bluesky/utils/__init__.py", line 2047, in __iter__
return (yield from self._iter)
^^^^^^^^^^^^^^^^^^^^^
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/bluesky/plan_stubs.py", line 1125, in stage
yield Msg("wait", None, group=group)
File "/home/runner/work/dodal/dodal/.venv/lib/python3.12/site-packages/bluesky/run_engine.py", line 2384, in _status_object_completed
raise FailedStatus(ret) from exc
bluesky.utils.FailedStatus: .wait_with_error_message at 0x7fc24d8d9d50>, errored: TimeoutError("Xspress3Mini-detector_state didn't match in 0.1s, last value ")>
INFO Dodal:xspress3.py:138 unstaging Xspress3 detector...
--------------------------- Captured stderr teardown ---------------------------
I 260908 10:28:34.523 beamline_utils:33] Clearing global path provider: None
I 260908 10:28:34.523 beamline_utils:56] Clearing global config client: None
---------------------------- Captured log teardown -----------------------------
INFO Dodal:beamline_utils.py:33 Clearing global path provider: None
INFO Dodal:beamline_utils.py:56 Clearing global config client: None
================================ tests coverage ================================
```
# Acceptance Criteria
The test is fixed and passes 100% of the time
Contributor guide
Research direction
Start by locating and running test_stage_fail_on_detector_not_busy_state in test_xspress3.py, using the linked GitHub Actions failure as context. Inspect the timeout path and the captured ophyd status callback stacks to identify why the test occasionally exceeds pytest-timeout's one-second limit. Done means the test reliably verifies the detector-not-busy failure without intermittent timeouts.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- testing-qa
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Active
- Clarity
- Mostly clear
- Newbie friendliness
- 58/100