/var/log/messages spammed by Bluetooth errors

Question

question

henrik asked Jan 16, '24

/var/log/messages spammed by Bluetooth errors

I have a Raspberry Pi Zero 2W with VenusOS firmware 3.13. It works fine, but /var/log/messages is spammed with Bluetooth error messages. It amounts to 100K every 10 minutes, which means that I don't have more than about 1 hour of history:

$ ls -ltr /var/log/messages*
-rw-r--r--    1 root     root        102492 Jan 16 07:43 /var/log/messages.5
-rw-r--r--    1 root     root        102492 Jan 16 07:52 /var/log/messages.4
-rw-r--r--    1 root     root        102479 Jan 16 08:02 /var/log/messages.3
-rw-r--r--    1 root     root        102467 Jan 16 08:12 /var/log/messages.2
-rw-r--r--    1 root     root        102406 Jan 16 08:22 /var/log/messages.1
-rw-r--r--    1 root     root        102492 Jan 16 08:32 /var/log/messages.0
-rw-r--r--    1 root     root           642 Jan 16 08:32 /var/log/messages

Here are the messages that are repeated every 10 seconds:

Jan 16 07:23:02 raspberrypi2 user.err kernel: [11986.963002] debugfs: File 'dut_mode' in directory 'hci0' already present!
Jan 16 07:23:02 raspberrypi2 user.err kernel: [11986.969956] debugfs: File 'vendor_diag' in directory 'hci0' already present!
Jan 16 07:23:05 raspberrypi2 user.err kernel: [11989.850713] Bluetooth: hci0: command 0xfc18 tx timeout
Jan 16 07:23:13 raspberrypi2 user.err kernel: [11997.930756] Bluetooth: hci0: BCM: failed to write update baudrate (-110)
Jan 16 07:23:13 raspberrypi2 user.err kernel: [11997.937479] Bluetooth: hci0: Failed to set baudrate
Jan 16 07:23:13 raspberrypi2 user.info kernel: [11998.064492] Bluetooth: hci0: BCM: chip id 115
Jan 16 07:23:13 raspberrypi2 user.info kernel: [11998.070844] Bluetooth: hci0: BCM: features 0x0e
Jan 16 07:23:13 raspberrypi2 user.info kernel: [11998.098259] Bluetooth: hci0: BCM43430B0
Jan 16 07:23:13 raspberrypi2 user.info kernel: [11998.102150] Bluetooth: hci0: BCM (002.001.012) build 0000
Jan 16 07:23:13 raspberrypi2 user.err kernel: [11998.107632] Bluetooth: hci0: BCM: firmware Patch file not found, tried:
Jan 16 07:23:13 raspberrypi2 user.err kernel: [11998.114281] Bluetooth: hci0: BCM: 'brcm/BCM.hcd'

Raspberry Pi Bluetooth vrm logging

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

Modifications Space

Node Red Space

Answer 1 · 2024-01-16T08:50:34Z

henrik answered · Jan 16 at 08:50 AM

As usual, formulating the problem made me figure out a fix:

cd /lib/firmware/brcm
ln -s BCM43430B0.hcd BCM.hcd

The spamming stopped! :D

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

Answer 2 · 2024-01-16T09:15:14Z

Bluetooth still doesn't work though.

If I enable Bluetooth in the Remote Console, I get rfkill: unblock set for type bluetooth every second in /var/log/messages.

Also there's this every second in /var/log/vesmart-server/current:

@4000000065a647fe24c2c24c *** starting vesmart-server ***
@4000000065a647fe287d805c Using adapter hci0
@4000000065a64800143be4bc -------- vesmart-server, v0.5.6 is starting up --------
@4000000065a648001453451c INFO:logger:Loglevel set to INFO
@4000000065a6480017d84174 INFO:vesmart_server:Using product name: Raspberry Pi Zero 2 W Rev 1.0
@4000000065a6480017e3594c INFO:vesmart_server:Using product id: C003
@4000000065a648001889a784 Traceback (most recent call last):
@4000000065a64800188b5d04   File "/opt/victronenergy/vesmart-server/vesmart_server.py", line 162, in <module>
@4000000065a64800189e6bec     while not adapter_props.Get(bluezutils.ADAPTER_INTERFACE, "Powered"):
@4000000065a64800189f852c   File "/usr/lib/python3.8/site-packages/dbus/proxies.py", line 72, in __call__
@4000000065a6480018ab6c0c     return self._proxy_method(*args, **keywords)
@4000000065a6480018ac75ac   File "/usr/lib/python3.8/site-packages/dbus/proxies.py", line 141, in __call__
@4000000065a6480018bb7584     return self._connection.call_blocking(self._named_service,
@4000000065a6480018bcc574   File "/usr/lib/python3.8/site-packages/dbus/connection.py", line 666, in call_blocking
@4000000065a6480018e58edc     reply_message = self.send_message_with_reply_and_block(
@4000000065a6480018e69494 dbus.exceptions.DBusException: org.freedesktop.DBus.Error.UnknownObject: Method "Get" with signature "ss" on interface "org.freedesktop.DBus.Properties" doesn't exist

And this every second in /var/log/dbus-mqtt/current:

@4000000065a6427f093d5564 INFO:dbus_mqtt:[Scanning] service: com.victronenergy.ble
@4000000065a6427f15f982dc INFO:dbus_mqtt:[Scanning] No response from service during scan: com.victronenergy.ble
@4000000065a6427f1609e62c INFO:dbus_mqtt:[OwnerChange] Service disappeared: com.victronenergy.ble

And this every second in /var/log/dbus-ble-sensors/current:

@4000000065a64274232e4b54 *** starting dbus-ble-sensors ***
@4000000065a6427426040094 dbus-ble-sensors 0.12
@4000000065a6427427024a3c opening hci0
@4000000065a6427f04c634c4 HCIDEVUP: Invalid request code
@4000000065a6427f04cda704 no device found

And this every second in /var/log/gui/current:

@4000000065a6425c30463914 Get Items failed "com.victronenergy.ble"

Answer 3 · 2024-02-20T08:23:36Z

henrik answered · Feb 20 at 08:23 AM

Added an issue: https://github.com/victronenergy/venus/issues/1225

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

question