[SOLVED] Bluetooth pairing and connectivity failure on fresh install

pontifikas · 2019-12-27 18:50:11

I've been trying to set up Bluetooth after a fresh install on my new pc.

Here is my bluetooth device's info,
and my module loading status.

I am using KDE-Plasma (bluetooth front-end=>bluedevil),
and have installed all Bluetooth and pulseaudio (I have BT headphones) packages mentioned in the relative topics of the wiki.

Bluetooth Service is up and running (immediately after a reboot):

#systemctl status bluetooth 

● bluetooth.service - Bluetooth service 
     Loaded: loaded (/usr/lib/systemd/system/bluetooth.service; enabled; vendor preset: disabled) 
     Active: active (running) since Fri 2019-12-27 10:22:14 CET; 4min 37s ago 
       Docs: man:bluetoothd(8) 
   Main PID: 573 (bluetoothd) 
      Tasks: 1 (limit: 19092) 
     Memory: 2.5M 
     CGroup: /system.slice/bluetooth.service 
             └─573 /usr/lib/bluetooth/bluetoothd 
Dec 27 10:22:14 Hex systemd[1]: Starting Bluetooth service... 
Dec 27 10:22:14 Hex bluetoothd[573]: Bluetooth daemon 5.52 
Dec 27 10:22:14 Hex systemd[1]: Started Bluetooth service. 
Dec 27 10:22:14 Hex bluetoothd[573]: Starting SDP server 
Dec 27 10:22:14 Hex bluetoothd[573]: Bluetooth management interface 1.14 initialized 
Dec 27 10:22:26 Hex bluetoothd[573]: Endpoint registered: sender=:1.122 path=/MediaEndpoint/A2DPSink/sbc 
Dec 27 10:22:26 Hex bluetoothd[573]: Endpoint registered: sender=:1.122 path=/MediaEndpoint/A2DPSource/sbc

User is in lp group:

pontifikas@Hex ~:
$groups

lp pontifikas

(even though I don't see how that is relevant when not using the front-end since I am running bluetoothctl as root)

There is no soft blocking:

#rfkill list 

0: hci0: Bluetooth 
        Soft blocked: no 
        Hard blocked: no 
1: phy0: Wireless LAN 
        Soft blocked: no 
        Hard blocked: no

I tried pairing and connecting
a) to my mobile phone (Sony Xperia) and
b) to my bluetooth headphones (Bose QC35) (this is actually the device I mostly need).

I have been able to pair my phone (exchange pins and authenticate successfuly), but when trying to connect, even though the connection is initially established, after a while I get an error
eg:

[CHG] Device 40:40:A7:C4:93:E8 ServicesResolved: yes  
[CHG] Device 40:40:A7:C4:93:E8 Paired: yes  
Pairing successful  
[Xperia Z5 Compact]# connect 40:40:A7:C4:93:E8  
Attempting to connect to 40:40:A7:C4:93:E8  
Failed to connect: org.bluez.Error.NotAvailable  
[CHG] Device 40:40:A7:C4:93:E8 ServicesResolved: no  
[CHG] Device 40:40:A7:C4:93:E8 Connected: no

and in systemctl I get:

Dec 27 10:37:38 Hex bluetoothd[573]: 40:40:A7:C4:93:E8: error updating services: Connection timed out (110)

Here is a dump of my journalctl on that occasion.

This behaviour is not consistent. Sometimes I cannot connect at all and get "Failed" error message with different error messages on systemctl

Device or resource busy (16)

or

 Host is down (112)

Headphone issues
When I try to connect my bluetooth headphones, the device gets found but I cannot pair.
For the headphones I have deactivated ssp

#btmgmt ssp of

to avoid pin authentication(I think this is what it is for right?).

The headphones are identified but pairing fails with messages like

Failed to pair: org.bluez.Error.ConnectionAttemptFailed

whereas I sometimes also get

[bluetooth]# devices
Device 69:E3:AA:70:08:AA LE-Bose QuietComfort 35
Device 04:52:C7:79:02:3F Bose QuietComfort 35
Device 6F:0A:A1:CF:F4:14 LE-Bose QuietComfort 35
Device 6D:1C:E3:AF:36:66 6D-1C-E3-AF-36-66
[bluetooth]# pair 04:52:C7:79:02:3F
Attempting to pair with 04:52:C7:79:02:3F
[CHG] Device 04:52:C7:79:02:3F Connected: yes
Failed to pair: org.bluez.Error.AuthenticationRejected
[CHG] Device 04:52:C7:79:02:3F Connected: no

