I have a lead! I think this is a subtle network issue (i.e., WiFi is crap), interplaying poorly with the communication protocol Victron have chosen for the VM-3P75CT and a bug in dbus-modbus-client.
I caught this in the act today and I’ve got an idea why it’s misbehaving. From /var/log/dbus-modbus-client/current, I can see the following repeating errors in the small amount of logging that VenusOS seems to retain:
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 147, in update_device
self.del_device(dev)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 324, in del_device
s.del_tree('/Devices/' + dev.get_ident())
^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 371, in get_ident
return '%s_%s' % (self.vendor_id, self.get_unique())
^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 368, in get_unique
return self.info['/Serial']
~~~~~~~~~^^^^^^^^^^^
KeyError: '/Serial'
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 1 items for packing (got 2)
ERROR Uncaught exception in update
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 139, in update_device
dev.update()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 486, in update
self.reinit()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 454, in reinit
self.init(self.settings_dbus, self.enabled)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 463, in init
self.device_init()
File "/opt/victronenergy/dbus-modbus-client/victron_em.py", line 68, in device_init
phase_cfg = self.read_register(self.data_regs[0])
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 121, in read_register
reg.decode( — reidy.re
File "/opt/victronenergy/dbus-modbus-client/register.py", line 78, in decode
v = struct.unpack(self.coding[0], struct.pack(self.coding[1], *values))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: pack expected 1 items for packing (got 2)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 256, in update_timer
self.update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 290, in update
super().update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 239, in update
self.update_device(d)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 147, in update_device
self.del_device(dev)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 324, in del_device
s.del_tree('/Devices/' + dev.get_ident())
^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 371, in get_ident
return '%s_%s' % (self.vendor_id, self.get_unique())
^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 368, in get_unique
return self.info['/Serial']
~~~~~~~~~^^^^^^^^^^^
KeyError: '/Serial'
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 8 items for packing (got 1)
ERROR Uncaught exception in update
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 139, in update_device
dev.update()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 486, in update
self.reinit()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 454, in reinit
self.init(self.settings_dbus, self.enabled)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 464, in init
self.read_info()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 170, in read_info
self.read_info_regs(self.info)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 136, in read_info_regs
self.read_register(reg)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 121, in read_register
reg.decode( — reidy.re
File "/opt/victronenergy/dbus-modbus-client/register.py", line 157, in decode
newval = struct.pack(self.pfmt, *values).rstrip(b'\0')
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: pack expected 8 items for packing (got 1)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 256, in update_timer
self.update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 290, in update
super().update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 239, in update
self.update_device(d)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 147, in update_device
self.del_device(dev)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 324, in del_device
s.del_tree('/Devices/' + dev.get_ident())
^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 371, in get_ident
return '%s_%s' % (self.vendor_id, self.get_unique())
^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 368, in get_unique
return self.info['/Serial']
~~~~~~~~~^^^^^^^^^^^
KeyError: '/Serial'
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 2 items for packing (got 1)
INFO [udp:172.16.4.247:502:1] Found Energy meter: Victron Energy VM-3P75CT
INFO registered ourselves on D-Bus as com.victronenergy.grid.ve_HQ2331JZ4GT
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 2 items for packing (got 1)
ERROR Uncaught exception in update
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 139, in update_device
dev.update()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 486, in update
self.reinit()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 454, in reinit
self.init(self.settings_dbus, self.enabled)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 463, in init
self.device_init()
File "/opt/victronenergy/dbus-modbus-client/victron_em.py", line 76, in device_init
self.fwver = self.read_register(self.info_regs[1])
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 121, in read_register
reg.decode( — reidy.re
File "/opt/victronenergy/dbus-modbus-client/victron_regs.py", line 17, in decode
return self.update(struct.unpack('4B', struct.pack('>2H', *values)))
^^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: pack expected 2 items for packing (got 1)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 256, in update_timer
self.update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 290, in update
super().update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 239, in update
self.update_device(d)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 147, in update_device
self.del_device(dev)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 324, in del_device
s.del_tree('/Devices/' + dev.get_ident())
^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 371, in get_ident
return '%s_%s' % (self.vendor_id, self.get_unique())
^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 368, in get_unique
return self.info['/Serial']
~~~~~~~~~^^^^^^^^^^^
KeyError: '/Serial'
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 1 items for packing (got 2)
ERROR Uncaught exception in update
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 139, in update_device
dev.update()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 486, in update
self.reinit()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 454, in reinit
self.init(self.settings_dbus, self.enabled)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 463, in init
self.device_init()
File "/opt/victronenergy/dbus-modbus-client/victron_em.py", line 68, in device_init
phase_cfg = self.read_register(self.data_regs[0])
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 121, in read_register
reg.decode( — reidy.re
File "/opt/victronenergy/dbus-modbus-client/register.py", line 78, in decode
v = struct.unpack(self.coding[0], struct.pack(self.coding[1], *values))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: pack expected 1 items for packing (got 2)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 256, in update_timer
self.update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 290, in update
super().update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 239, in update
self.update_device(d)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 147, in update_device
self.del_device(dev)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 324, in del_device
s.del_tree('/Devices/' + dev.get_ident())
^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 371, in get_ident
return '%s_%s' % (self.vendor_id, self.get_unique())
^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 368, in get_unique
return self.info['/Serial']
~~~~~~~~~^^^^^^^^^^^
KeyError: '/Serial'
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 8 items for packing (got 1)
ERROR Uncaught exception in update
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 139, in update_device
dev.update()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 486, in update
self.reinit()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 454, in reinit
self.init(self.settings_dbus, self.enabled)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 464, in init
self.read_info()
File "/opt/victronenergy/dbus-modbus-client/device.py", line 170, in read_info
self.read_info_regs(self.info)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 136, in read_info_regs
self.read_register(reg)
File "/opt/victronenergy/dbus-modbus-client/device.py", line 121, in read_register
reg.decode( — reidy.re
File "/opt/victronenergy/dbus-modbus-client/register.py", line 157, in decode
newval = struct.pack(self.pfmt, *values).rstrip(b'\0')
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: pack expected 8 items for packing (got 1)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 256, in update_timer
self.update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 290, in update
super().update()
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 239, in update
self.update_device(d)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 147, in update_device
self.del_device(dev)
File "/opt/victronenergy/dbus-modbus-client/dbus-modbus-client.py", line 324, in del_device
s.del_tree('/Devices/' + dev.get_ident())
^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 371, in get_ident
return '%s_%s' % (self.vendor_id, self.get_unique())
^^^^^^^^^^^^^^^^^
File "/opt/victronenergy/dbus-modbus-client/device.py", line 368, in get_unique
return self.info['/Serial']
~~~~~~~~~^^^^^^^^^^^
KeyError: '/Serial'
INFO [udp:172.16.4.247:502:1] Device failed: pack expected 2 items for packing (got 1)
INFO [udp:172.16.4.247:502:1] Found Energy meter: Victron Energy VM-3P75CT
INFO registered ourselves on D-Bus as com.victronenergy.grid.ve_HQ2331JZ4GT
My working hypothesis is that malformed data is coming in, and dbus-modbus-client not is handling the error terribly gracefully. I’m assuming the data malformation is due to a combination of a sometimes-flaky WiFi connection (even though it doesn’t drop packets according to my network monitoring) and the UDP connection, which lacks any kind of error correction.
There seems to be no validation of the incoming data, hence the unhandled exception. I’m assuming that causes dbus-modbus-client to crash or otherwise misbehave, +/- is then respawned and results in the loop of “disconnect-reconnect” behaviour, which appears in the GUI as the energy meter dropping on and off (and ESS flicking in and out of Pass-Thru mode).
Unfortunately, Victron haven’t allowed issues to be reported in the GitHub repository for dbus-modbus-client, so I’m hoping the only committer I can find on here @ptrenz might be able to take this on notice, or pass it onto someone who can.
I’ll have a play with the code myself in coming days, but this ultimately feels like a bug combined with a good reason not to use WiFi for your energy infrastructure. I’ll know for sure once I change the Cerbo over to a wired connection tomorrow.