BLE Mesh light control example won't go to "NRF_MESH_EVT_PROV_COMPLETE"

[Mitch996]

Hello, when trying to finish provisioning my nodes (3 total, per example program's instructions), my provisioner program keeps running into

NRF_MESH_EVT_PROV_LINK_CLOSED

and this is the rough flowchart:

Note the dash arrow connection line means I don't know what happened in between, but I can only guess some sort of time out took place...

What could be the problem??

Also, after reaching NRF_MESH_EVT_PROV_LINK_CLOSED, this is the part of program it went next:

__LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "Provisioning failed. Retrying...\n");
        m_prov_state = PROV_STATE_WAIT;

How should I proceede next to make it goes to

NRF_MESH_EVT_PROV_COMPLETE

？？

Follow up:

I've found the more detailed program flow but nevertheless don't have the knowledge sufficient enough to decode WHY it behaves the way it does, so this is how it goes:

main() -> nrf_mesh_process() -> transport_sar_process() -> status = trs_sar_rx_process()

then, right in the middle of executing

trs_sar_rx_process()

, most likely when executing

           (void)trs_sar_drop_session(p_sar_ctx, NRF_MESH_SAR_CANCEL_REASON_NO_MEM);

, QDEC_IRQHandler

kicks in, and things go down hill from there, this is what happens:

EVENT_IRQHandler(void) -> handle_events() -> m_flag_event_callbacksi -> fire_timers(time_now )

-> p_evt->cb(time_now, p_evt->p_context) -> adv_evt_timeout(timestamp_t timestamp, void * p_context)

-> p_advertiser->queue_empty_cb(p_advertiser) (AKA close_link(prov_bearer_adv_t * p_pb_adv, nrf_mesh_prov_link_close_reason_t reason), the reason is always 0x02 error.)

-> prov_cb_link_closed(prov_bearer_t * p_bearer, nrf_mesh_prov_link_close_reason_t close_reason) (AKA prov_provisioner_cb_link_closed(prov_bearer_t * p_bearer, nrf_mesh_prov_link_close_reason_t reason))

in which an event with the type "NRF_MESH_EVT_PROV_LINK_CLOSED" will be pushed into the event queue and the program will keep running till it reaches:

mesh_evt_handler 's

case NRF_MESH_EVT_PROV_LINK_CLOSED

, and go to :

             m_prov_state = PROV_STATE_WAIT;

Now... the obvious question: what do I do now? I'm positive my provisionee/server boards/nodes are responding, because the program won't go to above mentioned places at all if none of the nodes were turned on.

@thomasstenersen

@bjorn-spockeli

@joh2

Help...?

Edit #2:

So I plugged in the provisionee/server board, and found out that it keeps sending prov failure in the RTT window, and sure enough, I found the culprit, but before I list it here, a call stack tree first:

So why send_failed was called? Apparently it meets this standard:

if(!prov_utils_confirmation_check(p_ctx))

in

prov_provisionee_pkt_in function.

Now, naturally I looked into the "prov_utils_confirmation_check(p_ctx)" fucntion and did a little modification (nothing major, don't worry) to make my life easier, things went wrong at this line:

ble_mesh_v0.9.1-Alpha\mesh\src\prov\prov_utils.c:

line 341:

int result = memcmp(confirmation, p_ctx->peer_confirmation, sizeof(confirmation)) == 0;
	return result;

the result is 0, indicating that everything is alright.

But when it returns, since there is an "!" mark involved in the if, 0 gets turned into a 1.

I'm kind of confused: it isn't supposed to be 0? The size compared should be different? Why?

My project

[Mitch996]

and now, for the provisionee/server logs:

 0> SEGGER J-Link V6.12a - Real time terminal output
 0> SEGGER J-Link CE V8.0, SN=*********
 0> Process: UV4.exe
 0> <t:          0>, main.c,  245, ----- BLE Mesh Provisionee + Remote Provisioning Server Demo -----
 0> <t:          0>, main.c,  114, Initializing softdevice...
 0> <t:          0>, nrf_mesh_sdk.c,  118, Initializing SoftDevice...
 0> <t:          0>, nrf_mesh_sdk.c,  128, Ram base: 0x20006000
 0> <t:         11>, nrf_mesh_sdk.c,  133, sd_ble_enable: app_ram_base should be adjusted to 0x200019C0
 0> <t:         16>, main.c,  122, Initializing mesh stack...
 0> <t:        281>, main.c,  134, Enabling mesh stack...
 0> <t:        288>, main.c,  143, Initializing provisionee context...
 0> <t:      14596>, main.c,  250, Starting listening for incoming provisioning links...
 0> <t:     143996>, main.c,  162, Provisioning link established!
 0> <t:     168057>, main.c,  221, Static authentication data provided!
 0> <t:     170881>, main.c,  235, Unexpected event: 13.
 0> <t:     172680>, main.c,  171, Provisioning link closed!
 0> <t:     188634>, main.c,  162, Provisioning link established!
 0> <t:     212673>, main.c,  221, Static authentication data provided!
 0> <t:     216007>, main.c,  235, Unexpected event: 13.
 0> <t:     218267>, main.c,  171, Provisioning link closed!
 0> <t:     280776>, main.c,  162, Provisioning link established!
 0> <t:     305510>, main.c,  221, Static authentication data provided!
 0> <t:     308403>, main.c,  235, Unexpected event: 13.
 0> <t:     311044>, main.c,  171, Provisioning link closed!
 0> <t:     333946>, main.c,  162, Provisioning link established!
 0> <t:     359869>, main.c,  221, Static authentication data provided!
 0> <t:     363057>, main.c,  235, Unexpected event: 13.
 0> <t:     365325>, main.c,  171, Provisioning link closed!
 0> <t:     428779>, main.c,  162, Provisioning link established!
 0> <t:     452161>, main.c,  221, Static authentication data provided!
 0> <t:     454649>, main.c,  235, Unexpected event: 13.
 0> <t:     456705>, main.c,  171, Provisioning link closed!
 0> <t:     506581>, main.c,  162, Provisioning link established!
 0> <t:     529949>, main.c,  221, Static authentication data provided!
 0> <t:     533323>, main.c,  235, Unexpected event: 13.
 0> <t:     535416>, main.c,  171, Provisioning link closed!
 0> <t:     609835>, main.c,  162, Provisioning link established!
 0> <t:     633448>, main.c,  221, Static authentication data provided!
 0> <t:     636288>, main.c,  235, Unexpected event: 13.
 0> <t:     638623>, main.c,  171, Provisioning link closed!
 0> <t:     713886>, main.c,  162, Provisioning link established!
 0> <t:     738453>, main.c,  221, Static authentication data provided!
 0> <t:     741949>, main.c,  235, Unexpected event: 13.
 0> <t:     744463>, main.c,  171, Provisioning link closed!
 0> <t:     772893>, main.c,  162, Provisioning link established!
 0> <t:     796519>, main.c,  221, Static authentication data provided!
 0> <t:     799669>, main.c,  235, Unexpected event: 13.
 0> <t:     801471>, main.c,  171, Provisioning link closed!
 0> <t:     857955>, main.c,  162, Provisioning link established!
 0> <t:     881371>, main.c,  221, Static authentication data provided!
 0> <t:     884597>, main.c,  235, Unexpected event: 13.
 0> <t:     886733>, main.c,  171, Provisioning link closed!