Error adding app-key to device on mesh provisioner

Question

Heelo, i'm trying to use a nordic nrf5340 as a provisioner for the remaining network however i'm getting an error on sending the app-key to the un-provisioned node (I'm using the mesh provisioner example as a guide). 
 Both the devices exchange the correct information until the app-key add step. 
 Provisioner log: (The status code is different everytime) 
 Bluetooth initialized
Mesh initialized
Loading stored settings
Provision Complete
Provision Complete
Using stored CDB
Using stored settings
UART initialized
New device: 2ef3540c530a4faf80eb000000000002
Provisioning device
Method: No Auth
Node added
Check unconfigured
Configuring node 0x0002...
Status: 206
Err -11
Failed to add app-key (err -11 status 206)

I've narrow it down to the return on this function from "cfg_cli.c": 
 int bt_mesh_cfg_app_key_add(uint16_t net_idx, uint16_t addr, uint16_t key_net_idx,
 uint16_t key_app_idx, const uint8_t app_key[16],
 uint8_t *status)
{
	BT_MESH_MODEL_BUF_DEFINE(msg, OP_APP_KEY_ADD, 19);
	struct bt_mesh_msg_ctx ctx = {
 .net_idx = net_idx,
 .app_idx = BT_MESH_KEY_DEV_REMOTE,
 .addr = addr,
 .send_ttl = BT_MESH_TTL_DEFAULT,
	};
	struct app_key_param param = {
 .status = status,
 .net_idx = key_net_idx,
 .app_idx = key_app_idx,
	};
	int err;

	err = cli_prepare(&param, OP_APP_KEY_STATUS, addr);
	if (err) {
 return err;
	}

	bt_mesh_model_msg_init(&msg, OP_APP_KEY_ADD);
	key_idx_pack(&msg, key_net_idx, key_app_idx);
	net_buf_simple_add_mem(&msg, app_key, 16);

	err = bt_mesh_model_send(cli->model, &ctx, &msg, NULL, NULL);
	if (err) {
 BT_ERR("model_send() failed (err %d)", err);
 bt_mesh_msg_ack_ctx_clear(&cli->ack_ctx);
 return err;
	}

	if (!status) {
 bt_mesh_msg_ack_ctx_clear(&cli->ack_ctx);
 return 0;
	}

	return bt_mesh_msg_ack_ctx_wait(&cli->ack_ctx, K_MSEC(msg_timeout));
} 
 The error happens because the timeout of the ack message, i've ben trying to narrow it down even further but no success, does anyone know what it could be?

EDIT (PLEASE TAKE INTO CONSIDERATION) 
 From what i understand the problem is in the await acknowledged message in the cfg_cli.c script like this 
 
 In the line 40 of the function above presented 
 return bt_mesh_msg_ack_ctx_wait(&cli->ack_ctx, K_MSEC(msg_timeout)); 
 The script does the correct thing and blocks the device for "msg_timeout" ms and afterwards it checks if the semaphore "&ack->sem" (Saying the message got replied) however this is where the problem exists. It get's timedout and clears the ack field from the config client before receiving the message itself like this 
 Configuring node 0x0003...

**The expected response is saved into config client fields**
Prepared Response
OpCode: 0x8003
addr : 0x0003

Sending message

**The await function times out**
Failed to add app-key (err -11 status 0)

**Received a message with the expected OpCode**
OpCode 0x8003 received

**The config client field was cleared due to time out**
Prepared response
OpCode: 0x0000
addr : 0x0000


**Message is always rejected by match**
Response received
-------------------
OpCode : 0x0000 -- 0x8003
isUnicast : true
addr : 0 -- 3
-------------------

Message not the expected

DavidAbreu99 · Accepted Answer

The problem is fixed, for anyone this happens here's my conclusion and my fix for it.

In the "mesh_provisioner" example there is a function named "configure_node" called after the provisioner assigns a unicast address to the node and saves the node in the cdb. This function performs the configuration requests and sets on the new device such as send the app-key, Get and decode the new device composition and bind the app-key to every model on the device.

The problem lies in the back-end algorithm, this function calls the "cfg_cli.c" script like this:

"Send the app-key" - calls "bt_mesh_cfg_app_key_add" in the cfg_cli script

The problem exists because of the semaphore on what i understand the code, the function returns a k_sem_take that blocks the code. The code only continues to run after the timeout ends and in that way the ack_ctx is cleared and we get a "no match" error every time.

Fix:

To fix this issue i used a thread, instead of having the configure_node called by the interruptions on the process i created a variable and an array (Because i receive the device to provision by uart, i decided to create a queue in case the provision takes long than the command is received):

uint16_t node_queue[100];
int queue_counter = 0;

Next i created an infinite loop in the function to run in threading (And a condition because i have a queue):

static void configure_node()
{
    while (1)
    {
        if (queue_counter > 0)
        {
            struct bt_mesh_cdb_node *node = bt_mesh_cdb_node_get(node_queue[0]);
            ;
            NET_BUF_SIMPLE_DEFINE(buf, BT_MESH_RX_SDU_MAX);
            struct bt_mesh_comp_p0_elem elem;
            struct bt_mesh_cdb_app_key *key;
            struct bt_mesh_comp_p0 comp;
            uint8_t status;
            int err, elem_addr;

            printk("Configuring node 0x%04x...\n", node->addr);

            key = bt_mesh_cdb_app_key_get(app_idx);
            if (key == NULL)
            {
                printk("No app-key 0x%04x\n", app_idx);
                return;
            }

            /* Add Application Key */
            err = bt_mesh_cfg_app_key_add(net_idx, node->addr, net_idx, app_idx,
                key->keys[0].app_key, &status);
            if (err || status)
            {
                printk("Failed to add app-key (err %d status %d)\n", err, status);
                return;
            }

            /* Get the node's composition data */
            err = bt_mesh_cfg_comp_data_get(net_idx, node->addr, 0, &status, &buf);
            if (err || status)
            {
                printk("Failed to get Composition data (err %d, status: %d)\n",
                    err, status);
                return;
            }

            err = bt_mesh_comp_p0_get(&comp, &buf);
            if (err)
            {
                printk("Unable to parse composition data (err: %d)\n", err);
                return;
            }

            /* Bind all models to the appkey */

            elem_addr = node->addr;
            while (bt_mesh_comp_p0_elem_pull(&comp, &elem))
            {
                printk("Element @ 0x%04x: %u + %u models\n", elem_addr,
                    elem.nsig, elem.nvnd);
                for (int i = 0; i < elem.nsig; i++)
                {
                    uint16_t id = bt_mesh_comp_p0_elem_mod(&elem, i);

                    if (id == BT_MESH_MODEL_ID_CFG_CLI ||
                        id == BT_MESH_MODEL_ID_CFG_SRV)
                    {
                        continue;
                    }
                    printk("Binding AppKey to model 0x%03x:%04x\n",
                        elem_addr, id);

                    err = bt_mesh_cfg_mod_app_bind(net_idx, node->addr,
                        elem_addr, app_idx, id,
                        &status);
                    if (err || status)
                    {
                        printk("Failed (err: %d, status: %d)\n", err,
                            status);
                    }
                }

                for (int i = 0; i < elem.nvnd; i++)
                {
                    struct bt_mesh_mod_id_vnd id =
                        bt_mesh_comp_p0_elem_mod_vnd(&elem, i);

                    printk("Binding AppKey to model 0x%03x:%04x:%04x\n",
                        elem_addr, id.company, id.id);

                    err = bt_mesh_cfg_mod_app_bind_vnd(net_idx, node->addr,
                        elem_addr, app_idx,
                        id.id, id.company,
                        &status);
                    if (err || status)
                    {
                        printk("Failed (err: %d, status: %d)\n", err,
                            status);
                    }
                }

                elem_addr++;
            }

            atomic_set_bit(node->flags, BT_MESH_CDB_NODE_CONFIGURED);

            if (IS_ENABLED(CONFIG_BT_SETTINGS))
            {
                bt_mesh_cdb_node_store(node);
            }

            printk("Configuration complete\n");

            for (int i = 0; i < queue_counter - 1; i++)
            {
                node_queue[i] = node_queue[i + 1];
            }

            
            queue_counter--;
        }

        k_msleep(2000);
    }
}

I assign that function to a thread with a 2048 memory allocation because 1024 was giving me memory error:

K_THREAD_DEFINE(config_thread_id, 2048,
                configure_node, NULL, NULL, NULL,
                7, 0, 0);

I don't know if it's the better way to do things but it was the way i found it to work correctly.

My best regards to all,

David Abreu.