Ubuntu
bluez package

  1. Bug #1710601
  2. Comment #0

Comment 0 for bug 1710601

Revision history for this message
doru001 (headset001) wrote : bluetoothctl fails to connect

bluetooth stopped working after some update, probably to bluez5
before it was working flawlessly following https://wiki.archlinux.org/index.php/Bluetooth#Configuration_via_the_CLI
now $ bluetoothctl shows no typed characters, $ sudo bluetoothctl works well until I try to connect the device:
[bluetooth]# connect A8:7E:33:FC:6D:15
Attempting to connect to A8:7E:33:FC:6D:15
[CHG] Device A8:7E:33:FC:6D:15 Connected: yes
Failed to connect: org.bluez.Error.NotAvailable
[CHG] Device A8:7E:33:FC:6D:15 Connected: no
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -81
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -63
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -73
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -65
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -79
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -61
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -75
[CHG] Device A8:7E:33:FC:6D:15 RSSI: -63

I am using bluez 5.37-0ubuntu5 under Ubuntu 16.04.3 LTS, updated to the day.

I found errors in logs:
aug 13 17:34:25 george bluetoothd[752]: Starting SDP server
aug 13 17:34:26 george ModemManager[738]: <info> ModemManager (version 1.4.12) starting in system bus...
aug 13 17:34:26 george kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
aug 13 17:34:26 george kernel: Bluetooth: BNEP filters: protocol multicast
aug 13 17:34:26 george kernel: Bluetooth: BNEP socket layer initialized
aug 13 17:34:26 george bluetoothd[752]: Bluetooth management interface 1.10 initialized
aug 13 17:34:26 george dbus[702]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.fre
aug 13 17:34:26 george bluetoothd[752]: Failed to obtain handles for "Service Changed" characteristic
aug 13 17:34:26 george bluetoothd[752]: Not enough free handles to register service
aug 13 17:34:26 george bluetoothd[752]: Error adding Link Loss service
aug 13 17:34:26 george bluetoothd[752]: Not enough free handles to register service
aug 13 17:34:26 george bluetoothd[752]: Not enough free handles to register service
aug 13 17:34:26 george bluetoothd[752]: Not enough free handles to register service
aug 13 17:34:26 george bluetoothd[752]: Current Time Service could not be registered
aug 13 17:34:26 george bluetoothd[752]: gatt-time-server: Input/output error (5)
aug 13 17:34:26 george bluetoothd[752]: Not enough free handles to register service
aug 13 17:34:26 george bluetoothd[752]: Not enough free handles to register service
aug 13 17:34:26 george bluetoothd[752]: Sap driver initialization failed.
aug 13 17:34:26 george bluetoothd[752]: sap-server: Operation not permitted (1)

