bt_gatt: Unable to import the key for AES CMAC -141

[jwitowski]

I am using a dynamic BAS service. I have noticed that after a few bt_gatt_service_unregister() and bt_gatt_service_register() calls, the following error occurs:
bt_gatt: Unable to import the key for AES CMAC -141.

It appears that the problem is caused by bt_gatt_service_register() calling psa_import_key() without freeing the allocated memory during bt_gatt_service_unregister()

I have added some logs to psa_crypto.c:

*** Booting My Application v2.0.99-b2bc05116228 ***
*** Using nRF Connect SDK v3.0.2-89ba1294ac9b ***
*** Using Zephyr OS v4.0.99-f791c49f492c ***
<inf> main_app: Application started
<inf> bt_sdc_hci_driver: SoftDevice Controller build revision:
                                            89 9a 50 8a 95 01 9c 58  fc 39 d2 c1 10 04 ee 02 |..P....X .9......
                                            64 ce 25 be                                      |d.%.
<inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
<inf> bt_hci_core: HW Variant: nRF52x (0x0002)
<inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 137.20634 Build 2617349514
<inf> bt_hci_core: No ID address. App must call settings_load()
<inf> bt_hci_core: Identity: E2:09:BC:9E:13:5E (random)
<inf> bt_hci_core: HCI: version 6.0 (0x0e) revision 0x10f3, manufacturer 0x0059
<inf> bt_hci_core: LMP: version 6.0 (0x0e) subver 0x10f3

<err> psa_crypto_srvc: === IMPORT KEY ===
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=0 peak=0
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=16 peak=16

<err> bas: SVC REGISTER
<err> psa_crypto_srvc: === REMOVE KEY DATA ===
<err> psa_crypto_srvc: === IMPORT KEY ===
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=16 peak=48

<err> bas: SVC UNREGISTER
<err> bas: SVC REGISTER
<err> psa_crypto_srvc: === IMPORT KEY ===
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=32 peak=48

<err> bas: SVC UNREGISTER
<err> bas: SVC REGISTER
<err> psa_crypto_srvc: === IMPORT KEY ===
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=48 peak=48

<err> bas: SVC UNREGISTER
<err> bas: SVC REGISTER
<err> psa_crypto_srvc: === IMPORT KEY ===
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=64 peak=64

...

<err> bas: SVC UNREGISTER
<err> bas: SVC REGISTER
<err> psa_crypto_srvc: === IMPORT KEY ===
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=144 peak=144

<err> psa_crypto_srvc: ==== IMPORT KEY ====
<err> psa_crypto_srvc: === PSA KEYS: tracked_cur=160 peak=160
<err> psa_crypto_srvc: === mbedtls_calloc failed ===
<err> psa_crypto_srvc: === PSA allocate buffer failed ===
<err> psa_crypto_srvc: === REMOVE KEY DATA ===
<err> bt_gatt: Unable to import the key for AES CMAC -141

Code snippet:

static void register_bas(void)
{
	for (size_t i = 0; i < ARRAY_SIZE(batteries); i++) {
		struct battery *battery = &batteries[i];

		if (!battery->registered) {
			LOG_ERR("SVC REGISTER");
			const int ret = bt_gatt_service_register(battery->svc);
			if (ret) {
				LOG_ERR("Can't register bas: %d", ret);
				continue;
			}
		}

		battery->registered = true;
	}
}

static void unregister_bas(void)
{
	for (size_t i = 0; i < ARRAY_SIZE(batteries); i++) {
		if (batteries[i].registered) {
			LOG_ERR("SVC UNREGISTER");
			const int ret = bt_gatt_service_unregister(batteries[i].svc);
			if (ret) {
				LOG_ERR("Can't unregister bas: %d", ret);
			} else {
				batteries[i].registered = false;
			}
		}
	}
}

[jwitowski]

psa_crypto.c modifications:

diff --git a/library/psa_crypto.c b/library/psa_crypto.c
index 301eed0..d9421c1 100644
--- a/library/psa_crypto.c
+++ b/library/psa_crypto.c
@@ -37,6 +37,8 @@
 #include "mbedtls/constant_time.h"
 #include "mbedtls/cipher.h"  // mbedtls_operation_t

