search

raspberrypi / linux

Kernel source tree for Raspberry Pi-provided kernel builds. Issues unrelated to the linux kernel should be posted on the community forum at https://forums.raspberrypi.com/
Other
11.15k stars 4.99k forks source link

Android Pixel 6 Pro unable to complete Bluetooth Connection Reason code 0x08 and Wrong link type (-22) #4847

Open hando-gomes opened 2 years ago

hando-gomes commented 2 years ago

Describe the bug

A few Android devices are unable to successfully establish a bluetooth connection to the Raspberry Pi 4. The devices connect, and after 5 seconds, it is disconnected with a timeout reason code 0x08.

> HCI Event: Disconnect Complete (0x05) plen 4
        Status: Success (0x00)
        Handle: 64
        Reason: Connection Timeout (0x08)
@ MGMT Event: Device Disconnected (0x000c) plen 8
        LE Address: 54:FA:15:75:50:1B (Resolvable)
        Reason: Connection timeout (0x01)
@ MGMT Event: Device Disconnected (0x000c) plen 8
        LE Address: 54:FA:15:75:50:1B (Resolvable)
        Reason: Connection timeout (0x01)

The following Android devices have shown this behavior:

After connection, this message can be seen in the journal and dmesg: raspberrypi kernel: Bluetooth: Wrong link type (-22)

The issue seems to be that during the discovery phase something goes wrong at the kernel level and the the device and raspi never completes the discovery phase. Bluez never receives the request for discovery and therefore the connection is closed due to timeout.

The log can be traced back to here: https://github.com/raspberrypi/linux/blob/2697f7403187bb2bb61cc716f33ee9f6cfb9af7c/net/bluetooth/l2cap_core.c#L6382

Steps to reproduce the behaviour

The client will connect, start discovering services and after 5 seconds on inactivity the device will be disconnected.

Device (s)

Raspberry Pi 4 Mod. B

System

$ cat /etc/rpi-issue
Raspberry Pi reference 2021-10-30
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 288b21fc27e128ea6b330777aca68e0061ebf4fe, stage2
$ vcgencmd version
Oct 29 2021 10:47:33
Copyright (c) 2012 Broadcom
version b8a114e5a9877e91ca8f26d1a5ce904b2ad3cf13 (clean) (release) (start)
$ uname -a
Linux raspberrypi 5.10.63-v7l+ #1459 SMP Wed Oct 6 16:41:57 BST 2021 armv7l GNU/Linux
$ modinfo bluetooth
filename:       /lib/modules/5.10.63-v7l+/kernel/net/bluetooth/bluetooth.ko
alias:          net-pf-31
license:        GPL
version:        2.22
description:    Bluetooth Core ver 2.22
author:         Marcel Holtmann <marcel@holtmann.org>
srcversion:     45D3D4C44F9D5986B018E4D
depends:        rfkill,ecdh_generic
intree:         Y
name:           bluetooth
vermagic:       5.10.63-v7l+ SMP mod_unload modversions ARMv7 p2v8
parm:           disable_esco:Disable eSCO connection creation (bool)
parm:           disable_ertm:Disable enhanced retransmission mode (bool)
parm:           enable_ecred:Enable enhanced credit flow control mode (bool)
$ /usr/libexec/bluetooth/bluetoothd --version
5.55

Logs

Logs when Android Pixel 6 Pro connects and then is disconnected.

Journal

Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/adapter.c:connected_callback() hci0 device 78:E5:C9:D0:57:CC connected eir_len 0
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:device_create() dst 78:E5:C9:D0:57:CC
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:device_new() address 78:E5:C9:D0:57:CC
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_78_E5_C9_D0_57_CC
Jan 25 21:05:09 raspberrypi systemd[691]: Reached target Bluetooth.
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 25 21:05:09 raspberrypi bluetoothd[951]: attrib/gattrib.c:g_attrib_ref() 0x15468a8: g_attrib_ref=1
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:load_gatt_db() Restoring 78:E5:C9:D0:57:CC gatt database from file
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:load_gatt_db() No cache for 78:E5:C9:D0:57:CC
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jan 25 21:05:09 raspberrypi kernel: Bluetooth: Wrong link type (-22)
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0013 end: 0xffff
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Primary services found: 2
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0001, end: 0x0009, uuid: 00001801-0000-1000-8000-00805f9b34fb
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0014, end: 0xffff, uuid: 00001800-0000-1000-8000-00805f9b34fb
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0005 end: 0x0005
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Server Features found: handle 0x0005 length 0x0001 value 0x01
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
Jan 25 21:05:09 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x000f end: 0x000f

Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/adapter.c:dev_disconnected() Device 78:E5:C9:D0:57:CC disconnected, reason 1
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/adapter.c:adapter_remove_connection()
Jan 25 21:05:14 raspberrypi bluetoothd[951]: plugins/policy.c:disconnect_cb() reason 1
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 78:E5:C9:D0:57:CC type 2 status 0xe
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:device_bonding_failed() status 14
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/adapter.c:resume_discovery()
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() service disappeared: start 0x0001 end 0x0009
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() service disappeared: start 0x0014 end 0xffff
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Failed to initialize gatt-client
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:gatt_client_ready_cb() status: failed, error: 0
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_78_E5_C9_D0_57_CC err -5
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:att_disconnected_cb()
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:att_disconnected_cb() Connection timed out (110)
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/device.c:att_disconnected_cb() Automatic connection disabled
Jan 25 21:05:14 raspberrypi bluetoothd[951]: src/gatt-database.c:btd_gatt_database_att_disconnected()
Jan 25 21:05:14 raspberrypi bluetoothd[951]: attrib/gattrib.c:g_attrib_unref() 0x15468a8: g_attrib_unref=0
Jan 25 21:05:45 raspberrypi bluetoothd[951]: src/device.c:device_remove() Removing device /org/bluez/hci0/dev_78_E5_C9_D0_57_CC
Jan 25 21:05:45 raspberrypi bluetoothd[951]: src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_78_E5_C9_D0_57_CC
Jan 25 21:05:45 raspberrypi bluetoothd[951]: src/device.c:device_free() 0x1546318

btmon:

> HCI Event: LE Meta Event (0x3e) plen 19                                                                                                                       #111 [hci0] 2022-01-25 21:05:09.028707
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 64
        Role: Slave (0x01)
        Peer address type: Random (0x01)
        Peer address: 78:E5:C9:D0:57:CC (Resolvable)
        Connection interval: 45.00 msec (0x0024)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
        Master clock accuracy: 0x01
@ MGMT Event: Device Connected (0x000b) plen 13                                                                                                             {0x0001} [hci0] 2022-01-25 21:05:09.028782
        LE Address: 78:E5:C9:D0:57:CC (Resolvable)
        Flags: 0x00000000
        Data length: 0
> HCI Event: Vendor (0xff) plen 5                                                                                                                               #112 [hci0] 2022-01-25 21:05:09.028717
        55 00 00 40 00                                   U..@.
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2                                                                                                #113 [hci0] 2022-01-25 21:05:09.029005
        Handle: 64
> HCI Event: Command Status (0x0f) plen 4                                                                                                                       #114 [hci0] 2022-01-25 21:05:09.030325
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 14                                                                                                                    #115 [hci0] 2022-01-25 21:05:09.030337
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
        00 00 00 00 00 00 00 00 00 00                    ..........
> HCI Event: LE Meta Event (0x3e) plen 12                                                                                                                       #116 [hci0] 2022-01-25 21:05:09.132805
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 64
        Features: 0x2f 0x00 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          Connection Parameter Request Procedure
          Extended Reject Indication
          Slave-initiated Features Exchange
          LE Data Packet Length Extension
= bluetoothd: src/device.c:load_gatt_db() No cache for 78:E5:C9:D0:57:CC                                                                                                    2022-01-25 21:05:09.134028
< ACL Data TX: Handle 64 flags 0x00 dlen 7                                                                                                                      #117 [hci0] 2022-01-25 21:05:09.134350
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 517
> ACL Data RX: Handle 64 flags 0x02 dlen 26                                                                                                                     #118 [hci0] 2022-01-25 21:05:09.223062
      LE L2CAP: Enhanced Credit Connection Request (0x17) ident 2 len 18
        PSM: 39 (0x0027)
        MTU: 256
        MPS: 251
        Credits: 65535
        Source CID: 251
        Source CID: 65535
        Source CID: 76
        Source CID: 67
        Source CID: 70
        Source CID: 65
        Source CID: 72
< ACL Data TX: Handle 64 flags 0x00 dlen 10                                                                                                                     #119 [hci0] 2022-01-25 21:05:09.223144
      LE L2CAP: Command Reject (0x01) ident 2 len 2
        Reason: Command not understood (0x0000)
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #120 [hci0] 2022-01-25 21:05:09.223617
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
< ACL Data TX: Handle 64 flags 0x00 dlen 24                                                                                                                     #121 [hci0] 2022-01-25 21:05:09.224017
      ATT: Read By Group Type Response (0x11) len 19
        Attribute data length: 6
        Attribute group list: 3 entries
        Handle range: 0x0001-0x0005
        UUID: Generic Access Profile (0x1800)
        Handle range: 0x0006-0x000f
        UUID: Generic Attribute Profile (0x1801)
        Handle range: 0x0010-0x0012
        UUID: Device Information (0x180a)
