SCAN_REQ and SCAN_RSP logging

[Felipe1]

Hello, I have a question about the scan request event.

I checked the logs of BLE_GAP_EVT_SCAN_REQ_REPORT.  If this event is received, does Softdevice recognize the packet as SCAN_REQ properly and surely send back SCAN_RSP?  If there are any problems in receiving a SCAN_REQ packet (e.g. CRC error), can I see any logs/messages?  Or if there are any problems in sending a SCAN_RSP packet, can I see any logs/messages as well?

I am looking for any tools/methods to make sure the scan response procedure works in the software level.

[Environment]

nRF52832 custom board

nRF5 SDK 17.1.0

Softdevice S132 v7.0.1, 7.2.0, 7.3.0

Sample source code : ble_peripheral\ble_app_blinky

 

[Modification]

I added the following lines in main.c and built a debug module.  The log messages are seen.

// In advertising_init

    adv_params.scan_req_notification  = 1;

 // In ble_evt_handler

         case BLE_GAP_EVT_SCAN_REQ_REPORT:

            NRF_LOG_INFO("SCAN_REQ");

            break;

[ShibuyaT]

Hi Vidar

Thank you for reply.

I am colleague of Toru. I asked him to contact you.

I took two images about this phenomenon.

There are snapshots of power consumption wave form.

X axis is time(ms) and Y axis power consumption(mA)

AS you can see, OK file shows Advertise->SCAN_REQ->SCAN_RSEP.

On the other hand, NG file show Advertise->SCAN_REQ.

Our nRF52832 does not respond SCAN_RSEP.

 

Advertise interval is 40ms.

The phenomenon is happened about once or twice per 1second.

 

First I used softdevice version 7.0.1.

Then we found s132_nrf52_7.3.0 improve missing scan request reception.

So we update softdevice from 7.0.1 to 7.3.0.

However the result is the same.

Do you have any suggestion?

For example I might miss some improvement information/errata, 

or I can get debug? how to debug?

If you can indicate me to put some debug coed and help you to analyze, please let me know.

[Vidar Berg]

Hi,

Based on the DRGN-15484 description, I would only expect reception to potentially improve in v7.3.0 if you are advertising with a timeout. I still believe the most likely explanation to the missed response is that the scan request failed to be received by the nRF. To confirm this, you could try to monitor the RADIO crc match event (EVENTS_CRCOK) as done in the snippet below.

#define MONITOR_RADIO_CRC_MATCH 1

#if MONITOR_RADIO_CRC_MATCH

void SWI3_IRQHandler(void)
{
    /* Clear event register */
    NRF_EGU3->EVENTS_TRIGGERED[0] = 0;
    NRF_LOG_INFO("Packet received with CRC ok");
}

void monitor_radio_crc_match(void)
{
    /* 6 is the default int. priority used in SDK drivers */
    NVIC_SetPriority(SWI3_IRQn, 6);
    NVIC_EnableIRQ(SWI3_IRQn);

    NRF_EGU3->INTENSET = EGU_INTEN_TRIGGERED0_Msk;

    NRF_PPI->CH[0].EEP = (uint32_t) &NRF_RADIO->EVENTS_CRCOK;
    NRF_PPI->CH[0].TEP = (uint32_t) &NRF_EGU3->TASKS_TRIGGER[0];

    NRF_PPI->CHENSET = PPI_CHENSET_CH0_Msk;
}
#endif //MONITOR_RADIO_CRC_MATCH


/**@brief Application main function.
 */
