Freeze of nrf52840 USB Dongle due to USB CDC-ACM data transfer

[daten]

I'm experiencing a freeze - at least from user's perspective - when using a slightly modified "usbd_cdc_acm"-example and applying some human generated load (meaning: hitting the keyboard for a couple of seconds, incl. '\n' every now and then in order to reset the buffer / break out of the loop (see code below)).
Sooner or later it's going to freeze at the point right after the `break`.

Hardware is a nRF52840 USB dongle, SDK nRF5 SDK v16.0.0, SoftDevice s140_nrf52_7.0.1

The following diff to mentioned example code will render the nrf52840 unresponsive, meaning, it's stuck and doesn't loop through the main loop anymore.

diff --git a/examples/peripheral/usbd_cdc_acm/main.c b/examples/peripheral/usbd_cdc_acm/main.c
index c78f24cc..1ebc20bf 100644
--- a/examples/peripheral/usbd_cdc_acm/main.c
+++ b/examples/peripheral/usbd_cdc_acm/main.c
@@ -133,7 +133,8 @@ APP_USBD_CDC_ACM_GLOBAL_DEF(m_app_cdc_acm,

#define READ_SIZE 1

-static char m_rx_buffer[READ_SIZE];
+static uint8_t m_rx_buffer_pos = 0;
+static char m_rx_buffer[512];
 static char m_tx_buffer[NRF_DRV_USBD_EPSIZE];
 static bool m_send_flag = 0;

@@ -172,12 +173,21 @@ static void cdc_acm_user_ev_handler(app_usbd_class_inst_t const * p_inst,
 {
 /*Get amount of data transfered*/
 size_t size = app_usbd_cdc_acm_rx_size(p_cdc_acm);
- NRF_LOG_INFO("RX: size: %lu char: %c", size, m_rx_buffer[0]);
+ NRF_LOG_INFO("RX: size: %lu - char: %d - pos: %d", size, m_rx_buffer[m_rx_buffer_pos], m_rx_buffer_pos);

/* Fetch data until internal buffer is empty */
 ret = app_usbd_cdc_acm_read(&m_app_cdc_acm,
- m_rx_buffer,
+ &m_rx_buffer[++m_rx_buffer_pos],
 READ_SIZE);
+
+ if(m_rx_buffer[m_rx_buffer_pos-1] == '\r')
+ {
+ m_rx_buffer[++m_rx_buffer_pos] = '\0';
+ NRF_LOG_INFO("Transmission finished - resetting buffer");
+ m_rx_buffer_pos = 0;
+ break;
+ }
+
 } while (ret == NRF_SUCCESS);

bsp_board_led_invert(LED_CDC_ACM_RX);
@@ -296,6 +306,7 @@ int main(void)

ret = NRF_LOG_INIT(NULL);
 APP_ERROR_CHECK(ret);
+ NRF_LOG_DEFAULT_BACKENDS_INIT();

ret = nrf_drv_clock_init();
 APP_ERROR_CHECK(ret);

According to my debugger it appears to be stuck at __WFE(), however I'm not sure how much I can trust it in that state, also given I've seen it showing me various locations when hitting ^C at the moment of freeze:

Program received signal SIGINT, Interrupt.
0x000311b4 in __WFE () at ../../../../../../components/toolchain/cmsis/include/cmsis_gcc.h:396
396 __ASM volatile ("wfe");

Last line of output from above modified example after hitting the keyboard like a monkey:

<info> app: RX: size: 1 - char: 116 - pos: 1
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 13 - pos: 2
<info> app: Transmission finished - resetting buffer
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 32 - pos: 0
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 32 - pos: 1
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 13 - pos: 2
<info> app: Transmission finished - resetting buffer
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 32 - pos: 0
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 104 - pos: 1
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 13 - pos: 2
<info> app: Transmission finished - resetting buffer
<info> app: Bytes waiting: 0
<info> app: RX: size: 1 - char: 32 - pos: 0
<info> app: Bytes waiting: 1
<info> app: RX: size: 1 - char: 13 - pos: 1
<info> app: Transmission finished - resetting buffer

I'm chasing the root cause for a while now and herewith tried to break and narrow it down to a minimal example triggering the issue, hoping somebody else might be able to spot the flaw.

[hmolesworth]

I am having issues with something similar, and pushed it to one side. In this case the example only reads a singe byte at a time (what a strange example ..) and I see you modified that to attempt to read more, however this is now an issue:

ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_rx_buffer[++m_rx_buffer_pos], READ_SIZE);

I would suggest trying:

m_rx_buffer_pos += READ_SIZE;
ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_rx_buffer[m_rx_buffer_pos], READ_SIZE);

or:

ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_rx_buffer[m_rx_buffer_pos], READ_SIZE);
m_rx_buffer_pos += READ_SIZE;

Assuming each invocation reads READ_SIZE bytes from the USN buffer

[daten]

Hello and thanks for your reply. I could change the code accordingly (and adjust READ_SIZE to sth. like 8 I suppose), however that rather sounds like the issue occurring "less likely" due to less loop cycles, as in hiding it instead of solving the issue.

The freeze is a state I don't know how to recover from and I can't risk it happening - even if it's "less likely" due to reading >1byte per loop cycle.

So I'd really like to know what's happening and how to get rid of the freeze for good.

[daten]

After rethinking the issue, its potential causes and occurrences, I don't think increasing READ_SIZE would help much, if at all:

a) Looking at the log output I posted the freeze in this very case already occurred after 2 loop cycles, which really isn't a lot, so even if I heavily increase READ_SIZE I most likely will still have more than 1 loop cycle.

b) The freeze seems not to happen within the loop, but when / after leaving it. Potentially related to re-setting the buffer array index to 0.

[daten]

I allow myself to push a bit for a solution. This is a hard blocker for us and currently halting rollout.

[hmolesworth]

I don't have an answer, but there does seem to be an inconsistency in that the first location is never used and the '\r' terminator doesn't terminate unless followed by another character which is then followed by inserting a 0 which could be past the end of the buffer as it is not checked:

This line pre-increments m_rx_buffer_pos before the call, so m_rx_buffer[0] is never populated
+ &m_rx_buffer[++m_rx_buffer_pos], READ_SIZE);

This line looks at the previous character received, not the most recent
+ if(m_rx_buffer[m_rx_buffer_pos-1] == '\r')
+ {
// This line replaces the chracter after the most recent with 0
+ m_rx_buffer[++m_rx_buffer_pos] = '\0';

So .. termination is by '\r',[anything], otherwise the buffer will eventually overflow. m_rx_buffer[0] will never be set but will contain whatever anything else writing to this buffer last put there.

\r will only terminate immediately when hit if the terminal is configured to append - say - \n after every \r.

Using an 8-bit index to a 9-bit (512) element array will also not work as intended:

+static uint8_t m_rx_buffer_pos = 0;
+static char m_rx_buffer[512];