and in the journalctl I see

Dec 27 19:09:44 Hex NetworkManager[579]: <info>  [1577470184.1354] device (wlp4s0): set-hw-addr: set MAC address to 1E:92:3E:8D:AE:53 (scanning)
Dec 27 19:14:59 Hex NetworkManager[579]: <info>  [1577470499.1481] device (wlp4s0): set-hw-addr: set MAC address to 5E:AE:7B:D4:C4:98 (scanning)
Dec 27 19:14:59 Hex NetworkManager[579]: <info>  [1577470499.2142] device (wlp4s0): supplicant interface state: inactive -> disconnected
Dec 27 19:14:59 Hex NetworkManager[579]: <info>  [1577470499.2142] device (p2p-dev-wlp4s0): supplicant management interface state: inactive -> disconnected
Dec 27 19:14:59 Hex NetworkManager[579]: <info>  [1577470499.2193] device (wlp4s0): supplicant interface state: disconnected -> inactive
Dec 27 19:14:59 Hex NetworkManager[579]: <info>  [1577470499.2195] device (p2p-dev-wlp4s0): supplicant management interface state: disconnected -> inactive
Dec 27 19:14:59 Hex wpa_supplicant[634]: wlp4s0: Reject scan trigger since one is already pending
Dec 27 19:18:07 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:20:11 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:20:14 Hex NetworkManager[579]: <info>  [1577470814.1321] device (wlp4s0): set-hw-addr: set MAC address to A2:70:E2:09:44:A3 (scanning)
Dec 27 19:20:24 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:20:26 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:11 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:11 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:11 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:11 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:11 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:32 Hex kernel: debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Dec 27 19:21:32 Hex kernel: debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Dec 27 19:21:32 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:21:45 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:22:02 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:22:04 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:23:28 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:23:28 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:23:37 Hex kernel: debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Dec 27 19:23:37 Hex kernel: debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Dec 27 19:23:37 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:23:44 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:24:37 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:24:39 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:25:29 Hex NetworkManager[579]: <info>  [1577471129.1492] device (wlp4s0): set-hw-addr: set MAC address to 7A:F2:35:2C:C9:63 (scanning)
Dec 27 19:25:29 Hex NetworkManager[579]: <info>  [1577471129.1741] device (wlp4s0): supplicant interface state: inactive -> disconnected
Dec 27 19:25:29 Hex NetworkManager[579]: <info>  [1577471129.1742] device (p2p-dev-wlp4s0): supplicant management interface state: inactive -> disconnected
Dec 27 19:25:29 Hex NetworkManager[579]: <info>  [1577471129.1794] device (wlp4s0): supplicant interface state: disconnected -> inactive
Dec 27 19:25:29 Hex NetworkManager[579]: <info>  [1577471129.1795] device (p2p-dev-wlp4s0): supplicant management interface state: disconnected -> inactive
Dec 27 19:25:29 Hex wpa_supplicant[634]: wlp4s0: Reject scan trigger since one is already pending
Dec 27 19:25:53 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:25:55 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:27:16 Hex kernel: debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Dec 27 19:27:16 Hex kernel: debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Dec 27 19:27:16 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined
Dec 27 19:27:22 Hex plasmashell[905]: file:///usr/share/plasma/plasmoids/org.kde.plasma.bluetooth/contents/ui/logic.js:36: TypeError: Cannot read property 'devices' of undefined

Does anyone have an idea where I could start? It might be this intel Wireless-Bluetooth blocking issue because I repeatedly see this NetworkManager wpa_supplicant messages in the journalctl, but I don't know.
I have also installed linux-firmware in case my adapter had this problem.
I also tried restarting pulseaudio (as user, even hough bluetoothctl was being run by the root at that time ) but this made no difference.
I am running out of ideas.
I only care about my headphones (the phone I tried to make sure the behaviour is not specific to the headphones), even though everything should be working as expected (and ideally configurable by the bluedevil front-end).
I thank you in advance

Last edited by pontifikas (2019-12-29 00:13:36)

pontifikas · 2019-12-29 00:11:52

I managed to pair the headphones. Not connect to them however. I see in btmon that the connection times out.
It worked after I set the option about Bluetooth_coexistence.

The connection issue however appears to be a firmware issue.
The firmware version for my hardware (Intel® Wi-Fi 6 AX200 160MHz), according to Intel, is iwlwifi-cc-a0-46.ucode. However the firmware which my kernel tries to load is iwlwifi-cc-a0-50.ucode

