Bluetooth connection disrupted

[idstein]

Describe the bug

Using a cronjob to restart at 0 and 12 the entire Bluetooth stack is really disruptive. Can we remove that restart line?

Otherwise it will interrupt the BMS communication for several seconds during that period.

JKBMS BLE may require it, but JBD BMS BLE does not and has built in recovery mechanisms.

How to reproduce

Steps to reproduce the behavior:

1. Go to '...'
2. Click on '....'
3. Scroll down to '....'
4. See error

Expected behavior

Bluetooth Stack is not restarted

Driver version

1.0

Venus OS device type

Raspberry Pi

Venus OS version

3.0

BMS type

Smart BMS (LLT, JBD, Overkill Solar)

Cell count

18

Connection type

Bluetooth

Config file

Default

Relevant log output

.

Any other information that may be helpful

No response

[mr-manuel]

The JKBMS also do not require it, but we tracked it down to the bluez stack. It kills the driver, if there is no more answer. We tried the driver also with Raspian and it was no problem.

The bluez stack freezes after 15 hours and 20 minutes and has then to be killed to recover. This issue is known by bluez.

See the links here #485

[idstein]

Super strange. I do not have had these issues before with 2.93 VenusOS and was running my JBD code for 60+ days without intervention.

[mr-manuel]

We tried with Venus OS 2.92, bleak 5.55 if I remember correctly. Have to check, if they updated it maybe.

[mr-manuel]

On what device are you running Venus OS? Are you also using an external Bluetooth adapter?

[idstein]

Using built-in bluetooth of a Raspberry Pi 4.

Linux raspberrypi4 5.10.110-rpi-venus-3 #1 SMP Fri May 12 18:57:15 UTC 2023 armv7l GNU/Linux

VenusOS 3.0.0~42
Bleak 0.20.2
BlueZ 5.55.

It was running without any bluetooth restart for 24h after I removed the cronjob. I'm now constantly checking the logs (A) dbus-blebattery and (B) messages for something related to bluetooth.

[mr-manuel]

@baranator could you also try to remove the cronjob with Venus OS v3.00~42? I have no more possibility to connect my JKBMS over Bluetooth.

[baranator]

@baranator could you also try to remove the cronjob with Venus OS v3.00~42? I have no more possibility to connect my JKBMS over Bluetooth.

i'm quite busy at the moment, but i'm gonna have a look at it on the weekend and disable the cron. then we'll see if the watchdog is still triggered regularly every 15h20 or if this bug indeed got fixed upstream.

[baranator]

I Installed v.3.00~42 and dbus-serialbattery master yesterday evening.

