Bluetooth issue with version 4.1 (20230401-starlte) on S9

[nbaerts]

Hello,

The bluetooth on version 4.1 (20230401-starlte) for S9 is not fully working. It's well pairing/using headphones,... but has issue to pair devices such as fitbit watches and PM5 (it well see them but is unable to pair them). Note that the same S9 device put back on version 3.5 (20230131-starlte) is well able to pair all the devices.

Here are the logs (see the INVALID_HCI_COMMAND_PARAMETERS error below):

[D/ActivityAttributionService]
notifyActivityAttributionInfo UID=1002 packageName=com.android.bluetooth deviceAddress=no_active_device_address

[I/bt_stack]
[INFO:le_scanning_manager.cc(238)] ScanFilterEnable in shim layer

[I/bt_btif]
packages/modules/Bluetooth/system/btif/src/bluetooth.cc:463 get_profile_interface: get_profile_interface: id = activity_attribution

[I/bt_stack]
[INFO:le_scanning_manager.cc(174)] ScanFilterParamSetup in shim layer
[INFO:le_scanning_manager.cc(154)] Scan in shim layer started
[INFO:le_scanning_manager.cc(154)] Scan in shim layer stopped
[INFO:le_scanning_manager.cc(250)] SetScanParameters in shim layer
[INFO:le_scanning_manager.cc(154)] Scan in shim layer started

[I/bluetooth]
packages/modules/Bluetooth/system/gd/hci/le_scanning_manager.cc:665 stop_scan: Scanning already stopped, return!
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:175 register_client: Client registered
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:190 unregister_client: Client unregistered
packages/modules/Bluetooth/system/gd/hci/le_scanning_manager.cc:665 stop_scan: Scanning already stopped, return!
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:175 register_client: Client registered

[E/]
[6:HwBinder:4248_1: 4261] [BT] set_wake_locked value = 1

[W/[7:HwBinder:4259_3:14281] HwBinder]
4259_3: page allocation failure: order:4, mode:0x242c0c2(GFP_HIGHUSER|__GFP_COMP|__GFP_ZERO)

[W/[7:HwBinder:4259_3:14281] CPU]
7 PID: 14281 Comm: HwBinder:4259_3 Tainted: G        W       4.9.337-ies-g2afeeb6353f9 #1

[W/]
[7:HwBinder:4259_3:14281] Hardware name: Samsung Star rev26 board based on EXYNOS9810 (DT)
[7:HwBinder:4259_3:14281] Call trace:
[7:HwBinder:4259_3:14281] [<000000002b68c0e2>] dump_backtrace+0x0/0x2b0
[7:HwBinder:4259_3:14281] [<000000003e3d255e>] show_stack+0x14/0x1c
[7:HwBinder:4259_3:14281] [<000000000294a326>] dump_stack+0xcc/0x104
[7:HwBinder:4259_3:14281] [<0000000034838307>] warn_alloc+0x110/0x144
[7:HwBinder:4259_3:14281] [<0000000040d2e7b6>] __alloc_pages_nodemask+0xf50/0x10b0
[7:HwBinder:4259_3:14281] [<00000000d3091af7>] ion_page_pool_alloc+0x9c/0xcc
[7:HwBinder:4259_3:14281] [<000000007dfa0716>] ion_system_heap_allocate+0x11c/0x3d8
[7:HwBinder:4259_3:14281] [<000000006a37b8ab>] __ion_alloc+0x374/0xc68
[7:HwBinder:4259_3:14281] [<0000000000780ddc>] ion_ioctl+0x264/0x494
[7:HwBinder:4259_3:14281] [<000000006b1b51d5>] do_vfs_ioctl+0x810/0xc30
[7:HwBinder:4259_3:14281] [<0000000087300e73>] SyS_ioctl+0x88/0x94
[7:HwBinder:4259_3:14281] [<00000000d33208c7>] el0_svc_naked+0x34/0x38

[W/[7:HwBinder:4259_3:14281] Mem-Info]

[W/[7:HwBinder:4259_3:14281] SystemHeap]
470384kB SystemHeapPool:0kB VmallocAPIsize:61532kB

[W/[7:HwBinder:4259_3:14281] active_anon]
227038 inactive_anon:80790 isolated_anon:0

[W/[7:HwBinder:4259_3:14281]  active_file]
71495 inactive_file:92699 isolated_file:0

[W/[7:HwBinder:4259_3:14281]  unevictable]
43895 dirty:402 writeback:0 unstable:0

[W/[7:HwBinder:4259_3:14281]  slab_reclaimable]
14858 slab_unreclaimable:32199