$modinfo iwlwifi

filename:       /lib/modules/5.4.6-arch1-1/kernel/drivers/net/wireless/intel/iwlwifi/iwlwifi.ko.xz
license:        GPL
author:         Copyright(c) 2003- 2015 Intel Corporation <linuxwifi@intel.com>
description:    Intel(R) Wireless WiFi driver for Linux
firmware:       iwlwifi-100-5.ucode
firmware:       iwlwifi-1000-5.ucode
firmware:       iwlwifi-135-6.ucode
firmware:       iwlwifi-105-6.ucode
firmware:       iwlwifi-2030-6.ucode
firmware:       iwlwifi-2000-6.ucode
firmware:       iwlwifi-5150-2.ucode
firmware:       iwlwifi-5000-5.ucode
firmware:       iwlwifi-6000g2b-6.ucode
firmware:       iwlwifi-6000g2a-6.ucode
firmware:       iwlwifi-6050-5.ucode
firmware:       iwlwifi-6000-6.ucode
firmware:       iwlwifi-7265D-29.ucode
firmware:       iwlwifi-7265-17.ucode
firmware:       iwlwifi-3168-29.ucode
firmware:       iwlwifi-3160-17.ucode
firmware:       iwlwifi-7260-17.ucode
firmware:       iwlwifi-8265-36.ucode
firmware:       iwlwifi-8000C-36.ucode
firmware:       iwlwifi-9260-th-b0-jf-b0-46.ucode
firmware:       iwlwifi-9000-pu-b0-jf-b0-46.ucode
firmware:       iwlwifi-ty-a0-gf-a0-50.ucode
firmware:       iwlwifi-so-a0-gf-a0-50.ucode
firmware:       iwlwifi-so-a0-hr-b0-50.ucode
firmware:       iwlwifi-so-a0-jf-b0-50.ucode
firmware:       iwlwifi-cc-a0-50.ucode <=============================================
firmware:       iwlwifi-QuQnj-b0-jf-b0-50.ucode
firmware:       iwlwifi-QuZ-a0-jf-b0-50.ucode
firmware:       iwlwifi-QuZ-a0-hr-b0-50.ucode
firmware:       iwlwifi-Qu-b0-jf-b0-50.ucode
firmware:       iwlwifi-Qu-c0-hr-b0-50.ucode
firmware:       iwlwifi-QuQnj-a0-hr-a0-50.ucode
firmware:       iwlwifi-QuQnj-b0-hr-b0-50.ucode
firmware:       iwlwifi-QuQnj-f0-hr-a0-50.ucode
firmware:       iwlwifi-Qu-a0-jf-b0-50.ucode
firmware:       iwlwifi-Qu-a0-hr-a0-50.ucode

I tried to replace the 50.ucode file with the 46.ucode one and remove all others

#dmesg
[ 2031.031636] Intel(R) Wireless WiFi driver for Linux
[ 2031.031638] Copyright(c) 2003- 2015 Intel Corporation
[ 2031.035607] iwlwifi 0000:04:00.0: Direct firmware load for iwlwifi-cc-a0-50.ucode failed with error -2
[ 2031.035623] iwlwifi 0000:04:00.0: Direct firmware load for iwlwifi-cc-a0-49.ucode failed with error -2
[ 2031.035638] iwlwifi 0000:04:00.0: Direct firmware load for iwlwifi-cc-a0-48.ucode failed with error -2
[ 2031.035653] iwlwifi 0000:04:00.0: Direct firmware load for iwlwifi-cc-a0-47.ucode failed with error -2
[ 2031.036212] iwlwifi 0000:04:00.0: loaded firmware version 46.3cfab8da.0 op_mode iwlmvm
[ 2031.066923] iwlwifi 0000:04:00.0: Detected Intel(R) Wi-Fi 6 AX200 160MHz, REV=0x340
[ 2031.221733] iwlwifi 0000:04:00.0: base HW address: 50:eb:71:77:e0:0c
[ 2031.234452] thermal thermal_zone0: failed to read out thermal zone (-61)
[ 2031.237396] iwlwifi 0000:04:00.0 wlp4s0: renamed from wlan0

but nothing changed regarding connectivity.

I'm afraid I will have to wait for next kernel versions .

Arch Linux

#1 2019-12-27 18:50:11

[SOLVED] Bluetooth pairing and connectivity failure on fresh install

#2 2019-12-29 00:11:52

Re: [SOLVED] Bluetooth pairing and connectivity failure on fresh install

Board footer