Otap: better handle otap exchange with neighbors

When a node exchanges a scatchpad to one of its neighbors,
the dual mcu is not able to serve UART requests.
And dual mcu app for now doesn't discard old requests from
host. So better handle this situation to avoid detecting an
uart issue when it is just an OTAP exchange.

Also remove some redundant traces (especially printing
received buffers).

Author: GwendalRaoul

lib/platform/linux/platform.c

@@ -214,9 +214,9 @@ static void * poll_for_indication(void * unused)
         }
 
 #if MAX_DURATION_POLL_FAIL_S != 0
-        if (get_ind_res >= 0)
+        if (get_ind_res >= 0 || get_ind_res == WPC_INT_SYNC_ERROR)
         {
-            // Poll request executed fine, reset fail counter
+            // Poll request executed fine or at least com is working with sink, reset fail counter
             m_last_successful_poll_ts = get_timestamp_s();
         }
         else

lib/platform/linux/serial.c

@@ -16,7 +16,7 @@
 #include "serial_termios2.h"
 
 #define LOG_MODULE_NAME "SERIAL"
-#define MAX_LOG_LEVEL DEBUG_LOG_LEVEL
+#define MAX_LOG_LEVEL INFO_LOG_LEVEL
 #include "logger.h"
 
 static int fd = -1;
@@ -143,7 +143,7 @@ int Serial_close()
 
     if (close(fd) < 0)
     {
-        LOGD("Error %d closing serial link: %s\n", errno, strerror (errno));
+        LOGW("Error %d closing serial link: %s\n", errno, strerror (errno));
         return -1;
     }
 

lib/wpc/include/wpc_internal.h

@@ -8,6 +8,15 @@
 
 #include "wpc_types.h"
 