[W/[7:HwBinder:4259_3:14281]  mapped]
107381 shmem:3082 pagetables:14642 bounce:0

[W/[7:HwBinder:4259_3:14281]  free]
64570 free_pcp:95 free_cma:76 free_rbin:0

[W/]
[7:HwBinder:4259_3:14281] Node 0 active_anon:908152kB inactive_anon:323160kB active_file:285980kB inactive_file:370796kB unevictable:175580kB isolated(anon):0kB isolated(file):0kB mapped:429524kB dirty:1608kB writeback:0kB shmem:12328kB writeback_tmp:0kB unstable:0kB pages_scanned:0 all_unreclaimable? no
[7:HwBinder:4259_3:14281] Normal free:258280kB min:7684kB low:57572kB high:61304kB active_anon:908152kB inactive_anon:323160kB active_file:285980kB inactive_file:370796kB unevictable:176656kB writepending:1608kB present:4103168kB managed:3732528kB mlocked:175580kB slab_reclaimable:59432kB slab_unreclaimable:128796kB kernel_stack:34192kB pagetables:58568kB bounce:0kB free_pcp:380kB local_pcp:0kB free_cma:304kB free_rbin:0kB

[I/lowmem_reserve[]]
0 0

[W/[7:HwBinder:4259_3:14281] Normal]
16501*4kB (UMEHC) 20586*8kB (UMEHC) 1479*16kB (UMH) 43*32kB (UMH) 12*64kB (H) 3*128kB (H) 4*256kB (H) 1*512kB (H) 0*1024kB 0*2048kB 0*4096kB = 258420kB

[I/]
236699 total pagecache pages

[W/]
[7:HwBinder:4259_3:14281] 25512 pages in swap cache
[7:HwBinder:4259_3:14281] Swap cache stats: add 1445954, delete 1420442, find 148957/491757
[7:HwBinder:4259_3:14281] Free swap  = 1310676kB
[7:HwBinder:4259_3:14281] Total swap = 2097148kB
[7:HwBinder:4259_3:14281] 1025792 pages RAM
[7:HwBinder:4259_3:14281] 0 pages HighMem/MovableOnly
[7:HwBinder:4259_3:14281] 92660 pages reserved
[7:HwBinder:4259_3:14281] 40960 pages cma reserved

...

[D/BluetoothGatt]
connect() - device: E0:A8:04:C3:6E:6E, auto: false
registerApp()
registerApp() - UUID=461b5446-8830-424b-b9ba-9c969b55898b

[2097:2154 I/bluetooth]
packages/modules/Bluetooth/system/stack/gatt/gatt_api.cc:1122 GATT_Register: Allocated name:GattClient uuid:5de3c237-60a4-3aef-b5b7-300227f09b0e gatt_if:6 eatt_support:0

[D/BluetoothGatt]
onClientRegistered() - status=0 clientIf=6

[E/]
[5:HwBinder:4248_1: 4261] [BT] set_wake_locked value = 1

[I/bt_btif_gattc]
packages/modules/Bluetooth/system/btif/src/btif_gatt_client.cc:365 btif_gattc_open_impl: Transport=2, device type=2, address type =1, phy=1

[I/bt_stack]
[INFO:gatt_attr.cc(946)] gatt_sr_init_cl_status: bda=e0:a8:04:c3:6e:6e, cl_supp_feat=0000, aware=1

[I/bluetooth]
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:257 ack_pause: Client already in paused state
packages/modules/Bluetooth/system/stack/gatt/gatt_main.cc:370 gatt_update_app_use_link_flag: check_acl_link is false, no need to check
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:257 ack_pause: Client already in paused state
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:257 ack_pause: Client already in paused state
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:576 OnCommandComplete: Received command complete with op_code LE_ADD_DEVICE_TO_FILTER_ACCEPT_LIST
packages/modules/Bluetooth/system/gd/hci/le_address_manager.cc:286 resume_registered_clients: Resuming registered clients

[E/bluetooth]
packages/modules/Bluetooth/system/gd/hci/hci_layer.cc:156 on_command_status: Received UNEXPECTED command status:INVALID_HCI_COMMAND_PARAMETERS opcode:0x200d (LE_CREATE_CONNECTION)
packages/modules/Bluetooth/system/gd/hci/acl_manager/le_impl.h:683 update_connectability_state_after_armed: Le connection state machine armed failed status:INVALID_HCI_COMMAND_PARAMETERS

[I/bluetooth]
packages/modules/Bluetooth/system/gd/hci/acl_manager/le_impl.h:690 update_connectability_state_after_armed: Le connection state machine armed state:ConnectabilityState::DISARMED status:INVALID_HCI_COMMAND_PARAMETERS