Timeout on reading from ophyd_async if not read from ophyd first

[DominicOram]

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)

[DominicOram]

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]

Could only be on old versions of ophyd/ophyd_async:

ophyd                                    1.9.0
ophyd-async                          0.3.4

[olliesilvester]

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]

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

[DominicOram]

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]

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]

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