Closed Schnullerbacke2 closed 3 days ago
After a reboot without successful reconnection, the log shows the following.
2024-07-03 21:54:49.437041500 2024-07-03 21:54:50.191633500 INFO:SerialBattery: 2024-07-03 21:54:50.192071500 INFO:SerialBattery:Starting dbus-serialbattery 2024-07-03 21:54:50.193135500 INFO:SerialBattery:Venus OS v3.33 2024-07-03 21:54:50.193590500 INFO:SerialBattery:dbus-serialbattery v1.2.20240401 2024-07-03 21:55:06.468249500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:BA:6F 2024-07-03 21:55:06.468532500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:BA:6F 2024-07-03 21:55:17.097821500 INFO:SerialBattery:--> asy_connect_and_scrape(): device not found: C8:47:8C:EC:BA:6F 2024-07-03 21:55:17.098157500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 21:55:17.185993500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:BA:6F 2024-07-03 21:55:17.186304500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble 2024-07-03 21:55:17.376305500 [CHG] Device C8:47:8C:EC:BA:6F RSSI: -57 2024-07-03 21:55:17.376572500 2024-07-03 21:55:17.376633500 INFO:Bluetooth details 2024-07-03 21:55:17.408004500 Attempting to disconnect from C8:47:8C:EC:BA:6F 2024-07-03 21:55:17.408009500 Successful disconnected 2024-07-03 21:55:22.449397500 Device C8:47:8C:EC:BA:6F (public) 2024-07-03 21:55:22.449402500 Alias: JK_B2A24S15P 2024-07-03 21:55:22.449404500 Paired: no 2024-07-03 21:55:22.449407500 Trusted: no 2024-07-03 21:55:22.449409500 Blocked: no 2024-07-03 21:55:22.449411500 Connected: no 2024-07-03 21:55:22.449413500 LegacyPairing: no 2024-07-03 21:55:22.449415500 UUID: Device Information (0000180a-0000-1000-8000-00805f9b34fb) 2024-07-03 21:55:22.449419500 RSSI: -55 2024-07-03 21:55:22.451376500 2024-07-03 21:55:23.155704500 INFO:SerialBattery: 2024-07-03 21:55:23.155975500 INFO:SerialBattery:Starting dbus-serialbattery 2024-07-03 21:55:23.156872500 INFO:SerialBattery:Venus OS v3.33 2024-07-03 21:55:23.157143500 INFO:SerialBattery:dbus-serialbattery v1.2.20240401 2024-07-03 21:55:39.424715500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:BA:6F 2024-07-03 21:55:39.425001500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:BA:6F 2024-07-03 21:55:40.626482500 INFO:SerialBattery:--> asy_connect_and_scrape(): error while connecting to bt: BleakDBusError('org.bluez.Error.Failed', 'Software caused connection abort') of type <class 'bleak.exc.BleakDBusError'> in /opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py line #474 2024-07-03 21:55:40.627076500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 21:55:40.630664500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 21:55:40.746956500 [CHG] Device C8:47:8C:EC:BA:6F RSSI: -55 2024-07-03 21:55:40.746961500 [CHG] Device C8:47:8C:EC:BA:6F RSSI: -55 2024-07-03 21:55:40.746965500 [CHG] Device C8:47:8C:EC:BA:6F RSSI is nil 2024-07-03 21:55:42.722294500 Starting bluetooth: bluetoothd. 2024-07-03 21:55:42.744304500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 21:55:55.095326500 INFO:SerialBattery:--> asy_connect_and_scrape(): device not found: C8:47:8C:EC:BA:6F 2024-07-03 21:55:55.095638500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 21:55:55.153250500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:BA:6F 2024-07-03 21:55:55.153646500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble ...
Additional information - Jkbms: Hardware Ver.: V11.XW Software Ver.: V11.26
After several reboots a I was able to restore a connection. Periodical a reconnect-beep each roughly minute accorse.
Log:
2024-07-03 22:22:30.084866500 [CHG] Device C8:47:8C:EC:BA:6F RSSI: -77 2024-07-03 22:22:30.084874500 [CHG] Device C8:47:8C:EC:BA:6F RSSI: -78 2024-07-03 22:22:30.084879500 [CHG] Device C8:47:8C:EC:BA:6F RSSI is nil 2024-07-03 22:22:32.023222500 Starting bluetooth: bluetoothd. 2024-07-03 22:22:32.046447500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 22:23:42.869651500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 22:23:42.872635500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 22:23:44.969469500 Starting bluetooth: bluetoothd. 2024-07-03 22:23:44.991916500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 22:24:55.866244500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 22:24:55.868883500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 22:24:57.961846500 Starting bluetooth: bluetoothd. 2024-07-03 22:24:57.980363500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 22:26:02.896132500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 22:26:02.898873500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 22:26:04.992019500 Starting bluetooth: bluetoothd. 2024-07-03 22:26:05.010720500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 22:27:09.902714500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 22:27:09.904826500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 22:27:11.997207500 Starting bluetooth: bluetoothd. 2024-07-03 22:27:12.015723500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 22:28:16.897239500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 22:28:16.899233500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 22:28:18.990674500 Starting bluetooth: bluetoothd. 2024-07-03 22:28:19.009483500 INFO:SerialBattery:System Bluetooth daemon should have been restarted 2024-07-03 22:29:23.907271500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit 2024-07-03 22:29:23.909872500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered 2024-07-03 22:29:26.004568500 Starting bluetooth: bluetoothd. 2024-07-03 22:29:26.025009500 INFO:SerialBattery:System Bluetooth daemon should have been restarted
I have the same issue. I turned off the bluetooth in the Venus GX device (serial battery turns it on itself) so it worked better. However, it still hung from time to time. The solution for me so far is to switch off NodeRed. I don't understand why and how NodeRed has an influence, CPU load is good, temperature too and I only have a few nodes for displaying voltage and current or for day/night adjustment of the feed.
What kind of system do I have? Three battery blocks (16S 280Ah) each with a JKB2A20S20P, connected via Bluetooth, three Multiplus 3000 and three MPPT charge controllers.
With NodeRed switched off, it runs quite stable, regulates and limits the voltages perfectly to a maximum of 3.45V, then drops to 3.35V. So far so good. But what is still a problem are the many cell imbalance warnings, even though there is no load and a real maximum difference of 5mV.
Unfortunately my knowledge of Bluetooth connections is very limited and I'm not able to solve and troubleshoot this problem. Any help is very welcome!
I'm having a similar problem. First thing I tried to do is run the /etc/init.d/bluetooth restart script to restart bluetoothd, but this doesn't seem to work.
I just started having this problem. I used to lose connection every couple weeks, and a restart of the Cerbo would solve it. This morning, it has happened three times already. A restart solves it for a bit.
I am using Large OS. Updating now to 3.41 to see if that helps. Next step is to try a bluetooth dongle instead of built-in bluetooth.
I just started having this problem. I used to lose connection every couple weeks, and a restart of the Cerbo would solve it. This morning, it has happened three times already. A restart solves it for a bit.
I am using Large OS. Updating now to 3.41 to see if that helps. Next step is to try a bluetooth dongle instead of built-in bluetooth.
I also started having connection disrupts. I believe it was with updating to 3.41. I try to go back to 3.40. Could you find any solutions? I need to power cycle the cerbo gx every day. Sometimes if I can still reach it, it says no battery manager found. It was running more or less stable before. I also suspect some shelly dms or mqtt connection problem to have an influence as the problem increased since my home assistant instance with a mqtt broker stopped working because of an update.
I dont really know how to trouble shoot as i can barely reach the device.
I've got the same Problem, but I belive the BMS is the problem. What makes me think of that? Even rebooting or disconnect the Raspberry PI3b from the power source doesn't help. But if I press the button on the BMS for 5 seconds, the dbus serialbattery is able to connect automatically.
I'll check if there is a firmware update for the BMS.
This is the endless loop tring to reconnect:
2024-10-01 15:58:47.650939500 INFO:SerialBattery:
2024-10-01 15:58:47.651412500 INFO:SerialBattery:Starting dbus-serialbattery
2024-10-01 15:58:47.652900500 INFO:SerialBattery:Venus OS v3.42
2024-10-01 15:58:47.653332500 INFO:SerialBattery:dbus-serialbattery v1.4.20240928
2024-10-01 15:59:03.999950500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:80:03:B1:8D
2024-10-01 15:59:04.000444500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:80:03:B1:8D
2024-10-01 15:59:05.920678500 INFO:SerialBattery:--> asy_connect_and_scrape(): error while connecting to bt: BleakDBusError('org.bluez.Error.Failed', 'Software caused connection abort') of type <class 'bleak.exc.BleakDBusError'> in /opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py line #474
2024-10-01 15:59:05.921429500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit
2024-10-01 15:59:05.927431500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered
2024-10-01 15:59:06.019008500 [CHG] Device C8:47:80:03:B1:8D RSSI: -57
2024-10-01 15:59:06.019016500 [CHG] Device C8:47:80:03:B1:8D RSSI: -57
2024-10-01 15:59:06.019020500 [CHG] Device C8:47:80:03:B1:8D RSSI is nil
2024-10-01 15:59:08.037842500 Starting bluetooth: bluetoothd.
2024-10-01 15:59:08.071667500 INFO:SerialBattery:System Bluetooth daemon should have been restarted
2024-10-01 15:59:11.260295500 INFO:SerialBattery:--> asy_connect_and_scrape(): error while connecting to bt: BleakDBusError('org.bluez.Error.Failed', 'Software caused connection abort') of type <class 'bleak.exc.BleakDBusError'> in /opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py line #474
2024-10-01 15:59:11.260792500 INFO:SerialBattery:--> asy_connect_and_scrape(): Exit
2024-10-01 15:59:11.265866500 INFO:SerialBattery:Reset of system Bluetooth daemon triggered
2024-10-01 15:59:13.364495500 Starting bluetooth: bluetoothd.
2024-10-01 15:59:13.385058500 INFO:SerialBattery:System Bluetooth daemon should have been restarted
2024-10-01 15:59:13.513742500 ERROR:SerialBattery:No BMS found at C8:47:80:03:B1:8D
2024-10-01 15:59:13.516017500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2024-10-01 15:59:15.811012500
2024-10-01 15:59:15.811211500
2024-10-01 15:59:15.811438500 INFO:Preparing Bluetooth for connection to BMS
2024-10-01 15:59:15.811625500 INFO:Bluetooth details
2024-10-01 15:59:15.849032500 Attempting to disconnect from C8:47:80:03:B1:8D
2024-10-01 15:59:15.849039500 Successful disconnected
2024-10-01 15:59:20.901560500 Device C8:47:80:03:B1:8D (public)
2024-10-01 15:59:20.901566500 Alias: A2H
2024-10-01 15:59:20.901567500 Paired: no
2024-10-01 15:59:20.901569500 Trusted: no
2024-10-01 15:59:20.901571500 Blocked: no
2024-10-01 15:59:20.901573500 Connected: no
2024-10-01 15:59:20.901574500 LegacyPairing: no
2024-10-01 15:59:20.901576500 UUID: Device Information (0000180a-0000-1000-8000-00805f9b34fb)
2024-10-01 15:59:20.901581500 RSSI: -57
2024-10-01 15:59:20.903545500
2024-10-01 15:59:23.989540500 INFO:SerialBattery:
2024-10-01 15:59:23.989979500 INFO:SerialBattery:Starting dbus-serialbattery
2024-10-01 15:59:23.991427500 INFO:SerialBattery:Venus OS v3.42
2024-10-01 15:59:23.991874500 INFO:SerialBattery:dbus-serialbattery v1.4.20240928
I troubleshooted the Bluetooth problems now way over 100 hours and found no real solution to all this problems. Therefore I decided to not put any other effort into the Bluetooth part. Another reason is, that the users apparently do not appreciate the work I do and they cannot immagine how much time consuming this all is.
For that 1-2 donations, if at all, a month on over 9.000 dbus-serialbattery installations it is not worth it. If everyone would donate 1 €/year then the motivation would be another, but that is not the case.
Feel free to open a PR in my repository to help me with this :-)
So, I have this script running as a cron job every 5 minutes. The bluetooth connection has been pretty dang stable since adding this script. I wonder if this check can somehow be written into the driver. I don't really have time to dig through the code and submit a PR. However, I'd be happy to submit a PR with this script and a short addition to the docs describing in what scenarios to use the script.
#/usr/bin/bash
date -d @$(($(date +%s) - 7*3600)) '+[%Y-%m-%d %H:%M:%S]'
/etc/init.d/bluetooth status
if [ $? -eq 3 ]; then
/data/etc/dbus-serialbattery/restart-driver.sh
echo "dbus-serial battery restarted"
fi
We already had once a workaround like this. Since this is not really a real solution I will not add it, since restarting the driver too many times can cause even more issues and you need to reboot the device.
This looks more like a kernel / bluetooth driver issue. I've just dumped the onboard bluetooth controller for a USB one and it seems to be far more stable. The internet has plenty of similar scenarios where the connection just randomly drops.
I note that in my case, I see all the logs above. Running bluetoothctl
command and trying anything results in "org.bluez.Error.NotReady" and any attempt to recover it appears futile. I just have to reboot... I installed a realtek usb bluetooth dongle, blacklisted the driver module for the onboard Bluetooth and enabled BLUETOOTH_USE_USB = True
in the config.ini file
This might be a "hurry up and wait" for improvement on the support for it on a kernel level. I've found with my raspberry pi 4, connecting via bluetooth to be impossible - its flakey as hell. I could only connect via network cable and do the config there.
@mr-manuel I feel your pain. I worked on a project for years and received very little reward for it. For what its worth, I appreciate your efforts on this project. Thankyou.
Has anyone tried changing the Bluetooth Poll rate? I updated my serialbattery today to the current stable version, was running one a couple months old, and it went from disconnect every couple days to not staying connected for even an hour.
I tried polling at every 1.2 seconds, but it made no tangible difference - at least not using the onboard RPI Bluetooth. I have 2 of these setups One on a Cerbo and one on a Raspberry Pi 4 both with JKBMS 11.X BMS x 2. I note now that both setups seem to run pretty similarly now since I stopped using the RPI onboard Bluetooth. I also recently updated from an older version too. I don't believe this newer version is any less stable than the old one I updated from, but I never saw a dropout on the older version where I have seen it on the odd occasion now. I get the occasional dropout for a minute or so (on both setups) before it comes good. I might try a few different Bluetooth dongles to see if one is better than another. But the jury is in for me - at least for now - I wouldn't stake my life on using the onboard Bluetooth on this raspberry Pi 4 that I am using right now. It's one of a few that I own, and it caused issues from the day I bought it for use as a Victron clone....
I tried polling at every 1.2 seconds, but it made no tangible differenc
How did you change the polling interval? I set 10s as the Poll_Interval in the config.ini but I can still see updates roughly every second in the remote console. Did I miss something or is that parameter broken?
I did the same as you. Even without a setting there (should default to 1 second), I see updates better than a second. After looking at the code, there is a "use_callback" function ->
def use_callback(self, callback: Callable) -> bool:
"""
Each driver may override this function to indicate whether it is
able to provide value updates on its own.
:return: false when battery cannot provide updates by itself and will be polled
every poll_interval milliseconds for new values
true if callable should be used for updates as they arrive from the battery
"""
return False
I've not spent a lot of time in the code yet, but I'd suggest that POLLING only works where/when the BMS doesn't provide updates...
This is called in dbus-serialbattery.py by
# try using active callback on this battery
if not battery.use_callback(lambda: poll_battery(mainloop)):
# if not possible, poll the battery every poll_interval milliseconds
gobject.timeout_add(battery.poll_interval, lambda: poll_battery(mainloop))
# print log at this point, else not all data is correctly populated
battery.log_settings()
So I think, it's pointless to try setting a polling time. I still don't think the issue is anything to do with the code.
I got regular reconnection that i never had before (BMS beeping at each BTooth reconnection), today i tried updating VenusOS from 3.3 to 3.42 .. it failed .. rebooted ... tried again .. failed at 4% install each time. I suspected dbus-serialbattery, disabled it, reboot... upgraded to VenusOS 3.42 without problem. Somethig is wrong with the driver.
I downgraded to v1.1.20240121 ~7 hours ago and both BMS's still show a connection, without reboot. This is not exactly a long term observation, but right now I suspect the behavior got worse from v1.1 to v1.4. Misconfiguration? (the config file changed) Or did the polling/timing behavior change?
Any update?
For me v1.1 has a more stable connection to the BMS. I also didn't hear the reconnect beep from the BMS when near the battery (which is seldom).
Comparing v1.1 to the later releases, I noticed Line 23 changed in the init function in jkbms_ble.py:
From
self.jk = Jkbms_Brn(address)
To
self.jk = Jkbms_Brn(address, lambda: self.reset_bluetooth())
Didn't look any further into it, but maybe the bluetooth reset is causing issues / called too often.
Here is the whole function a little more down.
def reset_bluetooth(self):
logger.info("Reset of system Bluetooth daemon triggered")
self.resetting = True
if self.jk.is_running():
if self.jk.stop_scraping():
logger.info("Scraping stopped, issuing sys-commands")
else:
logger.warning("Scraping was unable to stop, issuing sys-commands")
# process kill is needed, since the service/bluetooth driver is probably freezed
os.system('pkill -f "bluetoothd"')
# stop will not work, if service/bluetooth driver is stuck
# os.system("/etc/init.d/bluetooth stop")
sleep(2)
os.system("rfkill block bluetooth")
os.system("rfkill unblock bluetooth")
os.system("/etc/init.d/bluetooth start")
logger.info("System Bluetooth daemon should have been restarted")
It is called as part of refresh_data too
if not self.resetting and last_update >= 60:
logger.error(
"Jkbms_Ble: Bluetooth died. Restarting Bluetooth system driver."
)
self.reset_bluetooth()
sleep(2)
self.jk.start_scraping()
sleep(2)
The underlying issues seems to be a segmentation fault that occurs. I saw it last week before I went off to work. Only got back last night so haven't had time to troubleshoot it more. It's fair to say that when the driver falls over, this function doesn't always (or perhaps never) successfully restart the driver properly.
will try to look into it this week.
I've rolled back to v1.2.20240408 and pretty stable for the day. Will keep running for the few days and report back. I had to roll back on the Pi and the Cerbo as both fell over in the end on a later version. Hopefully can get to a point where I can understand the difference between the latest version and this working version to see what is causing the dropouts.
etooth driver issue. I've just dumped the onboard bluetooth controller for a USB one and it seems to be far more stable. The internet has plenty of similar scenarios where the connection just randomly drops. I note that in my case, I see all the logs above. Running
bluetoothctl
command and trying anything results in "org.bluez.Error.NotReady" and any attempt to recover it appears futile. I just have to reboot... I installed a realtek usb bluetooth dongle, blacklisted the driver module for the onboard Bluetooth and enabledBLUETOOTH_USE_USB = True
in the config.ini fileThis might be a "hurry up and wait" for improvement on the support for it on a kernel
I used 1.3.2.2024 for months without any disconnection on JKBMS/Bluetooth. The last 1.4 failed after minutes only and would not be stable at all... I used poll of 10s ... would apparently change nothing to the data refresh speed...
I've rolled back to 1.3.2 and even if i restarted twice .. it work since a week now without any BT issue, something wrong has been done between those versions 1.3.2-1.4.
Resetting bluetooth for whatever small reason, is an shortcut i would not take.... the underlying cause need to be found and solved. Specially when this is a regression vs previous version.
Will continue in https://github.com/mr-manuel/venus-os_dbus-serialbattery/issues/86
I'm a bit confused, was this now closed without an actual fix to the problem? As we mentioned above, somehow the behavior got worse in the newer releases, I think this is not just related to "unstable onboard Bluetooth".
Describe the bug
I’m facing sporadic disconnect issues after a while (sometimes one hour, sometimes a day or a bit more). Venus OS doesn’t recognize the disconnect as values don’t get updated. After a while the messages in the log changes. I have spent hours searching through reported issue reports, but have not found any identical, unfixed or reported bugs.
How to reproduce
Issue is reproducible, but periodes vary. Sometimes the connection works for more than 24 hours, in other cases only for minutes or hours.
Expected behavior
Stable connection
Driver version
1.2.20240401
Venus OS device type
Raspberry Pi 4
Venus OS version
v3.33
BMS type
JKBMS / Heltec BMS
Cell count
18
Battery count
1
Connection type
Bluetooth
Config file
Relevant log output
Any other information that may be helpful
This behavior was already apparent immediately after initial operation. It is reproducible, but periodes vary. Sometimes the connection works for more than 24 hours, in other cases only for minutes or hours.