Bluetooth: settings: No space to store CCC config after successful pairing

Qbicz commented 5 years ago

When subsequent peer connects, enabling CCC fails even though pairing was successful.

Steps to reproduce:

clear flash memory
pair BLE host A -> it connects, pairing successful, after reading GATT services host writes CCC and it is possible to send notifications. Disconnect host A.
pair BLE host B -> it connects, pairing successful, after reading GATT services there is warning: [bt] [WRN] bt_gatt_attr_write_ccc: No space to store CCC cfg CCC is not enabled and it is not possible to send notifications.

Reproduced on BLE peripheral, nRF52840, BT_MAX_PAIRED = 2.

@Vudentz please let me know if you need additional information.

Qbicz commented 5 years ago

CC @pdunaj

carlescufi commented 5 years ago

CC @nvlsianpu

Qbicz commented 5 years ago

Increasing BT_GATT_CCC_MAX (to BT_MAX_PAIRED+BT_MAX_CONN+5) nor CCC_STORE_MAX (from 48 to 96) does not solve the problem. Still can be reproduced with the above scenario.

Vudentz commented 5 years ago

This might be a different issue than just lack of storage then. Do you have the logs with CONFIG_BT_GATT_DEBUG=y?

Qbicz commented 5 years ago

Logs with GATT debug and BT storage debug enabled:

[bt] [DBG] bt_settings_init: (0x200058f0)
[bt] [INF] hci_vs_init: HW Platform: Nordic Semiconductor (0x0002)
[bt] [INF] hci_vs_init: HW Variant: nRF52x (0x0002)
[bt] [INF] hci_vs_init: Firmware: Standard Bluetooth controller (0x00) Version 1.13 Build 99
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008f64 handle 0x0001 uuid 2800 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008f78 handle 0x0002 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008f8c handle 0x0003 uuid 2a00 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008fa0 handle 0x0004 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008fb4 handle 0x0005 uuid 2a01 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008fc8 handle 0x0006 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008fdc handle 0x0007 uuid 2a04 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008ffc handle 0x0008 uuid 2800 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20009010 handle 0x0009 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20009024 handle 0x000a uuid 2a05 perm 0x00
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20009038 handle 0x000b uuid 2902 perm 0x03
[bt] [WRN] bt_init: No ID address. Expecting one to come from storage.
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008a38 handle 0x000c uuid 2800 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008a4c handle 0x000d uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20008a60 handle 0x000e uuid 2a19 perm 0x01
[...]
[bt] [DBG] gatt_register: (0x200058f0) attr 0x200092ac handle 0x0016 uuid 2a50 perm 0x01
[bt] [DBG] update_range: (0x200058f0) start 0x000c end 0x000f new_start 0x0010 new_end 0x0016
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20000354 handle 0x0017 uuid 2800 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20000368 handle 0x0018 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x2000037c handle 0x0019 uuid 2a4e perm 0x03
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20000390 handle 0x001a uuid 2803 perm 0x01
[...]
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20000444 handle 0x0023 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20000458 handle 0x0024 uuid 2a4a perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x2000046c handle 0x0025 uuid 2803 perm 0x01
[bt] [DBG] gatt_register: (0x200058f0) attr 0x20000480 handle 0x0026 uuid 2a4c perm 0x02
[bt] [DBG] update_range: (0x200058f0) start 0x000c end 0x0016 new_start 0x0017 new_end 0x0026
[bt] [DBG] commit: (0x200058f0)
[bt] [INF] bt_dev_show_info: Identity: Xa:cc:c2:8d:fa:d9 (random)
[bt] [INF] bt_dev_show_info: HCI: version 5.0 (0x09) revision 0x0000, manufacturer 0x05f1
[bt] [INF] bt_dev_show_info: LMP: version 5.0 (0x09) subver 0xffff
[bt] [DBG] save_id: (0x200058f0) Saving ID addr as value Xdn6jcLM2g==
[bt] [DBG] sc_process: (0x200058f0) start 0x000c end 0x0026

