Automatic download triggered crash and forced recharge

[endurance1968]

this morning I was observing my MPII charging full speed (max current allowed) the batteries even without any sunshine. Only strange observation was that the BatteryAggregator was showing not connected.

Logs:

@40000000665bff9c2fc178b4 Traceback (most recent call last):
@40000000665bff9c2fc1a3ac   File "/data/BatteryAggregator/battery_service.py", line 12, in <module>
@40000000665bff9c2fc1af64     from vedbus import VeDbusService
@40000000665bff9c2fc1b734 ModuleNotFoundError: No module named 'vedbus'
@40000000665bff9e243ef804 Traceback (most recent call last):
@40000000665bff9e243f135c   File "/data/BatteryAggregator/battery_service.py", line 12, in <module>
@40000000665bff9e243f22fc     from vedbus import VeDbusService
@40000000665bff9e243f2acc ModuleNotFoundError: No module named 'vedbus'
@40000000665bff9f321111ec Traceback (most recent call last):
@40000000665bff9f321138fc   File "/data/BatteryAggregator/battery_service.py", line 12, in <module>
@40000000665bff9f321144b4     from vedbus import VeDbusService
@40000000665bff9f32114c84 ModuleNotFoundError: No module named 'vedbus'
@40000000665bffa103441904 Traceback (most recent call last):
@40000000665bffa103444014   File "/data/BatteryAggregator/battery_service.py", line 12, in <module>
@40000000665bffa103444bcc     from vedbus import VeDbusService
@40000000665bffa10344539c ModuleNotFoundError: No module named 'vedbus'
@40000000665bffa2199b986c Traceback (most recent call last):
@40000000665bffa2199bb7ac   File "/data/BatteryAggregator/battery_service.py", line 12, in <module>
@40000000665bffa2199bc364     from vedbus import VeDbusService
@40000000665bffa2199bcf1c ModuleNotFoundError: No module named 'vedbus'

Since I was not there it was cuased by something automatically - then I saw that there is a new version. I set my system to automatically download but not install - seem the download broke the installation since after installing it worked again immediately. There seems to be an issue when downloading but not installing using the packagemanager. Or it was something else creating a strange beavious, just describing observations.

For now I switched off the automatic github check / download.

[endurance1968]

I was able to randomly reproduce the result (charging batteries full speed) by kill dbus-serial BMS, so that Venus do not get any information any more. Interestingly this does not immediately result in a BMS communiction lost and switch to pass through instead the MPII goes into idle. Which can cause this unwanted charging behaviour.

for me this looks like a bug but not sure if in Venus or in BatteryAggregator.

[pulquero]

What is your setup/config.json?

[endurance1968]

{
        "excludedServices": ["com.victronenergy.battery.socketcan_can0_vi0_uc288664"],
        "logLevel": "DEBUG"
}

so intentionally excluded the Shunt otherwise it would have done miscalculations on current etc.

services running are

[pulquero]

Do you have a log of when this happens? In particular, what happens to the CCL value?

[endurance1968]

tried to catch the right point in time

@40000000665e9b4c1217f734 INFO:dbusmonitor:com.victronenergy.battery.ttyUSB0 disappeared from the dbus. Removing it from our lists
@40000000665e9b4c1231303c DEBUG:com.victronenergy.battery.aggregator:Battery removed: com.victronenergy.battery.ttyUSB0
@40000000665e9b4c16175b7c INFO:com.victronenergy.battery.aggregator:Individual CCLs: {}
@40000000665e9b4c1619d064 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b4c162647cc INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c1635341c INFO:com.victronenergy.battery.aggregator:CCL estimates: []
@40000000665e9b4c1654f504 INFO:com.victronenergy.battery.aggregator:Individual DCLs: {}
@40000000665e9b4c1665bde4 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b4c17d3bd34 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c17d9a8d4 INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@40000000665e9b4c18191334 INFO:com.victronenergy.battery.aggregator:Individual DCLs: {}
@40000000665e9b4c191ac7dc INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b4c192cb1cc INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c193fb114 INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@40000000665e9b4c1b86ab44 INFO:com.victronenergy.battery.aggregator:Individual CCLs: {}
@40000000665e9b4c1b96187c INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b4c1ba5722c INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c1bb35cac INFO:com.victronenergy.battery.aggregator:CCL estimates: []

