This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

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

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:

image description

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:

image description

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

Parents
  • This is the first run, stopped at a breakpoint I set, right after the link was closed:

     0> SEGGER J-Link V6.12a - Real time terminal output
     0> J-Link OB-SAM3U128-V2-NordicSemi compiled Nov 14 2016 16:58:29 V1.0, SN=******
     0> Process: UV4.exe
     0> s layer and models
     0> <t:      14912>, main.c,  226, Button 2 pressed
     0> <t:      14915>, main.c,  229, Not in RUNNING state
     0> <t:      41870>, provisioner.c,  227, Local provisioning link established
     0> <t:      43808>, provisioner.c,  212, Using static authentication
     0> <t:     133807>, provisioner.c,  221, Static authentication data provided
     0> <t:     268684>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     271920>, provisioner.c,  182, Local provisioning link closed
     0> <t:     271924>, provisioner.c,  185, Provisioning failed. Retrying...
    

    This is the 2nd run on the provisioner, I let it run for as long as it's meaningful and I set no breakpoint whatsoever:

     0> s layer and models
     0> <t:      14906>, main.c,  226, Button 2 pressed
     0> <t:      14909>, main.c,  229, Not in RUNNING state
     0> <t:     106434>, provisioner.c,  227, Local provisioning link established
     0> <t:     173731>, provisioner.c,  212, Using static authentication
     0> <t:     331101>, provisioner.c,  221, Static authentication data provided
     0> <t:     467035>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     470620>, provisioner.c,  182, Local provisioning link closed
     0> <t:     470624>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:     487711>, provisioner.c,  227, Local provisioning link established
     0> <t:     489781>, provisioner.c,  212, Using static authentication
     0> <t:     642797>, provisioner.c,  221, Static authentication data provided
     0> <t:     779372>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     782818>, provisioner.c,  182, Local provisioning link closed
     0> <t:     782821>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:     806230>, provisioner.c,  227, Local provisioning link established
     0> <t:     808280>, provisioner.c,  212, Using static authentication
     0> <t:     829558>, provisioner.c,  221, Static authentication data provided
     0> <t:     899170>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     902787>, provisioner.c,  182, Local provisioning link closed
     0> <t:     902791>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:     932006>, provisioner.c,  227, Local provisioning link established
     0> <t:     933824>, provisioner.c,  212, Using static authentication
     0> <t:     956056>, provisioner.c,  221, Static authentication data provided
     0> <t:    1358099>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    1361948>, provisioner.c,  182, Local provisioning link closed
     0> <t:    1361951>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    1461773>, provisioner.c,  227, Local provisioning link established
     0> <t:    1463235>, provisioner.c,  212, Using static authentication
     0> <t:    1685457>, provisioner.c,  221, Static authentication data provided
     0> <t:    1688713>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    1692887>, provisioner.c,  182, Local provisioning link closed
     0> <t:    1692890>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    1771467>, provisioner.c,  227, Local provisioning link established
     0> <t:    1773304>, provisioner.c,  212, Using static authentication
     0> <t:    1861263>, provisioner.c,  221, Static authentication data provided
     0> <t:    1930761>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    1934291>, provisioner.c,  182, Local provisioning link closed
     0> <t:    1934294>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    1956877>, provisioner.c,  227, Local provisioning link established
     0> <t:    2025293>, provisioner.c,  212, Using static authentication
     0> <t:    2115336>, provisioner.c,  221, Static authentication data provided
     0> <t:    2119466>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2123187>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2123191>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2173550>, provisioner.c,  227, Local provisioning link established
     0> <t:    2175380>, provisioner.c,  212, Using static authentication
     0> <t:    2263470>, provisioner.c,  221, Static authentication data provided
     0> <t:    2267080>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2270511>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2270514>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2321070>, provisioner.c,  227, Local provisioning link established
     0> <t:    2323053>, provisioner.c,  212, Using static authentication
     0> <t:    2481790>, provisioner.c,  221, Static authentication data provided
     0> <t:    2551704>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2555112>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2555116>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2580018>, provisioner.c,  227, Local provisioning link established
     0> <t:    2581703>, provisioner.c,  212, Using static authentication
     0> <t:    2602395>, provisioner.c,  221, Static authentication data provided
     0> <t:    2672133>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2675517>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2675521>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2726462>, provisioner.c,  227, Local provisioning link established
     0> <t:    2728430>, provisioner.c,  212, Using static authentication
     0> <t:    2817485>, provisioner.c,  221, Static authentication data provided
     0> <t:    2887476>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2891303>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2891306>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2920871>, provisioner.c,  227, Local provisioning link established
     0> <t:    2922668>, provisioner.c,  212, Using static authentication
     0> <t:    3080014>, provisioner.c,  221, Static authentication data provided
     0> <t:    3084274>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3087973>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3087976>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3145509>, provisioner.c,  227, Local provisioning link established
     0> <t:    3213220>, provisioner.c,  212, Using static authentication
     0> <t:    3234371>, provisioner.c,  221, Static authentication data provided
     0> <t:    3370493>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3373816>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3373820>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3433072>, provisioner.c,  227, Local provisioning link established
     0> <t:    3434923>, provisioner.c,  212, Using static authentication
     0> <t:    3523344>, provisioner.c,  221, Static authentication data provided
     0> <t:    3593215>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3596942>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3596946>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3666584>, provisioner.c,  227, Local provisioning link established
     0> <t:    3668377>, provisioner.c,  212, Using static authentication
     0> <t:    3689317>, provisioner.c,  221, Static authentication data provided
     0> <t:    3692892>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3696696>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3696700>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3739814>, provisioner.c,  227, Local provisioning link established
     0> <t:    3741826>, provisioner.c,  212, Using static authentication
     0> <t:    3831463>, provisioner.c,  221, Static authentication data provided
     0> <t:    3835622>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3838916>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3838920>, provisioner.c,  185, Provisioning failed. Retrying...
    
