Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Bluetooth with JKBMS doesn't work #693

Closed
simsandmann opened this issue Jun 5, 2023 · 27 comments
Closed

Bluetooth with JKBMS doesn't work #693

simsandmann opened this issue Jun 5, 2023 · 27 comments
Assignees
@mr-manuel
Labels
bug Something isn't working

Comments

@simsandmann
Copy link

simsandmann commented Jun 5, 2023 •
edited
Loading

Describe the bug

Bluetooth connection to JKBMS is not working since the new latest version (1.0.20230531)

How to reproduce

Steps to reproduce the behavior:

  1. Reboot Venus OS under 3.0.0

Expected behavior

Venus OS is connecting to the JKBMS

Driver version

1.0.20230531

Venus OS device type

Cerbo GX

Venus OS version

3.0.0 (newest stable)

BMS type

JKBMS / Heltec BMS

Cell count

16

Connection type

Bluetooth

Config file

[DEFAULT]

; --------- Battery Current limits ---------
MAX_BATTERY_CHARGE_CURRENT    = 70.0
MAX_BATTERY_DISCHARGE_CURRENT = 100.0

; --------- Cell Voltages ---------
; Description: Cell min/max voltages which are used to calculate the min/max battery voltage
; Example: 16 cells * 3.45V/cell = 55.2V max charge voltage. 16 cells * 2.90V = 46.4V min discharge voltage
MIN_CELL_VOLTAGE   = 2.900
; Max voltage can seen as absorption voltage
MAX_CELL_VOLTAGE   = 3.450
FLOAT_CELL_VOLTAGE = 3.375

; --------- Bluetooth BMS ---------
; Description: List the Bluetooth BMS here that you want to install
; Example with 1 BMS: Jkbms_Ble C8:47:8C:00:00:00
; Example with 3 BMS: Jkbms_Ble C8:47:8C:00:00:00, Jkbms_Ble C8:47:8C:00:00:11, Jkbms_Ble C8:47:8C:00:00:22
BLUETOOTH_BMS = Jkbms_Ble C8:47:8C:E8:04:67, Jkbms_Ble C8:47:8C:E9:03:8B

; --------- BMS disconnect behaviour ---------
; Description: Block charge and discharge when the communication to the BMS is lost. If you are removing the
;              BMS on purpose, then you have to restart the driver/system to reset the block.
; False: Charge and discharge is not blocked on BMS communication loss
; True: Charge and discharge is blocked on BMS communication loss, it's unblocked when connection is established
;       again or the driver/system is restarted
BLOCK_ON_DISCONNECT = False

.........

Relevant log output

JKBMS 1:

2023-06-04 08:38:22.491621500
2023-06-05 14:44:51.436875500 Missing device address argument
2023-06-05 14:44:55.843897500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-05 14:44:55.855365500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-05 14:44:56.879772500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-05 14:44:56.884387500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-05 14:44:57.967597500 ERROR:SerialBattery:[org.freedesktop.DBus.Error.ServiceUnknown] The name org.bluez was not provided by any .service files
2023-06-05 14:44:57.968800500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble

JKBMS 2:

2023-06-04 08:38:22.461507500
2023-06-05 14:44:51.432646500 Missing device address argument
2023-06-05 14:44:55.670973500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-05 14:44:55.677493500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-05 14:44:56.645783500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-05 14:44:56.649977500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-05 14:44:57.729882500 ERROR:SerialBattery:[org.freedesktop.DBus.Error.ServiceUnknown] The name org.bluez was not provided by any .service files
2023-06-05 14:44:57.730651500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble

Any other information that may be helpful

No response
@simsandmann simsandmann added the bug Something isn't working label Jun 5, 2023
@drago-more
Copy link

The same here. I have a similar setup and got exactly the same error message when trying to add my two JKBMS (4s) with BT. Adding only one BMS works just fine.

@simsandmann
Copy link
Author

One JKBMS via Bluetooth is not working for me, but I am also connected with serial connection as my system is productive.
So I am connected to "two" BMS as well.

@mr-manuel
Copy link
Collaborator

Could you try to execute this lines manually and check the results?

opkg update
opkg install python3-misc python3-pip
pip3 install bleak

@simsandmann
Copy link
Author

simsandmann commented Jun 5, 2023 •
edited
Loading

Seems like nothing has changed:

root@einstein:/data/log# opkg update
Downloading https://updates.victronenergy.com/feeds/venus/release/packages/dunfell/all/Packages.gz.
Updated source 'all'.
Downloading https://updates.victronenergy.com/feeds/venus/release/packages/dunfell/cortexa7hf-neon-vfpv4/Packages.gz.
Updated source 'cortexa7hf-neon-vfpv4'.
Downloading https://updates.victronenergy.com/feeds/venus/release/packages/dunfell/einstein/Packages.gz.
Updated source 'einstein'.
root@einstein:/data/log#  opkg install python3-misc python3-pip
No packages installed or removed.
root@einstein:/data/log# pip3 install bleak
Requirement already satisfied: bleak in /usr/lib/python3.8/site-packages (0.20.2)
Requirement already satisfied: async-timeout<5,>=3.0.0; python_version < "3.11" in /usr/lib/python3.8/site-packages (from bleak) (4.0.2)
Requirement already satisfied: dbus-fast<2.0.0,>=1.83.0; platform_system == "Linux" in /usr/lib/python3.8/site-packages (from bleak) (1.86.0)

Edit: But it worked. Restarted the Cerbo and now 2 Bluetooth connections are working.
Edit2: At second restart of Venus OS no Bluetooth connection is established...

@mr-manuel
Copy link
Collaborator

Could you also post the output of

/usr/libexec/bluetooth/bluetoothd -v
/usr/bin/bluetoothctl -v
bluetoothctl devices

Does it connect, if you restart the bluetooth driver?

/etc/init.d/bluetooth restart

If you revert back to the latest beta all works fine?

@simsandmann
Copy link
Author

simsandmann commented Jun 5, 2023 •
edited
Loading 

root@einstein:/data/log# /usr/libexec/bluetooth/bluetoothd -v
5.55

root@einstein:/data/log# /usr/bin/bluetoothctl -v
bluetoothctl: 5.55

root@einstein:/data/log# bluetoothctl devices
Device ED:D5:E6:BC:BF:4E MPPT 1
Device CA:BF:98:7A:39:16 MPPT 2
Device C8:47:8C:E9:03:8B JKBMS 1
Device C8:47:8C:E8:04:67 JKBMS 2
Device 88:BF:E4:CD:2E:8E 88-BF-E4-CD-2E-8E

/etc/init.d/bluetooth restart --> Still no connection

At the latest beta version the connection was already unstable. It connected and disconnected around 4 times a day. It worked approx. 6h and then it did not for the next 6 hours. And so on.

I also updated from Venus OS 2.92 to 3.0 trying to fix the issue with the latest version. It did not work.

@mr-manuel
Copy link
Collaborator

You have disabled Bluetooth in the Venus OS settings?

Have you tried an external Bluetooth dongle?

@simsandmann
Copy link
Author

simsandmann commented Jun 6, 2023 •
edited by mr-manuel
Loading