+#include <zephyr/logging/log.h>
+LOG_MODULE_REGISTER(psa_crypto_srvc);

 #if defined(PSA_CRYPTO_DRIVER_TFM_BUILTIN_KEY_LOADER)
 #include "tfm_builtin_key_loader.h"
@@ -283,9 +285,37 @@ MBEDTLS_STATIC_TESTABLE psa_status_t psa_mac_key_can_do(
     return PSA_ERROR_INVALID_ARGUMENT;
 }

+// ...existing code...
+static atomic_t g_psa_key_bytes_current;
+static atomic_t g_psa_key_bytes_peak;
+
+static void psa_debug_acc_add(size_t sz)
+{
+    atomic_add(&g_psa_key_bytes_current, sz);
+    size_t cur = atomic_get(&g_psa_key_bytes_current);
+    size_t peak = atomic_get(&g_psa_key_bytes_peak);
+    if (cur > peak) {
+        atomic_set(&g_psa_key_bytes_peak, cur);
+    }
+}
+
+static void psa_debug_acc_sub(size_t sz)
+{
+    atomic_sub(&g_psa_key_bytes_current, sz);
+}
+
+void psa_crypto_debug_dump(void)
+{
+    size_t cur = atomic_get(&g_psa_key_bytes_current);
+    size_t peak = atomic_get(&g_psa_key_bytes_peak);
+    LOG_ERR("=== PSA KEYS: tracked_cur=%zu peak=%zu", cur, peak);
+}
+// ...existing code...
+
 psa_status_t psa_allocate_buffer_to_slot(psa_key_slot_t *slot,
                                          size_t buffer_length)
 {
+    psa_crypto_debug_dump();
 #if defined(MBEDTLS_PSA_STATIC_KEY_SLOTS)
     if (buffer_length > ((size_t) MBEDTLS_PSA_STATIC_KEY_SLOT_BUFFER_SIZE)) {
         return PSA_ERROR_NOT_SUPPORTED;
@@ -297,8 +327,10 @@ psa_status_t psa_allocate_buffer_to_slot(psa_key_slot_t *slot,

     slot->key.data = mbedtls_calloc(1, buffer_length);
     if (slot->key.data == NULL) {
+        LOG_ERR("=== mbedtls_calloc failed ===");
         return PSA_ERROR_INSUFFICIENT_MEMORY;
     }
+    psa_debug_acc_add(buffer_length);
 #endif

     slot->key.bytes = buffer_length;
@@ -729,12 +761,14 @@ static psa_status_t psa_get_and_lock_transparent_key_slot_with_policy(

 psa_status_t psa_remove_key_data_from_memory(psa_key_slot_t *slot)
 {
+    LOG_ERR("=== REMOVE KEY DATA ===");
 #if defined(MBEDTLS_PSA_STATIC_KEY_SLOTS)
     if (slot->key.bytes > 0) {
         mbedtls_platform_zeroize(slot->key.data, MBEDTLS_PSA_STATIC_KEY_SLOT_BUFFER_SIZE);
     }
 #else
     if (slot->key.data != NULL) {
+        psa_debug_acc_sub(slot->key.bytes);
         mbedtls_zeroize_and_free(slot->key.data, slot->key.bytes);
     }

@@ -1541,6 +1575,7 @@ psa_status_t psa_import_key(const psa_key_attributes_t *attributes,
                             size_t data_length,
                             mbedtls_svc_key_id_t *key)
 {
+    LOG_ERR("==== IMPORT KEY ====");
     psa_status_t status;
     psa_key_slot_t *slot = NULL;
     psa_se_drv_table_entry_t *driver = NULL;
@@ -1598,6 +1633,7 @@ psa_status_t psa_import_key(const psa_key_attributes_t *attributes,
         }
         status = psa_allocate_buffer_to_slot(slot, storage_size);
         if (status != PSA_SUCCESS) {
+            LOG_ERR("=== PSA allocate buffer failed ===");
             goto exit;
         }
     }