Reply
  • This is the first run, stopped at a breakpoint I set, right after the link was closed:

     0> SEGGER J-Link V6.12a - Real time terminal output
     0> J-Link OB-SAM3U128-V2-NordicSemi compiled Nov 14 2016 16:58:29 V1.0, SN=******
     0> Process: UV4.exe
     0> s layer and models
     0> <t:      14912>, main.c,  226, Button 2 pressed
     0> <t:      14915>, main.c,  229, Not in RUNNING state
     0> <t:      41870>, provisioner.c,  227, Local provisioning link established
     0> <t:      43808>, provisioner.c,  212, Using static authentication
     0> <t:     133807>, provisioner.c,  221, Static authentication data provided
     0> <t:     268684>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     271920>, provisioner.c,  182, Local provisioning link closed
     0> <t:     271924>, provisioner.c,  185, Provisioning failed. Retrying...
    

    This is the 2nd run on the provisioner, I let it run for as long as it's meaningful and I set no breakpoint whatsoever:

     0> s layer and models
     0> <t:      14906>, main.c,  226, Button 2 pressed
     0> <t:      14909>, main.c,  229, Not in RUNNING state
     0> <t:     106434>, provisioner.c,  227, Local provisioning link established
     0> <t:     173731>, provisioner.c,  212, Using static authentication
     0> <t:     331101>, provisioner.c,  221, Static authentication data provided
     0> <t:     467035>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     470620>, provisioner.c,  182, Local provisioning link closed
     0> <t:     470624>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:     487711>, provisioner.c,  227, Local provisioning link established
     0> <t:     489781>, provisioner.c,  212, Using static authentication
     0> <t:     642797>, provisioner.c,  221, Static authentication data provided
     0> <t:     779372>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     782818>, provisioner.c,  182, Local provisioning link closed
     0> <t:     782821>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:     806230>, provisioner.c,  227, Local provisioning link established
     0> <t:     808280>, provisioner.c,  212, Using static authentication
     0> <t:     829558>, provisioner.c,  221, Static authentication data provided
     0> <t:     899170>, provisioner.c,  235, Unexpected event: 13.
     0> <t:     902787>, provisioner.c,  182, Local provisioning link closed
     0> <t:     902791>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:     932006>, provisioner.c,  227, Local provisioning link established
     0> <t:     933824>, provisioner.c,  212, Using static authentication
     0> <t:     956056>, provisioner.c,  221, Static authentication data provided
     0> <t:    1358099>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    1361948>, provisioner.c,  182, Local provisioning link closed
     0> <t:    1361951>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    1461773>, provisioner.c,  227, Local provisioning link established
     0> <t:    1463235>, provisioner.c,  212, Using static authentication
     0> <t:    1685457>, provisioner.c,  221, Static authentication data provided
     0> <t:    1688713>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    1692887>, provisioner.c,  182, Local provisioning link closed
     0> <t:    1692890>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    1771467>, provisioner.c,  227, Local provisioning link established
     0> <t:    1773304>, provisioner.c,  212, Using static authentication
     0> <t:    1861263>, provisioner.c,  221, Static authentication data provided
     0> <t:    1930761>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    1934291>, provisioner.c,  182, Local provisioning link closed
     0> <t:    1934294>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    1956877>, provisioner.c,  227, Local provisioning link established
     0> <t:    2025293>, provisioner.c,  212, Using static authentication
     0> <t:    2115336>, provisioner.c,  221, Static authentication data provided
     0> <t:    2119466>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2123187>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2123191>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2173550>, provisioner.c,  227, Local provisioning link established
     0> <t:    2175380>, provisioner.c,  212, Using static authentication
     0> <t:    2263470>, provisioner.c,  221, Static authentication data provided
     0> <t:    2267080>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2270511>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2270514>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2321070>, provisioner.c,  227, Local provisioning link established
     0> <t:    2323053>, provisioner.c,  212, Using static authentication
     0> <t:    2481790>, provisioner.c,  221, Static authentication data provided
     0> <t:    2551704>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2555112>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2555116>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2580018>, provisioner.c,  227, Local provisioning link established
     0> <t:    2581703>, provisioner.c,  212, Using static authentication
     0> <t:    2602395>, provisioner.c,  221, Static authentication data provided
     0> <t:    2672133>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2675517>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2675521>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2726462>, provisioner.c,  227, Local provisioning link established
     0> <t:    2728430>, provisioner.c,  212, Using static authentication
     0> <t:    2817485>, provisioner.c,  221, Static authentication data provided
     0> <t:    2887476>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    2891303>, provisioner.c,  182, Local provisioning link closed
     0> <t:    2891306>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    2920871>, provisioner.c,  227, Local provisioning link established
     0> <t:    2922668>, provisioner.c,  212, Using static authentication
     0> <t:    3080014>, provisioner.c,  221, Static authentication data provided
     0> <t:    3084274>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3087973>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3087976>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3145509>, provisioner.c,  227, Local provisioning link established
     0> <t:    3213220>, provisioner.c,  212, Using static authentication
     0> <t:    3234371>, provisioner.c,  221, Static authentication data provided
     0> <t:    3370493>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3373816>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3373820>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3433072>, provisioner.c,  227, Local provisioning link established
     0> <t:    3434923>, provisioner.c,  212, Using static authentication
     0> <t:    3523344>, provisioner.c,  221, Static authentication data provided
     0> <t:    3593215>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3596942>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3596946>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3666584>, provisioner.c,  227, Local provisioning link established
     0> <t:    3668377>, provisioner.c,  212, Using static authentication
     0> <t:    3689317>, provisioner.c,  221, Static authentication data provided
     0> <t:    3692892>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3696696>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3696700>, provisioner.c,  185, Provisioning failed. Retrying...
     0> <t:    3739814>, provisioner.c,  227, Local provisioning link established
     0> <t:    3741826>, provisioner.c,  212, Using static authentication
     0> <t:    3831463>, provisioner.c,  221, Static authentication data provided
     0> <t:    3835622>, provisioner.c,  235, Unexpected event: 13.
     0> <t:    3838916>, provisioner.c,  182, Local provisioning link closed
     0> <t:    3838920>, provisioner.c,  185, Provisioning failed. Retrying...
    
Children
No Data
Related