Bluetooth is disabled.

I have no Bluetooth dongle.

Some time later the Bluetooth connection established. Maybe that helps:

JKBMS 1: 
root@einstein:~# tail -n 200 -f /data/log/dbus-blebattery.0/current | tai64nlocal
2023-06-06 00:12:08.061872500   File "/opt/victronenergy/dbus-serialbattery/dbushelper.py", line 361, in publish_battery
2023-06-06 00:12:08.061876500     success = self.battery.refresh_data()
2023-06-06 00:12:08.061879500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 162, in refresh_data
2023-06-06 00:12:08.061883500     self.jk.start_scraping()
2023-06-06 00:12:08.061885500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py", line 366, in start_scraping
2023-06-06 00:12:08.062018500     self.bt_thread.start()
2023-06-06 00:12:08.062022500   File "/usr/lib/python3.8/threading.py", line 848, in start
2023-06-06 00:12:08.062024500     raise RuntimeError("threads can only be started once")
2023-06-06 00:12:08.062027500 RuntimeError: threads can only be started once
2023-06-06 00:12:08.062080500
2023-06-06 00:12:08.062082500 connect and scrape on address: C8:47:8C:E8:04:67
2023-06-06 00:12:08.062084500 btloop
2023-06-06 00:12:08.062086500 reconnect
2023-06-06 00:12:08.062087500
2023-06-06 00:12:08.062088500 btloop
2023-06-06 00:12:08.062089500 reconnect
2023-06-06 00:12:08.062090500 Exiting bt-loop
2023-06-06 00:12:08.769699500 Missing device address argument
2023-06-06 00:12:10.962119500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:12:10.963453500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:12:11.539063500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:12:11.539869500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:12:21.298406500 INFO:SerialBattery:Jkbms_Ble found!
2023-06-06 00:12:21.299587500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:12:21.301136500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-06 00:12:21.301873500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce80467
2023-06-06 00:12:21.302468500 INFO:SerialBattery:========== Settings ==========
2023-06-06 00:12:21.303168500 INFO:SerialBattery:> Connection voltage: 53.14V | Current: -1.7A | SoC: 93%
2023-06-06 00:12:21.303762500 INFO:SerialBattery:> Cell count: 16 | Cells populated: 16
2023-06-06 00:12:21.304382500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: True
2023-06-06 00:12:21.305095500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 70.0A | MAX BATTERY DISCHARGE CURRENT: 100.0A
2023-06-06 00:12:21.306386500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 110.0A | MAX BATTERY DISCHARGE CURRENT: 180.0A (read from BMS)
2023-06-06 00:12:21.308612500 INFO:SerialBattery:> CVCM:     True
2023-06-06 00:12:21.309349500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-06 00:12:21.310144500 INFO:SerialBattery:> CCCM CV:  True  | DCCM CV:  True
2023-06-06 00:12:21.311038500 INFO:SerialBattery:> CCCM T:   True  | DCCM T:   True
2023-06-06 00:12:21.311763500 INFO:SerialBattery:> CCCM SOC: True  | DCCM SOC: True
2023-06-06 00:12:21.312401500 INFO:SerialBattery:Serial Number/Unique Identifier: 2082316058
2023-06-06 00:12:21.582115500 INFO:SerialBattery:DeviceInstance = 3
2023-06-06 00:12:21.583995500 INFO:SerialBattery:com.victronenergy.battery.c8478ce80467
2023-06-06 00:12:21.585330500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:12:21.651462500 INFO:SerialBattery:publish config values = 1
2023-06-06 00:13:05.820105500 INFO:SerialBattery:Jkbms_Ble: Bluetooth died
2023-06-06 00:13:05.827462500 INFO:SerialBattery:Reset of Bluetooth triggered
2023-06-06 00:13:05.827471500 INFO:SerialBattery:Scraping ended, issuing sys-commands
2023-06-06 00:13:07.963645500 Starting bluetooth: bluetoothd.
2023-06-06 00:13:07.987368500 INFO:SerialBattery:Bluetooth should have been restarted
2023-06-06 00:13:08.029511500 Traceback (most recent call last):
2023-06-06 00:13:08.029520500   File "/opt/victronenergy/dbus-serialbattery/dbushelper.py", line 361, in publish_battery
2023-06-06 00:13:08.029524500     success = self.battery.refresh_data()
2023-06-06 00:13:08.029527500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 162, in refresh_data
2023-06-06 00:13:08.029530500     self.jk.start_scraping()
2023-06-06 00:13:08.029533500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py", line 366, in start_scraping
2023-06-06 00:13:08.029674500     self.bt_thread.start()
2023-06-06 00:13:08.029677500   File "/usr/lib/python3.8/threading.py", line 848, in start
2023-06-06 00:13:08.029681500     raise RuntimeError("threads can only be started once")
2023-06-06 00:13:08.029683500 RuntimeError: threads can only be started once
2023-06-06 00:13:08.038150500
2023-06-06 00:13:08.038157500 connect and scrape on address: C8:47:8C:E8:04:67
2023-06-06 00:13:08.038159500 btloop
2023-06-06 00:13:08.038160500 reconnect
2023-06-06 00:13:08.038162500
2023-06-06 00:13:08.038163500 btloop
2023-06-06 00:13:08.038165500 reconnect
2023-06-06 00:13:08.038166500 Exiting bt-loop
2023-06-06 00:13:08.935589500 Missing device address argument
2023-06-06 00:13:10.943643500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:13:10.945068500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:13:11.333901500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:13:11.334671500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:13:21.850598500 INFO:SerialBattery:Jkbms_Ble found!
2023-06-06 00:13:21.850607500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:13:21.850609500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-06 00:13:21.850612500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce80467
2023-06-06 00:13:21.850616500 INFO:SerialBattery:========== Settings ==========
2023-06-06 00:13:21.850618500 INFO:SerialBattery:> Connection voltage: 53.13V | Current: -1.5A | SoC: 93%
2023-06-06 00:13:21.850621500 INFO:SerialBattery:> Cell count: 16 | Cells populated: 16
2023-06-06 00:13:21.850816500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: True
2023-06-06 00:13:21.853142500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 70.0A | MAX BATTERY DISCHARGE CURRENT: 100.0A
2023-06-06 00:13:21.854286500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 110.0A | MAX BATTERY DISCHARGE CURRENT: 180.0A (read from BMS)
2023-06-06 00:13:21.855227500 INFO:SerialBattery:> CVCM:     True
2023-06-06 00:13:21.857471500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-06 00:13:21.858982500 INFO:SerialBattery:> CCCM CV:  True  | DCCM CV:  True
2023-06-06 00:13:21.860063500 INFO:SerialBattery:> CCCM T:   True  | DCCM T:   True
2023-06-06 00:13:21.861245500 INFO:SerialBattery:> CCCM SOC: True  | DCCM SOC: True
2023-06-06 00:13:21.862266500 INFO:SerialBattery:Serial Number/Unique Identifier: 2082316058
2023-06-06 00:13:21.991216500 INFO:SerialBattery:DeviceInstance = 3
2023-06-06 00:13:21.992360500 INFO:SerialBattery:com.victronenergy.battery.c8478ce80467
2023-06-06 00:13:21.993718500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:13:22.141216500 INFO:SerialBattery:publish config values = 1
2023-06-06 00:14:06.231351500 INFO:SerialBattery:Jkbms_Ble: Bluetooth died
2023-06-06 00:14:06.232205500 INFO:SerialBattery:Reset of Bluetooth triggered
2023-06-06 00:14:06.232874500 INFO:SerialBattery:Scraping ended, issuing sys-commands
2023-06-06 00:14:08.362680500 Starting bluetooth: bluetoothd.
2023-06-06 00:14:08.385440500 INFO:SerialBattery:Bluetooth should have been restarted
2023-06-06 00:14:08.397378500 Traceback (most recent call last):
2023-06-06 00:14:08.397387500   File "/opt/victronenergy/dbus-serialbattery/dbushelper.py", line 361, in publish_battery
2023-06-06 00:14:08.397391500     success = self.battery.refresh_data()
2023-06-06 00:14:08.397394500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 162, in refresh_data
2023-06-06 00:14:08.397398500     self.jk.start_scraping()
2023-06-06 00:14:08.397399500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py", line 366, in start_scraping
2023-06-06 00:14:08.397527500     self.bt_thread.start()
2023-06-06 00:14:08.397531500   File "/usr/lib/python3.8/threading.py", line 848, in start
2023-06-06 00:14:08.397533500     raise RuntimeError("threads can only be started once")
2023-06-06 00:14:08.397536500 RuntimeError: threads can only be started once
2023-06-06 00:14:08.397802500
2023-06-06 00:14:08.397806500 connect and scrape on address: C8:47:8C:E8:04:67
2023-06-06 00:14:08.397809500 btloop
2023-06-06 00:14:08.397810500 reconnect
2023-06-06 00:14:08.397811500
2023-06-06 00:14:08.397812500 btloop
2023-06-06 00:14:08.397813500 reconnect
2023-06-06 00:14:08.397815500 Exiting bt-loop
2023-06-06 00:14:09.411165500 Missing device address argument
2023-06-06 00:14:11.200771500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:14:11.202354500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:14:11.899368500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:14:11.900501500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:14:22.794672500 INFO:SerialBattery:Jkbms_Ble found!
2023-06-06 00:14:22.795835500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:14:22.797860500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-06 00:14:22.799486500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce80467
2023-06-06 00:14:22.800106500 INFO:SerialBattery:========== Settings ==========
2023-06-06 00:14:22.800800500 INFO:SerialBattery:> Connection voltage: 53.13V | Current: -1.5A | SoC: 93%
2023-06-06 00:14:22.801378500 INFO:SerialBattery:> Cell count: 16 | Cells populated: 16
2023-06-06 00:14:22.801982500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: True
2023-06-06 00:14:22.802606500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 70.0A | MAX BATTERY DISCHARGE CURRENT: 100.0A
2023-06-06 00:14:22.803216500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 110.0A | MAX BATTERY DISCHARGE CURRENT: 180.0A (read from BMS)
2023-06-06 00:14:22.803811500 INFO:SerialBattery:> CVCM:     True
2023-06-06 00:14:22.804463500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-06 00:14:22.805098500 INFO:SerialBattery:> CCCM CV:  True  | DCCM CV:  True
2023-06-06 00:14:22.805684500 INFO:SerialBattery:> CCCM T:   True  | DCCM T:   True
2023-06-06 00:14:22.806273500 INFO:SerialBattery:> CCCM SOC: True  | DCCM SOC: True
2023-06-06 00:14:22.806845500 INFO:SerialBattery:Serial Number/Unique Identifier: 2082316058
2023-06-06 00:14:22.910876500 INFO:SerialBattery:DeviceInstance = 3
2023-06-06 00:14:22.911717500 INFO:SerialBattery:com.victronenergy.battery.c8478ce80467
2023-06-06 00:14:22.912736500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:14:22.959463500 INFO:SerialBattery:publish config values = 1
2023-06-06 00:15:07.052266500 INFO:SerialBattery:Jkbms_Ble: Bluetooth died
2023-06-06 00:15:07.052970500 INFO:SerialBattery:Reset of Bluetooth triggered
2023-06-06 00:15:07.053806500 INFO:SerialBattery:Scraping ended, issuing sys-commands
2023-06-06 00:15:09.187155500 Starting bluetooth: bluetoothd.
2023-06-06 00:15:09.217427500 INFO:SerialBattery:Bluetooth should have been restarted
2023-06-06 00:15:09.258158500 Traceback (most recent call last):
2023-06-06 00:15:09.258167500   File "/opt/victronenergy/dbus-serialbattery/dbushelper.py", line 361, in publish_battery
2023-06-06 00:15:09.258171500     success = self.battery.refresh_data()
2023-06-06 00:15:09.258173500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 162, in refresh_data
2023-06-06 00:15:09.258177500     self.jk.start_scraping()
2023-06-06 00:15:09.258179500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py", line 366, in start_scraping
2023-06-06 00:15:09.258311500     self.bt_thread.start()
2023-06-06 00:15:09.258314500   File "/usr/lib/python3.8/threading.py", line 848, in start
2023-06-06 00:15:09.258317500     raise RuntimeError("threads can only be started once")
2023-06-06 00:15:09.258320500 RuntimeError: threads can only be started once
2023-06-06 00:15:09.258581500
2023-06-06 00:15:09.258587500 connect and scrape on address: C8:47:8C:E8:04:67
2023-06-06 00:15:09.258589500 btloop
2023-06-06 00:15:09.258590500 reconnect
2023-06-06 00:15:09.258592500
2023-06-06 00:15:09.258593500 btloop
2023-06-06 00:15:09.258594500 reconnect
2023-06-06 00:15:09.258595500 Exiting bt-loop
2023-06-06 00:15:10.178107500 Missing device address argument
2023-06-06 00:15:12.044011500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:15:12.046681500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:15:12.939625500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:15:12.942122500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:15:34.361598500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-06 00:15:34.361607500
2023-06-06 00:15:34.361608500 connect and scrape on address: C8:47:8C:E8:04:67
2023-06-06 00:15:34.361611500 btloop
2023-06-06 00:15:34.361612500 reconnect
2023-06-06 00:15:34.361613500
2023-06-06 00:15:34.361614500 Exiting bt-loop
2023-06-06 00:15:37.982733500 Attempting to disconnect from C8:47:8C:E9:03:8B
2023-06-06 00:15:37.982743500 [CHG] Device C8:47:8C:E9:03:8B ServicesResolved: no
2023-06-06 00:15:37.982746500 Successful disconnected
2023-06-06 00:15:40.167916500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:15:40.169655500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:15:40.633469500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:15:40.634213500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E8:04:67
2023-06-06 00:15:51.318404500 INFO:SerialBattery:Jkbms_Ble found!
2023-06-06 00:15:51.319442500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:15:51.321491500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-06 00:15:51.322685500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce80467
2023-06-06 00:15:51.325185500 INFO:SerialBattery:========== Settings ==========
2023-06-06 00:15:51.327975500 INFO:SerialBattery:> Connection voltage: 53.13V | Current: -1.5A | SoC: 93%
2023-06-06 00:15:51.329432500 INFO:SerialBattery:> Cell count: 16 | Cells populated: 16
2023-06-06 00:15:51.333357500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: True
2023-06-06 00:15:51.336436500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 70.0A | MAX BATTERY DISCHARGE CURRENT: 100.0A
2023-06-06 00:15:51.340117500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 110.0A | MAX BATTERY DISCHARGE CURRENT: 180.0A (read from BMS)
2023-06-06 00:15:51.341350500 INFO:SerialBattery:> CVCM:     True
2023-06-06 00:15:51.342563500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-06 00:15:51.343659500 INFO:SerialBattery:> CCCM CV:  True  | DCCM CV:  True
2023-06-06 00:15:51.355771500 INFO:SerialBattery:> CCCM T:   True  | DCCM T:   True
2023-06-06 00:15:51.357220500 INFO:SerialBattery:> CCCM SOC: True  | DCCM SOC: True
2023-06-06 00:15:51.358905500 INFO:SerialBattery:Serial Number/Unique Identifier: 2082316058
2023-06-06 00:15:51.506262500 INFO:SerialBattery:DeviceInstance = 3
2023-06-06 00:15:51.507475500 INFO:SerialBattery:com.victronenergy.battery.c8478ce80467
2023-06-06 00:15:51.508690500 INFO:SerialBattery:BAT: JKBMS 10.XW 16 cells (20221217)
2023-06-06 00:15:51.546020500 INFO:SerialBattery:publish config values = 1
JKBMS 2: 
root@einstein:~# tail -n 200 -f /data/log/dbus-blebattery.1/current | tai64nloca                                                                                   l
2023-06-06 00:14:39.031847500 Traceback (most recent call last):
2023-06-06 00:14:39.031856500   File "/opt/victronenergy/dbus-serialbattery/dbushelper.py", line 361, in publish_battery
2023-06-06 00:14:39.031859500     success = self.battery.refresh_data()
2023-06-06 00:14:39.031862500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 162, in refresh_data
2023-06-06 00:14:39.031866500     self.jk.start_scraping()
2023-06-06 00:14:39.031867500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_brn.py", line 366, in start_scraping
2023-06-06 00:14:39.032070500     self.bt_thread.start()
2023-06-06 00:14:39.032072500   File "/usr/lib/python3.8/threading.py", line 848, in start
2023-06-06 00:14:39.032075500     raise RuntimeError("threads can only be started once")
2023-06-06 00:14:39.032078500 RuntimeError: threads can only be started once
2023-06-06 00:14:39.032334500
2023-06-06 00:14:39.032338500 connect and scrape on address: C8:47:8C:E9:03:8B
2023-06-06 00:14:39.032340500 btloop
2023-06-06 00:14:39.032342500 reconnect
2023-06-06 00:14:39.032343500
2023-06-06 00:14:39.032344500 btloop
2023-06-06 00:14:39.032345500 reconnect
2023-06-06 00:14:39.032346500 Exiting bt-loop
2023-06-06 00:14:39.913518500 Missing device address argument
2023-06-06 00:14:41.986549500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:14:41.988481500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:14:42.428697500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:14:42.429519500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:14:51.825723500 INFO:SerialBattery:Jkbms_Ble found!
2023-06-06 00:14:51.825731500
2023-06-06 00:14:51.825732500 connect and scrape on address: C8:47:8C:E9:03:8B
2023-06-06 00:14:51.825735500 btloop
2023-06-06 00:14:51.825736500 reconnect
2023-06-06 00:14:51.825737500
2023-06-06 00:14:51.840021500 Traceback (most recent call last):
2023-06-06 00:14:51.840030500   File "/opt/victronenergy/dbus-serialbattery/dbus-serialbattery.py", line 163, in <module>
2023-06-06 00:14:51.840034500     main()
2023-06-06 00:14:51.840035500   File "/opt/victronenergy/dbus-serialbattery/dbus-serialbattery.py", line 128, in main
2023-06-06 00:14:51.840039500     if testbms.test_connection() is True:
2023-06-06 00:14:51.840041500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 103, in test_connection
2023-06-06 00:14:51.840168500     self.get_settings()
2023-06-06 00:14:51.840170500   File "/opt/victronenergy/dbus-serialbattery/bms/jkbms_ble.py", line 131, in get_settings
2023-06-06 00:14:51.840175500     self.capacity = self.jk.get_status()["cell_info"]["capacity_nominal"]
2023-06-06 00:14:51.840178500 KeyError: 'capacity_nominal'
2023-06-06 00:14:54.299904500 Exiting bt-loop
2023-06-06 00:14:54.690997500 Missing device address argument
2023-06-06 00:14:56.304447500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:14:56.305833500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:14:56.989659500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:14:56.991087500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:15:12.857607500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-06 00:15:12.857615500
2023-06-06 00:15:12.857616500 connect and scrape on address: C8:47:8C:E9:03:8B
2023-06-06 00:15:12.857619500 btloop
2023-06-06 00:15:12.857621500 reconnect
2023-06-06 00:15:12.857622500
2023-06-06 00:15:12.857623500 btloop
2023-06-06 00:15:12.857624500 reconnect
2023-06-06 00:15:12.857625500 Exiting bt-loop
2023-06-06 00:15:13.232099500 Missing device address argument
2023-06-06 00:15:14.945606500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:15:14.947312500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:15:15.388731500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:15:15.389478500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:15:21.010133500 ERROR:SerialBattery:No Jkbms_Ble found at C8:47:8C:E9:03:8B
2023-06-06 00:15:21.010937500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-06 00:15:21.011232500
2023-06-06 00:15:21.320001500 Missing device address argument
2023-06-06 00:15:23.011497500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-06 00:15:23.012837500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-06 00:15:23.393564500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:15:23.394271500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:E9:03:8B
2023-06-06 00:15:34.503645500 INFO:SerialBattery:Jkbms_Ble found!
2023-06-06 00:15:34.505407500 INFO:SerialBattery:BAT: JKBMS 11.XW 16 cells (20221224)
2023-06-06 00:15:34.507196500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-06 00:15:34.509434500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478ce9038b
2023-06-06 00:15:34.512183500 INFO:SerialBattery:========== Settings ==========
2023-06-06 00:15:34.514573500 INFO:SerialBattery:> Connection voltage: 53.25V | Current: -2.1A | SoC: 93%
2023-06-06 00:15:34.515542500 INFO:SerialBattery:> Cell count: 16 | Cells populated: 16
2023-06-06 00:15:34.516443500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: True
2023-06-06 00:15:34.517465500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 70.0A | MAX BATTERY DISCHARGE CURRENT: 100.0A
2023-06-06 00:15:34.518427500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 140.0A | MAX BATTERY DISCHARGE CURRENT: 200.0A (read from BMS)
2023-06-06 00:15:34.519296500 INFO:SerialBattery:> CVCM:     True
2023-06-06 00:15:34.538814500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-06 00:15:34.541594500 INFO:SerialBattery:> CCCM CV:  True  | DCCM CV:  True
2023-06-06 00:15:34.543211500 INFO:SerialBattery:> CCCM T:   True  | DCCM T:   True
2023-06-06 00:15:34.544732500 INFO:SerialBattery:> CCCM SOC: True  | DCCM SOC: True
2023-06-06 00:15:34.546482500 INFO:SerialBattery:Serial Number/Unique Identifier: 2092245065
2023-06-06 00:15:34.832464500 INFO:SerialBattery:DeviceInstance = 4
2023-06-06 00:15:34.836261500 INFO:SerialBattery:com.victronenergy.battery.c8478ce9038b
2023-06-06 00:15:34.838402500 INFO:SerialBattery:BAT: JKBMS 11.XW 16 cells (20221224)
2023-06-06 00:15:34.907198500 INFO:SerialBattery:publish config values = 1

