pc-ble-driver reports “Failed to decode event, error code is 14/0xe”.

[Paul Bradford]

I'm using the nrf52840 with connectivity firmware and S140 SoftDevice, accessed through pc-ble-driver version 4.1.1, with NRF_SD_BLE_API=6

Occasionally pc-ble-driver fails to decode an advertisement event, and notifies my application with a status callback with PKT_DECODE_ERROR and message “Failed to decode event, error code is 14/0xe”.  Error code 14 is NRF_ERROR_NULL.  I have tracked down the cause of the NRF_ERROR_NULL.

I’ve debugged enough to find out what event is received over the virtual serial port – hex dumps of a sample invalid event are below.

In “ble_data_t_dec” this decodes to a ‘buf_id’ of zero, and it then calls “app_ble_gap_adv_buf_unregister” with zero, which returns a nullptr. That nullptr passed to ‘SER_PULL_len16data’ is invalid and causes it to return NRF_ERROR_NULL, which is the error reported to my application.  

So pc-ble-driver expects that the connectivity firmware will never give it an advertisement with this “buf_id” of zero. What is causing this?

Hex dump of invalid event (62 bytes):

1d 00 ff ff 03 00 04 68 ce e3 b1 14 7d fe 00 00

00 00 00 00 01 ff 7f e3 27 ff 00 00 00 00 00 00

18 00 01 02 01 1a 14 ff 4c 00 01 00 00 00 00 00

00 40 00 00 00 00 00 00 00 00 00 09 03 03

 

Numbering the bytes starting from zero, the “buffer id” is bytes 27-31 (decimal)

[Krzysztof Chruscinski]

buf_id = 0 would indicate that buffer was already freed on connectivity side. One case that comes to my mind is a race between ADV_SET_TERMINATED event and ADV_REPORT event. Do you have logs which would show traffic before that error?

[Paul Bradford]

Here's a fragment of my code that's preparing to call "sd_ble_gap_adv_set_configure", indicating that we should never get event BLE_GAP_EVT_ADV_SET_TERMINATED:

// Because we set both 'duration' and 'max_adv_evts' to zero, advertising won't auto-stop,
// so we'll never get event BLE_GAP_EVT_ADV_SET_TERMINATED according to devzone.nordicsemi.com/.../bug-ble_gap_evt_adv_set_terminated-is-never-raised
ble_gap_adv_params_t     m_adv_params;
m_adv_params.duration = BLE_GAP_ADV_TIMEOUT_GENERAL_UNLIMITED;
m_adv_params.max_adv_evts = 0;// 0 means no limit.

This code is setting up undirected advertising (BLE_GAP_ADV_TYPE_NONCONNECTABLE_NONSCANNABLE_UNDIRECTED). How is undirected advertising related to the events I receive because I'm scanning? Are undirected advertising and scanning tied together in some way I don't understand?

The event whose decoding leads to the 'Failed to decode event' error is BLE_GAP_EVT_ADV_REPORT.  That event has a zero 'buffer id'. What 'buffer id' is this, and what would cause it to be freed?

[Paul Bradford]

Do you have any update with answers to my questions from April 23?

[Krzysztof Chruscinski]

I'm having trouble reproducing it. Will continue to hunt it.

[Paul Bradford]

HI Krzysztof,

The test program I attached to my other support case reproduces this problem intermittently: devzone.nordicsemi.com/.../disconnecting-while-operations-are-in-progress-never-gives-ble_gap_evt_disconnected-event

Can you answer my questions from April 23. I'll restate my questions and add another

1. Your reply on April 23 said "that buffer was already freed". What buffer?

2. Is there some race condition with the SoftDevice receiving advertisements around the time sd_ble_gap_scan_stop is called, which could cause this?

3. The event whose decoding leads to the 'Failed to decode event' error is BLE_GAP_EVT_ADV_REPORT, which I receive because I'm scanning.  That event has a zero 'buffer id'. What 'buffer id' is this, and what would cause it to be freed?

4. Your April 23 reply talked about a race condition involving ADV_SET_TERMINATED, which is an event related to sending out advertisements, but which won't be received with my configuration. How is sending undirected advertisements related to the event BLE_GAP_EVT_ADV_REPORT I receive because I'm scanning? Are undirected advertising and scanning tied together in some way I don't understand?

-Paul

-Paul