search

dls-controls / aioca

Asynchronous Channel Access client for asyncio and Python using libca via ctypes
Apache License 2.0
6 stars 3 forks source link

Clean shutdown #3

Closed willrogers closed 3 years ago

willrogers commented 3 years ago

I am using aioca.run(start, forever=True) to run my app. I then press Ctrl-C.

I get an extremely long stack trace finishing like the below. It is not clear to me how to exit cleanly.

Coniql exits cleanly via aiohttp.

Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 232, in 'calling callback function'
  File "/scratch/hgs15624/local/venvs/tsim-S4hY2n4f/lib/python3.7/site-packages/aioca/_catools.py", line 174, in on_ca_connect
    self.__event_loop.call_soon_threadsafe(self.on_ca_connect_, op)
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 733, in call_soon_threadsafe
    self._check_closed()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 480, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 232, in 'calling callback function'
  File "/scratch/hgs15624/local/venvs/tsim-S4hY2n4f/lib/python3.7/site-packages/aioca/_catools.py", line 174, in on_ca_connect
    self.__event_loop.call_soon_threadsafe(self.on_ca_connect_, op)
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 733, in call_soon_threadsafe
    self._check_closed()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 480, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
terminate called after throwing an instance of 'epicsMutex::invalidMutex'
  what():  epicsMutex::invalidMutex()
Aborted
thomascobb commented 3 years ago

coniql always closes its monitors before exit, is it that? Can you list a minimal example?

thomascobb commented 3 years ago

Do you get the same result if you use asyncio.run instead of aioca.run?

willrogers commented 3 years ago

Minimal example: 

def start_sim():
    print("starting")

    def print_val(val):
        print(val)

    async def start():
        camonitor("SR-DI-DCCT-01:SIGNAL", print_val)

    aioca.run(start(), forever=True)
    print("done")

Replacing with asyncio.run() means that the process completes and exits with this exception:

starting
done
Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 232, in 'calling callback function'
  File "/scratch/hgs15624/local/venvs/tsim-S4hY2n4f/lib/python3.7/site-packages/aioca/_catools.py", line 174, in on_ca_connect
    self.__event_loop.call_soon_threadsafe(self.on_ca_connect_, op)
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 733, in call_soon_threadsafe
    self._check_closed()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 480, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
_catools_atexit
terminate called after throwing an instance of 'epicsMutex::invalidMutex'
  what():  epicsMutex::invalidMutex()
Aborted

I just edited the above to add logging from _catools_atexit().

thomascobb commented 3 years ago

I get a different result:

import aioca
from aioca import camonitor
import asyncio

def start_sim():
    print("starting")

    async def start():
        camonitor("SR-DI-DCCT-01:SIGNAL", print)

    aioca.run(start(), forever=True)
    print("done")

start_sim()

Gives

$ pipenv run python tests/will_example.py 
starting
0.0008098685749999973
0.0009127748940000041
^CTraceback (most recent call last):
  File "tests/will_example.py", line 15, in <module>
    start_sim()
  File "tests/will_example.py", line 12, in start_sim
    aioca.run(start(), forever=True)
  File "/dls/science/users/tmc43/common/python/aioca/aioca/_catools.py", line 995, in run
    loop.run_forever()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 539, in run_forever
    self._run_once()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 1739, in _run_once
    event_list = self._selector.select(timeout)
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/selectors.py", line 468, in select
    fd_event_list = self._selector.poll(timeout, max_ev)
KeyboardInterrupt

Which is what I expected to find.

I have:

$ pipenv graph
aioca==1.0+3.g79a97ce
  - epicscorelibs [required: >=7.0.3.99.4.0, installed: 7.0.3.99.4.0]
    - numpy [required: Any, installed: 1.18.4]
    - setuptools [required: Any, installed: 51.1.1]
  - numpy [required: Any, installed: 1.18.4]
  - typing-extensions [required: Any, installed: 3.7.4.1]
atomicwrites==1.3.0
flake8-isort==3.0.0
  - flake8 [required: >=3.2.1, installed: 3.7.9]
    - entrypoints [required: >=0.3.0,<0.4.0, installed: 0.3]
    - mccabe [required: >=0.6.0,<0.7.0, installed: 0.6.1]
    - pycodestyle [required: >=2.5.0,<2.6.0, installed: 2.5.0]
    - pyflakes [required: >=2.1.0,<2.2.0, installed: 2.1.1]
  - isort [required: >=4.3.5, installed: 4.3.21]
  - testfixtures [required: Any, installed: 6.14.0]