+typedef enum {
+    WPC_INT_GEN_ERROR = -1,          //< Generic error code
+    WPC_INT_TIMEOUT_ERROR = -2,      //< Timeout error
+    WPC_INT_SYNC_ERROR = -3,         //< Synchronization error
+    WPC_INT_WRONG_PARAM_ERROR = -4,  //< Wrong parameter
+    WPC_INT_WRONG_CRC = -5,          //< Wrong crc
+    WPC_INT_WRONG_BUFFER_SIZE = -6,  //< Wrong provided buffer size
+} WPC_Int_error_code_e;
+
 /**
  * \brief   Callback to be called when an indication is received
  * \param   frame

lib/wpc/slip.c

@@ -12,6 +12,7 @@
 //#define PRINT_BUFFERS
 #include "logger.h"
 
+#include "wpc_internal.h"
 #include "slip.h"
 #include "util.h"
 
@@ -138,13 +139,13 @@ static uint32_t slip_encode_buffer(uint8_t * buffer,
         if (current == END_SLIP_OCTET || current == ESC_SLIP_OCTET) {
             //Check for buffer_escaped overflow
             if (write >= len_escaped)
-                return -1;
+                return WPC_INT_WRONG_BUFFER_SIZE;
             buffer_escaped[write++] = ESC_SLIP_OCTET;
             current = (current == END_SLIP_OCTET ? END_SUBS_OCTET : ESC_SUBS_OCTET);
         }
         //Check for buffer_escaped overflow
         if (write >= len_escaped)
-            return -1;
+            return WPC_INT_WRONG_BUFFER_SIZE;
 
         buffer_escaped[write++] = current;
     }
@@ -167,7 +168,7 @@ int Slip_decode(uint8_t * buffer,
     {
         LOG_PRINT_BUFFER(buffer, len);
         LOGE("Wrong crc 0x%04x (computed) vs 0x%04x (received)\n", crc, crc_from_frame);
-        return -1;
+        return WPC_INT_WRONG_CRC;
     }
 
     return decoded_len - 2;
@@ -191,7 +192,7 @@ int Slip_encode(uint8_t * buffer_in,
     if (total_size == -1)
     {
         LOGE("Provided buffer in encode is too small\n");
-        return -1;
+        return WPC_INT_WRONG_BUFFER_SIZE;
     }
 
     //Add the escaped crc to the end of the buffer in LE
@@ -204,7 +205,7 @@ int Slip_encode(uint8_t * buffer_in,
         if (temp_size == -1)
         {
             LOGE("Provided buffer in encode is too small\n");
-            return -1;
+            return WPC_INT_WRONG_BUFFER_SIZE;
         }
 
         total_size += temp_size;
@@ -240,7 +241,7 @@ int Slip_send_buffer(uint8_t * buffer,
     if (written_size != size + 4)
     {
         LOGE("Not able to write all the encoded packet %d vs %d\n", written_size, size + 4);
-        return -1;
+        return WPC_INT_GEN_ERROR;
     }
 
     return 0;
@@ -269,7 +270,7 @@ int Slip_get_buffer(uint8_t * buffer,
         if (res == 0)
         {
             LOGW("Timeout to receive frame (size=%d)\n", size);
-            return -1;
+            return WPC_INT_TIMEOUT_ERROR;
         }
         else if (res < 0 || res > 1)
         {
@@ -321,7 +322,7 @@ int Slip_get_buffer(uint8_t * buffer,
             if (size > sizeof(receiving_buffer))
             {
                 LOGE("Receiving too much bytes from serial line %d vs %d\n", size, sizeof(receiving_buffer));
-                return -1;
+                return WPC_INT_GEN_ERROR;
             }
         }
         else
@@ -346,7 +347,7 @@ int Slip_init(write_f write,
               read_f read)
 {
     if (!write || !read)
-        return -1;
+        return WPC_INT_WRONG_PARAM_ERROR;
 
     write_function = write;
     read_function = read;

lib/wpc/wpc_internal.c

@@ -32,10 +32,13 @@
 // the stack for a request
 #define TIMEOUT_CONFIRM_MS 500
 
-// Attempt to receive confirm. In some seldom use cases it can happen
-// that a previous confirm request was still in the buffer. Just try several
-// times to get the right confirm
-#define MAX_CONFIRM_ATTEMPT 5
+// Attempt to receive confirm from a request.
+// In some cases like OTAP it can happen that Dual MCU app doesn't answer
+// for a long time (can be up to 1mins when exchanging an OTAP with a neighbor).
+// So all the poll requests done during this period can be received in a raw
+// So this mechanism allows to flush previous poll requests. Try several
+// times to get the right confirm.
+#define MAX_CONFIRM_ATTEMPT 50
 
 // Struct that describes a received frame with its timestamp
 typedef struct
@@ -106,7 +109,7 @@ static int send_request_locked(wpc_frame_t * request,
     if (Slip_send_buffer((uint8_t *) request, request->payload_length + 3) < 0)
     {
         LOGE("Cannot send request\n");
-        return -1;
+        return WPC_INT_GEN_ERROR;
     }
 
     while (attempt < MAX_CONFIRM_ATTEMPT)
@@ -116,7 +119,8 @@ static int send_request_locked(wpc_frame_t * request,
         if (confirm_size < 0)
         {
             LOGE("Didn't receive answer to the request 0x%02x\n", request->primitive_id);
-            return -1;
+            // Return confirm_size to propagate the error code
+            return confirm_size;
         }
 
         // Check the confirm
@@ -127,7 +131,7 @@ static int send_request_locked(wpc_frame_t * request,
             LOGW("Waiting confirm for primitive_id 0x%02x but received 0x%02x\n",
                              request->primitive_id + SAP_CONFIRM_OFFSET,
                              rec_confirm->primitive_id);
-            LOG_PRINT_BUFFER(buffer, FRAME_SIZE((wpc_frame_t *) buffer));
+            //LOG_PRINT_BUFFER(buffer, FRAME_SIZE((wpc_frame_t *) buffer));
             attempt++;
             continue;
         }
@@ -136,7 +140,7 @@ static int send_request_locked(wpc_frame_t * request,
             LOGW("Waiting confirm for frame_id 0x%02x but received 0x%02x\n",
                              request->frame_id,
                              rec_confirm->frame_id);
-            LOG_PRINT_BUFFER(buffer, FRAME_SIZE((wpc_frame_t *) buffer));
+            //LOG_PRINT_BUFFER(buffer, FRAME_SIZE((wpc_frame_t *) buffer));
             attempt++;
             continue;
         }
@@ -146,7 +150,7 @@ static int send_request_locked(wpc_frame_t * request,
     if (attempt == MAX_CONFIRM_ATTEMPT)
     {
         LOGE("Synchronization lost\n");
-        return -1;
+        return WPC_INT_SYNC_ERROR;
     }
 
     // Copy the confirm
@@ -209,7 +213,7 @@ static int handle_indication(bool last_one,
     if (res <= 0)
     {
         LOGE("Timeout waiting for indication last_one=%d\n", last_one);
-        return -1;
+        return WPC_INT_TIMEOUT_ERROR;
     }
 
     // Get timestamp just after reception
@@ -246,25 +250,27 @@ static int get_indication_locked(unsigned int max_ind,
     wpc_frame_t request;
     wpc_frame_t confirm;
     int remaining_ind = 1;
+    int ret;
 
     if (max_ind == 0)
     {
         // Poll request cannot be done if no indication
         // can be handled
         LOGE("Wrong number of indication\n");
-        return -1;
+        return WPC_INT_WRONG_PARAM_ERROR;
     }
 
     request.primitive_id = MSAP_INDICATION_POLL_REQUEST;
     request.payload_length = 0;
 
     LOGD("Start a poll request\n");
-    if (send_request_locked(&request,
-                            &confirm,
-                            TIMEOUT_CONFIRM_MS) < 0)
+    ret = send_request_locked(&request,
+                              &confirm,
+                              TIMEOUT_CONFIRM_MS);
+    if (ret < 0)
     {
         LOGE("Unable to poll for request\n");
-        return -1;
+        return ret;
     }
 
     if (confirm.payload.sap_generic_confirm_payload.result == 0)
@@ -281,7 +287,7 @@ static int get_indication_locked(unsigned int max_ind,
         if (remaining_ind < 0)
         {
             LOGE("Cannot get an indication\n");
-            return -1;
+            return remaining_ind;
         }
     }
 
@@ -320,15 +326,15 @@ int WPC_Int_initialize(char * port_name, unsigned long bitrate)
 {
     // Open the serial connection
     if (Serial_open(port_name, bitrate) < 0)
-        return -1;
+        return WPC_INT_GEN_ERROR;
 
     // Initialize the slip module
     Slip_init(&Serial_write, &Serial_read);
 
     if (!Platform_init())
     {
         Serial_close();
-        return -1;
+        return WPC_INT_GEN_ERROR;
     }
 
     dsap_init();