int main(void)
{
    ...
    ble_stack_init();
#if MONITOR_RADIO_CRC_MATCH
    monitor_radio_crc_match();
#endif //MONITOR_RADIO_CRC_MATCH
    ...

[Felipe1]

Hi Vidar,

Thank you for your Info. For the BLE_GAP_EVT_SCAN_REQ_REPORT event detection, I am using the Softdevice SoC event handler just like the other BLE events like connected, disconnected, and others. For CRC error event detection, I referred to your snippet and I am using the software interrupt with the help of PPI. For both cases, I am calling bsp_board_led_on and then bsp_board_led_off, which will call nrf_gpio_pin_clear and nrf_gpio_pin_set internally.

These are my code:

static void ble_evt_handler(ble_evt_t const * p_ble_evt, void * p_context)
{
    ret_code_t err_code;

    switch (p_ble_evt->header.evt_id)
    {
    ....
            case BLE_GAP_EVT_SCAN_REQ_REPORT:
            // SCAN_REQ received event.
            bsp_board_led_on(SCANRSP_LED);
            NRF_LOG_INFO("SCAN_REQ");

            ble_gap_evt_scan_req_report_t * p_scan_req_report_t = (ble_gap_evt_scan_req_report_t *)&p_ble_evt->evt.gap_evt.params.scan_req_report;
                  NRF_LOG_INFO("Peer Address = 0x%02x:%02x:%02x:%02x:%02x:%02x",    \
                                p_scan_req_report_t->peer_addr.addr[5],     \
                                p_scan_req_report_t->peer_addr.addr[4],     \
                                p_scan_req_report_t->peer_addr.addr[3],     \
                                p_scan_req_report_t->peer_addr.addr[2],     \
                                p_scan_req_report_t->peer_addr.addr[1],     \
                                p_scan_req_report_t->peer_addr.addr[0]);
                  NRF_LOG_INFO("RSSI value = %d dBm", p_scan_req_report_t->rssi);
            bsp_board_led_off(SCANRSP_LED);
            break;

        default:
            // No implementation needed.
            break;
    }
}

#if MONITOR_RADIO_CRC_MATCH

void SWI3_IRQHandler(void)
{
    bsp_board_led_on(LEDBUTTON_LED);
    /* Clear event register */
    NRF_EGU3->EVENTS_TRIGGERED[0] = 0;
    // NRF_LOG_INFO("Packet received with CRC ok");
    NRF_LOG_INFO("Packet received with CRC error");
    bsp_board_led_off(LEDBUTTON_LED);
}

void monitor_radio_crc_match(void)
{
    /* 6 is the default int. priority used in SDK drivers */
    NVIC_SetPriority(SWI3_IRQn, 6);
    NVIC_EnableIRQ(SWI3_IRQn);

    NRF_EGU3->INTENSET = EGU_INTEN_TRIGGERED0_Msk;

    // NRF_PPI->CH[0].EEP = (uint32_t) &NRF_RADIO->EVENTS_CRCOK;
    NRF_PPI->CH[0].EEP = (uint32_t) &NRF_RADIO->EVENTS_CRCERROR;
    NRF_PPI->CH[0].TEP = (uint32_t) &NRF_EGU3->TASKS_TRIGGER[0];

    NRF_PPI->CHENSET = PPI_CHENSET_CH0_Msk;
}
#endif //MONITOR_RADIO_CRC_MATCH

Thank you,

Toru

[Vidar Berg]

Hi Toru,

Thanks for confirming. This means the CPU is executing code from the application and not in the Softdevice when the outputs are toggled. 

If you haven't already, please comment out the leds_init() and buttons_init() calls in main() and turn off logging by setting NRF_LOG_ENABLED to '0' in sdk_config.h. The LED indication relies on app timer interrupts to toggle the output, so that might be what we are seeing in the waveform. That, or it could be an UART interrupt from the log processing. 

Vidar

[Felipe1]

Hi Vidar,

Thank you for your comments.  I will follow your advice and let you know the result.

Thank you,

Toru

[Felipe1]

Hi Vidar,

For the quick testing, the above pattern 1 and 2 waveforms have been changed by setting NRF_LOG_ENABLED to '0' in sdk_config.h.  The ~8mA current part has gone.  I will go through the data and check if there are any other patterns like 4.

Thank you,

Toru

[Felipe1]

Hi Vidar,

I retested it using nrf_gpio_pin_toggle() for mapping BLE_GAP_EVT_SCAN_REQ_REPORT into channel 0 and CRC error into channel 1.

In my testing, the following 3 patterns were recorded.

1. BLE_GAP_EVT_SCAN_REQ_REPORT (SCAN_REQ is received and then SCAN_RSP is sent)

2. CRC error (Received packet is discarded due to CRC error)

3. No packet is received

Besides these, there were 2 more patterns.

4. SCAN_REQ is received for the 1st ADV_IND, and the SCAN_RSP is sent. One packet is received after SCAN_RSP, and then CRC error occurs.

5. One packet is received after the 1st ADV_IND and then CRC error occurs. SCAN_REQ is received after the 3rd ADV_IND and then SCAN_RSP is sent.

Seeing the above, the wave patterns are categorized by these cases, and each case can be explained as a normal behavior. If it makes sense, I will close this discussion.  Thank you.  -Toru

[Vidar Berg]

Hi Toru,

Yes, everything appears to be as expected now. 

[Felipe1]

Hi Vidar,

Thank you for your comments and I am grateful for your support.

Best Regards,

Toru