52832 works different outside of JLink Debugger

[rolandash]

Hi,

This is a really weird problem. 

======================

Setup of 52832 hardware:

- Custom board, using 32MHz XTAL and LF RC.

- SDK15.2, S132 610

- Segger RTT client with JLink debugger.

=======================

This 52832 hardware mainly acts as peripheral and been worked quite well, can connect and communication correctly with iPhone/iPad. 

Recently I try to use a 52840 instead of iPhone/iPad as central to connect with this 52832. The connection parameters are as in below's log.

info> app: [Central Scanning] updating neighbour list: 1 neighbour nodes ...
<info> app: [Central Scanning] connect to peer 0 ......
<info> app: CENTRAL: Connected, handle: 0.
<info> app: CENTRAL: init db discovery: 0.
<debug> ble_db_disc: Starting discovery of service with UUID 0x1 on connection handle 0x0.
<info> app: CENTRAL: start discovery: 0.
<debug> nrf_ble_gatt: Requesting to update ATT MTU to 224 bytes on connection 0x0.
<debug> nrf_ble_gatt: sd_ble_gattc_exchange_mtu_request() on connection 0x0 returned busy, will retry.
<debug> nrf_ble_gatt: Updating data length to 224 on connection 0x0.
<debug> nrf_ble_gatt: Peer on connection 0x0 requested an ATT MTU of 127 bytes.
<debug> nrf_ble_gatt: Updating ATT MTU to 127 bytes (desired: 224) on connection 0x0.
<debug> ble_db_disc: Found service UUID 0x1.
<debug> nrf_ble_gatt: Data length updated to 127 on connection 0x0.
<debug> nrf_ble_gatt: max_rx_octets: 127
<debug> nrf_ble_gatt: max_tx_octets: 127
<debug> nrf_ble_gatt: max_rx_time: 1989
<debug> nrf_ble_gatt: max_tx_time: 1989

In this setup 52832 will send HVX notification to 840, and I am expecting to see maximum 127 bytes of messages received on 840 side.

However, I found that part of the notifications that 52832 send to 52840 are wrong(sometimes even leads to connection timeout), and this problem only occur when 52832 is not connected with JLink Debugger, When I try to investigated it with JLink debugger attached, the problem does not show up.

This seems like some potential memory conflicts with RTT backend to me, probably because I missed something somewhere, or maybe some issue with RTT itself. But the point is I have no means to debug this problem in this case, any suggestion about this situation?

Thank you.

[Kenneth]

Hello,

What have you set NRF_SDH_CLOCK_LF_ACCURACY to on the peripheral/central? Can you try to set it to '1'.

Does you system_nrf52.c file contain errata_108()?

Best regards,
Kenneth

[rolandash]

I suspected clock accuracy issue at first when encounter this problem. But when I check deep into it more, I realized that the physical layer of communication actually works properly on both side. So far I can isolate the cause of this issue within the side of 52832.

I specially checked the memory that sd_ble_gatts_hvx() function referred to, and it seems when JLink debugger is removed, 

sd_ble_gatts_hvx used a very different memory other than I fed it, that explained why 840 received unexpected data as the sender just fetch data from wrong location. But I can not track it down why this could happen because once JLink debugger attached, this problem does not occur.

[Kenneth]

Is it possible you have somehow set that the characteristic should use BLE_GATTS_VLOC_USER instead of BLE_GATTS_VLOC_STACK? (For instance check if ble_add_char_params_t set .is_value_user).

[rolandash]

Kenneth

I did set the characteristic to be BLE_GATTS_VLOC_STACK. In this case I assume the SD should copy the data to sent into internal buffer, so it should be safe to release my user buffer after NRF_SUCCESS returned.

[Kenneth]

Hi,

That is the correct assumption.

I don't have any other good suggestion here, it is indeed very weird, have you tried to look at the connection parameters and/or using an on-air sniffer trace and/or just output all BLE events to check if there is an event not handled here and/or occurring only when connected to the nRF52840? 

If you disable sleep (wait for event) on the nRF52832, does it then behave as expected?

Best regards,
Kenneth

[rolandash]

Hi,

The connection params are as below. I did not try sniffing yet, but I will do it in a few days. 

BLE_GAP_EVT_CONN_PARAM_UPDATE: min_intval: 19, max_interval: 19, slave_latency: 0, sup_timeout: 100

I actually did more testing today, and my previous description about the problem is not 100% accurate. It looks have 2 problems here than just one.

P1: PPI on 52832 seems related very much to the inconsistent behavior. in the setup 52832 receives data through UART from an external MCU, driver by PPI, at baud rate of 921600, and then forward to radio to send to 840. When JLink is not presented, PPI seems received wrong data. So it is not sd_ble_gatts_hvx() referenced wrong memory, but PPI may not working properly in that special condition and forwarded wrong data to radio. 

I am not sure though why PPI has this behavior, as this setup was tested on previous SDK (14.x.x) and not shoowing this behavior. Recently I ported to 15.2.0. It might be the lead to the issue but still need to verify.

P2. Although the data transferred is correct, the radio link between 832 and 840 seems not quite stable sometimes disconnect. Of course many things can cause a disconnection, and I think this is independent from JLink attached or not. But one doubt I have is will 840 automatically reconnect 832 if link is lost? I am pretty sure that I did not add any re-connect logic in application level. 840 only use sd_ble_gap_connect() to connect on first discovery. But between data transmission log from 832 shows another connection comes in when initial 0x0 connection lost. So the question is can 840 do link-layer auto reconnection? 