> HCI Event: LE Meta Event (0x3e) plen 11                                                                                                                       #122 [hci0] 2022-01-25 21:05:09.312914
      LE Remote Connection Parameter Request (0x06)
        Handle: 64
        Min connection interval: 7.50 msec (0x0006)
        Max connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
< HCI Command: LE Remote Connection Parameter Request Reply (0x08|0x0020) plen 14                                                                               #123 [hci0] 2022-01-25 21:05:09.312994
        Handle: 64
        Min connection interval: 7.50 msec (0x0006)
        Max connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Complete (0x0e) plen 6                                                                                                                     #124 [hci0] 2022-01-25 21:05:09.315462
      LE Remote Connection Parameter Request Reply (0x08|0x0020) ncmd 1
        Status: Success (0x00)
        Handle: 64
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #125 [hci0] 2022-01-25 21:05:09.538470
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 7                                                                                                                      #126 [hci0] 2022-01-25 21:05:09.582432
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 517
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #127 [hci0] 2022-01-25 21:05:09.582850
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0013-0xffff
        Attribute group type: Primary Service (0x2800)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                                                                                                                     #128 [hci0] 2022-01-25 21:05:09.582972
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Unknown (0x2b3a)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                                                                                                                      #129 [hci0] 2022-01-25 21:05:09.583242
      ATT: Error Response (0x01) len 4
        Read By Group Type Request (0x10)
        Handle: 0x0013
        Error: Attribute Not Found (0x0a)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #130 [hci0] 2022-01-25 21:05:09.627901
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 9                                                                                                                      #131 [hci0] 2022-01-25 21:05:09.672484
      ATT: Read By Type Response (0x09) len 4
        Attribute data length: 3
        Attribute data list: 1 entry
        Handle: 0x0005
        Value: 01
< ACL Data TX: Handle 64 flags 0x00 dlen 11                                                                                                                     #132 [hci0] 2022-01-25 21:05:09.672837
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #133 [hci0] 2022-01-25 21:05:09.672863
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0005
        Attribute type: Include (0x2802)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                                                                                                                      #134 [hci0] 2022-01-25 21:05:09.673203
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0001
        Error: Attribute Not Found (0x0a)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #135 [hci0] 2022-01-25 21:05:09.717902
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 18                                                                                                                     #136 [hci0] 2022-01-25 21:05:09.762529
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0001-0x0009
        UUID: Generic Attribute Profile (0x1801)
        Handle range: 0x0014-0xffff
        UUID: Generic Access Profile (0x1800)
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #137 [hci0] 2022-01-25 21:05:09.762923
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0005
        Attribute type: Characteristic (0x2803)
< ACL Data TX: Handle 64 flags 0x00 dlen 20                                                                                                                     #138 [hci0] 2022-01-25 21:05:09.765084
      ATT: Read By Type Response (0x09) len 15
        Attribute data length: 7
        Attribute data list: 2 entries
        Handle: 0x0002
        Value: 020300002a
        Handle: 0x0004
        Value: 020500012a
< ACL Data TX: Handle 64 flags 0x00 dlen 11                                                                                                                     #139 [hci0] 2022-01-25 21:05:09.765130
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0006-0xffff
        Attribute type: Unknown (0x2b3a)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #140 [hci0] 2022-01-25 21:05:09.815464
        Num handles: 1
        Handle: 64
        Count: 2
> HCI Event: LE Meta Event (0x3e) plen 10                                                                                                                       #141 [hci0] 2022-01-25 21:05:09.815962
      LE Connection Update Complete (0x03)
        Status: Success (0x00)
        Handle: 64
        Connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #142 [hci0] 2022-01-25 21:05:09.830373
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0005-0x0005
        Attribute type: Characteristic (0x2803)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                                                                                                                      #143 [hci0] 2022-01-25 21:05:09.830792
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0005
        Error: Attribute Not Found (0x0a)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                                                                                                                      #144 [hci0] 2022-01-25 21:05:09.844853
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0006
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                                                                                                                     #145 [hci0] 2022-01-25 21:05:09.845272
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Secondary Service (0x2801)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #146 [hci0] 2022-01-25 21:05:09.875370
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #147 [hci0] 2022-01-25 21:05:09.890303
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0006-0x000f
        Attribute type: Include (0x2802)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                                                                                                                      #148 [hci0] 2022-01-25 21:05:09.890745
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0006
        Error: Attribute Not Found (0x0a)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                                                                                                                      #149 [hci0] 2022-01-25 21:05:09.891010
      ATT: Error Response (0x01) len 4
        Read By Group Type Request (0x10)
        Handle: 0x0001
        Error: Unsupported Group Type (0x10)
< ACL Data TX: Handle 64 flags 0x00 dlen 11                                                                                                                     #150 [hci0] 2022-01-25 21:05:09.891270
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Include (0x2802)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #151 [hci0] 2022-01-25 21:05:09.905368
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #152 [hci0] 2022-01-25 21:05:09.919955
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0006-0x000f
        Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 64 flags 0x02 dlen 9                                                                                                                      #153 [hci0] 2022-01-25 21:05:09.920354
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0001
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 64 flags 0x00 dlen 34                                                                                                                     #154 [hci0] 2022-01-25 21:05:09.920437
      ATT: Read By Type Response (0x09) len 29
        Attribute data length: 7
        Attribute data list: 4 entries
        Handle: 0x0007
        Value: 200800052a
        Handle: 0x000a
        Value: 0a0b00292b
        Handle: 0x000c
        Value: 020d002a2b
        Handle: 0x000e
        Value: 020f003a2b
< ACL Data TX: Handle 64 flags 0x00 dlen 11                                                                                                                     #155 [hci0] 2022-01-25 21:05:09.920542
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #156 [hci0] 2022-01-25 21:05:09.936035
        Num handles: 1
        Handle: 64
        Count: 2
> ACL Data RX: Handle 64 flags 0x02 dlen 11                                                                                                                     #157 [hci0] 2022-01-25 21:05:09.949955
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x000f-0x000f
        Attribute type: Characteristic (0x2803)
< ACL Data TX: Handle 64 flags 0x00 dlen 9                                                                                                                      #158 [hci0] 2022-01-25 21:05:09.950364
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x000f
        Error: Attribute Not Found (0x0a)
< HCI Command: LE Set Advertising Parameters (0x08|0x0006) plen 15                                                                                              #159 [hci0] 2022-01-25 21:05:10.078360
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                     #160 [hci0] 2022-01-25 21:05:10.078816
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Enable (0x08|0x000a) plen 1                                                                                                     #161 [hci0] 2022-01-25 21:05:10.078886
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                                     #162 [hci0] 2022-01-25 21:05:10.079272
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #163 [hci0] 2022-01-25 21:05:10.152271
        Num handles: 1
        Handle: 64
        Count: 1

> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                          #164 [hci0] 2022-01-25 21:05:14.953336
        Num handles: 1
        Handle: 64
        Count: 1
> HCI Event: Disconnect Complete (0x05) plen 4                                                                                                                  #165 [hci0] 2022-01-25 21:05:14.953389
        Status: Success (0x00)
        Handle: 64
        Reason: Connection Timeout (0x08)
@ MGMT Event: Device Disconnected (0x000c) plen 8                                                                                                           {0x0001} [hci0] 2022-01-25 21:05:14.953424
        LE Address: 78:E5:C9:D0:57:CC (Resolvable)
        Reason: Connection timeout (0x01)

bluetoothctl

[NEW] Device 78:E5:C9:D0:57:CC 78-E5-C9-D0-57-CC
[CHG] Device 78:E5:C9:D0:57:CC Connected: no
[DEL] Device 78:E5:C9:D0:57:CC 78-E5-C9-D0-57-CC

nRF Connect (Phone log)