aug 13 17:35:00 george dbus[702]: [system] Rejected send message, 2 matched rules; type="method_call", sender=":1.22" (uid=100
aug 13 17:35:14 george sudo[1199]: user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/usr/bin/bluetoothctl
aug 13 17:35:14 george sudo[1199]: pam_unix(sudo:session): session opened for user root by user(uid=0)
aug 13 17:35:23 george systemd[1]: Starting Stop ureadahead data collection...
aug 13 17:35:23 george systemd[1]: Started Stop ureadahead data collection.
aug 13 17:35:23 george systemd[1]: Stopped Read required files in advance.
aug 13 17:43:26 george sudo[1199]: pam_unix(sudo:session): session closed for user root
aug 13 17:47:44 george sshd[1389]: Accepted publickey for user from 192.168.69.200 port 57812 ssh2: RSA SHA256:MQ3JEM2k/Yw2jzz
aug 13 17:47:44 george sshd[1389]: pam_unix(sshd:session): session opened for user user by (uid=0)
aug 13 17:47:44 george systemd-logind[742]: New session 2 of user user.
aug 13 17:47:44 george systemd[1]: Started Session 2 of user user.
aug 13 17:47:52 george sudo[1431]: user : TTY=pts/1 ; PWD=/home/user ; USER=root ; COMMAND=/usr/bin/bluetoothctl
aug 13 17:47:52 george sudo[1431]: pam_unix(sudo:session): session opened for user root by user(uid=0)
aug 13 17:49:30 george /usr/lib/snapd/snapd[685]: snapmgr.go:422: No snaps to auto-refresh found
aug 13 17:49:30 george systemd[1]: Starting Cleanup of Temporary Directories...
aug 13 17:49:30 george snapd[685]: 2017/08/13 17:49:30.803962 snapmgr.go:422: No snaps to auto-refresh found
aug 13 17:49:30 george systemd-tmpfiles[1459]: [/usr/lib/tmpfiles.d/var.conf:14] Duplicate line for path "/var/log", ignoring.
aug 13 17:49:31 george systemd[1]: Started Cleanup of Temporary Directories.
aug 13 17:53:16 george sudo[1520]: user : TTY=pts/0 ; PWD=/var/log ; USER=root ; COMMAND=/usr/bin/vim -R dmesg
aug 13 17:53:16 george sudo[1520]: pam_unix(sudo:session): session opened for user root by user(uid=0)
aug 13 17:53:18 george sudo[1520]: pam_unix(sudo:session): session closed for user root

these errors are common, as you can see in comments to this bug report: https://bugs.launchpad.net/ubuntu/+source/bluez/+bug/1490349

user@george:~$ lsmod | grep bt\\\|blue
btusb 40960 0
btrtl 16384 1 btusb
btbcm 16384 1 btusb
btintel 16384 1 btusb
bluetooth 479232 24 bnep,btbcm,btrtl,btusb,btintel
toshiba_bluetooth 16384 0

strangely enough, I succeded to connect from the xfce4 GUI, using the applet next to the clock, probably using blueman-manager and associated GUI only commands.

hardware used is the same and of good quality, a Toshiba laptop and a Nokia phone. I can use the GUI connection without problems, and bluetoothctl also works correctly in user space as long as the GUI keeps the device connected.

it looks like a permissions issue

/dev$ ls -tl | head # after boot in text mode, wireless card on
total 0
crw-rw-rw- 1 root tty 5, 2 aug 14 11:59 ptmx
crw------- 1 root root 5, 1 aug 14 11:57 console
crw--w---- 1 root tty 4, 1 aug 14 11:57 tty1
crw--w---- 1 root tty 4, 6 aug 14 11:57 tty6
crw--w---- 1 root tty 4, 5 aug 14 11:57 tty5
crw--w---- 1 root tty 4, 4 aug 14 11:57 tty4
crw--w---- 1 root tty 4, 3 aug 14 11:57 tty3
crw--w---- 1 root tty 4, 2 aug 14 11:57 tty2
brw-rw---- 1 root disk 8, 3 aug 14 11:57 sda3
/dev$ ls -tl | head # after startx
total 0
drwxrwxrwt 2 root root 80 aug 14 12:01 shm
crw-rw-rw- 1 root tty 5, 2 aug 14 12:01 ptmx
crw------- 1 user tty 4, 1 aug 14 12:01 tty1
crw-rw-rw- 1 root tty 5, 0 aug 14 12:00 tty
crw------- 1 root root 5, 1 aug 14 11:57 console
crw--w---- 1 root tty 4, 6 aug 14 11:57 tty6
crw--w---- 1 root tty 4, 5 aug 14 11:57 tty5
crw--w---- 1 root tty 4, 4 aug 14 11:57 tty4
crw--w---- 1 root tty 4, 3 aug 14 11:57 tty3
/dev$ ls -tl | head # connected
total 0
crw-rw-rw- 1 root tty 5, 2 aug 14 12:06 ptmx
crw-rw---- 1 root dialout 216, 0 aug 14 12:04 rfcomm0
drwxr-xr-x 2 root root 3760 aug 14 12:04 char
drwxrwxrwt 2 root root 120 aug 14 12:04 shm
crw------- 1 user tty 4, 1 aug 14 12:01 tty1
crw-rw-rw- 1 root tty 5, 0 aug 14 12:00 tty
crw------- 1 root root 5, 1 aug 14 11:57 console
crw--w---- 1 root tty 4, 6 aug 14 11:57 tty6
crw--w---- 1 root tty 4, 5 aug 14 11:57 tty5