@40000000665e9b4c17d3bd34 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c17d9a8d4 INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@40000000665e9b4c18191334 INFO:com.victronenergy.battery.aggregator:Individual DCLs: {}
@40000000665e9b4c191ac7dc INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b4c192cb1cc INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c193fb114 INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@40000000665e9b4c1b86ab44 INFO:com.victronenergy.battery.aggregator:Individual CCLs: {}
@40000000665e9b4c1b96187c INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b4c1ba5722c INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b4c1bb35cac INFO:com.victronenergy.battery.aggregator:CCL estimates: []
@40000000665e9b751e7c0614 INFO:dbusmonitor:Found: com.victronenergy.battery.ttyUSB0, scanning and storing items
@40000000665e9b791dc8cf2c INFO:dbusmonitor:       com.victronenergy.battery.ttyUSB0 has device instance 1
@40000000665e9b792a3fd19c DEBUG:com.victronenergy.battery.aggregator:Battery added: com.victronenergy.battery.ttyUSB0
@40000000665e9b792c624824 INFO:com.victronenergy.battery.aggregator:Individual CCLs: {dbus.String('com.victronenergy.battery.ttyUSB0'): 150.0}
@40000000665e9b792c72de3c INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b792e022514 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b792e11c8fc INFO:com.victronenergy.battery.aggregator:CCL estimates: []
@40000000665e9b792e352f7c INFO:com.victronenergy.battery.aggregator:Individual DCLs: {dbus.String('com.victronenergy.battery.ttyUSB0'): 140.0}
@40000000665e9b792ee97004 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b792efa061c INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b792f09502c INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@40000000665e9b79304ab584 INFO:com.victronenergy.battery.aggregator:Individual DCLs: {dbus.String('com.victronenergy.battery.ttyUSB0'): 140.0}
@40000000665e9b793057cd14 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b7930655204 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b7931a3b9bc INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@40000000665e9b7931c5fb44 INFO:com.victronenergy.battery.aggregator:Individual CCLs: {dbus.String('com.victronenergy.battery.ttyUSB0'): 150.0}
@40000000665e9b7931d3b2fc INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@40000000665e9b7931e15b14 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@40000000665e9b7931eda39c INFO:com.victronenergy.battery.aggregator:CCL estimates: []