@mr-manuel
Copy link
Collaborator

Please put tripple backticks ``` in the line before and after your code/logs for correct formatting.

This should help, thanks. What is your BMS hardware/firmware version?

@simsandmann
Copy link
Author

simsandmann commented Jun 6, 2023 •
edited
Loading

Both BMS are JK_B2A20S20P (JK-B2A20S20P)

JKBMS 1:
HW: 10.XW
SW: 10.10

JKBMS 2:
HW: 11.XW
SW: 11.25

/etc/init.d/bluetooth restart with a Serial connection and only one Bluetooth connection works instantly. (11.XW via Serial, 10.XW via BT). Having 2 Bluetooth JKBMS in Config --> No connection.

@sstolk90
Copy link

sstolk90 commented Jun 6, 2023

I can confirm the same issue with also two JK bms'es. Version is 2.92 and the troubleshooting mentioned in this topic/bug report is the same with mine setup. My Victron also reboots the GX side once in the X hours. My MQTT messages are missing for a couple of minutes and that is the moment the VenusOS reboots. The system also resets the names I've given them and when I check the names are standard. The connection is sometimes restored to both the units and sometimes not. I'm keeping the serial connection to one of the BMS'es live to keep the CCL and DCL accurate with settings.

@sstolk90
Copy link

sstolk90 commented Jun 6, 2023

Restarting the bluetooth connection as mentioned above works: /etc/init.d/bluetooth restart. Both BMS'es are displayed. When the VenusOS reboots it's probally resetted.
image

@mr-manuel
Copy link
Collaborator

@sstolk90 for the names see #100

@baranator could you take a look at the thread issue?

@mr-manuel mr-manuel mentioned this issue Jun 7, 2023
Merged
@seidler2547
Copy link
Contributor

@mr-manuel seems like it happens here, on reconnect:

dbus-serialbattery/etc/dbus-serialbattery/bms/jkbms_ble.py

Line 154 in 86a6b95

if time.time() - st["last_update"] > 30:

Do you really think it should do that? If anything, it should call stop_scraping first. But I would rather just exit and let a "normal" reconnect happen.

It could also be that with the scanning removed (#695) that the initial connect will be more reliable since there wouldn't be two processes doing exactly the same scan at exactly the same time.

@sstolk90 can you find out the reason for the reboot? There could be a hint in /var/log/messages (or /var/log/messages.0) on your GX device. For me it was OOM (out of memory) until I put a script in place to fix a memory leak.

@mr-manuel
Copy link
Collaborator

mr-manuel commented Jun 8, 2023 •
edited
Loading

Please execute this commands to apply the potential fixes:

wget -O /data/etc/dbus-serialbattery/bms/jkbms_ble.py https://raw.githubusercontent.com/mr-manuel/venus-os_dbus-serialbattery/dev/etc/dbus-serialbattery/bms/jkbms_ble.py
wget -O /data/etc/dbus-serialbattery/bms/jkbms_brn.py https://raw.githubusercontent.com/mr-manuel/venus-os_dbus-serialbattery/dev/etc/dbus-serialbattery/bms/jkbms_brn.py
bash /data/etc/dbus-serialbattery/reinstall-local.sh

reboot

Let me know, if this fixes your problem.

@sstolk90
Copy link

sstolk90 commented Jun 8, 2023 •
edited by mr-manuel
Loading

I have this in the logs 
Jun  8 04:27:53 nanopi daemon.debug rngd: [jitter]: xread_jitter requests 2500 bytes from pipe
Jun  8 04:27:53 nanopi daemon.debug rngd: [jitter]: xread_jitter falls back to AES
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 2472/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 2624/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 2762/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 2887/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3000/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3103/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3196/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3280/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3357/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3426/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3489/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3546/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3597/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3644/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3686/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3724/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3759/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3791/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3819/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3845/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3868/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3890/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3909/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3926/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3942/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3956/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3969/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3981/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 3992/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 4001/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 4010/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 4018/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 4025/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Added 4032/4096 bits entropy
Jun  8 04:27:53 nanopi daemon.debug rngd: Pool full at 4096, sleeping!
Jun  8 04:27:53 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:27:53 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 1 wakes up for refill
Jun  8 04:27:54 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 0 is 2.727370146900e+01 sec
Jun  8 04:27:54 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:27:54 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:27:54 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 0 wakes up for refill
Jun  8 04:27:56 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 3 is 2.818484219600e+01 sec
Jun  8 04:27:56 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:27:56 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:27:56 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 3 wakes up for refill
Jun  8 04:27:57 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 2 is 3.010089842900e+01 sec
Jun  8 04:27:57 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:27:57 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:27:57 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 2 wakes up for refill
Jun  8 04:28:02 nanopi daemon.info connmand[648]: ntp: time slew +0.980480 s
Jun  8 04:28:08 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 1 is 1.501241921800e+01 sec
Jun  8 04:28:08 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:08 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:28:08 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 1 wakes up for refill
Jun  8 04:28:12 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 0 is 1.933747561700e+01 sec
Jun  8 04:28:12 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:12 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:28:12 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 0 wakes up for refill
Jun  8 04:28:14 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 3 is 1.801609917500e+01 sec
Jun  8 04:28:14 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:14 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:28:14 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 3 wakes up for refill
Jun  8 04:28:20 nanopi daemon.info bluetoothd[581]: Terminating
Jun  8 04:28:20 nanopi daemon.info bluetoothd[581]: Exit
Jun  8 04:28:20 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 2 is 2.439997932700e+01 sec
Jun  8 04:28:20 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:20 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 04:28:20 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 2 wakes up for refill
Jun  8 04:28:21 nanopi daemon.info bluetoothd[1963]: Bluetooth daemon 5.55
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.warn bluetoothd[1963]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 04:28:21 nanopi daemon.info bluetoothd[1963]: Bluetooth management interface 1.18 initialized
Jun  8 04:28:21 nanopi user.err kernel: [   58.940176] debugfs: File 'force_bredr_smp' in directory 'hci0' already present!
Jun  8 04:28:21 nanopi authpriv.notice login[1972]: ROOT LOGIN  on '/dev/ttyS0'
Jun  8 04:28:27 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 3 is 1.470116609000e+01 sec
Jun  8 04:28:27 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:29 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 1 is 2.159808453200e+01 sec
Jun  8 04:28:29 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:30 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 0 is 1.843361019900e+01 sec
Jun  8 04:28:30 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:28:34 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 2 is 1.423564782700e+01 sec
Jun  8 04:28:34 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 04:30:39 nanopi user.err kernel: [  197.267149] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:30:39 nanopi user.err kernel: [  197.273273] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:31:10 nanopi user.err kernel: [  228.045058] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:31:10 nanopi user.err kernel: [  228.051130] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:38:00 nanopi user.err kernel: [  637.635959] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:38:00 nanopi user.err kernel: [  637.642162] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:38:52 nanopi user.err kernel: [  689.514931] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:38:52 nanopi user.err kernel: [  689.521030] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:42:45 nanopi user.err kernel: [  922.883960] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:42:45 nanopi user.err kernel: [  922.890251] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:48:41 nanopi user.err kernel: [ 1278.721918] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:48:41 nanopi user.err kernel: [ 1278.727932] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:49:02 nanopi user.err kernel: [ 1299.365108] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:49:02 nanopi user.err kernel: [ 1299.371351] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:52:22 nanopi user.err kernel: [ 1500.022043] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 04:52:22 nanopi user.err kernel: [ 1500.028087] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3013/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3328/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3400/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3465/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3524/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Reading entropy from JITTER Entropy generator
Jun  8 05:52:45 nanopi daemon.debug rngd: [jitter]: xread_jitter requests 2500 bytes from pipe
Jun  8 05:52:45 nanopi daemon.debug rngd: [jitter]: xread_jitter gets 2500 bytes
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3578/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3626/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3670/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3710/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3746/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3779/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3809/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3835/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3860/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3882/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3902/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3920/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3936/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3951/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3965/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3977/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3988/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 3998/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 4007/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 4015/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 4023/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 4030/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Added 4036/4096 bits entropy
Jun  8 05:52:45 nanopi daemon.debug rngd: Pool full at 4096, sleeping!
Jun  8 05:58:35 nanopi daemon.notice wpa_supplicant[710]: wifi0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
Jun  8 06:28:03 nanopi daemon.info connmand[648]: ntp: time slew -0.246757 s
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3013/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3328/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3400/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3465/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3524/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3578/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3626/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3670/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3710/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3746/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3779/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3809/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3835/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3860/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3882/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3902/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Reading entropy from JITTER Entropy generator
Jun  8 08:02:54 nanopi daemon.debug rngd: [jitter]: xread_jitter requests 2500 bytes from pipe
Jun  8 08:02:54 nanopi daemon.debug rngd: [jitter]: xread_jitter gets 2500 bytes
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3920/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3936/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3951/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3965/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3977/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3988/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 3998/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 4007/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 4015/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 4023/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 4030/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Added 4036/4096 bits entropy
Jun  8 08:02:54 nanopi daemon.debug rngd: Pool full at 4096, sleeping!
Jun  8 08:03:35 nanopi daemon.notice wpa_supplicant[710]: wifi0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
Jun  8 08:19:59 nanopi authpriv.notice sudo:     root : TTY=pts/0 ; PWD=/data/home/root ; USER=root ; COMMAND=/bin/cat /var/log/messages

@sstolk90
Copy link

sstolk90 commented Jun 8, 2023 

bash /data/etc/dbus-serialbattery/reinstall-local.sh

I've installed this and will monitor for issues!

@sstolk90
Copy link

sstolk90 commented Jun 8, 2023 •
edited by mr-manuel
Loading

Well, the bluetooth is not coming back after installing the above command's:

Logs: 
Jun  8 08:23:35 nanopi user.notice shutdown[19486]: shutting down for system reboot
**snip reboot process*
Jun  8 08:24:18 nanopi daemon.info rngd: [jitter]: Initialized
Jun  8 08:24:18 nanopi daemon.debug rngd: Reading entropy from JITTER Entropy generator
Jun  8 08:24:18 nanopi daemon.debug rngd: [jitter]: xread_jitter requests 2500 bytes from pipe
Jun  8 08:24:18 nanopi daemon.debug rngd: [jitter]: xread_jitter falls back to AES
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 2496/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 2646/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 2782/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 2905/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3016/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3118/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3209/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3292/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3367/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3436/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3497/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3553/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3604/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3650/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3692/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3730/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3764/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3795/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3823/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3849/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3872/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3893/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3912/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3929/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3944/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3959/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3971/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3983/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 3993/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 4003/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 4012/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 4019/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 4027/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Added 4033/4096 bits entropy
Jun  8 08:24:18 nanopi daemon.debug rngd: Pool full at 4096, sleeping!
Jun  8 08:24:18 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:18 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 1 wakes up for refill
Jun  8 08:24:19 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 0 is 2.708381613600e+01 sec
Jun  8 08:24:19 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:19 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:19 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 0 wakes up for refill
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 3 is 2.714628865500e+01 sec
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 3 wakes up for refill
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 2 is 2.859560384600e+01 sec
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:20 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 2 wakes up for refill
Jun  8 08:23:53 nanopi daemon.info dnsmasq[592]: started, version 2.83 cachesize 150
Jun  8 08:24:24 nanopi daemon.warn dnsmasq[592]: overflow: 3 log entries lost
Jun  8 08:24:27 nanopi daemon.info connmand[651]: ntp: time slew +1.014409 s
Jun  8 08:24:34 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 3 is 1.538958903100e+01 sec
Jun  8 08:24:34 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:34 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:34 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 3 wakes up for refill
Jun  8 08:24:37 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 0 is 1.803464688300e+01 sec
Jun  8 08:24:37 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:37 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:37 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 0 wakes up for refill
Jun  8 08:24:38 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 1 is 2.150073990900e+01 sec
Jun  8 08:24:38 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:38 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:38 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 1 wakes up for refill
Jun  8 08:24:40 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 2 is 2.034135634100e+01 sec
Jun  8 08:24:40 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:40 nanopi daemon.debug rngd: [jitter]: DONE Writing to pipe with return 16535
Jun  8 08:24:40 nanopi daemon.debug rngd: [jitter]: JITTER thread on cpu 2 wakes up for refill
Jun  8 08:24:45 nanopi daemon.info bluetoothd[584]: Terminating
Jun  8 08:24:45 nanopi daemon.info bluetoothd[584]: Exit
Jun  8 08:24:46 nanopi daemon.info bluetoothd[2059]: Bluetooth daemon 5.55
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.warn bluetoothd[2059]: ../bluez-5.55/src/main.c:parse_controller_config() Key file does not have group “Controller”
Jun  8 08:24:46 nanopi daemon.info bluetoothd[2059]: Bluetooth management interface 1.18 initialized
Jun  8 08:24:46 nanopi user.err kernel: [   58.685906] debugfs: File 'force_bredr_smp' in directory 'hci0' already present!
Jun  8 08:24:46 nanopi authpriv.notice login[2075]: ROOT LOGIN  on '/dev/ttyS0'
Jun  8 08:24:54 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 3 is 2.007782503200e+01 sec
Jun  8 08:24:54 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:54 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 2 is 1.534074821500e+01 sec
Jun  8 08:24:54 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:57 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 0 is 2.010459607400e+01 sec
Jun  8 08:24:57 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:24:57 nanopi daemon.debug rngd: [jitter]: jent_read_entropy time on cpu 1 is 1.948698686600e+01 sec
Jun  8 08:24:57 nanopi daemon.debug rngd: [jitter]: Writing to pipe
Jun  8 08:25:57 nanopi daemon.notice wpa_supplicant[710]: wifi0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
Jun  8 08:26:33 nanopi user.err kernel: [  165.724899] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 08:26:33 nanopi user.err kernel: [  165.731008] Bluetooth: hci0: unexpected event for opcode 0xfc19
Jun  8 08:26:48 nanopi authpriv.notice sudo:     root : TTY=pts/0 ; PWD=/data/home/root ; USER=root ; COMMAND=/bin/cat /var/log/messages
image

@mr-manuel
Copy link
Collaborator

mr-manuel commented Jun 8, 2023 •
edited
Loading

What does the driver log say?

Did you reboot after install? If not, please reboot.

The logs say it...

Jun  8 08:23:35 nanopi user.notice shutdown[19486]: shutting down for system reboot
**snip reboot process*

@mr-manuel
Copy link
Collaborator

In the meanwhile I found this two links regarding Jun 8 08:26:33 nanopi user.err kernel: [ 165.724899] Bluetooth: hci0: unexpected event for opcode 0xfc19:

@seidler2547 do you also see this in your logs with the LltJbd_Ble driver?

@sstolk90
Copy link

sstolk90 commented Jun 8, 2023 •
edited by mr-manuel
Loading

What does the driver log say?

Did you reboot after install? If not, please reboot.

The logs say it...

Jun  8 08:23:35 nanopi user.notice shutdown[19486]: shutting down for system reboot
**snip reboot process*
Logs: 
root@nanopi:~# tail -n 200 -f /data/log/dbus-blebattery.0/current | tai64nlocal
2023-06-08 08:37:17.157119500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:37:17.157634500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:37:36.712378500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:37:36.712929500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:37:36.713172500
2023-06-08 08:37:36.713174500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:37:36.713177500 btloop
2023-06-08 08:37:36.713178500 reconnect
2023-06-08 08:37:39.931032500 Exiting bt-loop
2023-06-08 08:37:40.348123500 Missing device address argument
2023-06-08 08:37:40.348133500 [CHG] Device 64:24:24:D2:5B:B2 RSSI: -86
2023-06-08 08:37:40.348135500 [CHG] Device 53:5F:79:C4:C5:5F RSSI: -86
2023-06-08 08:37:41.429974500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:37:41.431079500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:37:41.745620500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:37:41.746134500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:37:55.379084500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:37:55.379768500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:37:55.380031500
2023-06-08 08:37:55.380033500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:37:55.380035500 btloop
2023-06-08 08:37:55.380036500 reconnect
2023-06-08 08:37:55.380038500 Exiting bt-loop
2023-06-08 08:37:55.772616500 Missing device address argument
2023-06-08 08:37:56.866450500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:37:56.867572500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:37:57.213077500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:37:57.213592500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:38:16.766025500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:38:16.766577500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:38:16.766821500
2023-06-08 08:38:16.766823500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:38:16.766826500 btloop
2023-06-08 08:38:16.766827500 reconnect
2023-06-08 08:38:17.272814500 Exiting bt-loop
2023-06-08 08:38:17.679314500 Missing device address argument
2023-06-08 08:38:18.810272500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:38:18.811441500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:38:19.153269500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:38:19.153784500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:38:38.705242500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:38:38.705828500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:38:38.706118500
2023-06-08 08:38:38.706121500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:38:38.706124500 btloop
2023-06-08 08:38:38.706125500 reconnect
2023-06-08 08:38:41.924633500 Exiting bt-loop
2023-06-08 08:38:42.358526500 Missing device address argument
2023-06-08 08:38:42.358535500 [CHG] Device C8:47:8C:E5:01:1B RSSI: -72
2023-06-08 08:38:43.467436500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:38:43.468483500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:38:43.779671500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:38:43.780220500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:01.033969500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:39:01.036566500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:39:01.036579500
2023-06-08 08:39:01.036580500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:39:01.036583500 btloop
2023-06-08 08:39:01.036584500 reconnect
2023-06-08 08:39:01.036586500
2023-06-08 08:39:01.036587500 Exiting bt-loop
2023-06-08 08:39:01.439948500 Missing device address argument
2023-06-08 08:39:02.528394500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:39:02.529650500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:39:02.879346500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:02.880122500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:16.121000500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:39:16.121538500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:39:16.121781500
2023-06-08 08:39:16.121783500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:39:16.121786500 btloop
2023-06-08 08:39:16.121787500 reconnect
2023-06-08 08:39:16.121788500 Exiting bt-loop
2023-06-08 08:39:16.528639500 Missing device address argument
2023-06-08 08:39:17.620968500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:39:17.622748500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:39:17.988295500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:17.988863500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:28.718557500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:39:28.719207500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:39:28.719864500
2023-06-08 08:39:28.719868500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:39:28.719871500 btloop
2023-06-08 08:39:28.719872500 reconnect
2023-06-08 08:39:28.719873500 Exiting bt-loop
2023-06-08 08:39:29.195531500 Missing device address argument
2023-06-08 08:39:29.195542500 [CHG] Device C8:47:8C:EC:C0:B5 RSSI: -70
2023-06-08 08:39:29.195544500 [CHG] Device 1E:06:A5:97:5F:B3 RSSI: -90
2023-06-08 08:39:29.195547500 [CHG] Device 51:F6:73:8B:3C:23 RSSI: -82
2023-06-08 08:39:30.363853500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:39:30.365059500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:39:30.697952500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:30.698459500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:49.360947500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:39:49.361509500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:39:49.361745500
2023-06-08 08:39:49.361747500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:39:49.361750500 btloop
2023-06-08 08:39:49.361751500 reconnect
2023-06-08 08:39:49.361752500 Exiting bt-loop
2023-06-08 08:39:49.777739500 Missing device address argument
2023-06-08 08:39:50.926646500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:39:50.927710500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:39:51.289704500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:39:51.290352500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:40:10.838773500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:40:10.839411500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:40:10.839664500
2023-06-08 08:40:10.839666500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:40:10.839669500 btloop
2023-06-08 08:40:10.839670500 reconnect
2023-06-08 08:40:11.055222500 Exiting bt-loop
2023-06-08 08:40:11.512186500 Missing device address argument
2023-06-08 08:40:11.512196500 [CHG] Device 6D:1D:19:A3:EB:D7 RSSI: -88
2023-06-08 08:40:12.581057500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:40:12.582151500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:40:12.919646500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:40:12.920181500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:40:32.472887500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:40:32.473459500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:40:32.473715500
2023-06-08 08:40:32.473717500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:40:32.473720500 btloop
2023-06-08 08:40:32.473721500 reconnect
2023-06-08 08:40:33.318244500 Exiting bt-loop
2023-06-08 08:40:33.719572500 Missing device address argument
2023-06-08 08:40:34.813950500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:40:34.815608500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:40:35.170029500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:40:35.171300500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:40:45.796798500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:40:45.797356500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:40:45.797596500
2023-06-08 08:40:45.797598500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:40:45.797601500 btloop
2023-06-08 08:40:45.797602500 reconnect
2023-06-08 08:40:45.797604500 Exiting bt-loop
2023-06-08 08:40:46.253334500 Missing device address argument
2023-06-08 08:40:46.253344500 [CHG] Device 62:75:1E:E2:AE:1C RSSI: -78
2023-06-08 08:40:46.253347500 [CHG] Device 6E:62:C4:E6:AA:42 RSSI: -88
2023-06-08 08:40:47.329465500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:40:47.330649500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:40:47.653924500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:40:47.654465500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:01.006750500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:41:01.007524500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:41:01.007840500
2023-06-08 08:41:01.007844500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:41:01.007847500 btloop
2023-06-08 08:41:01.007848500 reconnect
2023-06-08 08:41:01.007849500
2023-06-08 08:41:01.007850500 Exiting bt-loop
2023-06-08 08:41:01.439193500 Missing device address argument
2023-06-08 08:41:02.544338500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:41:02.545467500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:41:02.901426500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:02.902128500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:16.339168500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:41:16.339869500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:41:16.340172500
2023-06-08 08:41:16.340175500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:41:16.340177500 btloop
2023-06-08 08:41:16.340179500 reconnect
2023-06-08 08:41:16.340180500 Exiting bt-loop
2023-06-08 08:41:16.737880500 Missing device address argument
2023-06-08 08:41:17.896655500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:41:17.897836500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:41:18.276201500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:18.276856500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:28.895411500 ERROR:SerialBattery:No BMS found at C8:47:8C:EC:C0:B5
2023-06-08 08:41:28.895958500 ERROR:SerialBattery:ERROR >>> No battery connection at Jkbms_Ble
2023-06-08 08:41:28.896201500
2023-06-08 08:41:28.896202500 connect and scrape on address: C8:47:8C:EC:C0:B5
2023-06-08 08:41:28.896205500 btloop
2023-06-08 08:41:28.896206500 reconnect
2023-06-08 08:41:28.896208500 Exiting bt-loop
2023-06-08 08:41:29.399314500 Missing device address argument
2023-06-08 08:41:29.399323500 [CHG] Device 62:75:1E:E2:AE:1C RSSI: -80
2023-06-08 08:41:30.523260500 INFO:SerialBattery:Starting dbus-serialbattery
2023-06-08 08:41:30.524318500 INFO:SerialBattery:dbus-serialbattery v1.0.20230531
2023-06-08 08:41:30.839653500 INFO:SerialBattery:Init of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:30.840248500 INFO:SerialBattery:Test of Jkbms_Ble at C8:47:8C:EC:C0:B5
2023-06-08 08:41:35.354509500 INFO:SerialBattery:BAT: JKBMS 11.XW 16 cells (20230504)
2023-06-08 08:41:35.355559500 INFO:SerialBattery:Connection established to Jkbms_Ble
2023-06-08 08:41:35.357001500 INFO:SerialBattery:Battery Jkbms_Ble connected to dbus from c8478cecc0b5
2023-06-08 08:41:35.357435500 INFO:SerialBattery:========== Settings ==========
2023-06-08 08:41:35.358025500 INFO:SerialBattery:> Connection voltage: 53.57V | Current: 34.7A | SoC: 58%
2023-06-08 08:41:35.358412500 INFO:SerialBattery:> Cell count: 16 | Cells populated: 16
2023-06-08 08:41:35.358809500 INFO:SerialBattery:> LINEAR LIMITATION ENABLE: True
2023-06-08 08:41:35.359218500 INFO:SerialBattery:> MAX BATTERY CHARGE CURRENT: 100.0A | MAX BATTERY DISCHARGE CURRENT: 100.0A
2023-06-08 08:41:35.359780500 INFO:SerialBattery:> CVCM:     True
2023-06-08 08:41:35.360215500 INFO:SerialBattery:> MIN CELL VOLTAGE: 2.9V | MAX CELL VOLTAGE: 3.45V
2023-06-08 08:41:35.360614500 INFO:SerialBattery:> CCCM CV:  True  | DCCM CV:  True
2023-06-08 08:41:35.360984500 INFO:SerialBattery:> CCCM T:   True  | DCCM T:   True
2023-06-08 08:41:35.361346500 INFO:SerialBattery:> CCCM SOC: True  | DCCM SOC: True
2023-06-08 08:41:35.361700500 INFO:SerialBattery:Serial Number/Unique Identifier: 2120146523
2023-06-08 08:41:35.415809500 INFO:SerialBattery:DeviceInstance = 4
2023-06-08 08:41:35.416358500 INFO:SerialBattery:com.victronenergy.battery.c8478cecc0b5
2023-06-08 08:41:35.417060500 INFO:SerialBattery:BAT: JKBMS 11.XW 16 cells (20230504)
2023-06-08 08:41:35.441925500 INFO:SerialBattery:publish config values = 1

After the reboot it detects 1 JK BMS over Bluetooth and the other one on serial. I think when I reboot the bluetooth process it will reconnect to the second one. Will test it now

@sstolk90
Copy link

sstolk90 commented Jun 8, 2023

After entering the command /etc/init.d/bluetooth restart it shows this. Correct in my case but not sure if it will reboot. I will rename one of the BLE names to something own and when it's rebooted I will notice the name change.

image

@sstolk90
Copy link

sstolk90 commented Jun 8, 2023

After renaming all three it reconnects both bluetooth and resets their name after a while. The unit has not rebooted since the Batterij Onder (eng: Battery Below) has kept his name:
image

@mr-manuel
Copy link
Collaborator

Ok, this means, that the driver creashes and restarts. Can you contact me on Discord?

@seidler2547
Copy link
Contributor

hci0: unexpected event for opcode 0xfc19
I think I've seen this too, occasionally. I don't think it's a problem.

@sstolk90 is the BT dongle far away from the batteries or is there a lot of interference, e.g. From WiFi?

Also, you did disable Bluetooth in the GUI, didn't you?

Right now from the logs it seems that the connection doesn't work because the communication between the GX and the BMS is interrupted. I don't immediately see how the driver could work around that, but it's hard to say.

@mr-manuel
Copy link
Collaborator

I made some changes in my dev branch. The log will display the signal strenght of a Bluetooth connections in the logs, this will help troubleshooting.

@mr-manuel
Copy link
Collaborator

This is solved with https://github.com/mr-manuel/venus-os_dbus-serialbattery/releases/tag/v1.0.20230610beta which gets merged with the dev branch of this repo later today. Then it can be installed using the install script by selecting nightly and then dev.

@mr-manuel mr-manuel self-assigned this Jun 10, 2023
@mr-manuel mr-manuel mentioned this issue Jun 11, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mr-manuel mr-manuel

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@seidler2547 @mr-manuel @simsandmann @sstolk90 @drago-more