Arch Linux

Please read this before reporting a bug:
https://wiki.archlinux.org/title/Bug_reporting_guidelines

Do NOT report bugs when a package is just outdated, or it is in the AUR. Use the 'flag out of date' link on the package page, or the Mailing List.

REPEAT: Do NOT report bugs for outdated packages!
Tasklist

FS#46685 - [bluez] Number of errors in logs on startup

Attached to Project: Arch Linux
Opened by john doe (jatone) - Monday, 12 October 2015, 21:50 GMT
Last edited by Andreas Radke (AndyRTR) - Monday, 04 January 2016, 18:12 GMT
Task Type Bug Report
Category Packages: Extra
Status Closed
Assigned To Andreas Radke (AndyRTR)
Architecture All
Severity Very Low
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 1
Private No

Details

There are a number of errors emitted into the bluetooth logs on start up, which have gone unresolved for awhile.


package version:

logs:
journalctl -f --unit=bluetooth
Oct 12 17:39:36 jambli systemd[1]: Starting Bluetooth service...
Oct 12 17:39:36 jambli bluetoothd[1748]: Bluetooth daemon 5.35
Oct 12 17:39:36 jambli bluetoothd[1748]: Starting SDP server
Oct 12 17:39:36 jambli systemd[1]: Started Bluetooth service.
Oct 12 17:39:36 jambli bluetoothd[1748]: Bluetooth management interface 1.10 initialized

no idea what is causing the logs below:
Oct 12 17:39:36 jambli bluetoothd[1748]: Failed to obtain handles for "Service Changed" characteristic
Oct 12 17:39:36 jambli bluetoothd[1748]: Not enough free handles to register service
Oct 12 17:39:36 jambli bluetoothd[1748]: Error adding Link Loss service
Oct 12 17:39:36 jambli bluetoothd[1748]: Not enough free handles to register service
Oct 12 17:39:36 jambli bluetoothd[1748]: Not enough free handles to register service
Oct 12 17:39:36 jambli bluetoothd[1748]: Not enough free handles to register service
Oct 12 17:39:36 jambli bluetoothd[1748]: Current Time Service could not be registered

gatt-time-server - no idea whats causing this.
Oct 12 17:39:36 jambli bluetoothd[1748]: gatt-time-server: Input/output error (5)
Oct 12 17:39:36 jambli bluetoothd[1748]: Not enough free handles to register service
Oct 12 17:39:36 jambli bluetoothd[1748]: Not enough free handles to register service

sap-server: does this even need to be enabled?, adding --noplugin=sap disables the plugin, and fixes the issue.
Oct 12 17:39:36 jambli bluetoothd[1748]: Sap driver initialization failed.
Oct 12 17:39:36 jambli bluetoothd[1748]: sap-server: Operation not permitted (1)

seems like a pulseaudio-bluetooth bug: fixed by removing pulseaudio-bluetooth sudo pacman -Rn pulseaudio-bluetooth and restarting pulseaudio.
this isn't really a solution but the issue seems to be 2 A2DP endpoints get registered. I'll be filing a bug with pulseaudio as well.
Oct 12 17:39:36 jambli bluetoothd[1748]: Endpoint registered: sender=:1.75 path=/MediaEndpoint/A2DPSource
Oct 12 17:39:36 jambli bluetoothd[1748]: Endpoint registered: sender=:1.75 path=/MediaEndpoint/A2DPSink
Oct 12 17:39:36 jambli bluetoothd[1748]: Endpoint registered: sender=:1.51 path=/MediaEndpoint/A2DPSource
Oct 12 17:39:36 jambli bluetoothd[1748]: Endpoint registered: sender=:1.51 path=/MediaEndpoint/A2DPSink
Oct 12 17:39:36 jambli bluetoothd[1748]: RFCOMM server failed for Headset Voice gateway: rfcomm_bind: Address already in use (98)

there also seems to be a number of issues when talking to obexd:
sudo journalctl -f --unit=dbus
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")
Oct 12 17:47:54 jambli dbus[624]: [system] Rejected send message, 11 matched rules; type="method_return", sender=":1.133" (uid=1000 pid=1870 comm="/usr/lib/bluetooth/obexd ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.149" (uid=0 pid=1977 comm="/usr/lib/bluetooth/bluetoothd ")


Steps to reproduce:
sudo systemctl restart bluetooth
This task depends upon

Closed by  Andreas Radke (AndyRTR)
Monday, 04 January 2016, 18:12 GMT
Reason for closing:  Upstream
Additional comments about closing:  either an uncritical logging issue or has to be dealt upstream.
Comment by john doe (jatone) - Monday, 12 October 2015, 21:54 GMT
related packages and their versions:
extra/bluez 5.35-1 [installed]
Daemons for the bluetooth protocol stack
extra/bluez-cups 5.35-1 [installed]
CUPS printer backend for Bluetooth printers
extra/bluez-firmware 1.2-8 [installed]
Firmwares for Broadcom BCM203x and STLC2300 Bluetooth chips
extra/bluez-hid2hci 5.35-1 [installed]
Put HID proxying bluetooth HCI's into HCI mode
extra/bluez-libs 5.35-1 [installed]
Deprecated libraries for the bluetooth protocol stack
extra/bluez-plugins 5.35-1
bluez plugins (PS3 Sixaxis controller)
extra/bluez-qt 5.14.0-1 (kf5)
Qt wrapper for Bluez 5 DBus API
extra/bluez-utils 5.35-1 [installed]
Development and debugging utilities for the bluetooth protocol stack

[jatone@jambli ~]$ pacman -Q -s pulseaudio*
local/lib32-libpulse 7.0-2
A featureful, general-purpose sound server (32-bit client libraries)
local/libcanberra-pulse 0.30-5
PulseAudio plugin for libcanberra
local/pavucontrol 3.0-1
A GTK volume control for PulseAudio
local/pulseaudio 7.0-2
A featureful, general-purpose sound server
local/pulseaudio-alsa 2-3
ALSA Configuration for PulseAudio
local/pulseaudio-bluetooth 7.0-2
Bluetooth support for PulseAudio
local/pulseaudio-gconf 7.0-2
GConf support for PulseAudio
Comment by Gareth Sime (gazza94) - Saturday, 31 October 2015, 01:03 GMT
It would appear that other distributions are also experiencing this problem. Perhaps this is an upstream issue and should be marked as such?
https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1499858
https://bugzilla.redhat.com/show_bug.cgi?id=1259827

I am seeing these messages when using bluez 5.35-1.

This link may be related to the issue but I'm unsure:
http://stackoverflow.com/questions/29891254/bluez-5-30-not-enough-free-handles-to-register-service-error-in-starting-blue

Loading...