@40000000665e9b80266dedc4 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.ttyUSB0 /Soc 21.8
@40000000665e9b802689b324 DEBUG:com.victronenergy.battery.aggregator:Aggregator for /Soc updated with {com.victronenergy.battery.ttyUSB0: 21.8} now has values {dbus.String('com.victronenergy.battery.ttyUSB0'): 21.8} with result 21.8
@40000000665e9b80280070bc DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.ttyUSB0 /Dc/0/Voltage 53.67
@40000000665e9b8029090b04 DEBUG:com.victronenergy.battery.aggregator:Aggregator for /Dc/0/Voltage updated with {com.victronenergy.battery.ttyUSB0: 53.67} now has values {dbus.String('com.victronenergy.battery.ttyUSB0'): 53.67} with result 53.67
@40000000665e9b802e90094c CRITICAL:ve_utils:exit_on_error: there was an exception. Printing stacktrace will be tried and then exit
@40000000665e9b802e90382c Traceback (most recent call last):
@40000000665e9b802e903ffc   File "/data/BatteryAggregator/ext/ve_utils.py", line 22, in exit_on_error
@40000000665e9b802e904bb4     return func(*args, **kwargs)
@40000000665e9b802e905384   File "/data/BatteryAggregator/ext/dbusmonitor.py", line 345, in _execute_value_changes
@40000000665e9b802e906324     self.valueChangedCallback(serviceName, objectPath,
@40000000665e9b802e927e34   File "/data/BatteryAggregator/battery_service.py", line 496, in _service_value_changed
@40000000665e9b802e9291bc     self._battery_value_changed(dbusServiceName, dbusPath, options, changes, deviceInstance)
@40000000665e9b802e92a15c   File "/data/BatteryAggregator/battery_service.py", line 522, in _battery_value_changed
@40000000665e9b802e92b0fc     self._add_vi_sample(dbusServiceName, voltage, current)
@40000000665e9b802e947a04   File "/data/BatteryAggregator/battery_service.py", line 458, in _add_vi_sample
@40000000665e9b802e9489a4     if irdata.append_sample(voltage, current):
@40000000665e9b802e94955c   File "/data/BatteryAggregator/battery_service.py", line 291, in append_sample
@40000000665e9b802e94a114     if current >= 0:
@40000000665e9b802e94a8e4 TypeError: '>=' not supported between instances of 'NoneType' and 'int'
@40000000665e9b8413315a5c INFO:main:Starting...
@40000000665e9b84182cba74 INFO:dbusmonitor:===== Search on dbus for services that we will monitor starting... =====
@40000000665e9b8419276a3c INFO:dbusmonitor:Found: com.victronenergy.settings, scanning and storing items
@40000000665e9b84196baae4 INFO:dbusmonitor:       com.victronenergy.settings has device instance 0
@40000000665e9b8424f714d4 INFO:dbusmonitor:Found: com.victronenergy.system, scanning and storing items
@40000000665e9b8426e90d4c INFO:dbusmonitor:       com.victronenergy.system has device instance 0
@40000000665e9b842ade635c INFO:dbusmonitor:Found: com.victronenergy.battery.ttyUSB0, scanning and storing items
@40000000665e9b8609855ae4 INFO:dbusmonitor:       com.victronenergy.battery.ttyUSB0 has device instance 1
@40000000665e9b86268b0ecc INFO:dbusmonitor:===== Search on dbus for services that we will monitor finished =====
@40000000665e9b880c22e154 INFO:main:Waiting for batteries (attempt 1 of 30)...
@40000000665e9b880c993e1c INFO:root:registered ourselves on D-Bus as com.victronenergy.battery.aggregator
@40000000665e9b88141e238c DEBUG:com.victronenergy.battery.aggregator:Aggregator for /Alarms/HighTemperature updated with {com.victronenergy.battery.ttyUSB0: 0} now has values {'com.victronenergy.battery.ttyUSB0': 0} with result 0
@40000000665e9b88144bd6c4 DEBUG:com.victronenergy.battery.aggregator:Aggregator for /Alarms/LowTemperature updated with {com.victronenergy.battery.ttyUSB0: 0} now has values {'com.victronenergy.battery.ttyUSB0': 0} with result 0
@40000000665e9b881475ec34 DEBUG:com.victronenergy.battery.aggregator:Aggregator for /Dc/0/Current updated with {com.victronenergy.battery.ttyUSB0: 9.09} now has values {'com.victronenergy.battery.ttyUSB0': 9.09} with result 9.09

as soon as I kill (on the shell) the dbus-serial driver the lost connection is displayed and the current jumps to the 150A. After a while dbus-seriel is automatically restarted and everything goes back to normal.

but I am not worried about the current limit (150A is fine) more about that the is no BMS lost connection alarm and MP should go to passthrough instead of charging. Having charge and discharge limits on 0 would maybe have same effect as workaround. This will work obviously only if at least BA is running. If also BA crashes (as in my first post) it cannot set any limits any more and MPII has to go to passthrough and BMS not connected immediately (which it seems not to do always)

[pulquero]

I've fixed the TypeError. With regard to the alarm, I would need to know how that manifests itself in dbus so I can have BatteryAggregator trigger it.

[endurance1968]

There I unfortunately cannot really help - is there seomthing that can be traced (sometimes I get a BMS connection lost when I kill BA + Dbus serial) and then use the trace to figure out how it should work?

Could the Victron Lynx Shunt be used as fallback BMS if no other is there?

[pulquero]

Yes, you can use the shunt as a fallback, config will be like

{ "auxiliaryServices": {"com.victronenergy.battery.socketcan...."} }

Most people use the BMS as a fallback for the shunt, in which case, replace "auxiliaryServices" with "primaryServices".

[endurance1968]

OK that would be great - was not sure what auxiliary services are - I tried

{
        "auxiliaryServices": ["com.victronenergy.battery.socketcan_can0_vi0_uc288664"],
        "logLevel": "DEBUG"
}

in the logs I get

@400000006660b1331593df54 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Power -4147
@400000006660b1332134f424 INFO:dbusmonitor:com.victronenergy.battery.ttyUSB0 disappeared from the dbus. Removing it from our lists
@400000006660b133218f165c DEBUG:com.victronenergy.battery.aggregator:Battery removed: com.victronenergy.battery.ttyUSB0
@400000006660b13321cfa5b4 INFO:com.victronenergy.battery.aggregator:Individual CCLs: {}
@400000006660b13322863be4 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@400000006660b13322f633f4 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@400000006660b133234d970c INFO:com.victronenergy.battery.aggregator:CCL estimates: []
@400000006660b13323f855fc INFO:com.victronenergy.battery.aggregator:Individual CCLs: {}
@400000006660b133259613f4 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@400000006660b1332634b554 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@400000006660b13326475eac INFO:com.victronenergy.battery.aggregator:CCL estimates: []
@400000006660b13327a42ba4 INFO:com.victronenergy.battery.aggregator:Individual DCLs: {}
@400000006660b1332a4897b4 INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@400000006660b1332a4b04cc INFO:com.victronenergy.battery.aggregator:Current ratios: []
@400000006660b1332a9a2a84 INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@400000006660b1332ab72094 INFO:com.victronenergy.battery.aggregator:Individual DCLs: {}
@400000006660b1332bed1c0c INFO:com.victronenergy.battery.aggregator:Connected batteries: []
@400000006660b1332bed4704 INFO:com.victronenergy.battery.aggregator:Current ratios: []
@400000006660b1332bfd5c34 INFO:com.victronenergy.battery.aggregator:DCL estimates: []
@400000006660b135150f039c DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Voltage 51.18000030517578
@400000006660b135159aad84 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Current -81.19999694824219
@400000006660b13515b1a854 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Power -4155
@400000006660b136151b57dc DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Voltage 51.790000915527344
@400000006660b136153515b4 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Current -14.199999809265137
@400000006660b1361585a6b4 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Power -735
@400000006660b136159b3254 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /ConsumedAmphours -190.1999969482422
@400000006660b13616169ffc DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /TimeToGo 3060
@400000006660b138151dec04 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Voltage 51.90999984741211
@400000006660b138157b88dc DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Current -2.200000047683716
@400000006660b1381597ea7c DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Power -114
@400000006660b13815ce2164 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Soc 33.45000076293945
@400000006660b13915362724 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Voltage 52.650001525878906
@400000006660b139154a300c DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Current 83.0999984741211
@400000006660b13915f30a9c DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /Dc/0/Power 4375
@400000006660b139160c95ac DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /ConsumedAmphours -190.10000610351562
@400000006660b139162549e4 DEBUG:com.victronenergy.battery.aggregator:Battery value changed: com.victronenergy.battery.socketcan_can0_vi0_uc288664 /TimeToGo None

But seems not to be used if I disconnect the serial BMS.

[pulquero]

Try v3.0.64. There was an edge case that wasnt accounted for in the code.

[endurance1968]

using ..64 the switch to the shunt works immediately - big thanks for the speedy fix. there are now only ~2seconds when the serial driver comes back but has no valid data yet where batt agg show all 0 values and the MPII creates a low voltage alarm. Not sure if you could do anything there waiting for valid data before switching back to none aux service. Not sure if you can identify if data is valid or not.

[pulquero]

I've adjusted how it works.

[endurance1968]

Yepp works far better/quicker to switch with valid values. Still there is a short moment of low voltage alarm. Now this is only a few .x s versus several seconds between valid values switch before. Not sure if it can be better - for me OK.

Hope the mechanism having several dbus-serials are still working. Thanks for the improvement which are important for secure operations.