I am really confused where this new connection comes out from otherwise.

<info> app: Connected
<info> app: Connection with link 0x1 established.
<info> app: Fast advertising
<debug> nrf_ble_gatt: Peer on connection 0x1 requested an ATT MTU of 104 bytes.
<debug> nrf_ble_gatt: Updating ATT MTU to 104 bytes (desired: 224) on connection 0x1.
<info> app:  exchange MTU request...error 0
<debug> nrf_ble_gatt: ATT MTU updated to 104 bytes on connection 0x1 (response).
<info> app: ATT MTU updated to 104

[Kenneth]

On the BLE_GAP_EVT_CONNECTED event you should be able to read out the connection parameters from p_ble_evt->evt.gap_evt.params.connected.conn_params; Please duplicate these when using the nRF52840.

Did you try any test without nrf_pwr_mgmt_run() on the nRF52832/nRF52840, this may provide some more information what the debugger is doing here (e.g. is it keeping the system powered during some time critical part).

The softdevice will not do any auto-connect no, however typically the examples are setup to start advertise on BLE_GAP_EVT_DISCONNECTED, for instance see ble_advertising_on_ble_evt().

Ref this:

<info> app: Connection with link 0x1 established.
<info> app: Fast advertising

Are you starting advertisement while in a connection, is this intended and/or have you tried to not advertise and see if that may impact your issue.

[rolandash]

Kenneth

Some updates:

P1. After migrate from nrf_drv_ppi to nrfx_ppi in 15.2.0, this problem disappeared. Now 832 behave consistently with or without JLink attached, at least during the tests we performed so far. 

I did agree with you of attention on conn params, though I think that will impact more on P2.

P2. Yes I restarted advertising after connected intentionally, as it is expected to support multi-links. However I am not sure that even 832 is advertising, would 840 connect to it without been commanded?

I actually think it's more possible that unreasonable conn params leads to disconnection, and some LL procedure then be triggered to reconnect with different conn parameters set. Ref to this line:

<info> app: ATT MTU updated to 104

104 is not specified anywhere in my project, the number must be calculated and derived by some protocol entity

[Kenneth]

The softdevice on the nRF52840 will not do any active scanning or try to connect unless the application in specific do so after a connection is established or after a disconnect.

It is the gatt_init(), see nrf_ble_gatt_on_ble_evt() in nrf_ble_gatt.c that handle all ATT mtu and DLE exchange between the peers. See on_connected_evt() in the file, it typically is always initiated from the central after connection event. The supported sizes is configured in nrf_ble_gatt_init().

[rolandash]

Kenneth

Thanks for the hint. However, that did not explain why 840 connect 832 for then 2nd time without my explicit command.

I paste part of my code so you can also have an investigation:

static void ble_central_scan_evt_handler(scan_evt_t const * p_scan_evt)
{
    ret_code_t err_code;
    switch(p_scan_evt->scan_evt_id)
    {
        case NRF_BLE_SCAN_EVT_WHITELIST_REQUEST:
        {
            //on_whitelist_req();
            //m_whitelist_disabled = false;
        } break;
            
        case NRF_BLE_SCAN_EVT_CONNECTING_ERROR:
        {
            err_code = p_scan_evt->params.connecting_err.err_code;
            APP_ERROR_CHECK(err_code);
        } break;
            
        case NRF_BLE_SCAN_EVT_SCAN_TIMEOUT:
        {
            NRF_LOG_INFO("Scan timed out.");
            //scan_start();
        } break;
            
        case NRF_BLE_SCAN_EVT_FILTER_MATCH:
        {
            const ble_gap_evt_adv_report_t* adv_report = p_scan_evt->params.filter_match.p_adv_report;
            dt_phy_update_neighbour_list(adv_report, p_scan_evt);
        }
          break;
        .....
    }
}

.....

static void dt_phy_update_neighbour_list(ble_gap_evt_adv_report_t const * p_adv_report, scan_evt_t const * p_scan_evt)
{
    ......
    ret_code_t err_code = sd_ble_gap_connect(peer_addr,
                                  p_scan_evt->p_scan_params,
                                  &m_scan.conn_params,
                                  1/*APP_BLE_CENTRAL_CONN_CFG_TAG*/);

    ......

}

As you can see that sd_ble_gap_connect() is called only when NRF_BLE_SCAN_EVT_FILTER_MATCH

happen. 

According to nordic SDK document, central will stop scan after sd_ble_gap_connect() is called. So even peripheral is advertising, central should not scanning, so that NRF_BLE_SCAN_EVT_FILTER_MATCH should never happen for 2nd time, unless I explicitly start scanning again. 

The only explanation is sd_ble_gap_connect() does not stop scanning as document stated.

 

[Kenneth]

Do you call scan_stop() before calling sd_ble_gap_connect()? What timeout value do you use in sd_ble_gap_connect()?

Best regards,
Kenneth

[rolandash]

NO, I did not. As in document stated, calling sd_ble_gap_connect() will stop scan activity, so I should not need to duplicate the work.

I did not set scan params except connect_if_match to false. So I think the timeout value of scan is 0 (unlimited time)? sd_ble_gap_connect() should stop it anyway.

    ret_code_t          err_code;
    nrf_ble_scan_init_t init_scan;
    
    memset(&init_scan, 0, sizeof(init_scan));
    
    init_scan.connect_if_match = false;
    init_scan.conn_cfg_tag     = APP_BLE_CENTRAL_CONN_CFG_TAG;