for-loop doesn't exit within UART interrupt handler

[daten]

Hello,

I'm chasing a bug and narrowed it down to a minimal failing case. Even it's only very few lines, I'm still failing to grasp what's actually happening.

Taking the risk of making a fool out of myself:

A for-loop with a seemingly hard and simple exit condition just keeps going.

Anyway, here's the interrupt handler - it's based on the ble_peripheral/ble_app_uart example with only very few modifications. Full diff at the end.

#define BUFS 4
static uint8_t buf[BUFS][256];
static uint32_t buf_pos[BUFS] = {0,0,0,0};
static bool buf_locked[BUFS] = {false,false,false,false};
void uart_event_handle(app_uart_evt_t * p_event)
{
    uint8_t buf_id;
    switch (p_event->evt_type)
    {    
        case APP_UART_DATA_READY:
 
            for(buf_id = 0; (buf_id <= BUFS) && buf_locked[buf_id]; buf_id++)
            {    
                NRF_LOG_ERROR("Loop cycle - buf_id: %u | buf_locked[buf_id]: %u", buf_id);
            }
 
            NRF_LOG_ERROR("Outside of loop - buf_id: %u", buf_id);
 
            app_uart_get(&(buf[buf_id][buf_pos[buf_id]]));
            if (buf[buf_id][buf_pos[buf_id]] == ' ' || buf[buf_id][buf_pos[buf_id]] == '\r' || buf[buf_id][buf_pos[buf_id]] == '\n')
            {    
                buf_locked[buf_id] = true;
                return;
            }
            buf_pos[buf_id]++;
 
            break;
 
        case APP_UART_COMMUNICATION_ERROR:
            //APP_ERROR_HANDLER(p_event->data.error_communication);
            NRF_LOG_ERROR("uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (%08X)", p_event->data.error_communication);
            break;
 
        case APP_UART_FIFO_ERROR:
            APP_ERROR_HANDLER(p_event->data.error_code);
            break;
 
        default:
            break;
    }
}

Now I'm piping A B C D E F G H I J K L M N to the UART device the nrf is connected to. Basically just pasting the string into my terminal, one or several times.

Example log output:

<error> app: Outside of loop - buf_id: 0
<error> app: uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (00000001)
<error> app: Outside of loop - buf_id: 0
<error> app: Outside of loop - buf_id: 0
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 1
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 1
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 2
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 2
<error> app: uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (00000001)
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 2
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 2
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 3
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 3
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 3 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 4 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 5
<error> app: uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (00000001)
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 3 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 4 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 5
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 3 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 4 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 5 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 6
<error> app: uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (00000001)
<error> app: uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (00000001)
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 3 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 4 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 5 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 6
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 3 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 4 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 5 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 6 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 7
<error> app: Loop cycle - buf_id: 0 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 1 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 2 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 3 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 4 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 5 | buf_locked[buf_id]: 0
<error> app: Loop cycle - buf_id: 6 | buf_locked[buf_id]: 0
<error> app: Outside of loop - buf_id: 7

In case it isn't obvious: the variable buf_id exceeds the value of BUFS (=4), while it should go at most 5 rounds per function call.

Yes, i'm doing this in a interrupt handler, yes I probably shouldn't use NRF_LOG_* within (however the original example is doing the same) and, yes, I receive buffer overruns.

Still, I'm failing to understand how anything of these can result into this.

PS: Here's the whole diff to the original example:

diff --git a/examples/ble_peripheral/ble_app_uart/main.c b/examples/ble_peripheral/ble_app_uart/main.c
index 641339d0..7aa131ab 100644
--- a/examples/ble_peripheral/ble_app_uart/main.c
+++ b/examples/ble_peripheral/ble_app_uart/main.c
@@ -314,10 +314,6 @@ static void sleep_mode_enter(void)
     uint32_t err_code = bsp_indication_set(BSP_INDICATE_IDLE);
     APP_ERROR_CHECK(err_code);
 
-    // Prepare wakeup buttons.
-    err_code = bsp_btn_ble_sleep_mode_prepare();
-    APP_ERROR_CHECK(err_code);
-
     // Go to system-off mode (this function will not return; wakeup will cause a reset).
     err_code = sd_power_system_off();
     APP_ERROR_CHECK(err_code);
@@ -518,46 +514,38 @@ void bsp_event_handler(bsp_event_t event)
  *          'new line' '\n' (hex 0x0A) or if the string has reached the maximum data length.
  */
 /**@snippet [Handling the data received over UART] */