pytest-asyncio==0.10.0
  - pytest [required: >=3.0.6, installed: 5.4.1]
    - attrs [required: >=17.4.0, installed: 19.3.0]
    - importlib-metadata [required: >=0.12, installed: 1.6.0]
      - zipp [required: >=0.5, installed: 3.1.0]
    - more-itertools [required: >=4.0.0, installed: 8.2.0]
    - packaging [required: Any, installed: 20.3]
      - pyparsing [required: >=2.0.2, installed: 2.4.7]
      - six [required: Any, installed: 1.14.0]
    - pluggy [required: >=0.12,<1.0, installed: 0.13.1]
      - importlib-metadata [required: >=0.12, installed: 1.6.0]
        - zipp [required: >=0.5, installed: 3.1.0]
    - py [required: >=1.5.0, installed: 1.8.1]
    - wcwidth [required: Any, installed: 0.1.9]
pytest-black==0.3.10
  - black [required: Any, installed: 19.10b0]
    - appdirs [required: Any, installed: 1.4.3]
    - attrs [required: >=18.1.0, installed: 19.3.0]
    - click [required: >=6.5, installed: 7.1.1]
    - pathspec [required: >=0.6,<1, installed: 0.7.0]
    - regex [required: Any, installed: 2020.2.20]
    - toml [required: >=0.9.4, installed: 0.10.0]
    - typed-ast [required: >=1.4.0, installed: 1.4.1]
  - pytest [required: >=3.5.0, installed: 5.4.1]
    - attrs [required: >=17.4.0, installed: 19.3.0]
    - importlib-metadata [required: >=0.12, installed: 1.6.0]
      - zipp [required: >=0.5, installed: 3.1.0]
    - more-itertools [required: >=4.0.0, installed: 8.2.0]
    - packaging [required: Any, installed: 20.3]
      - pyparsing [required: >=2.0.2, installed: 2.4.7]
      - six [required: Any, installed: 1.14.0]
    - pluggy [required: >=0.12,<1.0, installed: 0.13.1]
      - importlib-metadata [required: >=0.12, installed: 1.6.0]
        - zipp [required: >=0.5, installed: 3.1.0]
    - py [required: >=1.5.0, installed: 1.8.1]
    - wcwidth [required: Any, installed: 0.1.9]
  - toml [required: Any, installed: 0.10.0]
pytest-cov==2.8.1
  - coverage [required: >=4.4, installed: 5.0.4]
  - pytest [required: >=3.6, installed: 5.4.1]
    - attrs [required: >=17.4.0, installed: 19.3.0]
    - importlib-metadata [required: >=0.12, installed: 1.6.0]
      - zipp [required: >=0.5, installed: 3.1.0]
    - more-itertools [required: >=4.0.0, installed: 8.2.0]
    - packaging [required: Any, installed: 20.3]
      - pyparsing [required: >=2.0.2, installed: 2.4.7]
      - six [required: Any, installed: 1.14.0]
    - pluggy [required: >=0.12,<1.0, installed: 0.13.1]
      - importlib-metadata [required: >=0.12, installed: 1.6.0]
        - zipp [required: >=0.5, installed: 3.1.0]
    - py [required: >=1.5.0, installed: 1.8.1]
    - wcwidth [required: Any, installed: 0.1.9]
pytest-flake8==1.0.6
  - flake8 [required: >=3.5, installed: 3.7.9]
    - entrypoints [required: >=0.3.0,<0.4.0, installed: 0.3]
    - mccabe [required: >=0.6.0,<0.7.0, installed: 0.6.1]
    - pycodestyle [required: >=2.5.0,<2.6.0, installed: 2.5.0]
    - pyflakes [required: >=2.1.0,<2.2.0, installed: 2.1.1]
  - pytest [required: >=3.5, installed: 5.4.1]
    - attrs [required: >=17.4.0, installed: 19.3.0]
    - importlib-metadata [required: >=0.12, installed: 1.6.0]
      - zipp [required: >=0.5, installed: 3.1.0]
    - more-itertools [required: >=4.0.0, installed: 8.2.0]
    - packaging [required: Any, installed: 20.3]
      - pyparsing [required: >=2.0.2, installed: 2.4.7]
      - six [required: Any, installed: 1.14.0]
    - pluggy [required: >=0.12,<1.0, installed: 0.13.1]
      - importlib-metadata [required: >=0.12, installed: 1.6.0]
        - zipp [required: >=0.5, installed: 3.1.0]
    - py [required: >=1.5.0, installed: 1.8.1]
    - wcwidth [required: Any, installed: 0.1.9]
