feat(ble_mesh): Miscellaneous log enhancement for Provisioning

This commit is contained in:
luoxu
2025-11-13 17:12:14 +08:00
parent b73eb03d88
commit e1d539d1ff
3 changed files with 89 additions and 27 deletions
+25 -9
View File
@@ -48,6 +48,7 @@ void bt_mesh_prov_buf_init(struct net_buf_simple *buf, uint8_t type)
bt_mesh_output_action_t bt_mesh_prov_output_action(uint8_t action) bt_mesh_output_action_t bt_mesh_prov_output_action(uint8_t action)
{ {
BT_DBG("ProvOutputAction:%d", action);
switch (action) { switch (action) {
case OUTPUT_OOB_BLINK: case OUTPUT_OOB_BLINK:
return BLE_MESH_BLINK; return BLE_MESH_BLINK;
@@ -66,6 +67,7 @@ bt_mesh_output_action_t bt_mesh_prov_output_action(uint8_t action)
bt_mesh_input_action_t bt_mesh_prov_input_action(uint8_t action) bt_mesh_input_action_t bt_mesh_prov_input_action(uint8_t action)
{ {
BT_DBG("ProvInputAction:%d", action);
switch (action) { switch (action) {
case INPUT_OOB_PUSH: case INPUT_OOB_PUSH:
return BLE_MESH_PUSH; return BLE_MESH_PUSH;
@@ -151,20 +153,27 @@ static uint8_t bt_mesh_prov_buf_type_get(struct net_buf_simple *buf)
uint8_t node_next_xact_id(struct bt_mesh_prov_link *link) uint8_t node_next_xact_id(struct bt_mesh_prov_link *link)
{ {
uint8_t nxt_xact_id = 0;
if (link->tx.id != 0 && link->tx.id != 0xFF) { if (link->tx.id != 0 && link->tx.id != 0xFF) {
return ++link->tx.id; nxt_xact_id = ++link->tx.id;
} else {
link->tx.id = 0x80;
nxt_xact_id = 0x80;
} }
link->tx.id = 0x80; BT_DBG("NodeNextXActId:%d", nxt_xact_id);
return link->tx.id; return nxt_xact_id;
} }
uint8_t pvnr_next_xact_id(struct bt_mesh_prov_link *link) uint8_t pvnr_next_xact_id(struct bt_mesh_prov_link *link)
{ {
uint8_t nxt_xact_id = 0;
if (link->tx.id > 0x7F) { if (link->tx.id > 0x7F) {
link->tx.id = 0; link->tx.id = 0;
} }
return link->tx.id++; nxt_xact_id = link->tx.id++;
BT_DBG("PvnrNextXActId:%d", nxt_xact_id);
return nxt_xact_id;
} }
bool bt_mesh_gen_prov_start(struct bt_mesh_prov_link *link, bool bt_mesh_gen_prov_start(struct bt_mesh_prov_link *link,
@@ -186,7 +195,7 @@ bool bt_mesh_gen_prov_start(struct bt_mesh_prov_link *link,
link->rx.id = rx->xact_id; link->rx.id = rx->xact_id;
link->rx.fcs = net_buf_simple_pull_u8(buf); link->rx.fcs = net_buf_simple_pull_u8(buf);
BT_DBG("len %u last_seg %u total_len %u fcs 0x%02x", buf->len, BT_DBG("LinkId:%08x,len %u last_seg %u total_len %u fcs 0x%02x", link->link_id, buf->len,
START_LAST_SEG(rx->gpc), link->rx.buf->len, link->rx.fcs); START_LAST_SEG(rx->gpc), link->rx.buf->len, link->rx.fcs);
/* At least one-octet pdu type is needed */ /* At least one-octet pdu type is needed */
@@ -227,9 +236,10 @@ bool bt_mesh_gen_prov_start(struct bt_mesh_prov_link *link,
link->rx.last_seg = START_LAST_SEG(rx->gpc); link->rx.last_seg = START_LAST_SEG(rx->gpc);
memcpy(link->rx.buf->data, buf->data, buf->len); memcpy(link->rx.buf->data, buf->data, buf->len);
XACT_SEG_RECV(link, 0); XACT_SEG_RECV(link, 0);
BT_DBG("Seg: %04x, lastSeg: %04x, Data: %s", link->rx.seg, link->rx.last_seg, bt_hex(buf->data, buf->len));
/* Still have some segments to receive */ /* Still have some segments to receive */
if (link->rx.seg) { if (link->rx.seg) {
BT_DBG("Still have some segments to receive: %02x", link->rx.seg);
return false; return false;
} }
@@ -242,7 +252,7 @@ bool bt_mesh_gen_prov_cont(struct bt_mesh_prov_link *link,
{ {
uint8_t seg = CONT_SEG_INDEX(rx->gpc); uint8_t seg = CONT_SEG_INDEX(rx->gpc);
BT_DBG("len %u, seg_index %u", buf->len, seg); BT_DBG("LinkId:%08x,len %u,seg_index %u", link->link_id, buf->len, seg);
if (link->rx.seg == 0 && link->rx.prev_id == rx->xact_id) { if (link->rx.seg == 0 && link->rx.prev_id == rx->xact_id) {
BT_INFO("Resending ack"); BT_INFO("Resending ack");
@@ -287,6 +297,7 @@ bool bt_mesh_gen_prov_cont(struct bt_mesh_prov_link *link,
/* Still have some segments to receive */ /* Still have some segments to receive */
if (link->rx.seg) { if (link->rx.seg) {
BT_DBG("Still have some segments to receive: %02x", link->rx.seg);
return false; return false;
} }
@@ -346,12 +357,14 @@ void bt_mesh_gen_prov_ack_send(struct bt_mesh_prov_link *link, uint8_t xact_id)
net_buf_add_u8(buf, xact_id); net_buf_add_u8(buf, xact_id);
net_buf_add_u8(buf, GPC_ACK); net_buf_add_u8(buf, GPC_ACK);
BT_DBG("GenericProvAckSend,LinkId:%08x,XActId:%02x", link->link_id, xact_id);
bt_mesh_adv_send(buf, PROV_XMIT, complete, link); bt_mesh_adv_send(buf, PROV_XMIT, complete, link);
net_buf_unref(buf); net_buf_unref(buf);
} }
static void free_segments(struct bt_mesh_prov_link *link) static void free_segments(struct bt_mesh_prov_link *link)
{ {
BT_DBG("FreeSegments:%08x", link->link_id);
for (size_t i = 0; i < ARRAY_SIZE(link->tx.buf); i++) { for (size_t i = 0; i < ARRAY_SIZE(link->tx.buf); i++) {
struct net_buf *buf = link->tx.buf[i]; struct net_buf *buf = link->tx.buf[i];
@@ -386,6 +399,7 @@ static void buf_sent(int err, void *user_data)
int32_t timeout = RETRANSMIT_TIMEOUT; int32_t timeout = RETRANSMIT_TIMEOUT;
if (!link->tx.buf[0]) { if (!link->tx.buf[0]) {
BT_DBG("LinkId:%08x,NoTxBuf", link->link_id);
return; return;
} }
@@ -412,6 +426,8 @@ static void prov_retransmit(struct k_work *work)
struct bt_mesh_prov_link *link = work->user_data; struct bt_mesh_prov_link *link = work->user_data;
int64_t timeout = TRANSACTION_TIMEOUT; int64_t timeout = TRANSACTION_TIMEOUT;
BT_DBG("LinkRetransmit:%08x,flag:%s", link->link_id, bt_hex(link->flags, sizeof(link->flags)));
if (!bt_mesh_atomic_test_bit(link->flags, LINK_ACTIVE) && if (!bt_mesh_atomic_test_bit(link->flags, LINK_ACTIVE) &&
!bt_mesh_atomic_test_bit(link->flags, LINK_CLOSING)) { !bt_mesh_atomic_test_bit(link->flags, LINK_CLOSING)) {
BT_WARN("Link not active"); BT_WARN("Link not active");
@@ -493,7 +509,7 @@ static void prov_retransmit(struct k_work *work)
BT_DBG("%u bytes: %s", buf->len, bt_hex(buf->data, buf->len)); BT_DBG("%u bytes: %s", buf->len, bt_hex(buf->data, buf->len));
if (i + 1 < ARRAY_SIZE(link->tx.buf) && link->tx.buf[i + 1]) { if (likely(i + 1 < ARRAY_SIZE(link->tx.buf) && link->tx.buf[i + 1])) {
bt_mesh_adv_send(buf, PROV_XMIT, NULL, NULL); bt_mesh_adv_send(buf, PROV_XMIT, NULL, NULL);
} else { } else {
bt_mesh_adv_send(buf, PROV_XMIT, &buf_sent_cb, link); bt_mesh_adv_send(buf, PROV_XMIT, &buf_sent_cb, link);
@@ -521,7 +537,7 @@ static void send_reliable(struct bt_mesh_prov_link *link, uint8_t xmit)
break; break;
} }
if (i + 1 < ARRAY_SIZE(link->tx.buf) && link->tx.buf[i + 1]) { if (likely(i + 1 < ARRAY_SIZE(link->tx.buf) && link->tx.buf[i + 1])) {
bt_mesh_adv_send(buf, xmit, NULL, NULL); bt_mesh_adv_send(buf, xmit, NULL, NULL);
} else { } else {
bt_mesh_adv_send(buf, xmit, &buf_sent_cb, link); bt_mesh_adv_send(buf, xmit, &buf_sent_cb, link);
+25 -9
View File
@@ -2,7 +2,7 @@
/* /*
* SPDX-FileCopyrightText: 2017 Intel Corporation * SPDX-FileCopyrightText: 2017 Intel Corporation
* SPDX-FileContributor: 2018-2024 Espressif Systems (Shanghai) CO LTD * SPDX-FileContributor: 2018-2025 Espressif Systems (Shanghai) CO LTD
* *
* SPDX-License-Identifier: Apache-2.0 * SPDX-License-Identifier: Apache-2.0
*/ */
@@ -52,6 +52,7 @@ struct bt_mesh_prov_link *bt_mesh_prov_node_get_link(void)
static void close_link(uint8_t reason) static void close_link(uint8_t reason)
{ {
BT_DBG("LinkClose(Rpr:%d),Reason:%d", bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE), reason);
if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) { if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) {
if (prov_link.pb_remote_close) { if (prov_link.pb_remote_close) {
prov_link.pb_remote_close(&prov_link, reason); prov_link.pb_remote_close(&prov_link, reason);
@@ -69,6 +70,7 @@ void bt_mesh_prov_node_close_link(uint8_t reason)
static void reset_state(void) static void reset_state(void)
{ {
BT_INFO("ProvLinkStateReset");
k_delayed_work_cancel(&prov_link.prot_timer); k_delayed_work_cancel(&prov_link.prot_timer);
/* Disable Attention Timer if it was set */ /* Disable Attention Timer if it was set */
@@ -122,6 +124,7 @@ static void reset_adv_link(struct bt_mesh_prov_link *link, uint8_t reason)
{ {
ARG_UNUSED(link); ARG_UNUSED(link);
BT_INFO("ResetAdvLink:%08x", link->link_id);
bt_mesh_prov_clear_tx(&prov_link, true); bt_mesh_prov_clear_tx(&prov_link, true);
if (bt_mesh_prov_get()->link_close) { if (bt_mesh_prov_get()->link_close) {
@@ -267,6 +270,7 @@ static int prov_auth(uint8_t method, uint8_t action, uint8_t size)
auth_size = PROV_AUTH_SIZE(&prov_link); auth_size = PROV_AUTH_SIZE(&prov_link);
BT_INFO("ProvAuth:method:%d,action:%d,size:%d", method, action, size);
switch (method) { switch (method) {
case AUTH_METHOD_NO_OOB: case AUTH_METHOD_NO_OOB:
if (action || size) { if (action || size) {
@@ -411,6 +415,7 @@ static void prov_start(const uint8_t *data)
if ((bt_mesh_prov_get()->oob_type & BIT(PROV_ONLY_OOB_AUTH_SUPPORT)) && if ((bt_mesh_prov_get()->oob_type & BIT(PROV_ONLY_OOB_AUTH_SUPPORT)) &&
((data[0] == PROV_ALG_P256_HMAC_SHA256 && data[2] == AUTH_METHOD_NO_OOB) || ((data[0] == PROV_ALG_P256_HMAC_SHA256 && data[2] == AUTH_METHOD_NO_OOB) ||
data[0] == PROV_ALG_P256_CMAC_AES128)) { data[0] == PROV_ALG_P256_CMAC_AES128)) {
BT_WARN("InvalidCapabilities,Alg:%d,Method:%d", data[0], data[2]);
close_link(PROV_ERR_NVAL_FMT); close_link(PROV_ERR_NVAL_FMT);
return; return;
} }
@@ -561,9 +566,10 @@ int bt_mesh_input_number(uint32_t num)
auth_size = PROV_AUTH_SIZE(&prov_link); auth_size = PROV_AUTH_SIZE(&prov_link);
BT_INFO("%u", num); BT_INFO("ProvInputNumber:%u", num);
if (!bt_mesh_atomic_test_and_clear_bit(prov_link.flags, WAIT_NUMBER)) { if (!bt_mesh_atomic_test_and_clear_bit(prov_link.flags, WAIT_NUMBER)) {
BT_WARN("InvalidFlag:WAIT_NUMBER");
return -EINVAL; return -EINVAL;
} }
@@ -572,6 +578,7 @@ int bt_mesh_input_number(uint32_t num)
send_input_complete(); send_input_complete();
if (!bt_mesh_atomic_test_bit(prov_link.flags, HAVE_DHKEY)) { if (!bt_mesh_atomic_test_bit(prov_link.flags, HAVE_DHKEY)) {
BT_INFO("DHKeyExists");
return 0; return 0;
} }
@@ -587,6 +594,7 @@ int bt_mesh_input_string(const char *str)
BT_INFO("%s", str); BT_INFO("%s", str);
if (!bt_mesh_atomic_test_and_clear_bit(prov_link.flags, WAIT_STRING)) { if (!bt_mesh_atomic_test_and_clear_bit(prov_link.flags, WAIT_STRING)) {
BT_WARN("InvalidFlag:WAIT_STRING");
return -EINVAL; return -EINVAL;
} }
@@ -595,6 +603,7 @@ int bt_mesh_input_string(const char *str)
send_input_complete(); send_input_complete();
if (!bt_mesh_atomic_test_bit(prov_link.flags, HAVE_DHKEY)) { if (!bt_mesh_atomic_test_bit(prov_link.flags, HAVE_DHKEY)) {
BT_INFO("DHKeyExists");
return 0; return 0;
} }
@@ -712,6 +721,7 @@ int bt_mesh_set_oob_pub_key(const uint8_t pub_key_x[32],
/* If remote public key is not got, just return */ /* If remote public key is not got, just return */
if (!bt_mesh_atomic_test_bit(prov_link.flags, REMOTE_PUB_KEY)) { if (!bt_mesh_atomic_test_bit(prov_link.flags, REMOTE_PUB_KEY)) {
BT_WARN("RemotePubKeyNotSet");
return 0; return 0;
} }
@@ -902,6 +912,7 @@ static void prov_data(const uint8_t *data)
uint8_t reason = 0; uint8_t reason = 0;
if (bt_mesh_rpr_srv_nppi_check(prov_link.pb_remote_nppi, pdu, net_idx, if (bt_mesh_rpr_srv_nppi_check(prov_link.pb_remote_nppi, pdu, net_idx,
iv_index, addr, &reason) == false) { iv_index, addr, &reason) == false) {
BT_WARN("RprNppiCheckFail:%d", reason);
close_link(reason); close_link(reason);
return; return;
} }
@@ -924,6 +935,7 @@ static void prov_data(const uint8_t *data)
pdu, net_idx, flags, pdu, net_idx, flags,
iv_index, addr, dev_key); iv_index, addr, dev_key);
if (err) { if (err) {
BT_WARN("RprNppiStoreFail:%d", err);
close_link(PROV_ERR_UNEXP_ERR); close_link(PROV_ERR_UNEXP_ERR);
return; return;
} }
@@ -964,6 +976,7 @@ static void prov_data(const uint8_t *data)
* using Node Identity. * using Node Identity.
*/ */
if (IS_ENABLED(CONFIG_BLE_MESH_GATT_PROXY_SERVER) && identity_enable) { if (IS_ENABLED(CONFIG_BLE_MESH_GATT_PROXY_SERVER) && identity_enable) {
BT_DBG("EnableProxyIdentity");
bt_mesh_proxy_identity_enable(); bt_mesh_proxy_identity_enable();
} }
} }
@@ -973,7 +986,7 @@ static void prov_complete(const uint8_t *data)
static void prov_failed(const uint8_t *data) static void prov_failed(const uint8_t *data)
{ {
BT_WARN("Error: 0x%02x", data[0]); BT_WARN("ProvError: 0x%02x", data[0]);
#if CONFIG_BLE_MESH_RPR_SRV #if CONFIG_BLE_MESH_RPR_SRV
if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) { if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) {
@@ -1011,7 +1024,7 @@ static const struct {
#if CONFIG_BLE_MESH_PB_ADV #if CONFIG_BLE_MESH_PB_ADV
static void link_open(struct prov_rx *rx, struct net_buf_simple *buf) static void link_open(struct prov_rx *rx, struct net_buf_simple *buf)
{ {
BT_DBG("len %u", buf->len); BT_DBG("LinkOpenLen:%u", buf->len);
if (buf->len < 16) { if (buf->len < 16) {
BT_ERR("Too short bearer open message (len %u)", buf->len); BT_ERR("Too short bearer open message (len %u)", buf->len);
@@ -1065,7 +1078,7 @@ static void link_open(struct prov_rx *rx, struct net_buf_simple *buf)
static void link_ack(struct prov_rx *rx, struct net_buf_simple *buf) static void link_ack(struct prov_rx *rx, struct net_buf_simple *buf)
{ {
BT_DBG("len %u", buf->len); BT_DBG("LinkAckLen:%u",buf->len);
#if CONFIG_BLE_MESH_RPR_SRV #if CONFIG_BLE_MESH_RPR_SRV
if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) { if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) {
@@ -1094,7 +1107,7 @@ static void link_close(struct prov_rx *rx, struct net_buf_simple *buf)
{ {
uint8_t reason = 0; uint8_t reason = 0;
BT_DBG("len %u", buf->len); BT_DBG("LinkCloseLen %u", buf->len);
if (buf->len != 1) { if (buf->len != 1) {
BT_ERR("Invalid Link Close length %d", buf->len); BT_ERR("Invalid Link Close length %d", buf->len);
@@ -1258,12 +1271,14 @@ static void gen_prov_ack(struct prov_rx *rx, struct net_buf_simple *buf)
BT_DBG("len %u", buf->len); BT_DBG("len %u", buf->len);
if (!prov_link.tx.buf[0]) { if (!prov_link.tx.buf[0]) {
BT_DBG("AlreadyReceived");
return; return;
} }
#if CONFIG_BLE_MESH_RPR_SRV #if CONFIG_BLE_MESH_RPR_SRV
if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) { if (bt_mesh_atomic_test_bit(prov_link.flags, PB_REMOTE)) {
if (prov_link.tx.id == 0) { if (prov_link.tx.id == 0) {
BT_DBG("ZeroTxId");
return; return;
} }
@@ -1278,6 +1293,7 @@ static void gen_prov_ack(struct prov_rx *rx, struct net_buf_simple *buf)
#endif /* CONFIG_BLE_MESH_RPR_SRV */ #endif /* CONFIG_BLE_MESH_RPR_SRV */
if (rx->xact_id == prov_link.tx.id) { if (rx->xact_id == prov_link.tx.id) {
BT_DBG("XActId:%04x,ReceivedAck", rx->xact_id);
bt_mesh_prov_clear_tx(&prov_link, true); bt_mesh_prov_clear_tx(&prov_link, true);
} }
} }
@@ -1342,7 +1358,7 @@ void bt_mesh_pb_adv_recv(struct net_buf_simple *buf)
rx.xact_id = net_buf_simple_pull_u8(buf); rx.xact_id = net_buf_simple_pull_u8(buf);
rx.gpc = net_buf_simple_pull_u8(buf); rx.gpc = net_buf_simple_pull_u8(buf);
BT_DBG("link_id 0x%08x xact_id %u", rx.link_id, rx.xact_id); BT_DBG("link_id 0x%08x xact_id %u gpc %u", rx.link_id, rx.xact_id, rx.gpc);
if (bt_mesh_atomic_test_bit(prov_link.flags, LINK_ACTIVE) && if (bt_mesh_atomic_test_bit(prov_link.flags, LINK_ACTIVE) &&
prov_link.link_id != rx.link_id) { prov_link.link_id != rx.link_id) {
@@ -1441,7 +1457,7 @@ int bt_mesh_pb_gatt_recv(struct bt_mesh_conn *conn, struct net_buf_simple *buf)
int bt_mesh_pb_gatt_open(struct bt_mesh_conn *conn) int bt_mesh_pb_gatt_open(struct bt_mesh_conn *conn)
{ {
BT_DBG("conn %p", conn); BT_DBG("ProvConnOpen %p", conn);
/** /**
* It's necessary to determine if it is PB_REMOTE because when the * It's necessary to determine if it is PB_REMOTE because when the
@@ -1482,7 +1498,7 @@ int bt_mesh_pb_gatt_open(struct bt_mesh_conn *conn)
int bt_mesh_pb_gatt_close(struct bt_mesh_conn *conn, uint8_t reason) int bt_mesh_pb_gatt_close(struct bt_mesh_conn *conn, uint8_t reason)
{ {
BT_DBG("conn %p", conn); BT_DBG("ProvConnClose %p", conn);
if (prov_link.conn != conn) { if (prov_link.conn != conn) {
BT_ERR("Not connected"); BT_ERR("Not connected");
+39 -9
View File
@@ -1,5 +1,5 @@
/* /*
* SPDX-FileCopyrightText: 2017-2024 Espressif Systems (Shanghai) CO LTD * SPDX-FileCopyrightText: 2017-2025 Espressif Systems (Shanghai) CO LTD
* *
* SPDX-License-Identifier: Apache-2.0 * SPDX-License-Identifier: Apache-2.0
*/ */
@@ -202,6 +202,7 @@ static inline void bt_mesh_pb_gatt_unlock(void)
void bt_mesh_provisioner_pbg_count_dec(void) void bt_mesh_provisioner_pbg_count_dec(void)
{ {
BT_DBG("PbgCntDec:%d", prov_ctx.pbg_count);
if (prov_ctx.pbg_count) { if (prov_ctx.pbg_count) {
prov_ctx.pbg_count--; prov_ctx.pbg_count--;
} }
@@ -210,6 +211,7 @@ void bt_mesh_provisioner_pbg_count_dec(void)
static inline void provisioner_pbg_count_inc(void) static inline void provisioner_pbg_count_inc(void)
{ {
prov_ctx.pbg_count++; prov_ctx.pbg_count++;
BT_DBG("PbgCntInc:%d", prov_ctx.pbg_count);
} }
void bt_mesh_provisioner_clear_link_info(const uint8_t addr[6]) void bt_mesh_provisioner_clear_link_info(const uint8_t addr[6])
@@ -436,8 +438,8 @@ static int provisioner_start_prov_pb_gatt(const uint8_t uuid[16], const bt_mesh_
*/ */
if (assign_addr == BLE_MESH_ADDR_UNASSIGNED && if (assign_addr == BLE_MESH_ADDR_UNASSIGNED &&
prov_ctx.alloc_addr == BLE_MESH_ADDR_UNASSIGNED) { prov_ctx.alloc_addr == BLE_MESH_ADDR_UNASSIGNED) {
BT_ERR("No available unicast address to assign");
bt_mesh_pb_gatt_unlock(); bt_mesh_pb_gatt_unlock();
BT_ERR("No available unicast address to assign");
return -EIO; return -EIO;
} }
@@ -451,6 +453,7 @@ static int provisioner_start_prov_pb_gatt(const uint8_t uuid[16], const bt_mesh_
!bt_mesh_atomic_test_bit(prov_links[i].flags, LINK_ACTIVE)) { !bt_mesh_atomic_test_bit(prov_links[i].flags, LINK_ACTIVE)) {
if (bt_mesh_gattc_conn_create(addr, BLE_MESH_UUID_MESH_PROV_VAL)) { if (bt_mesh_gattc_conn_create(addr, BLE_MESH_UUID_MESH_PROV_VAL)) {
bt_mesh_pb_gatt_unlock(); bt_mesh_pb_gatt_unlock();
BT_ERR("ProvGattCreateFailed:%s", bt_hex(addr->val, 6));
return -EIO; return -EIO;
} }
@@ -598,6 +601,7 @@ int bt_mesh_provisioner_add_unprov_dev(struct bt_mesh_unprov_dev_add *add_dev, u
start: start:
/* If not provisioning immediately, directly return here */ /* If not provisioning immediately, directly return here */
if (!(flags & START_PROV_NOW)) { if (!(flags & START_PROV_NOW)) {
BT_DBG("StartProvNotSet");
return 0; return 0;
} }
@@ -617,6 +621,9 @@ start:
} }
if ((err = provisioner_check_unprov_dev_info(add_dev->uuid, add_dev->bearer))) { if ((err = provisioner_check_unprov_dev_info(add_dev->uuid, add_dev->bearer))) {
if (err == -EALREADY) {
BT_INFO("The device is being provisioning");
}
return err; return err;
} }
@@ -710,6 +717,9 @@ int bt_mesh_provisioner_prov_device_with_addr(const uint8_t uuid[16], const uint
} }
if ((err = provisioner_check_unprov_dev_info(uuid, bearer))) { if ((err = provisioner_check_unprov_dev_info(uuid, bearer))) {
if (err == -EALREADY) {
BT_INFO("The device is being provisioning");
}
return err; return err;
} }
@@ -749,10 +759,12 @@ int bt_mesh_provisioner_delete_device(struct bt_mesh_device_delete *del_dev)
return -EINVAL; return -EINVAL;
} }
BT_INFO("ProvisionerDeleteDevice:%s", bt_hex(del_dev->uuid, 16));
/* Find if the device is in the device queue */ /* Find if the device is in the device queue */
for (i = 0; i < ARRAY_SIZE(unprov_dev); i++) { for (i = 0; i < ARRAY_SIZE(unprov_dev); i++) {
if (!memcmp(unprov_dev[i].uuid, del_dev->uuid, 16)) { if (!memcmp(unprov_dev[i].uuid, del_dev->uuid, 16)) {
memset(&unprov_dev[i], 0, sizeof(struct unprov_dev_queue)); memset(&unprov_dev[i], 0, sizeof(struct unprov_dev_queue));
BT_INFO("Device is in the queue");
break; break;
} }
} }
@@ -761,6 +773,7 @@ int bt_mesh_provisioner_delete_device(struct bt_mesh_device_delete *del_dev)
for (i = 0; i < ARRAY_SIZE(prov_links); i++) { for (i = 0; i < ARRAY_SIZE(prov_links); i++) {
if (!memcmp(prov_links[i].uuid, del_dev->uuid, 16)) { if (!memcmp(prov_links[i].uuid, del_dev->uuid, 16)) {
close_link(&prov_links[i], CLOSE_REASON_FAILED); close_link(&prov_links[i], CLOSE_REASON_FAILED);
BT_INFO("Device is being provisioned");
break; break;
} }
} }
@@ -776,6 +789,7 @@ int bt_mesh_provisioner_set_dev_uuid_match(uint8_t offset, uint8_t length,
return -EINVAL; return -EINVAL;
} }
BT_INFO("SetUUIDMatch,offset:%d,value:%s,flag:%d", offset, bt_hex(match, length), prov_flag);
(void)memset(prov_ctx.match_value, 0, 16); (void)memset(prov_ctx.match_value, 0, 16);
prov_ctx.match_offset = offset; prov_ctx.match_offset = offset;
@@ -795,6 +809,7 @@ int bt_mesh_provisioner_adv_pkt_cb_register(unprov_adv_pkt_cb_t cb)
return -EINVAL; return -EINVAL;
} }
BT_INFO("RegisterAdvCB:%p", notify_unprov_adv_pkt_cb);
notify_unprov_adv_pkt_cb = cb; notify_unprov_adv_pkt_cb = cb;
return 0; return 0;
} }
@@ -815,6 +830,7 @@ int bt_mesh_provisioner_set_prov_data_info(struct bt_mesh_prov_data_info *info)
} }
prov_ctx.net_idx = info->net_idx; prov_ctx.net_idx = info->net_idx;
BT_INFO("SetProvCtx,NetIndex:%d", info->net_idx);
} }
return 0; return 0;
@@ -881,6 +897,7 @@ void bt_mesh_provisioner_set_prov_bearer(bt_mesh_prov_bearer_t bearers, bool cle
} else { } else {
prov_ctx.bearers &= ~bearers; prov_ctx.bearers &= ~bearers;
} }
BT_INFO("ProvCtxBearer:%04x,clear:%d", prov_ctx.bearers, clear);
} }
bt_mesh_prov_bearer_t bt_mesh_provisioner_get_prov_bearer(void) bt_mesh_prov_bearer_t bt_mesh_provisioner_get_prov_bearer(void)
@@ -909,7 +926,7 @@ int bt_mesh_provisioner_set_static_oob_value(const uint8_t *value, uint8_t lengt
prov_ctx.static_oob_len = MIN(BLE_MESH_PROV_STATIC_OOB_MAX_LEN, length); prov_ctx.static_oob_len = MIN(BLE_MESH_PROV_STATIC_OOB_MAX_LEN, length);
memcpy(prov_ctx.static_oob_val, value, prov_ctx.static_oob_len); memcpy(prov_ctx.static_oob_val, value, prov_ctx.static_oob_len);
BT_INFO("SetStaticOob:%s", bt_hex(value, prov_ctx.static_oob_len));
return 0; return 0;
} }
@@ -984,11 +1001,13 @@ int bt_mesh_test_provisioner_update_alloc_addr(uint16_t unicast_addr, uint16_t e
void bt_mesh_provisioner_fast_prov_enable(bool enable) void bt_mesh_provisioner_fast_prov_enable(bool enable)
{ {
prov_ctx.fast_prov.enable = enable; prov_ctx.fast_prov.enable = enable;
BT_INFO("FastProvEnable:%d", enable);
} }
void bt_mesh_provisioner_set_fast_prov_net_idx(uint16_t net_idx) void bt_mesh_provisioner_set_fast_prov_net_idx(uint16_t net_idx)
{ {
prov_ctx.fast_prov.net_idx = net_idx; prov_ctx.fast_prov.net_idx = net_idx;
BT_INFO("FastProvNetIdx:%d", net_idx);
} }
uint16_t bt_mesh_provisioner_get_fast_prov_net_idx(void) uint16_t bt_mesh_provisioner_get_fast_prov_net_idx(void)
@@ -1017,7 +1036,7 @@ uint8_t bt_mesh_set_fast_prov_unicast_addr_range(uint16_t min, uint16_t max)
prov_ctx.fast_prov.unicast_addr_max = max; prov_ctx.fast_prov.unicast_addr_max = max;
prov_ctx.alloc_addr = prov_ctx.fast_prov.unicast_addr_min; prov_ctx.alloc_addr = prov_ctx.fast_prov.unicast_addr_min;
BT_INFO("FastProv,AddrMin:%04x,Max:%04x,allocAddr:%04x", min, max, prov_ctx.alloc_addr);
return 0x0; /* status: success */ return 0x0; /* status: success */
} }
@@ -1038,6 +1057,7 @@ static struct net_buf_simple *get_rx_buf(const uint8_t idx)
static void reset_adv_link(struct bt_mesh_prov_link *link, uint8_t reason) static void reset_adv_link(struct bt_mesh_prov_link *link, uint8_t reason)
{ {
BT_INFO("ResetAdvLink:%08x", link->link_id);
bt_mesh_prov_clear_tx(link, true); bt_mesh_prov_clear_tx(link, true);
if (bt_mesh_prov_get()->prov_link_close) { if (bt_mesh_prov_get()->prov_link_close) {
@@ -1106,6 +1126,7 @@ static void send_link_open(struct bt_mesh_prov_link *link)
if (bt_mesh_atomic_test_bit(prov_links[i].flags, LINK_ACTIVE) && if (bt_mesh_atomic_test_bit(prov_links[i].flags, LINK_ACTIVE) &&
prov_links[i].link_id == link->link_id) { prov_links[i].link_id == link->link_id) {
bt_mesh_rand(&link->link_id, sizeof(link->link_id)); bt_mesh_rand(&link->link_id, sizeof(link->link_id));
BT_DBG("ProvLinkIdx:%d,LinkId:%08x", i, link->link_id);
break; break;
} }
} }
@@ -1280,6 +1301,7 @@ static void prov_capabilities(struct bt_mesh_prov_link *link,
if ((algorithms & BIT(PROV_ALG_P256_CMAC_AES128)) || if ((algorithms & BIT(PROV_ALG_P256_CMAC_AES128)) ||
(!((oob_type & BIT(PROV_STATIC_OOB_AVAILABLE)) == 0x00 || (!((oob_type & BIT(PROV_STATIC_OOB_AVAILABLE)) == 0x00 ||
output_size == 0x00 || input_size == 0x00))) { output_size == 0x00 || input_size == 0x00))) {
BT_INFO("InvalidOobTypeSet:%02x,Alg:%02x", oob_type, algorithms);
goto fail; goto fail;
} }
} }
@@ -1358,6 +1380,7 @@ static void prov_capabilities(struct bt_mesh_prov_link *link,
* send Remote Provisioning PDU Send with Public Key. * send Remote Provisioning PDU Send with Public Key.
*/ */
if (bt_mesh_atomic_test_bit(link->flags, PB_REMOTE)) { if (bt_mesh_atomic_test_bit(link->flags, PB_REMOTE)) {
BT_DBG("WaitForRprClientCmd");
return; return;
} }
@@ -1387,6 +1410,7 @@ static int prov_auth(struct bt_mesh_prov_link *link,
bt_mesh_input_action_t input = 0U; bt_mesh_input_action_t input = 0U;
uint8_t auth_size = PROV_AUTH_SIZE(link); uint8_t auth_size = PROV_AUTH_SIZE(link);
BT_INFO("ProvAuth:method:%d,action:%d,size:%d", method, action, size);
switch (method) { switch (method) {
case AUTH_METHOD_NO_OOB: case AUTH_METHOD_NO_OOB:
if (action || size) { if (action || size) {
@@ -1778,6 +1802,7 @@ static void prov_gen_dh_key(struct bt_mesh_prov_link *link)
*/ */
if (link->auth_method == AUTH_METHOD_OUTPUT || if (link->auth_method == AUTH_METHOD_OUTPUT ||
link->auth_method == AUTH_METHOD_INPUT) { link->auth_method == AUTH_METHOD_INPUT) {
BT_INFO("WaitForNextAction:%d", link->auth_method);
return; return;
} }
@@ -1814,6 +1839,7 @@ static void prov_gen_dh_key(struct bt_mesh_prov_link *link)
* Input Complete, because if the authentication method is * Input Complete, because if the authentication method is
* Output OOB or Input OOB, it will directly return above. * Output OOB or Input OOB, it will directly return above.
*/ */
BT_DBG("LinkExpect:%d", link->expect);
if (link->expect != PROV_INPUT_COMPLETE) { if (link->expect != PROV_INPUT_COMPLETE) {
send_confirm(link); send_confirm(link);
} }
@@ -2094,6 +2120,7 @@ static void send_prov_data(struct bt_mesh_prov_link *link)
link->unicast_addr = alloc_addr; link->unicast_addr = alloc_addr;
} }
BT_DBG("ProvAllocAddr:%04x", link->unicast_addr);
bt_mesh_prov_buf_init(&buf, PROV_DATA); bt_mesh_prov_buf_init(&buf, PROV_DATA);
err = bt_mesh_prov_encrypt(session_key, nonce, pdu, net_buf_simple_add(&buf, 33)); err = bt_mesh_prov_encrypt(session_key, nonce, pdu, net_buf_simple_add(&buf, 33));
@@ -2310,7 +2337,7 @@ static void prov_complete(struct bt_mesh_prov_link *link,
static void prov_failed(struct bt_mesh_prov_link *link, static void prov_failed(struct bt_mesh_prov_link *link,
struct net_buf_simple *buf) struct net_buf_simple *buf)
{ {
BT_WARN("Error 0x%02x", buf->data[0]); BT_WARN("ProvError 0x%02x", buf->data[0]);
close_link(link, CLOSE_REASON_FAILED); close_link(link, CLOSE_REASON_FAILED);
} }
@@ -2360,7 +2387,7 @@ static void close_link(struct bt_mesh_prov_link *link, uint8_t reason)
#if CONFIG_BLE_MESH_PB_ADV #if CONFIG_BLE_MESH_PB_ADV
static void link_ack(struct bt_mesh_prov_link *link, struct prov_rx *rx, struct net_buf_simple *buf) static void link_ack(struct bt_mesh_prov_link *link, struct prov_rx *rx, struct net_buf_simple *buf)
{ {
BT_DBG("len %u", buf->len); BT_DBG("LinkAckLen %u", buf->len);
if (buf->len) { if (buf->len) {
BT_ERR("Invalid Link ACK length %d", buf->len); BT_ERR("Invalid Link ACK length %d", buf->len);
@@ -2388,7 +2415,7 @@ static void link_ack(struct bt_mesh_prov_link *link, struct prov_rx *rx, struct
static void link_close(struct bt_mesh_prov_link *link, struct prov_rx *rx, struct net_buf_simple *buf) static void link_close(struct bt_mesh_prov_link *link, struct prov_rx *rx, struct net_buf_simple *buf)
{ {
BT_DBG("len %u", buf->len); BT_DBG("LinkCloseLen %u", buf->len);
if (buf->len != 1) { if (buf->len != 1) {
BT_ERR("Invalid Link Close length %d", buf->len); BT_ERR("Invalid Link Close length %d", buf->len);
@@ -2511,10 +2538,12 @@ static void gen_prov_ack(struct bt_mesh_prov_link *link,
BT_DBG("len %u", buf->len); BT_DBG("len %u", buf->len);
if (!link->tx.buf[0]) { if (!link->tx.buf[0]) {
BT_DBG("NullTxbuf");
return; return;
} }
if (!link->tx.id) { if (!link->tx.id) {
BT_DBG("ZeroTxId");
return; return;
} }
@@ -2620,7 +2649,7 @@ void bt_mesh_provisioner_pb_adv_recv(struct net_buf_simple *buf)
rx.xact_id = net_buf_simple_pull_u8(buf); rx.xact_id = net_buf_simple_pull_u8(buf);
rx.gpc = net_buf_simple_pull_u8(buf); rx.gpc = net_buf_simple_pull_u8(buf);
BT_DBG("link_id 0x%08x xact_id %u", rx.link_id, rx.xact_id); BT_DBG("link_id 0x%08x xact_id %u gpc %u", rx.link_id, rx.xact_id, rx.gpc);
link = find_pba_link(rx.link_id); link = find_pba_link(rx.link_id);
if (link == NULL) { if (link == NULL) {
@@ -2783,7 +2812,7 @@ static void protocol_timeout(struct k_work *work)
{ {
struct bt_mesh_prov_link *link = work->user_data; struct bt_mesh_prov_link *link = work->user_data;
BT_WARN("Protocol timeout"); BT_WARN("Protocol timeout,LinkId:%08x", link->link_id);
close_link(link, CLOSE_REASON_TIMEOUT); close_link(link, CLOSE_REASON_TIMEOUT);
} }
@@ -3112,6 +3141,7 @@ int bt_mesh_rpr_cli_pdu_recv(struct bt_mesh_prov_link *link, uint8_t type,
return -EINVAL; return -EINVAL;
} }
BT_INFO("RprCliProvType:%d", type);
prov_handlers[type].func(link, buf); prov_handlers[type].func(link, buf);
return 0; return 0;
} }