+
+#define BUFS 4
+static uint8_t buf[BUFS][256];
+static uint32_t buf_pos[BUFS] = {0,0,0,0};
+static bool buf_locked[BUFS] = {false,false,false,false};
 void uart_event_handle(app_uart_evt_t * p_event)
 {
-    static uint8_t data_array[BLE_NUS_MAX_DATA_LEN];
-    static uint8_t index = 0;
-    uint32_t       err_code;
-
+    uint8_t buf_id;
     switch (p_event->evt_type)
     {    
         case APP_UART_DATA_READY:
-            UNUSED_VARIABLE(app_uart_get(&data_array[index]));
-            index++;
 
-            if ((data_array[index - 1] == '\n') ||
-                (data_array[index - 1] == '\r') ||
-                (index >= m_ble_nus_max_data_len))
+            for(buf_id = 0; (buf_id <= BUFS) && buf_locked[buf_id]; buf_id++)
             {
-                if (index > 1)
-                {
-                    NRF_LOG_DEBUG("Ready to send data over BLE NUS");
-                    NRF_LOG_HEXDUMP_DEBUG(data_array, index);
-
-                    do
-                    {
-                        uint16_t length = (uint16_t)index;
-                        err_code = ble_nus_data_send(&m_nus, data_array, &length, m_conn_handle);
-                        if ((err_code != NRF_ERROR_INVALID_STATE) &&
-                            (err_code != NRF_ERROR_RESOURCES) &&
-                            (err_code != NRF_ERROR_NOT_FOUND))
-                        {
-                            APP_ERROR_CHECK(err_code);
-                        }
-                    } while (err_code == NRF_ERROR_RESOURCES);
-                }
+                NRF_LOG_ERROR("Loop cycle - buf_id: %u | buf_locked[buf_id]: %u", buf_id);
+            }
+
+            NRF_LOG_ERROR("Outside of loop - buf_id: %u", buf_id);
 
-                index = 0;
+            app_uart_get(&(buf[buf_id][buf_pos[buf_id]]));
+            if (buf[buf_id][buf_pos[buf_id]] == ' ' || buf[buf_id][buf_pos[buf_id]] == '\r' || buf[buf_id][buf_pos[buf_id]] == '\n')
+            {
+                buf_locked[buf_id] = true;
+                return;
             }
+            buf_pos[buf_id]++;
+
             break;
 
         case APP_UART_COMMUNICATION_ERROR:
-            APP_ERROR_HANDLER(p_event->data.error_communication);
+            //APP_ERROR_HANDLER(p_event->data.error_communication);
+            NRF_LOG_ERROR("uart_ev_handler() :: APP_UART_COMMUNICATION_ERROR (%08X)", p_event->data.error_communication);
             break;
 
         case APP_UART_FIFO_ERROR:
@@ -583,12 +571,12 @@ static void uart_init(void)
         .tx_pin_no    = TX_PIN_NUMBER,
         .rts_pin_no   = RTS_PIN_NUMBER,
         .cts_pin_no   = CTS_PIN_NUMBER,
-        .flow_control = APP_UART_FLOW_CONTROL_DISABLED,
-        .use_parity   = false,
+        .flow_control = APP_UART_FLOW_CONTROL_ENABLED,
+        .use_parity   = true,
 #if defined (UART_PRESENT)
-        .baud_rate    = NRF_UART_BAUDRATE_115200
+        .baud_rate    = NRF_UART_BAUDRATE_57600
 #else
-        .baud_rate    = NRF_UARTE_BAUDRATE_115200
+        .baud_rate    = NRF_UARTE_BAUDRATE_57600
 #endif
     };
 
@@ -635,18 +623,7 @@ static void advertising_init(void)
  *
  * @param[out] p_erase_bonds  Will be true if the clear bonding button was pressed to wake the application up.
  */
-static void buttons_leds_init(bool * p_erase_bonds)
-{
-    bsp_event_t startup_event;
-
-    uint32_t err_code = bsp_init(BSP_INIT_LEDS | BSP_INIT_BUTTONS, bsp_event_handler);
-    APP_ERROR_CHECK(err_code);
 
-    err_code = bsp_btn_ble_init(NULL, &startup_event);
-    APP_ERROR_CHECK(err_code);
-
-    *p_erase_bonds = (startup_event == BSP_EVENT_CLEAR_BONDING_DATA);
-}
 
 
 /**@brief Function for initializing the nrf log module.
@@ -702,7 +679,6 @@ int main(void)
     uart_init();
     log_init();
     timers_init();
-    buttons_leds_init(&erase_bonds);
     power_management_init();
     ble_stack_init();
     gap_params_init();
@@ -714,7 +690,7 @@ int main(void)
     // Start execution.
     printf("\r\nUART started.\r\n");
     NRF_LOG_INFO("Debug logging for UART over RTT started.");
-    advertising_start();
+    //advertising_start();
 
     // Enter main loop.
     for (;;)


[daten]

Oh boy..

            for(buf_id = 0; (buf_id <= BUFS) && buf_locked[buf_id]; buf_id++)

While I do not write - I do read - in memory I'm not supposed to.

buf_locked[] is BUFS bytes long - that means 4.


However one condition for the for-loop is buf_id <= BUFS - which means we can have 5 loop cycles in which case - as part of the other condition - buf_locked[4] is being checked, which is the 5th element in an array having space for 4.

Just one byte. Just being read. Boom.

[Vidar Berg]

Thanks for updating the thread! Looks like this was the problem. Let me know if there is anything else.