eclipse-volttron / volttron-core

Other
5 stars 9 forks source link

VOLTTRON PLATFORM HAS SHUTDOWN raise RuntimeError("VIP loop ended prematurely") #174

Closed kefeimo closed 1 year ago

kefeimo commented 1 year ago

When running vctl install VOLTTRON platform shutdown

Traceback (most recent call last): File "src/gevent/greenlet.py", line 908, in gevent._gevent_cgreenlet.Greenlet.run File "/home/kefei/miniconda3/envs/volttron-modular/lib/python3.10/site-packages/volttron/client/vip/agent/core.py", line 298, in run raise RuntimeError("VIP loop ended prematurely") RuntimeError: VIP loop ended prematurely 2023-06-01T22:50:39Z <Greenlet at 0x7f4ac293be20: <bound method BasicCore.run of <volttron.client.vip.agent.core.ZMQCore object at 0x7f4ac23b2f50>>(<gevent._gevent_cevent.Event object at 0x7f4ac220a)> failed with RuntimeError

Shutting down.


### How to reproduce
With   [6171c2c (HEAD -> develop, origin/develop) developed config workflow](https://github.com/kefeimo/volttron-boptest/commit/6171c2c0e512450c9e5406835db3fc5efbf5fc40),
run the following command for couple of times (change the --agent-config and repo-root-path accordingly) 

vctl install /home/kefei/project/volttron-boptest \ --agent-config /home/kefei/project/volttron-boptest/boptest-agent-config.json \ --vip-identity boptest-agent \ --start --force

craig8 commented 1 year ago

Please trim the head that you posted to an agent that can be installed. (Create a gist of the agent and associated files)

Note this may be an issue with you using miniconda rather than cpython.

If you can provide an agent and config in this issue I can try it on my side and see if I can reproduce.

So this killed the platform because it was an unexpected exception.

kefeimo commented 1 year ago

Please trim the head that you posted to an agent that can be installed. (Create a gist of the agent and associated files)

Note this may be an issue with you using miniconda rather than cpython.

If you can provide an agent and config in this issue I can try it on my side and see if I can reproduce.

So this killed the platform because it was an unexpected exception.

It require to deploy the boptest server to reproduce. Maybe it is not worthy it.

Close the issue as the root cause is too extensive.

craig8 commented 1 year ago

I think it is worth it...since it should not have an effect on our running volttron. But if @shwethanidd thinks its not worth it.

kefeimo commented 1 year ago

version: volttron 10.0.4rc1 python: Python 3.10.9 OS: ubuntu 22.04 agent codebase: 2edb6d8

To reproduce

  1. create a venv python -m venv env, then source env/bin/activate.
  2. (assuming the rest of the command is operated within the venv)
  3. install volttron pip install volttron==10.0.4rc1
  4. git clone agent repo, (assuming to /tmp) git clone https://github.com/kefeimo/volttron-boptest.git
  5. then check out to commit 2edb6d8: git checkout 2edb6d8
  6. run the vctl install command (assuming agent path is at /tmp/volttron-boptest)
    vctl install /tmp/volttron-boptest \
    --agent-config /tmp/volttron-boptest/boptest-agent-config.json \
    --vip-identity boptest-agent \
    --start --force

Note: the first time when running vctl install the platform might not shut down. But running the second time might cause it. Note: No boptest side installation is required.

bbartling commented 1 year ago

When I started VOLTTRON without the actuator agent like this:

$ vctl status
UUID   AGENT                             IDENTITY                     TAG PRIORITY STATUS          HEALTH
9      openadrloadshed-0.1.0             example-agent                             running [2831]  GOOD
5      volttron-actuator-0.1.1a6         volttron-actuator-0.1.1a6_1
8      volttron-bacnet-proxy-0.2.0rc0    platform.bacnet_proxy                     running [2832]  GOOD
7      volttron-listener-0.2.0rc0        volttron-listener-0.2.0rc0_1              running [2833]  GOOD
c      volttron-openadr-ven-1.0.2rc1     openleadrvenagent.ven                     running [2834]  GOOD
6      volttron-platform-driver-0.2.1rc1 platform.driver                           running [2883]  GOOD
(env) bbartling@vm-bbartling2:~$ vctl restart 6
Stopping 6882bd28-46fb-4411-8836-b2628957307a volttron-platform-driver-0.2.1rc1
Starting 6882bd28-46fb-4411-8836-b2628957307a volttron-platform-driver-0.2.1rc1
(env) bbartling@vm-bbartling2:~$ vctl status
UUID   AGENT                             IDENTITY                     TAG PRIORITY STATUS          HEALTH
9      openadrloadshed-0.1.0             example-agent                             running [2831]  GOOD
5      volttron-actuator-0.1.1a6         volttron-actuator-0.1.1a6_1
8      volttron-bacnet-proxy-0.2.0rc0    platform.bacnet_proxy                     running [2832]  GOOD
7      volttron-listener-0.2.0rc0        volttron-listener-0.2.0rc0_1              running [2833]  GOOD
c      volttron-openadr-ven-1.0.2rc1     openleadrvenagent.ven                     running [2834]  GOOD
6      volttron-platform-driver-0.2.1rc1 platform.driver                           running [2947]  GOOD

agents are up and good health but no BACnet telemetry data printed in the message bus. I think notice lots of these errors when the platform driver was restarted as demonstrated above attempting to try get the BACnet telemetry working.

2023-06-23 13:30:58,048 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "/home/bbartling/env/lib/python3.10/site-packages/volttron/driver/base/driver.py", line 176, in get_interface
2023-06-23 13:30:58,049 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:     module = self.get_driver_module(driver_config, driver_type)
2023-06-23 13:30:58,049 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "/home/bbartling/env/lib/python3.10/site-packages/volttron/driver/base/driver.py", line 192, in get_driver_module
2023-06-23 13:30:58,050 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:     return get_module(f"volttron.driver.interfaces.{driver_type}.{driver_type}")
2023-06-23 13:30:58,051 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "/home/bbartling/env/lib/python3.10/site-packages/volttron/utils/dynamic_helper.py", line 55, in get_module
2023-06-23 13:30:58,052 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:     raise e
2023-06-23 13:30:58,052 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "/home/bbartling/env/lib/python3.10/site-packages/volttron/utils/dynamic_helper.py", line 52, in get_module
2023-06-23 13:30:58,053 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:     return importlib.import_module(module)
2023-06-23 13:30:58,054 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "/usr/lib/python3.10/importlib/__init__.py", line 126, in import_module
2023-06-23 13:30:58,054 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:     return _bootstrap._gcd_import(name[level:], package, level)
2023-06-23 13:30:58,055 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
2023-06-23 13:30:58,056 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
2023-06-23 13:30:58,057 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 992, in _find_and_load_unlocked
2023-06-23 13:30:58,057 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
2023-06-23 13:30:58,058 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
2023-06-23 13:30:58,059 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
2023-06-23 13:30:58,060 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 992, in _find_and_load_unlocked
2023-06-23 13:30:58,060 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
2023-06-23 13:30:58,061 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
2023-06-23 13:30:58,062 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
2023-06-23 13:30:58,063 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:   File "<frozen importlib._bootstrap>", line 1004, in _find_and_load_unlocked
2023-06-23 13:30:58,064 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR: ModuleNotFoundError: No module named 'volttron.driver.interfaces'
2023-06-23 13:30:58,064 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR: 2023-06-23T18:30:57Z <Greenlet at 0x7f759f588040: <bound method DriverAgent.starting of <volttron.driver.base.driver.DriverAgent object at 0x7f759f7255a0>>(<volttron.client.vip.agent.core.BasicCore object a)> failed with ModuleNotFoundError
2023-06-23 13:30:58,065 (volttron-platform-driver-0.2.1rc1 2947) <stderr>(0) ERROR:

Pip list on Ubuntu 22 LTS Python3.10.6

keyring                  23.13.1
lockfile                 0.12.2
lxml                     4.9.2
MarkupSafe               2.1.3
more-itertools           9.1.0
msgpack                  1.0.5
multidict                6.0.4
openadrloadshed          0.1.0
openleadr                0.5.27
packaging                23.1
pathspec                 0.11.1
pexpect                  4.8.0
pip                      22.2.2
pkginfo                  1.9.6
platformdirs             3.8.0
pluggy                   1.2.0
plumbum                  1.8.2
poetry                   1.5.1
poetry-core              1.6.1
poetry-plugin-export     1.4.0
prompt-toolkit           3.0.38
psutil                   5.9.5
ptyprocess               0.7.0
pycparser                2.21
pydantic                 1.10.9
Pygments                 2.15.1
pyOpenSSL                22.0.0
pyproject_hooks          1.0.0
pyrsistent               0.19.3
pytest                   7.4.0
pytest-timeout           2.1.0
python-dateutil          2.8.2
pytz                     2023.3
pytz-deprecation-shim    0.1.0.post0
PyYAML                   6.0
pyyaml-include           1.3
pyzmq                    25.1.0
questionary              1.10.0
rapidfuzz                2.15.1
requests                 2.31.0
requests-toolbelt        1.0.0
SecretStorage            3.3.3
setuptools               59.6.0
shellingham              1.5.0.post1
signxml                  2.10.1
six                      1.16.0
toml                     0.10.2
tomli                    2.0.1
tomlkit                  0.11.8
trove-classifiers        2023.5.24
types-pytz               2023.3.0.0
types-tzlocal            4.3.0.0
typing_extensions        4.6.3
tzdata                   2023.3
tzlocal                  4.3.1
urllib3                  1.26.16
virtualenv               20.23.1
volttron                 10.0.4rc1
volttron-actuator        0.1.1a6
volttron-bacnet-proxy    0.2.0rc0
volttron-lib-base-driver 0.1.1a7
volttron-listener        0.2.0rc0
volttron-openadr-ven     1.0.2rc1
volttron-platform-driver 0.2.1rc1
watchdog                 3.0.0
watchdog-gevent          0.1.1
wcwidth                  0.2.6
webencodings             0.5.1
xmltodict                0.13.0
yarl                     1.9.2
zipp                     3.15.0
zope.event               5.0
zope.interface           6.0
kefeimo commented 1 year ago

Another situation might trigger this issue is removing agent while it is still running. Possibably underneath the hood it will call --force, which is likely the root cause of this issue.

log

Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 908, in gevent._gevent_cgreenlet.Greenlet.run
  File "/home/kefei/miniconda3/envs/volttron-modular/lib/python3.10/site-packages/volttron/client/vip/agent/core.py", line 888, in vip_loop
    handle(message)
  File "/home/kefei/miniconda3/envs/volttron-modular/lib/python3.10/site-packages/volttron/client/vip/agent/core.py", line 589, in handle_error
    error = VIPError.from_errno(*args)
  File "/home/kefei/miniconda3/envs/volttron-modular/lib/python3.10/site-packages/volttron/client/vip/agent/errors.py", line 47, in from_errno
    errnum = int(errnum)
ValueError: invalid literal for int() with base 10: 'Errno.EHOSTUNREACH'
2023-07-07T05:24:42Z <Greenlet at 0x7fa777d5a480: vip_loop> failed with ValueError

Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 908, in gevent._gevent_cgreenlet.Greenlet.run
  File "/home/kefei/miniconda3/envs/volttron-modular/lib/python3.10/site-packages/volttron/client/vip/agent/core.py", line 298, in run
    raise RuntimeError("VIP loop ended prematurely")
RuntimeError: VIP loop ended prematurely
2023-07-07T05:24:42Z <Greenlet at 0x7fa777d5a160: <bound method BasicCore.run of <volttron.client.vip.agent.core.ZMQCore object at 0x7fa777d856f0>>(<gevent._gevent_cevent.Event object at 0x7fa77772d)> failed with RuntimeError

Shutting down.
kefeimo commented 1 year ago

@craig8 Found another example to trigger this error. When using RPC call.

To reproduce

Then run the "volttron-boptest/examples/vip_example.py" script

craig8 commented 1 year ago

Can you provide more context @kefeimo? When using RPC call is not specific enough to be actionable.