My Bluetooth-connection suddenly unstable and reconnects every 20s, even when calling m jkbms_brn.py seperately and independently from dbus-serialbattery on the device, so i assume there is an error in v3.00~42 :(

[mr-manuel]

Can you try to install from the dev branch? Run the install.sh, select 3 and then 2.

[baranator]

Can you try to install from the dev branch? Run the install.sh, select 3 and then 2.

got the same behaviour on almost every software-combination; then disabled raspi3 internal bluetooth and went back to external bluetooth-dongle again. That seemed to be the culprit for the 20s-Disconnect. I will let it run now for two days to verify if everything works for now "as it is" and then remove the cron.

[mr-manuel]

@baranator do you maybe have some news? In the meanwhile an issue #693 was opened and the driver was updated.

[drago-more]

@mr-manuel I used the nightly build from June 11. It seems that the BT connections die after the restart of the BT stack. In Remote Console the latest BMS figures of both BMS's freeze but there is no notification or error.

My setup: Cerbo GX, internal BT, Venus OS 3.00, 2 JK BMS, dbus-serialbattery v1.0.20230611beta

JK BMS 1:

2023-06-12 12:36:03.769154500 *** CCGX booted (0) ***
2023-06-12 12:37:07.870380500 
2023-06-12 12:37:07.870388500 INFO:Bluetooth details
2023-06-12 12:37:08.038571500 Attempting to disconnect from C8:47:8C:E6:E2:00
2023-06-12 12:37:08.038581500 Successful disconnected
2023-06-12 12:37:13.207532500 Device C8:47:8C:E6:E2:00 (public)
2023-06-12 12:37:13.207540500 	Alias: Batt-1-SB
2023-06-12 12:37:13.207543500 	Paired: no
2023-06-12 12:37:13.207544500 	Trusted: no
2023-06-12 12:37:13.207545500 	Blocked: no
2023-06-12 12:37:13.207547500 	Connected: no
2023-06-12 12:37:13.207548500 	LegacyPairing: no
2023-06-12 12:37:13.207550500 	UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
2023-06-12 12:37:13.207553500 	RSSI: -46
2023-06-12 12:37:13.209828500 
2023-06-12 12:37:17.264071500 INFO:SerialBattery:
2023-06-12 12:37:17.265205500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-12 12:37:17.266972500 INFO:SerialBattery:dbus-serialbattery v1.0.20230611beta
2023-06-12 12:37:18.175637500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E6:E2:00
2023-06-12 12:37:18.176532500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E6:E2:00
2023-06-12 12:37:23.233590500 INFO:SerialBattery:BAT: JKBMS 11.XW 4 cells (20230527)
2023-06-12 12:37:23.234920500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-12 12:37:23.237095500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce6e200
2023-06-12 12:37:23.237991500 INFO:SerialBattery:========== Settings ==========
2023-06-12 12:37:23.238758500 INFO:SerialBattery:> Connection voltage: 13.49V | Current: 0.0A | SoC: 98%
2023-06-12 12:37:23.239389500 INFO:SerialBattery:> Cell count: 4 | Cells populated: 4
2023-06-12 12:37:23.239988500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: False
2023-06-12 12:37:23.240611500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 80.0A | MAX BATTERY DISCHARGE CURRENT: 150.0A
2023-06-12 12:37:23.241226500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 150.0A | MAX BATTERY DISCHARGE CURRENT: 150.0A (read from BMS)
2023-06-12 12:37:23.241806500 INFO:SerialBattery:> CVCM:     True
2023-06-12 12:37:23.242447500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-12 12:37:23.243044500 INFO:SerialBattery:> CCCM CV:  False | DCCM CV:  False
2023-06-12 12:37:23.252561500 INFO:SerialBattery:> CCCM T:   False | DCCM T:   False
2023-06-12 12:37:23.253492500 INFO:SerialBattery:> CCCM SOC: False | DCCM SOC: False
2023-06-12 12:37:23.254171500 INFO:SerialBattery:Serial Number/Unique Identifier: 2081215375
2023-06-12 12:37:23.422572500 INFO:SerialBattery:DeviceInstance = 1
2023-06-12 12:37:23.423436500 INFO:SerialBattery:com.victronenergy.battery.c8478ce6e200
2023-06-12 12:37:23.426134500 INFO:SerialBattery:BAT: JKBMS 11.XW 4 cells (20230527)
2023-06-12 12:37:23.476325500 INFO:SerialBattery:publish config values = 1
2023-06-13 00:05:07.030437500 [CHG] Device C8:47:8C:E6:E2:00 RSSI: -46
2023-06-13 00:05:07.030446500 [CHG] Device C8:47:8C:E6:E2:00 RSSI: -46
2023-06-13 00:05:07.030449500 [CHG] Device C8:47:8C:E6:E2:00 RSSI: -46
2023-06-13 00:05:07.030452500 [CHG] Device C8:47:8C:E6:E2:00 RSSI: -48
2023-06-13 00:05:07.030455500 [CHG] Device C8:47:8C:E6:E2:00 RSSI is nil

JK BMS 2:

2023-06-12 12:36:03.787438500 *** CCGX booted (0) ***
2023-06-12 12:37:07.875977500 
2023-06-12 12:37:07.875984500 INFO:Bluetooth details
2023-06-12 12:37:08.028809500 Attempting to disconnect from C8:47:8C:E6:E3:C3
2023-06-12 12:37:08.028818500 Successful disconnected
2023-06-12 12:37:13.221070500 Device C8:47:8C:E6:E3:C3 (public)
2023-06-12 12:37:13.221080500 	Alias: Batt-2-SB
2023-06-12 12:37:13.221082500 	Paired: no
2023-06-12 12:37:13.221084500 	Trusted: no
2023-06-12 12:37:13.221085500 	Blocked: no
2023-06-12 12:37:13.221086500 	Connected: no
2023-06-12 12:37:13.221088500 	LegacyPairing: no
2023-06-12 12:37:13.221089500 	UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
2023-06-12 12:37:13.221092500 	RSSI: -50
2023-06-12 12:37:13.221093500 
2023-06-12 12:37:17.254650500 INFO:SerialBattery:
2023-06-12 12:37:17.255405500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-12 12:37:17.256649500 INFO:SerialBattery:dbus-serialbattery v1.0.20230611beta
2023-06-12 12:37:18.162887500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E6:E3:C3
2023-06-12 12:37:18.164028500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E6:E3:C3
2023-06-12 12:37:24.239800500 INFO:SerialBattery:BAT: JKBMS 11.XW 4 cells (20230108)
2023-06-12 12:37:24.241741500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-12 12:37:24.242723500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce6e3c3
2023-06-12 12:37:24.243820500 INFO:SerialBattery:========== Settings ==========
2023-06-12 12:37:24.244598500 INFO:SerialBattery:> Connection voltage: 13.49V | Current: 0.0A | SoC: 98%
2023-06-12 12:37:24.256720500 INFO:SerialBattery:> Cell count: 4 | Cells populated: 4
2023-06-12 12:37:24.257794500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: False
2023-06-12 12:37:24.258920500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 80.0A | MAX BATTERY DISCHARGE CURRENT: 150.0A
2023-06-12 12:37:24.259931500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 150.0A | MAX BATTERY DISCHARGE CURRENT: 150.0A (read from BMS)
2023-06-12 12:37:24.260861500 INFO:SerialBattery:> CVCM:     True
2023-06-12 12:37:24.261866500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-12 12:37:24.299383500 INFO:SerialBattery:> CCCM CV:  False | DCCM CV:  False
2023-06-12 12:37:24.300405500 INFO:SerialBattery:> CCCM T:   False | DCCM T:   False
2023-06-12 12:37:24.301377500 INFO:SerialBattery:> CCCM SOC: False | DCCM SOC: False
2023-06-12 12:37:24.302319500 INFO:SerialBattery:Serial Number/Unique Identifier: 2081215686
2023-06-12 12:37:25.176796500 INFO:SerialBattery:DeviceInstance = 2
2023-06-12 12:37:25.177627500 INFO:SerialBattery:com.victronenergy.battery.c8478ce6e3c3
2023-06-12 12:37:25.178743500 INFO:SerialBattery:BAT: JKBMS 11.XW 4 cells (20230108)
2023-06-12 12:37:25.278350500 INFO:SerialBattery:publish config values = 1
2023-06-12 12:42:08.222795500 [CHG] Device C8:47:8C:E6:E3:C3 RSSI: -50
2023-06-12 12:42:08.222806500 [CHG] Device C8:47:8C:E6:E3:C3 RSSI: -54

[drago-more]

The issue also exists for dbus-serialbattery v1.0.20230612beta. The BT connections die at around 00:05 GMT and 14:05 GMT, respectively.

[idstein]

All logs I've seen so far are related to JKBMS. Could it be an internal problem with JKBMS implementation? Has anyone also the BT connection salvation with JBD BMS?

[mr-manuel]

The issue also exists for dbus-serialbattery v1.0.20230612beta. The BT connections die at around 00:05 GMT and 14:05 GMT, respectively.

This is due to the cronjob. The cronjob is removed in the next beta. But anyway the driver should not behave like this. I'm searching for a solution, but have no system to test. Would you be available to contact me on Discord and give me direct SSH access to your GX device to find a solution?

[drago-more]

@mr-manuel A couple of days ago I removed the cronjob manually, running dbus-serialbattery v1.0.20230610beta at this time. The BT connection broke after about 15 hours ... as you mentioned above. So it seems that the bluez stack bug is still there. Though, happy to test your next beta.

Unfortunately I am not using Discord. You can drop me a mail: removed for privacy

[drago-more]

@mr-manuel I did some further tests. The issue can be reproduced by just restarting the BT stack with /etc/init.d/bluetooth restart. After running bash /data/etc/dbus-serialbattery/reinstall-local.sh the BT connection is reestablished. So it seems that when restarting BT in cronjob you also have to perform a "reconnect".

P.S. By the way, check your mail if you haven't already.

[mr-manuel]

Crodjob was removed. A new issue arised. See #720