freakent / dbus-mqtt-devices

A driver for Victron VenusOS GX devices to support use of dbus-mqtt/flashmq-mqtt
MIT License
111 stars 24 forks source link

Driver crashed looking up portal id #18

Closed cracker0dks closed 1 year ago

cracker0dks commented 2 years ago

Hey, I registered one device without problems, now (on the second) I get this error and the service restarts:

@40000000627bd6243b47d5ac INFO:logger:Loglevel set to INFO
@40000000627bd6251ce3d214 Traceback (most recent call last):
@40000000627bd6251ce3f53c   File "/usr/lib/python3.8/site-packages/dbus/bus.py", line 177, in activate_name_owner
@40000000627bd6251ce404dc     return self.get_name_owner(bus_name)
@40000000627bd6251ce40cac   File "/usr/lib/python3.8/site-packages/dbus/bus.py", line 361, in get_name_owner
@40000000627bd6251ce41c4c     return self.call_blocking(BUS_DAEMON_NAME, BUS_DAEMON_PATH,
@40000000627bd6251ce4241c   File "/usr/lib/python3.8/site-packages/dbus/connection.py", line 652, in call_blocking
@40000000627bd6251ce5cde4     reply_message = self.send_message_with_reply_and_block(
@40000000627bd6251ce5dd84 dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NameHasNoOwner: Could not get owner of name 'com.victronenergy.system': no such name
@40000000627bd6251ce5f10c
@40000000627bd6251ce5f4f4 During handling of the above exception, another exception occurred:
@40000000627bd6251ce600ac
@40000000627bd6251ce65e6c Traceback (most recent call last):
@40000000627bd6251ce6663c   File "/data/drivers/dbus-mqtt-devices-0.5.1/dbus_mqtt_devices.py", line 83, in <module>
@40000000627bd6251ce675dc     main()
@40000000627bd6251ce679c4   File "/data/drivers/dbus-mqtt-devices-0.5.1/dbus_mqtt_devices.py", line 65, in main
@40000000627bd6251ce68964     handler = MQTTDeviceManager(
@40000000627bd6251ce68d4c   File "/data/drivers/dbus-mqtt-devices-0.5.1/device_manager.py", line 37, in __init__
@40000000627bd6251ce6e33c     self.portalId = self._lookup_portalId()
@40000000627bd6251ce7680c   File "/data/drivers/dbus-mqtt-devices-0.5.1/device_manager.py", line 116, in _lookup_portalId
@40000000627bd6251ce777ac     portalId = VeDbusItemImport(self._dbus_conn, "com.victronenergy.system", "/Serial").get_value()
@40000000627bd6251ce7874c   File "/data/drivers/dbus-mqtt-devices-0.5.1/ext/velib_python/vedbus.py", line 217, in __init__
@40000000627bd6251ce796ec     self._proxy = bus.get_object(serviceName, path, introspect=False)
@40000000627bd6251ce7e8f4   File "/usr/lib/python3.8/site-packages/dbus/bus.py", line 241, in get_object
@40000000627bd6251ce7f4ac     return self.ProxyObjectClass(self, bus_name, object_path,
@40000000627bd6251ce80064   File "/usr/lib/python3.8/site-packages/dbus/proxies.py", line 250, in __init__
@40000000627bd6251ce80c1c     self._named_service = conn.activate_name_owner(bus_name)
@40000000627bd6251ce817d4   File "/usr/lib/python3.8/site-packages/dbus/bus.py", line 182, in activate_name_owner
@40000000627bd6251ce9d13c     self.start_service_by_name(bus_name)
@40000000627bd6251ce9dcf4   File "/usr/lib/python3.8/site-packages/dbus/bus.py", line 277, in start_service_by_name
@40000000627bd6251ce9ec94     return (True, self.call_blocking(BUS_DAEMON_NAME, BUS_DAEMON_PATH,
@40000000627bd6251ce9f84c   File "/usr/lib/python3.8/site-packages/dbus/connection.py", line 652, in call_blocking
@40000000627bd6251cea8cbc     reply_message = self.send_message_with_reply_and_block(
@40000000627bd6251cea9874 dbus.exceptions.DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name com.victronenergy.system was not provided by any .service files

I think I tried to register a device twice (on the same name) or something, now the service is just dead. Even after a cerbo restart. Can I reset all my changes (devices)? I removed them on the cerbo but this is not enough as it seems. Thanks for help

cracker0dks commented 2 years ago

Sorry was my fault: was Sending: "{ "clientId": pvInverterTest3, "connected": 1, "version": "1.0", "services": {"pv10" : "pvinverter"} }" instead of this: "{ "clientId": "pvInverterTest3", "connected": 1, "version": "1.0", "services": {"pv10" : "pvinverter"} }" this crashed the thing :P

freakent commented 2 years ago

Thanks for sharing the error and your fix. Unfortunately I can't see how missing the quotes around pvInverterTest3 would have caused this particular error. The error points to a point in the code where the driver reads the VRM portal id from the dbus. An invalid json payload should not have gotten that far. Please can you send the whole log file. Besides, if a badly formatted json file causes the driver to crash, then the validation needs to be improved.

cracker0dks commented 2 years ago

There is not much I can add from this file but here you go :) current.txt

If you need an other file, let me know

freakent commented 2 years ago

Can you provide details about the Venus GX device you are using? CCGX, Cerbo, Raspberry Pi (which model) or other? What Venus OS version you are running?

The log file suggests things are very unstable. The driver is continually re-starting . That's not good.

cracker0dks commented 2 years ago

A normal Cerbo image

Since I fixed my mistake, the dbus-mqtt-devices not restarting anymore

Edit: /service/dbus-mqtt-devices: up (pid 4707) 1976 seconds this was always resetting after sending a "corrupt" payload

freakent commented 2 years ago

Very puzzling. The driver gets the portal id before it even connects to MQTT so I don't see how the payload caused this. I guess we just wait and see if it happens again. Feel free to post another log file if it happens again over the next few days.