fermi-ad / acsys-python

Python module to access the Fermilab Control System
MIT License
8 stars 4 forks source link

1 -6 status on first setting request #74

Closed beauremus closed 4 months ago

beauremus commented 4 months ago

There are reports of consistent 1 -6 errors.

There is this consistent, repeatable acsys behavior I don’t understand. The first time (in, say, a given work day) that I try to run a script which reads and sets some toy Z:CUBE_n devices, acsys.init() fails with acsys.status.Status: [1 -6], like below. Then I re-try within a few minutes or seconds, and it’s fine.

Traceback (most recent call last):
  File "/Users/user/utils.py", line 137, in safe_call
    result = func(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^
  File "/Users/user/eval.py", line 37, in set_and_get
    sc.apply_settings_once(list(inputs.keys()), list(inputs.values()), role=role)
  File "/Users/user/script.py", line 226, in apply_settings_once
    acsys.run_client(set_once, drf_list=drf_list, value_list=values,settings_role=role)
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/__init__.py", line 828, in run_client
    return loop.run_until_complete(client_fut)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/nest_asyncio.py", line 98, in run_until_complete
    return f.result()
           ^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/asyncio/futures.py", line 203, in result
    raise self._exception.with_traceback(self._exception_tb)
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/asyncio/tasks.py", line 316, in __step_run_and_handle_result
    result = coro.throw(exc)
             ^^^^^^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/__init__.py", line 800, in __client_main
    result = (await main(con, **kwargs))
              ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/user/script.py", line 46, in set_once
    await dpm.enable_settings(role=settings_role)
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/dpm/__init__.py", line 708, in enable_settings
    msg = await self._auth_step(None)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/dpm/__init__.py", line 651, in _auth_step
    _, msg = await self.con.request_reply(self.dpm_task, msg,
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/__init__.py", line 666, in request_reply
    return (await rpy_fut)
            ^^^^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/asyncio/futures.py", line 287, in __await__
    yield self  # This tells Task to wait for completion.
    ^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/asyncio/tasks.py", line 385, in __wakeup
    future.result()
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/asyncio/futures.py", line 203, in result
    raise self._exception.with_traceback(self._exception_tb)
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/__init__.py", line 661, in reply_handler
    rpy_fut.set_result(process_reply(reply))
                       ^^^^^^^^^^^^^^^^^^^^
  File "/Users/user/miniconda3/envs/xopt-dev/lib/python3.12/site-packages/acsys/__init__.py", line 635, in process_reply
    raise sts
acsys.status.Status: [1 -6]

We can add a 5-second timeout here: https://github.com/fermi-ad/acsys-python/blob/78833871ce08aa524a6696077e6628d2ea567b62/acsys/dpm/__init__.py#L714

_, msg = await self.con.request_reply(self.dpm_task, msg,
                                      timeout=5000,
                                      proto=acsys.dpm.dpm_protocol)

This should allow enough time for the extra auth overhead.

rneswold commented 4 months ago

@jasonstjohn offered to try it locally. If he reports that the problem is fixed, we'll release a new version using this change.