> HOST A connected
[bt] [DBG] bt_gatt_connected: (0x20004724) conn 0x20002afc
[bt] [DBG] bt_settings_encode_key: (0x20004724) Encoded path bt/keys/X883223e9a6b0
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0010 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0017 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x000c offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0010 offset 0 length 2
[...]
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0010 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0017 offset 0 length 2
[bt] [DBG] bt_gatt_attr_write_ccc: (0x20004724) handle 0x000b value 2
[bt] [DBG] gatt_ccc_changed: (0x20004724) ccc 0x20008f30 value 0x0002
[bt] [DBG] sc_ccc_cfg_changed: (0x20004724) value 0x0002
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0002 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0004 offset 0 length 5
[...]
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0016 offset 0 length 7
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0007 offset 0 length 8
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001d offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001f offset 0 length 22
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001f offset 22 length 22
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001f offset 44 length 18
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0024 offset 0 length 4
[bt] [DBG] bt_gatt_attr_write_ccc: (0x20004724) handle 0x001c value 1
[bt] [DBG] gatt_ccc_changed: (0x20004724) ccc 0x2000411c value 0x0001
[bt] [DBG] bt_gatt_attr_write_ccc: (0x20004724) handle 0x0022 value 1
[bt] [DBG] gatt_ccc_changed: (0x20004724) ccc 0x2000412c value 0x0001

> Sending data to Host A
[bt] [DBG] gatt_notify: (0x200058f0) conn 0x20002afc handle 0x001b
[bt] [DBG] gatt_notify: (0x200058f0) conn 0x20002afc handle 0x001b
[bt] [DBG] gatt_notify: (0x200058f0) conn 0x20002afc handle 0x001b

[bt] [DBG] bt_gatt_disconnected: (0x20004724) conn 0x20002afc
[bt] [DBG] sc_ccc_cfg_changed: (0x20004724) value 0x0000
[bt] [DBG] disconnected_cb: (0x20004724) ccc 0x20008f30 reseted
[bt] [DBG] disconnected_cb: (0x20004724) ccc 0x2000411c reseted
[bt] [DBG] disconnected_cb: (0x20004724) ccc 0x2000412c reseted
[bt] [DBG] ccc_save: (0x20004724) Storing CCCs handle 0x000b value 0x0002
[bt] [DBG] ccc_save: (0x20004724) Storing CCCs handle 0x001c value 0x0001
[bt] [DBG] ccc_save: (0x20004724) Storing CCCs handle 0x0022 value 0x0001
[bt] [DBG] bt_settings_encode_key: (0x20004724) Encoded path bt/ccc/X883223e9a6b0
[bt] [DBG] bt_gatt_store_ccc: (0x20004724) Stored CCCs for X8:83:22:3e:9a:6b (public) (bt/ccc/X883223e9a6b0) val XwACABwAAQAiAAEA
conn_id=0x20002afc DISCONNECTED

> HOST B connected
[bt] [DBG] bt_gatt_connected: (0x20004724) conn 0x20002afc
conn_id=0x20002afc CONNECTED
conn_id=0x20002afc SECURED
[bt] [DBG] bt_settings_encode_key: (0x20004724) Encoded path bt/keys/Y827ea307e830
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0001 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0008 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x000c offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0010 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0017 offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0002 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0004 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0006 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0016 offset 0 length 7
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0009 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x000d offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0011 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0013 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0015 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0018 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001a offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001e offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0020 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0023 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0025 offset 0 length 5
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0007 offset 0 length 8
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001d offset 0 length 2
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001f offset 0 length 22
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001f offset 22 length 22
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x001f offset 44 length 18
[bt] [DBG] bt_gatt_attr_read: (0x20004724) handle 0x0024 offset 0 length 4
[bt] [WRN] bt_gatt_attr_write_ccc: No space to store CCC cfg
[bt] [WRN] bt_gatt_attr_write_ccc: No space to store CCC cfg

Vudentz commented 5 years ago

@Qbicz Try printing what is the cfg_len, perhaps there is some bug in BT_GATT_CCC macro that don't evaluate the actual array size for some reason.

Qbicz commented 5 years ago

Hi, I did some additional investigation and this problem is not caused by GATT code. This is caused by custom service that we use. Closing this as it is not a Zephyr issue. Thanks for help!

BeckmaR commented 3 years ago

@Qbicz I have a similar issue, but no idea where it comes from. Do you happen to remember how you solved this issue?

Qbicz commented 3 years ago

Hi @BeckmaR at that time I was working on Gaming Mouse - you can find the code here: https://github.com/nrfconnect/sdk-nrf/blob/master/applications/nrf_desktop/src/modules

I think the problem was that the underlying HID Service implementation by Nordic had a bug which disallowed saving more CCCs. But it was fixed shortly after we found the bug. The service is here: https://github.com/nrfconnect/sdk-nrf/blob/master/subsys/bluetooth/services/hids.c

joerchan commented 3 years ago

@Qbicz I have a similar issue, but no idea where it comes from. Do you happen to remember how you solved this issue?

@BeckmaR Any chance you are using bt_gatt_service_unregister? A similar issue was fixed here: https://github.com/zephyrproject-rtos/zephyr/pull/27206

zephyrproject-rtos / zephyr

Bluetooth: settings: No space to store CCC config after successful pairing #10460