Timeout on reading from ophyd_async if not read from ophyd first #791

DominicOram · 2024-09-16T13:25:25Z

During beamline testing it was found that the following script timed out reading from current_pin:

from __future__ import annotations

import bluesky.plan_stubs as bps
from blueapi.core import BlueskyContext
from bluesky.run_engine import RunEngine
from dodal.beamlines import i03
from dodal.devices.detector.detector_motion import DetectorMotion
from dodal.devices.robot import BartRobot


def my_plan(
    robot: BartRobot,
    detector_motion: DetectorMotion,
):
    # Shouldn't be setting det_z here but otherwise following rd doesn't work?!?
    # current_det_z = yield from bps.rd(detector_motion.z)
    # yield from bps.abs_set(detector_motion.z, current_det_z)

    current_pin = yield from bps.rd(robot.current_pin)
    print(current_pin)


context = BlueskyContext()

context.with_dodal_module(
    i03,
    wait_for_connection=True,
)

robot = context.find_device("robot")
detector_motion = context.find_device("detector_motion")

RE = RunEngine()

RE(my_plan(robot, detector_motion))

However, if the current_det_z lines were uncommented it would no longer timeout and was happy to continue. The timeout error was:

Traceback (most recent call last):
  File "/dls_sw/apps/python/miniforge/4.10.0-0/envs/python3.11/lib/python3.11/asyncio/tasks.py", line 490, in wait_for
    return fut.result()
           ^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/ophyd_async/core/signal.py", line 190, in read
    return {self.name: await self._backend_or_cache(cached).get_reading()}
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/ophyd_async/epics/_backend/_aioca.py", line 307, in get_reading
    value = await self._caget(FORMAT_TIME)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/ophyd_async/epics/_backend/_aioca.py", line 295, in _caget
    return await caget(
           ^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/aioca/_catools.py", line 126, in call_wrapper
    return await throw_wrapper(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/aioca/_catools.py", line 108, in throw_wrapper
    return await awaitable
           ^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/aioca/_catools.py", line 158, in ca_timeout
    result = await awaitable
             ^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/aioca/_catools.py", line 709, in caget
    await channel.wait()
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/aioca/_catools.py", line 268, in wait
    await self.__connect_event.wait()
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/aioca/_catools.py", line 66, in wait
    await self._event.wait()
  File "/dls_sw/apps/python/miniforge/4.10.0-0/envs/python3.11/lib/python3.11/asyncio/locks.py", line 213, in wait
    await fut
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/run_engine.py", line 1563, in _run
    msg = self._plan_stack[-1].throw(stashed_exception or resp)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/src/hyperion/scratch_reading_issues.py", line 19, in my_plan
    current_pin = yield from bps.rd(robot.current_pin)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/utils/__init__.py", line 1931, in __iter__
    return (yield from self._iter)
            ^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/plan_stubs.py", line 422, in rd
    ret = yield from read(obj)
          ^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/utils/__init__.py", line 1931, in __iter__
    return (yield from self._iter)
            ^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/plan_stubs.py", line 131, in read
    return (yield Msg("read", obj))
            ^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/run_engine.py", line 1655, in _run
    new_response = await coro(msg)
                   ^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/run_engine.py", line 1944, in _read
    ret = await maybe_await(obj.read(*msg.args, **msg.kwargs))
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/utils/__init__.py", line 1913, in maybe_await
    return await ret
           ^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/ophyd_async/core/signal.py", line 41, in wrapper
    return await asyncio.wait_for(func(self, *args, **kwargs), self._timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/apps/python/miniforge/4.10.0-0/envs/python3.11/lib/python3.11/asyncio/tasks.py", line 492, in wait_for
    raise exceptions.TimeoutError() from exc
TimeoutError
Traceback (most recent call last):
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/src/hyperion/scratch_reading_issues.py", line 35, in <module>
    RE(my_plan(robot, detector_motion))
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/run_engine.py", line 964, in __call__
    plan_return = self._resume_task(init_func=_build_task)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/dls_sw/i03/software/bluesky/hyperion_v9.5.2/hyperion/.venv/lib/python3.11/site-packages/bluesky/run_engine.py", line 1100, in _resume_task
    raise exc
TimeoutError

Acceptance Criteria

Add a dummy read in the robot load plan to make sure it reads from an ophyd device first
Spin out a new issue to remove when aioca is released (see below)

The text was updated successfully, but these errors were encountered:

DominicOram · 2024-09-16T13:28:09Z

I suspect this may be because DetectorMotion is an ophyd device and BartRobot is a n ophyd_async device. Is this a known issue @coretl or @callumforrester?

DominicOram · 2024-09-16T13:36:56Z

Could only be on old versions of ophyd/ophyd_async:

ophyd                                    1.9.0
ophyd-async                          0.3.4

olliesilvester · 2024-09-16T14:36:06Z

I saw a similar issue a few months ago when using both ophyd and ophyd-async devices. I had to run a bluesky plan on an ophyd device before trying to set anything on an ophyd-async device, otherwise it would timeout

coretl · 2024-09-17T09:42:15Z

Does this branch fix the issue: https://github.com/DiamondLightSource/aioca/tree/contexts?

DominicOram · 2024-09-17T15:27:45Z

Great, that fixed it, thank you! Are we able to get it into a release soon? Or will we have to live with reading a dummy ophyd device for a bit?

coretl · 2024-09-17T15:53:11Z

I just have to work out how to write a test for the change... then I can make a release. Maybe a couple of weeks?

DominicOram · 2024-09-17T16:08:23Z

Ok, we will keep the dummy PV for now then. This issue will be for adding the read in on main and spin off a new issue to remove when aioca is released

DominicOram · 2024-10-10T09:09:16Z

Waiting on DiamondLightSource/aioca#51 to be merged

coretl · 2024-10-14T16:49:06Z

Merged and released as aioca 1.8. (Thanks @AlexanderWells-diamond!)

DominicOram · 2024-10-28T17:55:15Z

Now waiting on bluesky/ophyd-async#600 to be merged

DominicOram added this to Hyperion Sep 17, 2024

DominicOram moved this to Todo This Sprint in Hyperion Sep 17, 2024

DominicOram changed the title ~~Timeout on reading from robot if not done a set first~~ Timeout on reading from ophyd_async if not read from ophyd first Oct 1, 2024

DominicOram mentioned this issue Oct 1, 2024

Hyperion testing 01/10 DiamondLightSource/mx-bluesky#545

Closed

DominicOram self-assigned this Oct 3, 2024

DominicOram moved this from Todo This Sprint to In Progress in Hyperion Oct 3, 2024

This was referenced Oct 4, 2024

Sporadic ApertureScatterguard TimeoutErrors reported DiamondLightSource/mx-bluesky#549

Open

Add test for context race condition bluesky/ophyd-async#600

Merged

DominicOram closed this as completed Oct 29, 2024

github-project-automation bot moved this from Review to Done in Hyperion Oct 29, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Timeout on reading from ophyd_async if not read from ophyd first #791

Timeout on reading from ophyd_async if not read from ophyd first #791

DominicOram commented Sep 16, 2024 •

edited

Loading

DominicOram commented Sep 16, 2024

DominicOram commented Sep 16, 2024

olliesilvester commented Sep 16, 2024

coretl commented Sep 17, 2024

DominicOram commented Sep 17, 2024

coretl commented Sep 17, 2024

DominicOram commented Sep 17, 2024

DominicOram commented Oct 10, 2024

coretl commented Oct 14, 2024

DominicOram commented Oct 28, 2024

Timeout on reading from ophyd_async if not read from ophyd first #791

Timeout on reading from ophyd_async if not read from ophyd first #791

Comments

DominicOram commented Sep 16, 2024 • edited Loading

Acceptance Criteria

DominicOram commented Sep 16, 2024

DominicOram commented Sep 16, 2024

olliesilvester commented Sep 16, 2024

coretl commented Sep 17, 2024

DominicOram commented Sep 17, 2024

coretl commented Sep 17, 2024

DominicOram commented Sep 17, 2024

DominicOram commented Oct 10, 2024

coretl commented Oct 14, 2024

DominicOram commented Oct 28, 2024

DominicOram commented Sep 16, 2024 •

edited

Loading