nRF Connect, 2022-01-25
Hello (DC:A6:32:05:89:E9)
D   14:10:18.573    gatt.close()
D   14:10:18.574    wait(200)
V   14:10:18.775    Connecting to DC:A6:32:05:89:E9...
D   14:10:18.775    gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D   14:10:19.866    [Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I   14:10:19.866    Connected to DC:A6:32:05:89:E9
V   14:10:19.879    Discovering services...
D   14:10:19.879    gatt.discoverServices()
D   14:10:19.883    [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
I   14:10:20.500    Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
D   14:10:25.653    [Callback] Connection state changed with status: 0 and new state: DISCONNECTED (0)
I   14:10:25.653    Disconnected
D   14:10:25.675    [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED

Additional context

The same test was performed with these 2 other phones and the connection is successful and no warning about Bluetooth: Wrong link type (-22) is output.

Journal logs for Pixel 1 device:

Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/adapter.c:connected_callback() hci0 device 63:C1:07:5E:4C:77 connected eir_len 0
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:device_create() dst 63:C1:07:5E:4C:77
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:device_new() address 63:C1:07:5E:4C:77
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_63_C1_07_5E_4C_77
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 25 21:16:25 raspberrypi bluetoothd[951]: attrib/gattrib.c:g_attrib_ref() 0x1541c88: g_attrib_ref=1
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:load_gatt_db() Restoring 63:C1:07:5E:4C:77 gatt database from file
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:load_gatt_db() No cache for 63:C1:07:5E:4C:77
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
Jan 25 21:16:25 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0013 end: 0xffff
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Primary services found: 4
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0001, end: 0x0003, uuid: 00001801-0000-1000-8000-00805f9b34fb
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0014, end: 0x001a, uuid: 00001800-0000-1000-8000-00805f9b34fb
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0028, end: 0x0033, uuid: 16bcfd00-253f-c348-e831-0db3e334d580
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0034, end: 0xffff, uuid: abbafc00-e56a-484c-b832-8b17cf6cbfe8
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0005 end: 0x0005
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x000f end: 0x000f
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Find Info - start: 0x0009 end: 0x0009
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Characteristics found: 11
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0002, end: 0x0014, value: 0x0003, props: 0x20, uuid: 00002a05-0000-1
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0015, end: 0x0016, value: 0x0016, props: 0x02, uuid: 00002a00-0000-1
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0017, end: 0x0018, value: 0x0018, props: 0x02, uuid: 00002a01-0000-1
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0019, end: 0x0028, value: 0x001a, props: 0x02, uuid: 00002aa6-0000-1
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0029, end: 0x002b, value: 0x002a, props: 0x12, uuid: 16bcfd04-253f-c
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x002c, end: 0x002e, value: 0x002d, props: 0x10, uuid: 16bcfd02-253f-c
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x002f, end: 0x0030, value: 0x0030, props: 0x08, uuid: 16bcfd01-253f-c
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0031, end: 0x0034, value: 0x0032, props: 0x10, uuid: 16bcfd03-253f-c
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0035, end: 0x0037, value: 0x0036, props: 0x12, uuid: abbafc01-e56a-4
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0038, end: 0x003a, value: 0x0039, props: 0x12, uuid: abbafc02-e56a-4
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x003b, end: 0xffff, value: 0x003c, props: 0x10, uuid: abbafc03-e56a-4
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0010 end: 0x0012
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0010 end: 0x0012
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 1
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x003d, uuid: 00002902-0000-1000-8000-00805f9b34fb
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Registered handler for "Service Changed": 0
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_client_ready_cb() status: success, error: 0
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 63:C1:07:5E:4C:77
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 63:C1:07:5E:4C:77
Jan 25 21:16:26 raspberrypi bluetoothd[951]: profiles/gap/gas.c:gap_probe() GAP profile probe (63:C1:07:5E:4C:77)
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x153c018: device 63:C1:07:5E:4C:77 profile gap-profile state changed: unavailable -> disconnected (0)
Jan 25 21:16:26 raspberrypi bluetoothd[951]: profiles/gap/gas.c:gap_accept() GAP profile accept (63:C1:07:5E:4C:77)
Jan 25 21:16:26 raspberrypi bluetoothd[951]: profiles/gap/gas.c:handle_characteristic() Unsupported characteristic: 00002aa6-0000-1000-8000-00805f9b34fb
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x153c018: device 63:C1:07:5E:4C:77 profile gap-profile state changed: disconnected -> connected (0)
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 63:C1:07:5E:4C:77
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 63:C1:07:5E:4C:77
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_ready() GATT client ready
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:create_services() Exporting objects for GATT services: 63:C1:07:5E:4C:77
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0001
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0001/char0002
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char0029
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char0029/desc002b
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char002c
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char002c/desc002e
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char002f
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char0031
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0028/char0031/desc0033
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034/char0035
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034/char0035/desc0037
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034/char0038
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034/char0038/desc003a
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034/char003b
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_63_C1_07_5E_4C_77/service0034/char003b/desc003d
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_ready() Features 0x00
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_ready() Update Features 0x00
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_63_C1_07_5E_4C_77 err 0
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:store_gatt_db() Can't store GATT db for private addressed device /org/bluez/hci0/dev_63_C1_07_5E_4C_77
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0012 end: 0x0012
Jan 25 21:16:26 raspberrypi bluetoothd[951]: profiles/gap/gas.c:read_device_name_cb() GAP Device Name: Handerson's Pixel
Jan 25 21:16:26 raspberrypi bluetoothd[951]: src/device.c:btd_device_device_set_name() /org/bluez/hci0/dev_63_C1_07_5E_4C_77 Handerson's Pixel
Jan 25 21:16:26 raspberrypi bluetoothd[951]: profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x0000

Journal logs when connecting with iPhone 6S

Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/adapter.c:connected_callback() hci0 device 68:EA:49:22:94:D5 connected eir_len 0
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:device_create() dst 68:EA:49:22:94:D5
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:device_new() address 68:EA:49:22:94:D5
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_68_EA_49_22_94_D5
Jan 25 21:18:49 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 25 21:18:49 raspberrypi bluetoothd[951]: attrib/gattrib.c:g_attrib_ref() 0x153fa88: g_attrib_ref=1
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:load_gatt_db() Restoring 68:EA:49:22:94:D5 gatt database from file
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:load_gatt_db() No cache for 68:EA:49:22:94:D5
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 185
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0013 end: 0xffff
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Find Info - start: 0x0009 end: 0x000f
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Write Req - handle: 0x0009
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/gatt-database.c:gatt_ccc_write_cb() CCC write called for handle: 0x0009
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Write Complete: err 0
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0010 end: 0x0012
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Primary services found: 9
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0001, end: 0x0005, uuid: 00001800-0000-1000-8000-00805f9b34fb
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0006, end: 0x0009, uuid: 00001801-0000-1000-8000-00805f9b34fb
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x000a, end: 0x000e, uuid: d0611e78-bbb4-4591-a5f8-487910ae4366
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x000f, end: 0x0013, uuid: 9fa480e0-4967-4542-9390-d343dc5d04ae
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0014, end: 0x0017, uuid: 0000180f-0000-1000-8000-00805f9b34fb
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0018, end: 0x001d, uuid: 00001805-0000-1000-8000-00805f9b34fb
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x001e, end: 0x0022, uuid: 0000180a-0000-1000-8000-00805f9b34fb
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0023, end: 0x002c, uuid: 7905f431-b5ce-4e99-a40f-4b1e122d00d0
Jan 25 21:18:49 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x002d, end: 0x0038, uuid: 89d3502b-0f36-433a-8ef4-c502ad55f8dc
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Characteristics found: 16
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0002, end: 0x0003, value: 0x0003, props: 0x02, uuid: 00002a00-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0004, end: 0x0006, value: 0x0005, props: 0x02, uuid: 00002a01-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0007, end: 0x000a, value: 0x0008, props: 0x20, uuid: 00002a05-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x000b, end: 0x000f, value: 0x000c, props: 0x98, uuid: 8667556c-9a37-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0010, end: 0x0014, value: 0x0011, props: 0x98, uuid: af0badb1-5b99-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0015, end: 0x0018, value: 0x0016, props: 0x12, uuid: 00002a19-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0019, end: 0x001b, value: 0x001a, props: 0x12, uuid: 00002a2b-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x001c, end: 0x001e, value: 0x001d, props: 0x02, uuid: 00002a0f-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x001f, end: 0x0020, value: 0x0020, props: 0x02, uuid: 00002a29-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0021, end: 0x0023, value: 0x0022, props: 0x02, uuid: 00002a24-0000-1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0024, end: 0x0026, value: 0x0025, props: 0x88, uuid: 69d1d8f3-45e1-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0027, end: 0x0029, value: 0x0028, props: 0x10, uuid: 9fbf120d-6301-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x002a, end: 0x002d, value: 0x002b, props: 0x10, uuid: 22eac6e9-24d6-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x002e, end: 0x0031, value: 0x002f, props: 0x98, uuid: 9b3c81d8-57b1-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0032, end: 0x0035, value: 0x0033, props: 0x98, uuid: 2f7cabce-808d-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() start: 0x0036, end: 0x0038, value: 0x0037, props: 0x8a, uuid: c6b2f38c-23ab-4
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 2
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x000d, uuid: 00002900-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x000e, uuid: 00002902-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Ext. prop value: 0x0001
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Value set status: 0
Jan 25 21:18:50 raspberrypi systemd[1]: apt-daily-upgrade.service: Succeeded.
Jan 25 21:18:50 raspberrypi systemd[1]: Finished Daily apt upgrade and clean activities.
Jan 25 21:18:50 raspberrypi systemd[1]: apt-daily-upgrade.service: Consumed 1.118s CPU time.
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 2
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0012, uuid: 00002900-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0013, uuid: 00002902-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Ext. prop value: 0x0001
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Value set status: 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0026, uuid: 00002900-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Ext. prop value: 0x0001
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Value set status: 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 2
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0030, uuid: 00002900-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0031, uuid: 00002902-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Ext. prop value: 0x0001
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Value set status: 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 2
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0034, uuid: 00002900-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0035, uuid: 00002902-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Ext. prop value: 0x0001
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Value set status: 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Descriptors found: 1
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() handle: 0x0038, uuid: 00002900-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Ext. prop value: 0x0001
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Value set status: 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_client_ready_cb() status: success, error: 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/gap/gas.c:gap_probe() GAP profile probe (68:EA:49:22:94:D5)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x158b270: device 68:EA:49:22:94:D5 profile gap-profile state changed: unavailable -> disconnected (0)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/gap/gas.c:gap_accept() GAP profile accept (68:EA:49:22:94:D5)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x158b270: device 68:EA:49:22:94:D5 profile gap-profile state changed: disconnected -> connected (0)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/battery/battery.c:batt_probe() BATT profile probe (68:EA:49:22:94:D5)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x158ff70: device 68:EA:49:22:94:D5 profile batt-profile state changed: unavailable -> disconnected (0)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/battery/battery.c:batt_accept() BATT profile accept (68:EA:49:22:94:D5)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x158ff70: device 68:EA:49:22:94:D5 profile batt-profile state changed: disconnected -> connected (0)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x15900f0: device 68:EA:49:22:94:D5 profile deviceinfo state changed: unavailable -> disconnected (0)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/deviceinfo/deviceinfo.c:deviceinfo_accept() deviceinfo profile accept (68:EA:49:22:94:D5)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported characteristic: 00002a29-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported characteristic: 00002a24-0000-1000-8000-00805f9b34fb
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/service.c:change_state() 0x15900f0: device 68:EA:49:22:94:D5 profile deviceinfo state changed: disconnected -> connected (0)
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_probe_profiles() Probing profiles for device 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_ready() GATT client ready
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:create_services() Exporting objects for GATT services: 68:EA:49:22:94:D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0006
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0006/char0007
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0006/char0007/desc0009
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000a
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000a/char000b
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000a/char000b/desc000d
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000a/char000b/desc000e
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000f
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000f/char0010
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000f/char0010/desc0012
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service000f/char0010/desc0013
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0014
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0014/char0015
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0014/char0015/desc0017
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0018
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0018/char0019
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0018/char0019/desc001b
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0018/char001c
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service001e
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service001e/char001f
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service001e/char0021
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023/char0024
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023/char0024/desc0026
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023/char0027
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023/char0027/desc0029
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023/char002a
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service0023/char002a/desc002c
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:service_create() Exported GATT service: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char002e
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char002e/desc0030
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char002e/desc0031
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char0032
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char0032/desc0034
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char0032/desc0035
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:characteristic_create() Exported GATT characteristic: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char0036
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:descriptor_create() Exported GATT characteristic descriptor: /org/bluez/hci0/dev_68_EA_49_22_94_D5/service002d/char0036/desc0038
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_ready() Features 0x00
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/gatt-client.c:btd_gatt_client_ready() Update Features 0x00
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_68_EA_49_22_94_D5 err 0
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:store_gatt_db() Can't store GATT db for private addressed device /org/bluez/hci0/dev_68_EA_49_22_94_D5
Jan 25 21:18:50 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Registered handler for "Service Changed": 1
Jan 25 21:18:51 raspberrypi bluetoothd[951]: profiles/gap/gas.c:read_device_name_cb() GAP Device Name: iPhone
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/device.c:btd_device_device_set_name() /org/bluez/hci0/dev_68_EA_49_22_94_D5 iPhone
Jan 25 21:18:51 raspberrypi bluetoothd[951]: profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x0040
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/adapter.c:user_confirm_request_callback() hci0 68:EA:49:22:94:D5 confirm_hint 0
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/device.c:new_auth() Requesting agent authentication for 68:EA:49:22:94:D5
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/agent.c:agent_ref() 0x153fe68: ref=2
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/agent.c:agent_request_confirmation() Calling Agent.RequestConfirmation: name=:1.21, path=/org/bluez/agent, passkey=309570
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 25 21:18:51 raspberrypi bluetoothd[951]: src/gatt-database.c:gap_device_name_read_cb() GAP Device Name read request
hando-gomes commented 2 years ago

Running the newest Kernel, there's a new log message that helps narrow the issue:

Jan 25 18:59:15 bryte bluetoothd[23308]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
Jan 25 18:59:15 bryte bluetoothd[23308]: src/device.c:gatt_debug() (chan 0x1204940) ATT PDU received: 0x10
Jan 25 18:59:15 bryte bluetoothd[23308]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jan 25 18:59:15 bryte kernel: Bluetooth: Unknown LE signaling command 0x17
Jan 25 18:59:15 bryte kernel: Bluetooth: Wrong link type (-22)
Jan 25 18:59:15 bryte bluetoothd[23308]: src/device.c:gatt_debug() (chan 0x1204940) ATT PDU received: 0x08
Jan 25 18:59:15 bryte bluetoothd[23308]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0xffff

This commit refers to fixing the issue with the 0x17 which is the Enhanced Credit Based Flow Control Mode. https://github.com/raspberrypi/linux/commit/69d67b461a180144ad1d31174fadf3e3eda78e56#diff-21cdf1a8784787f91c59b5750610c31d15712ee406b107c21951f81c1b48c188

pelwell commented 2 years ago

Without changing the configuration, do other Android devices connect? If so, are they also attempting BLE connections, or is BLE the common factor in the failure cases?

pelwell commented 2 years ago

Wait - I see you have successful Pixel 1 and iPhone 6 logs there, both of them using BLE, which answers both my questions.

The patch you link to is interesting, but it is already in the newest kernel and the problem clearly isn't fixed.

Time to expense a Pixel 6 Pro?

hando-gomes commented 2 years ago

I was able to replicate this issue with these phones:

These phones work without an issue:

pelwell commented 2 years ago

Thanks for the confirmation. I was slightly joking with my previous comment re: expenses, but investigating this issue is going to depend on getting hold of one of the devices that shows the problem.

hando-gomes commented 2 years ago

:) I hope you can find one of these devices.

Here is something else that could help to narrow this issue. The bluetooth parameter for ecred is by default disabled on the latest kernel.

Mod info:

$ modinfo bluetooth
filename:       /lib/modules/5.10.63-v7l+/kernel/net/bluetooth/bluetooth.ko
alias:          net-pf-31
license:        GPL
version:        2.22
description:    Bluetooth Core ver 2.22
author:         Marcel Holtmann <marcel@holtmann.org>
srcversion:     45D3D4C44F9D5986B018E4D
depends:        rfkill,ecdh_generic
intree:         Y
name:           bluetooth
vermagic:       5.10.63-v7l+ SMP mod_unload modversions ARMv7 p2v8
parm:           disable_esco:Disable eSCO connection creation (bool)
parm:           disable_ertm:Disable enhanced retransmission mode (bool)
parm:           enable_ecred:Enable enhanced credit flow control mode (bool) 
$ head /sys/module/bluetooth/parameters/*
==> /sys/module/bluetooth/parameters/disable_ertm <==
N

==> /sys/module/bluetooth/parameters/disable_esco <==
N

==> /sys/module/bluetooth/parameters/enable_ecred <==
N

Then by changing the content to Y for enable_ecred, some connections will actually succeed, some of the time, but not always. sudo nano /sys/module/bluetooth/parameters/enable_ecred and replace the N with a Y Do not reboot.

Here are some notable differences: With the feature enable=N (the default value is disabled) the Pixel 6 Pro will always connect and then get disconnected. The journal will show this error during connection:

Jan 26 16:46:06 raspberrypi bluetoothd[2376]: src/device.c:load_gatt_db() No cache for 6D:B1:54:80:B7:EF
Jan 26 16:46:06 raspberrypi bluetoothd[2376]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Jan 26 16:46:06 raspberrypi kernel: Bluetooth: Wrong link type (-22)
Jan 26 16:46:06 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jan 26 16:46:07 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517```

The btmon will display the command been rejected:
```> ACL Data RX: Handle 66 flags 0x02 dlen 26
      LE L2CAP: Enhanced Credit Connection Request (0x17) ident 2 len 18
        PSM: 39 (0x0027)
        MTU: 256
        MPS: 251
        Credits: 65535
        Source CID: 251
        Source CID: 65535
        Source CID: 94
        Source CID: 87
        Source CID: 88
        Source CID: 78
        Source CID: 75
< ACL Data TX: Handle 66 flags 0x00 dlen 10
      LE L2CAP: Command Reject (0x01) ident 2 len 2
        Reason: Command not understood (0x0000)

Changing the value to Y (enabling ecred) when the phone successfully connects, there are no warnings on the journal, and the btmon shows a valid RX and TX for the Enhanced Credit Connection:

> ACL Data RX: Handle 65 flags 0x02 dlen 26                                                                                                               #2176 [hci0] 2022-01-26 16:49:44.274616
      LE L2CAP: Enhanced Credit Connection Request (0x17) ident 2 len 18
        PSM: 39 (0x0027)
        MTU: 256
        MPS: 251
        Credits: 65535
        Source CID: 251
        Source CID: 65535
        Source CID: 89
        Source CID: 66
        Source CID: 77
        Source CID: 68
        Source CID: 86
< ACL Data TX: Handle 65 flags 0x00 dlen 26                                                                                                               #2177 [hci0] 2022-01-26 16:49:44.274813
      LE L2CAP: Enhanced Credit Connection Response (0x18) ident 2 len 18
        MTU: 517
        MPS: 247
        Credits: 3
        Result: Connection successful (0x0000)
        Destination CID: 64
        Destination CID: 65
        Destination CID: 66
        Destination CID: 67
        Destination CID: 68
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2178 [hci0] 2022-01-26 16:49:44.275712
      LE L2CAP: Disconnection Request (0x06) ident 1 len 4
        Destination CID: 77
        Source CID: 66
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2179 [hci0] 2022-01-26 16:49:44.275999
      LE L2CAP: Disconnection Request (0x06) ident 2 len 4
        Destination CID: 68
        Source CID: 67
...
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2181 [hci0] 2022-01-26 16:49:44.276302
      LE L2CAP: Disconnection Request (0x06) ident 3 len 4
        Destination CID: 86
        Source CID: 68

There are a few RX/TX about LE L2CAP: Disconnection Request and LE L2CAP: Disconnection Response but they seem to not interrupt the client connection. The client stays connected. Sometimes on a successful connection the journal will output a warning about link tx timeout, but that doesn't affect the connection either.

Jan 26 16:56:49 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel limit reached
Jan 26 16:56:49 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 16:56:49 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel limit reached
Jan 26 16:56:49 raspberrypi kernel: Bluetooth: hci0: link tx timeout
Jan 26 16:56:49 raspberrypi kernel: Bluetooth: hci0: link tx timeout
Jan 26 16:56:50 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
Jan 26 16:56:50 raspberrypi bluetoothd[2376]: profiles/gap/gas.c:read_device_name_cb() GAP Device Name: Pixel 6 Pro
Jan 26 16:56:50 raspberrypi bluetoothd[2376]: profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x0000

However, even with this configuration, sometimes the connection will fail. There are not visible errors on the journal. The L2CAP for the Enhanced Credit Connection seems to happen but the device still get disconnected with a timeout.

I wonder if this is a different issue altogether that also leads to a 0x08 disconnect, this time not due to the disabled ecred param.

Here are the full logs for completeness when the ecred is enabled but the client connection fails:

journal with bluetoothd debug statements:

Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/adapter.c:connected_callback() hci0 device 61:DD:CB:12:94:BE connected eir_len 0
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_create() dst 61:DD:CB:12:94:BE
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_new() address 61:DD:CB:12:94:BE
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_61_DD_CB_12_94_BE
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: attrib/gattrib.c:g_attrib_ref() 0x327e70: g_attrib_ref=1
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:load_gatt_db() Restoring 61:DD:CB:12:94:BE gatt database from file
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:load_gatt_db() No cache for 61:DD:CB:12:94:BE
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel connected
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel connected
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel limit reached
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel limit reached
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:device_attach_att() EATT channel limit reached
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
Jan 26 17:03:00 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0013 end: 0xffff
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Primary services found: 2
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() start: 0x0001, end: 0x0009, uuid: 00001801-0000-1000-8000-00805f9b34fb
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() start: 0x0014, end: 0xffff, uuid: 00001800-0000-1000-8000-00805f9b34fb
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Server Features found: handle 0x0005 length 0x0001 value 0x01
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
Jan 26 17:03:01 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Read By Type - start: 0x0005 end: 0x0005
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/adapter.c:dev_disconnected() Device 61:DD:CB:12:94:BE disconnected, reason 1
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/adapter.c:adapter_remove_connection()
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: plugins/policy.c:disconnect_cb() reason 1
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 61:DD:CB:12:94:BE type 2 status 0xe
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:device_bonding_failed() status 14
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/adapter.c:resume_discovery()
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() service disappeared: start 0x0001 end 0x0009
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() service disappeared: start 0x0014 end 0xffff
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:gatt_debug() Failed to initialize gatt-client
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:gatt_client_ready_cb() status: failed, error: 0
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_61_DD_CB_12_94_BE err -5
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:att_disconnected_cb()
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:att_disconnected_cb() Connection timed out (110)
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/device.c:att_disconnected_cb() Automatic connection disabled
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: src/gatt-database.c:btd_gatt_database_att_disconnected()
Jan 26 17:03:06 raspberrypi bluetoothd[2376]: attrib/gattrib.c:g_attrib_unref() 0x327e70: g_attrib_unref=0
Jan 26 17:03:36 raspberrypi bluetoothd[2376]: src/device.c:device_remove() Removing device /org/bluez/hci0/dev_61_DD_CB_12_94_BE
Jan 26 17:03:36 raspberrypi bluetoothd[2376]: src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_61_DD_CB_12_94_BE
Jan 26 17:03:36 raspberrypi bluetoothd[2376]: src/device.c:device_free() 0x33afc0```

btmon
`> HCI Event: LE Meta Event (0x3e) plen 19                                                                                                                 #2938 [hci0] 2022-01-26 17:03:00.442582
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 65
        Role: Slave (0x01)
        Peer address type: Random (0x01)
        Peer address: 61:DD:CB:12:94:BE (Resolvable)
        Connection interval: 45.00 msec (0x0024)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
        Master clock accuracy: 0x01
@ MGMT Event: Device Connected (0x000b) plen 13                                                                                                        {0x0001} [hci0] 2022-01-26 17:03:00.442657
        LE Address: 61:DD:CB:12:94:BE (Resolvable)
        Flags: 0x00000000
        Data length: 0
> HCI Event: Vendor (0xff) plen 5                                                                                                                         #2939 [hci0] 2022-01-26 17:03:00.442592
        55 00 00 41 00                                   U..A.
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2                                                                                          #2940 [hci0] 2022-01-26 17:03:00.442894
        Handle: 65
> HCI Event: Command Status (0x0f) plen 4                                                                                                                 #2941 [hci0] 2022-01-26 17:03:00.444701
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> HCI Event: Command Complete (0x0e) plen 14                                                                                                              #2942 [hci0] 2022-01-26 17:03:00.444713
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
        00 00 00 00 00 00 00 00 00 00                    ..........
> HCI Event: LE Meta Event (0x3e) plen 12                                                                                                                 #2943 [hci0] 2022-01-26 17:03:00.546710
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 65
        Features: 0x2f 0x00 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          Connection Parameter Request Procedure
          Extended Reject Indication
          Slave-initiated Features Exchange
          LE Data Packet Length Extension
= bluetoothd: src/device.c:load_gatt_db() No cache for 61:DD:CB:12:94:BE                                                                                               2022-01-26 17:03:00.548507
< ACL Data TX: Handle 65 flags 0x00 dlen 7                                                                                                                #2944 [hci0] 2022-01-26 17:03:00.547808
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 517
> ACL Data RX: Handle 65 flags 0x02 dlen 26                                                                                                               #2945 [hci0] 2022-01-26 17:03:00.636995
      LE L2CAP: Enhanced Credit Connection Request (0x17) ident 2 len 18
        PSM: 39 (0x0027)
        MTU: 256
        MPS: 251
        Credits: 65535
        Source CID: 251
        Source CID: 65535
        Source CID: 89
        Source CID: 90
        Source CID: 91
        Source CID: 92
        Source CID: 93
< ACL Data TX: Handle 65 flags 0x00 dlen 26                                                                                                               #2946 [hci0] 2022-01-26 17:03:00.637198
      LE L2CAP: Enhanced Credit Connection Response (0x18) ident 2 len 18
        MTU: 517
        MPS: 247
        Credits: 3
        Result: Connection successful (0x0000)
        Destination CID: 64
        Destination CID: 65
        Destination CID: 66
        Destination CID: 67
        Destination CID: 68
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2947 [hci0] 2022-01-26 17:03:00.637613
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2948 [hci0] 2022-01-26 17:03:00.638498
      LE L2CAP: Disconnection Request (0x06) ident 1 len 4
        Destination CID: 91
        Source CID: 66
< ACL Data TX: Handle 65 flags 0x00 dlen 24                                                                                                               #2949 [hci0] 2022-01-26 17:03:00.638781
      ATT: Read By Group Type Response (0x11) len 19
        Attribute data length: 6
        Attribute group list: 3 entries
        Handle range: 0x0001-0x0005
        UUID: Generic Access Profile (0x1800)
        Handle range: 0x0006-0x000f
        UUID: Generic Attribute Profile (0x1801)
        Handle range: 0x0010-0x0012
        UUID: Device Information (0x180a)
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2950 [hci0] 2022-01-26 17:03:00.639177
      LE L2CAP: Disconnection Request (0x06) ident 2 len 4
        Destination CID: 92
        Source CID: 67
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2951 [hci0] 2022-01-26 17:03:00.639602
      LE L2CAP: Disconnection Request (0x06) ident 3 len 4
        Destination CID: 93
        Source CID: 68
> HCI Event: LE Meta Event (0x3e) plen 11                                                                                                                 #2952 [hci0] 2022-01-26 17:03:00.726847
      LE Remote Connection Parameter Request (0x06)
        Handle: 65
        Min connection interval: 7.50 msec (0x0006)
        Max connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
< HCI Command: LE Remote Connection Parameter Request Reply (0x08|0x0020) plen 14                                                                         #2953 [hci0] 2022-01-26 17:03:00.726939
        Handle: 65
        Min connection interval: 7.50 msec (0x0006)
        Max connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Complete (0x0e) plen 6                                                                                                               #2954 [hci0] 2022-01-26 17:03:00.729426
      LE Remote Connection Parameter Request Reply (0x08|0x0020) ncmd 1
        Status: Success (0x00)
        Handle: 65
< HCI Command: LE Set Advertising Parameters (0x08|0x0006) plen 15                                                                                        #2955 [hci0] 2022-01-26 17:03:00.798346
        Min advertising interval: 1280.000 msec (0x0800)
        Max advertising interval: 1280.000 msec (0x0800)
        Type: Connectable undirected - ADV_IND (0x00)
        Own address type: Public (0x00)
        Direct address type: Public (0x00)
        Direct address: 00:00:00:00:00:00 (OUI 00-00-00)
        Channel map: 37, 38, 39 (0x07)
        Filter policy: Allow Scan Request from Any, Allow Connect Request from Any (0x00)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                               #2956 [hci0] 2022-01-26 17:03:00.798666
      LE Set Advertising Parameters (0x08|0x0006) ncmd 1
        Status: Success (0x00)
< HCI Command: LE Set Advertise Enable (0x08|0x000a) plen 1                                                                                               #2957 [hci0] 2022-01-26 17:03:00.798733
        Advertising: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4                                                                                                               #2958 [hci0] 2022-01-26 17:03:00.799147
      LE Set Advertise Enable (0x08|0x000a) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2959 [hci0] 2022-01-26 17:03:00.952517
        Num handles: 1
        Handle: 65
        Count: 2
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2960 [hci0] 2022-01-26 17:03:00.953720
        Num handles: 1
        Handle: 65
        Count: 2
> ACL Data RX: Handle 65 flags 0x02 dlen 7                                                                                                                #2961 [hci0] 2022-01-26 17:03:00.996395
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 517
> ACL Data RX: Handle 65 flags 0x02 dlen 12                                                                                                               #2962 [hci0] 2022-01-26 17:03:00.996829
      LE L2CAP: Disconnection Response (0x07) ident 1 len 4
        Destination CID: 91
        Source CID: 66
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2963 [hci0] 2022-01-26 17:03:00.996940
        Num handles: 1
        Handle: 65
        Count: 2
< ACL Data TX: Handle 65 flags 0x00 dlen 13                                                                                                               #2964 [hci0] 2022-01-26 17:03:00.997185
      Channel: 90 len 9 sdu 7 [PSM 39 mode Enhanced Credit (0x81)] {chan 34}
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Unknown (0x2b3a)
< ACL Data TX: Handle 65 flags 0x00 dlen 13                                                                                                               #2965 [hci0] 2022-01-26 17:03:00.997227
      Channel: 89 len 9 [PSM 0 mode Basic (0x00)] {chan 65535}
        07 00 10 01 00 ff ff 00 28                       ........(
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2966 [hci0] 2022-01-26 17:03:00.997353
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0013-0xffff
        Attribute group type: Primary Service (0x2800)
> ACL Data RX: Handle 65 flags 0x02 dlen 12                                                                                                               #2967 [hci0] 2022-01-26 17:03:00.997936
      LE L2CAP: Disconnection Response (0x07) ident 2 len 4
        Destination CID: 92
        Source CID: 67
< ACL Data TX: Handle 65 flags 0x00 dlen 9                                                                                                                #2968 [hci0] 2022-01-26 17:03:00.998341
      ATT: Error Response (0x01) len 4
        Read By Group Type Request (0x10)
        Handle: 0x0013
        Error: Attribute Not Found (0x0a)
> ACL Data RX: Handle 65 flags 0x02 dlen 12                                                                                                               #2969 [hci0] 2022-01-26 17:03:00.998553
      LE L2CAP: Disconnection Response (0x07) ident 3 len 4
        Destination CID: 93
        Source CID: 68
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2970 [hci0] 2022-01-26 17:03:01.041391
      Channel: 65 len 7 sdu 5 [PSM 39 mode Enhanced Credit (0x81)] {chan 4}
      ATT: Read By Type Response (0x09) len 4
        Attribute data length: 3
        Attribute data list: 1 entry
        Handle: 0x0005
        Value: 01
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2971 [hci0] 2022-01-26 17:03:01.041476
      LE L2CAP: LE Flow Control Credit (0x16) ident 4 len 4
        Source CID: 65
        Credits: 1
< ACL Data TX: Handle 65 flags 0x00 dlen 11                                                                                                               #2972 [hci0] 2022-01-26 17:03:01.041788
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0006-0xffff
        Attribute type: Unknown (0x2b3a)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2973 [hci0] 2022-01-26 17:03:01.042348
        Num handles: 1
        Handle: 65
        Count: 2
> ACL Data RX: Handle 65 flags 0x02 dlen 20                                                                                                               #2974 [hci0] 2022-01-26 17:03:01.086496
      Channel: 64 len 16 sdu 14 [PSM 39 mode Enhanced Credit (0x81)] {chan 7}
      ATT: Read By Group Type Response (0x11) len 13
        Attribute data length: 6
        Attribute group list: 2 entries
        Handle range: 0x0001-0x0009
        UUID: Generic Attribute Profile (0x1801)
        Handle range: 0x0014-0xffff
        UUID: Generic Access Profile (0x1800)
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2975 [hci0] 2022-01-26 17:03:01.086584
      LE L2CAP: LE Flow Control Credit (0x16) ident 5 len 4
        Source CID: 64
        Credits: 1
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2976 [hci0] 2022-01-26 17:03:01.087373
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0005
        Attribute type: Include (0x2802)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2977 [hci0] 2022-01-26 17:03:01.087459
        Num handles: 1
        Handle: 65
        Count: 2
< ACL Data TX: Handle 65 flags 0x00 dlen 13                                                                                                               #2978 [hci0] 2022-01-26 17:03:01.088380
      Channel: 90 len 9 sdu 7 [PSM 39 mode Enhanced Credit (0x81)] {chan 34}
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Secondary Service (0x2801)
< ACL Data TX: Handle 65 flags 0x00 dlen 9                                                                                                                #2979 [hci0] 2022-01-26 17:03:01.088841
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0001
        Error: Attribute Not Found (0x0a)
> ACL Data RX: Handle 65 flags 0x02 dlen 9                                                                                                                #2980 [hci0] 2022-01-26 17:03:01.131369
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0006
        Error: Attribute Not Found (0x0a)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2981 [hci0] 2022-01-26 17:03:01.132192
        Num handles: 1
        Handle: 65
        Count: 2
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2982 [hci0] 2022-01-26 17:03:01.176435
      Channel: 65 len 7 sdu 5 [PSM 39 mode Enhanced Credit (0x81)] {chan 4}
      ATT: Error Response (0x01) len 4
        Read By Group Type Request (0x10)
        Handle: 0x0001
        Error: Unsupported Group Type (0x10)
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2983 [hci0] 2022-01-26 17:03:01.176519
      LE L2CAP: LE Flow Control Credit (0x16) ident 6 len 4
        Source CID: 65
        Credits: 1
< ACL Data TX: Handle 65 flags 0x00 dlen 13                                                                                                               #2984 [hci0] 2022-01-26 17:03:01.176909
      Channel: 89 len 9 [PSM 0 mode Basic (0x00)] {chan 65535}
        07 00 08 01 00 ff ff 02 28                       ........(
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2985 [hci0] 2022-01-26 17:03:01.177230
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0x0005
        Attribute type: Characteristic (0x2803)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2986 [hci0] 2022-01-26 17:03:01.177243
        Num handles: 1
        Handle: 65
        Count: 2
< ACL Data TX: Handle 65 flags 0x00 dlen 20                                                                                                               #2987 [hci0] 2022-01-26 17:03:01.177761
      ATT: Read By Type Response (0x09) len 15
        Attribute data length: 7
        Attribute data list: 2 entries
        Handle: 0x0002
        Value: 020300002a
        Handle: 0x0004
        Value: 020500012a
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2988 [hci0] 2022-01-26 17:03:01.229930
        Num handles: 1
        Handle: 65
        Count: 2
> HCI Event: LE Meta Event (0x3e) plen 10                                                                                                                 #2989 [hci0] 2022-01-26 17:03:01.230518
      LE Connection Update Complete (0x03)
        Status: Success (0x00)
        Handle: 65
        Connection interval: 7.50 msec (0x0006)
        Connection latency: 0 (0x0000)
        Supervision timeout: 5000 msec (0x01f4)
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2990 [hci0] 2022-01-26 17:03:01.236859
      Channel: 64 len 7 sdu 5 [PSM 39 mode Enhanced Credit (0x81)] {chan 7}
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0001
        Error: Attribute Not Found (0x0a)
< ACL Data TX: Handle 65 flags 0x00 dlen 12                                                                                                               #2991 [hci0] 2022-01-26 17:03:01.236953
      LE L2CAP: LE Flow Control Credit (0x16) ident 7 len 4
        Source CID: 64
        Credits: 1
< ACL Data TX: Handle 65 flags 0x00 dlen 13                                                                                                               #2992 [hci0] 2022-01-26 17:03:01.237342
      Channel: 90 len 9 sdu 7 [PSM 39 mode Enhanced Credit (0x81)] {chan 34}
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0001-0xffff
        Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 65 flags 0x02 dlen 11                                                                                                               #2993 [hci0] 2022-01-26 17:03:01.237500
      ATT: Read By Type Request (0x08) len 6
        Handle range: 0x0005-0x0005
        Attribute type: Characteristic (0x2803)
< ACL Data TX: Handle 65 flags 0x00 dlen 9                                                                                                                #2994 [hci0] 2022-01-26 17:03:01.237981
      ATT: Error Response (0x01) len 4
        Read By Type Request (0x08)
        Handle: 0x0005
        Error: Attribute Not Found (0x0a)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2995 [hci0] 2022-01-26 17:03:01.251886
        Num handles: 1
        Handle: 65
        Count: 2
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                    #2996 [hci0] 2022-01-26 17:03:01.259099
        Num handles: 1
        Handle: 65
        Count: 2
> HCI Event: Disconnect Complete (0x05) plen 4                                                                                                            #2997 [hci0] 2022-01-26 17:03:06.262317
        Status: Success (0x00)
        Handle: 65
        Reason: Connection Timeout (0x08)
@ MGMT Event: Device Disconnected (0x000c) plen 8                                                                                                      {0x0001} [hci0] 2022-01-26 17:03:06.262386
        LE Address: 61:DD:CB:12:94:BE (Resolvable)
        Reason: Connection timeout (0x01)

The client starts a gatt.discoverServices() but never get data back from the pi, and 5 seconds later it is disconnected.

Please let me know if there is anything I can do to help.

jbraswell commented 2 years ago

We are also encountering the exact behavior described in this issue and https://github.com/RPi-Distro/bluez-firmware/issues/9. The only difference for us is that enabling ecred deos not seem to help. Would love to see it fixed, and happy to help. Is there anything I can do to help move this along?

hando-gomes commented 2 years ago

I just left a comment on the link above.

jbraswell commented 2 years ago

@hando-gomes Sorry, not seeing a new comment on https://github.com/RPi-Distro/bluez-firmware/issues/9. Were you referring to another link?

cspensky commented 2 years ago

I'm seeing the same thing on my end. Has anyone made any progress on this? It seems to be hanging indefinitely after characteristic write in my case

Apr 20 08:35:31 chads-demo-reader bluetoothd[5072]: src/device.c:gatt_debug() Write Complete: err 0
Apr 20 08:35:36 chads-demo-reader bluetoothd[5072]: src/adapter.c:dev_disconnected() Device 6D:20:DB:B9:A7:76 disconnected, reason 1

And I see it time out in btmon

> HCI Event: Disconnect Complete (0x05) plen 4                                                           #247301 [hci0] 50873.494976
        Status: Success (0x00)
        Handle: 64
        Reason: Connection Timeout (0x08)

I have seen in connect successfully in very rare cases and after a lot of failures.

Is it possible that it's the BLE parameters that need to be tweaked for these phones? I know Apple has very specific recommendations for iPhones (https://developer.apple.com/library/archive/qa/qa1931/_index.html)

Vudentz commented 2 years ago 
> ACL Data RX: Handle 65 flags 0x02 dlen 26                                                                                                               #2945 [hci0] 2022-01-26 17:03:00.636995
      LE L2CAP: Enhanced Credit Connection Request (0x17) ident 2 len 18
        PSM: 39 (0x0027)
        MTU: 256
        MPS: 251
        Credits: 65535
        Source CID: 251
        Source CID: 65535
        Source CID: 89
        Source CID: 90
        Source CID: 91
        Source CID: 92
        Source CID: 93

First this is against the spec since there is way too many Source CID:

BLUETOOTH CORE SPECIFICATION Version 5.3 | Vol 3, Part A
page 1063
Logical Link Control and Adaptation Protocol Specification

• Source CID – (2 to 10 octets)
The Source CID is an array of up to 5 two-octet values and represents the
channel endpoints on the device sending the request. Once a channel has
been created, data packets flowing to the sender of the request shall be sent to

[Edit] This is a problem on btmon, it is not accounting the frame correctly causing 2 extra Source CIDs to be printed.

It also makes no sense to limit the MTU to 256 for EATT when for ATT the MTU is 517.

cspensky commented 2 years ago

After some serious digging I've narrowed it down quite a bit. The issue seems to be with negotiating the MTU (at least in my case). If I remove the following line from my code, it seems to work as expected.

gatt.requestMtu(512);

The Wrong link type (-22) appears to be a non-issue as I also see it with my Pixel 5 and everything works fine with the 5.

I believe this to be the same as https://github.com/RPi-Distro/bluez-firmware/issues/9

cspensky commented 2 years ago

Just to follow up. My previous fix only seems to fix part of the issue. After a few days, the phone seems to fail to connect again. Has anyone had any progress on this?

ln-12 commented 2 years ago

I am experiencing the exact same issue. Using a Pixel 6 (non Pro, Android 13 Beta 4), I get the following messages running sudo /usr/libexec/bluetooth/bluetoothd -d -n alongside cputemp when trying to connect from nRF Connect:

bluetoothd[1396]: src/adapter.c:connected_callback() hci0 device 4A:D4:07:B8:A6:99 connected eir_len 0
bluetoothd[1396]: src/device.c:device_create() dst 4A:D4:07:B8:A6:99
bluetoothd[1396]: src/device.c:device_new() address 4A:D4:07:B8:A6:99
bluetoothd[1396]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_4A_D4_07_B8_A6_99
bluetoothd[1396]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
bluetoothd[1396]: attrib/gattrib.c:g_attrib_ref() 0x6e0060: g_attrib_ref=1 
bluetoothd[1396]: src/device.c:load_gatt_db() Restoring 4A:D4:07:B8:A6:99 gatt database from file
bluetoothd[1396]: src/device.c:load_gatt_db() No cache for 4A:D4:07:B8:A6:99
bluetoothd[1396]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
bluetoothd[1396]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
bluetoothd[1396]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
bluetoothd[1396]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0013 end: 0xffff
bluetoothd[1396]: src/device.c:gatt_debug() Read By Grp Type - start: 0x001b end: 0xffff
bluetoothd[1396]: src/device.c:gatt_debug() Primary services found: 2
bluetoothd[1396]: src/device.c:gatt_debug() start: 0x0001, end: 0x0009, uuid: 00001801-0000-1000-8000-00805f9b34fb
bluetoothd[1396]: src/device.c:gatt_debug() start: 0x0014, end: 0xffff, uuid: 00001800-0000-1000-8000-00805f9b34fb
bluetoothd[1396]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
bluetoothd[1396]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0005
bluetoothd[1396]: src/device.c:gatt_debug() Server Features found: handle 0x0005 length 0x0001 value 0x01
bluetoothd[1396]: src/device.c:gatt_debug() Read By Type - start: 0x0005 end: 0x0005
bluetoothd[1396]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
bluetoothd[1396]: src/device.c:gatt_debug() Read By Type - start: 0x0006 end: 0x000f
bluetoothd[1396]: src/adapter.c:dev_disconnected() Device 4A:D4:07:B8:A6:99 disconnected, reason 1
bluetoothd[1396]: src/adapter.c:adapter_remove_connection() 
bluetoothd[1396]: plugins/policy.c:disconnect_cb() reason 1
bluetoothd[1396]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 4A:D4:07:B8:A6:99 type 2 status 0xe
bluetoothd[1396]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
bluetoothd[1396]: src/device.c:device_bonding_failed() status 14
bluetoothd[1396]: src/adapter.c:resume_discovery() 
bluetoothd[1396]: src/device.c:gatt_debug() service disappeared: start 0x0001 end 0x0009
bluetoothd[1396]: src/device.c:gatt_debug() service disappeared: start 0x0014 end 0xffff
bluetoothd[1396]: src/device.c:gatt_debug() Failed to initialize gatt-client
bluetoothd[1396]: src/device.c:gatt_client_ready_cb() status: failed, error: 0
bluetoothd[1396]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_4A_D4_07_B8_A6_99 err -5
bluetoothd[1396]: src/device.c:att_disconnected_cb() 
bluetoothd[1396]: src/device.c:att_disconnected_cb() Connection timed out (110)
bluetoothd[1396]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
bluetoothd[1396]: src/device.c:att_disconnected_cb() Automatic connection disabled
bluetoothd[1396]: src/gatt-database.c:btd_gatt_database_att_disconnected() 
bluetoothd[1396]: attrib/gattrib.c:g_attrib_unref() 0x6e0060: g_attrib_unref=0 
bluetoothd[1396]: src/device.c:device_remove() Removing device /org/bluez/hci0/dev_4A_D4_07_B8_A6_99
bluetoothd[1396]: src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_4A_D4_07_B8_A6_99
bluetoothd[1396]: src/device.c:device_free() 0x6e1308

I tried raspbian (both bullseye and buster), ubuntu server and even manjaro (using bluez 5.64-2), but as the issue seems to be located in the kernel, it does not make a difference. The manjaro journal log looks like this:

Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:manager_register_app() Registering application: :1.53:/
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/advertising.c:register_advertisement() RegisterAdvertisement
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/advertising.c:client_create() Adding proxy for /org/bluez/example/advertisement0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/advertising.c:register_advertisement() Registered advertisement at path /org/bluez/example/advertisement0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:proxy_added_cb() Object received: /org/bluez/example/service0, iface: org.bluez.GattService1
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:proxy_added_cb() Object received: /org/bluez/example/service0/char0, iface: org.bluez.GattCharacteristic1
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:proxy_added_cb() Object received: /org/bluez/example/service0/char0/desc0, iface: org.bluez.GattDescriptor1
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:proxy_added_cb() Object received: /org/bluez/example/service0/char1, iface: org.bluez.GattCharacteristic1
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:proxy_added_cb() Object received: /org/bluez/example/service0/char1/desc0, iface: org.bluez.GattDescriptor1
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:database_add_service() handle 0x0015 UUID 00000001-710e-4a5b-8d75-3e5b444bc3cf
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:database_add_ccc() Created CCC entry for characteristic
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:database_add_chrc() handle 0x0017 UUID 00000002-710e-4a5b-8d75-3e5b444bc3cf
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:database_add_desc() handle 0x0019 UUID 00002901-0000-1000-8000-00805f9b34fb
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:database_add_chrc() handle 0x001b UUID 00000003-710e-4a5b-8d75-3e5b444bc3cf
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:database_add_desc() handle 0x001c UUID 00002901-0000-1000-8000-00805f9b34fb
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:gatt_db_service_added() GATT Service added to local database
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/adapter.c:adapter_service_add() /org/bluez/hci0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10011
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000001-710e-4a5b-8d75-3e5b444
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000007-0000-1000-8000-00805f9
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/adapter.c:add_uuid() sending add uuid command for index 0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/gatt-database.c:client_ready_cb() GATT application registered: :1.53:/
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/advertising.c:refresh_extended_adv() Refreshing advertisement parameters: /org/bluez/example/advertisement0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/advertising.c:add_adv_params_callback() Refreshing advertisement data: /org/bluez/example/advertisement0
Jul 27 15:56:11 pi-pc bluetoothd[369]: src/advertising.c:add_adv_callback() Advertisement registered: /org/bluez/example/advertisement0
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/adapter.c:connected_callback() hci0 device 5E:27:85:B4:AE:F4 connected eir_len 0
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:device_create() dst 5E:27:85:B4:AE:F4
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:device_new() address 5E:27:85:B4:AE:F4
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_5E_27_85_B4_AE_F4
Jul 27 15:56:14 pi-pc systemd[467]: Reached target Bluetooth.
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
Jul 27 15:56:14 pi-pc bluetoothd[369]: attrib/gattrib.c:g_attrib_ref() 0xaaaaea3f7650: g_attrib_ref=1
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:load_gatt_db() Restoring 5E:27:85:B4:AE:F4 gatt database from file
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:load_gatt_db() Unable to load key file from /var/lib/bluetooth/E4:5F:01:6B:52:3D/cache/5E:27:85:B4:AE:F4: (No such file or directory)
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:load_gatt_db() No cache for 5E:27:85:B4:AE:F4
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x10
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0001 end: 0xffff
Jul 27 15:56:14 pi-pc kernel: Bluetooth: Wrong link type (-22)
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() MTU exchange complete, with MTU: 517
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x10
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Grp Type - start: 0x0015 end: 0xffff
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x10
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Grp Type - start: 0x001d end: 0xffff
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x08
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0007
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Primary services found: 2
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() start: 0x0001, end: 0x0009, uuid: 00001801-0000-1000-8000-00805f9b34fb
Jul 27 15:56:14 pi-pc bluetoothd[369]: src/device.c:gatt_debug() start: 0x0014, end: 0xffff, uuid: 00001800-0000-1000-8000-00805f9b34fb
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x08
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Type - start: 0x0001 end: 0x0007
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Server Features found: handle 0x0005 length 0x0001 value 0x01
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x08
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Type - start: 0x0007 end: 0x0007
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x08
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Type - start: 0x0008 end: 0x0011
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() (chan 0xaaaaea3f65d0) ATT PDU received: 0x08
Jul 27 15:56:15 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Read By Type - start: 0x0008 end: 0x0011
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/adapter.c:dev_disconnected() Device 5E:27:85:B4:AE:F4 disconnected, reason 1
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/adapter.c:adapter_remove_connection()
Jul 27 15:56:20 pi-pc bluetoothd[369]: plugins/policy.c:disconnect_cb() reason 1
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 5E:27:85:B4:AE:F4 type 2 status 0xe
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:device_bonding_failed() status 14
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/adapter.c:resume_discovery()
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Channel 0xaaaaea3f65d0 disconnected: Connection timed out
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:gatt_debug() service disappeared: start 0x0001 end 0x0009
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:gatt_debug() service disappeared: start 0x0014 end 0xffff
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:gatt_debug() Failed to initialize gatt-client
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:gatt_client_ready_cb() status: failed, error: 0
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_5E_27_85_B4_AE_F4 err -5
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:att_disconnected_cb()
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:att_disconnected_cb() Connection timed out (110)
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/device.c:att_disconnected_cb() Automatic connection disabled
Jul 27 15:56:20 pi-pc bluetoothd[369]: src/gatt-database.c:btd_gatt_database_att_disconnected()
Jul 27 15:56:20 pi-pc bluetoothd[369]: attrib/gattrib.c:g_attrib_unref() 0xaaaaea3f7650: g_attrib_unref=0
Jul 27 15:56:50 pi-pc bluetoothd[369]: src/device.c:device_remove() Removing device /org/bluez/hci0/dev_5E_27_85_B4_AE_F4
Jul 27 15:56:50 pi-pc bluetoothd[369]: src/device.c:btd_device_unref() Freeing device /org/bluez/hci0/dev_5E_27_85_B4_AE_F4
Jul 27 15:56:50 pi-pc bluetoothd[369]: src/device.c:device_free() 0xaaaaea402620

Did anyone find a solution/workaround?

ln-12 commented 2 years ago

I finally got it working, but only with an external USB bluetooth dongle. I had a random one lying around, plugged it in, disabled the integrated bluetooth adapter using sudo hciconfig hci0 down and ran the cputemp example again. My Pixel 6 connects immediately without any issue.

jbraswell commented 2 years ago

I finally got it working, but only with an external USB bluetooth dongle. I had a random one lying around, plugged it in, disabled the integrated bluetooth adapter using sudo hciconfig hci0 down and ran the cputemp example again. My Pixel 6 connects immediately without any issue.

Which dongle did you use?

ln-12 commented 2 years ago

I finally got it working, but only with an external USB bluetooth dongle. I had a random one lying around, plugged it in, disabled the integrated bluetooth adapter using sudo hciconfig hci0 down and ran the cputemp example again. My Pixel 6 connects immediately without any issue.

Which dongle did you use?

It's a TP-Link UB400, but I would guess that other dongles would also work.

Path-A commented 2 years ago

Another workaround on the Pixel 6 with Android 12 is to enable Gabeldorsche Bluetooth in the phone's developer settings. Unfortunately, it seems that Gabeldorsche is going away with Android 13 from what I can tell, so this may not work for very long.

zhonghuiwen commented 2 years ago

I finally got it working, but only with an external USB bluetooth dongle. I had a random one lying around, plugged it in, disabled the integrated bluetooth adapter using sudo hciconfig hci0 down and ran the cputemp example again. My Pixel 6 connects immediately without any issue.

Which dongle did you use?

It's a TP-Link UB400, but I would guess that other dongles would also work.

Thank you so much @ln-12, i just bought the TP-Link UB400 you mentioned and i am able to connect my OPPO1920 to the pi

Path-A commented 2 years ago

Would like to confirm that some newer phones on latest release of Raspbian (Linux 5.15 and BlueZ 5.55) are still not working. The following phones failed to connect via Bluetooth:

Pixel 6, Android 12 Pixel 6, Android 13 Pixel 6 Pro, Android 13 Samsung Ultra 22, Android 12 Samsung Ultra 22, Android 13

It appears that the new Gabeldorsche Bluetooth stack was widely adopted in Android 13, but it didn't fix the issue. Perhaps the stack wasn't entirely adopted yet because it previously allowed my Pixels to connect when I enabled Gabeldorsche in Developer settings.

cspensky commented 2 years ago

I am still having issues on my pixel 6 with android 13. Would love some insight on a long-term fix.

On Wed, Oct 5, 2022, 9:10 AM Austin Anderson @.***> wrote:

Would like to confirm that some newer phones on latest release of Raspbian (Linux 5.15 and BlueZ 5.55) are still not working. The following phones failed to connect via Bluetooth:

Pixel 6, Android 12 Pixel 6, Android 13 Pixel 6 Pro, Android 13 Samsung Ultra 22, Android 12 Samsung Ultra 22, Android 13

It appears that the new Gabeldorsche Bluetooth stack was widely adopted in Android 13, but it didn't fix the issue. Perhaps the stack wasn't entirely adopted yet because it previously allowed my Pixels to connect when I enabled Gabeldorsche in Developer settings.

— Reply to this email directly, view it on GitHub https://github.com/raspberrypi/linux/issues/4847#issuecomment-1268489815, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAVJBSJ4PQXSALCKF6GMQGLWBWD6DANCNFSM5MZMCSQQ . You are receiving this because you commented.Message ID: @.***>

pelwell commented 2 years ago

Locking thread to stop the cross-posting. Please use https://github.com/RPi-Distro/bluez-firmware/issues/9.