pytest-mypy==0.6.1
  - filelock [required: >=3.0, installed: 3.0.12]
  - mypy [required: >=0.500, installed: 0.770]
    - mypy-extensions [required: >=0.4.3,<0.5.0, installed: 0.4.3]
    - typed-ast [required: >=1.4.0,<1.5.0, installed: 1.4.1]
    - typing-extensions [required: >=3.7.4, installed: 3.7.4.1]
  - pytest [required: >=3.5, installed: 5.4.1]
    - attrs [required: >=17.4.0, installed: 19.3.0]
    - importlib-metadata [required: >=0.12, installed: 1.6.0]
      - zipp [required: >=0.5, installed: 3.1.0]
    - more-itertools [required: >=4.0.0, installed: 8.2.0]
    - packaging [required: Any, installed: 20.3]
      - pyparsing [required: >=2.0.2, installed: 2.4.7]
      - six [required: Any, installed: 1.14.0]
    - pluggy [required: >=0.12,<1.0, installed: 0.13.1]
      - importlib-metadata [required: >=0.12, installed: 1.6.0]
        - zipp [required: >=0.5, installed: 3.1.0]
    - py [required: >=1.5.0, installed: 1.8.1]
    - wcwidth [required: Any, installed: 0.1.9]
sphinx-rtd-theme==0.4.3
  - sphinx [required: Any, installed: 3.0.1]
    - alabaster [required: >=0.7,<0.8, installed: 0.7.12]
    - babel [required: >=1.3, installed: 2.8.0]
      - pytz [required: >=2015.7, installed: 2019.3]
    - docutils [required: >=0.12, installed: 0.16]
    - imagesize [required: Any, installed: 1.2.0]
    - Jinja2 [required: >=2.3, installed: 2.10.1]
      - MarkupSafe [required: >=0.23, installed: 1.1.1]
    - packaging [required: Any, installed: 20.3]
      - pyparsing [required: >=2.0.2, installed: 2.4.7]
      - six [required: Any, installed: 1.14.0]
    - Pygments [required: >=2.0, installed: 2.6.1]
    - requests [required: >=2.5.0, installed: 2.23.0]
      - certifi [required: >=2017.4.17, installed: 2020.4.5.1]
      - chardet [required: >=3.0.2,<4, installed: 3.0.4]
      - idna [required: >=2.5,<3, installed: 2.9]
      - urllib3 [required: >=1.21.1,<1.26,!=1.25.1,!=1.25.0, installed: 1.25.9]
    - setuptools [required: Any, installed: 51.1.1]
    - snowballstemmer [required: >=1.1, installed: 2.0.0]
    - sphinxcontrib-applehelp [required: Any, installed: 1.0.2]
    - sphinxcontrib-devhelp [required: Any, installed: 1.0.2]
    - sphinxcontrib-htmlhelp [required: Any, installed: 1.0.3]
    - sphinxcontrib-jsmath [required: Any, installed: 1.0.1]
    - sphinxcontrib-qthelp [required: Any, installed: 1.0.3]
    - sphinxcontrib-serializinghtml [required: Any, installed: 1.1.4]

What do you have?

thomascobb commented 3 years ago

At shutdown aioca should close all monitors for you. If you put a print in Channel._purge then you should see it being called once for each subscription you have made

willrogers commented 3 years ago

Oh wait hold on

+cothread==2.17

I expect that is the problem. I added cothread so that I could import code from Topup (which in turn imports from cothread.catools) but it's easy to believe wwe are running into problems at exit.

I don't see exactly the same problem when I do this in a test project but I do get 

starting
0.0009547276685000078
0.0009547276685000078
^CTraceback (most recent call last):
  File "atest.py", line 21, in <module>
    start_sim()
  File "atest.py", line 17, in start_sim
    run(start(), forever=True)
  File "/scratch/hgs15624/local/venvs/a-EouiYCWm/lib/python3.7/site-packages/aioca/_catools.py", line 995, in run
    loop.run_forever()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 539, in run_forever
    self._run_once()
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/asyncio/base_events.py", line 1739, in _run_once
    event_list = self._selector.select(timeout)
  File "/dls_sw/prod/tools/RHEL7-x86_64/Python3/3-7-2dls1/prefix/lib/python3.7/selectors.py", line 468, in select
    fd_event_list = self._selector.poll(timeout, max_ev)
KeyboardInterrupt
Segmentation fault
Araneidae commented 3 years ago

Mixing cothread and aioca sounds exciting. I wonder if there's a straightforward way to prevent doing that... there's going to be some funny interactions, can't quite think what will and won't work.

thomascobb commented 3 years ago

I guess we make one aware of the other, but which way round?

Can you run under gdb and get a backtrace of the seg fault?

thomascobb commented 3 years ago

Unless we can tell if a ca_context has already been created and raise there?

willrogers commented 3 years ago

A very brief experiment suggests that they do work side by side.

The offending line is cadef.ca_context_destroy(); if I comment this in catools.py then I no longer see problems.

I'm not going to chase this further now though.

willrogers commented 3 years ago

You can get a clean shutdown by running the following at startup.

import atexit
from cothread.catools import _catools_atexit

atexit.unregister(_catools_atexit)

That allows cothread to be imported. Using them together is a whole other experiment.