Merge pull request #12157 from michalpasztamobica/esp8266_send_retry

ESP8266: Avoid duplicate data sends

Author: 0xc0170

TESTS/netsocket/udp/udp_tests.h

@@ -48,7 +48,7 @@ static const int TESTS_TIMEOUT = MBED_GREENTEA_TEST_UDPSOCKET_TIMEOUT_S;
 #if MBED_CONF_TARGET_NETWORK_DEFAULT_INTERFACE_TYPE == MESH && MBED_CONF_NSAPI_DEFAULT_MESH_TYPE == WISUN
 static const int TESTS_TIMEOUT = (25 * 60);
 #else
-static const int TESTS_TIMEOUT = (10 * 60);
+static const int TESTS_TIMEOUT = (20 * 60);
 #endif
 #endif
 

components/wifi/esp8266-driver/ESP8266/ESP8266.cpp

@@ -58,6 +58,7 @@ ESP8266::ESP8266(PinName tx, PinName rx, bool debug, PinName rts, PinName cts)
       _error(false),
       _busy(false),
       _reset_done(false),
+      _sock_sending_id(-1),
       _conn_status(NSAPI_STATUS_DISCONNECTED)
 {
     _serial.set_baud(MBED_CONF_ESP8266_SERIAL_BAUDRATE);
@@ -89,13 +90,18 @@ ESP8266::ESP8266(PinName tx, PinName rx, bool debug, PinName rts, PinName cts)
     _parser.oob("busy ", callback(this, &ESP8266::_oob_busy));
     // NOTE: documentation v3.0 says '+CIPRECVDATA:<data_len>,' but it's not how the FW responds...
     _parser.oob("+CIPRECVDATA,", callback(this, &ESP8266::_oob_tcp_data_hdlr));
+    // Register 'SEND OK'/'SEND FAIL' oobs here. Don't get involved in oob management with send status
+    // because ESP8266 modem possibly doesn't reply these packets on error case.
+    _parser.oob("SEND OK", callback(this, &ESP8266::_oob_send_ok_received));
+    _parser.oob("SEND FAIL", callback(this, &ESP8266::_oob_send_fail_received));
 
     for (int i = 0; i < SOCKET_COUNT; i++) {
         _sock_i[i].open = false;
         _sock_i[i].proto = NSAPI_UDP;
         _sock_i[i].tcp_data = NULL;
         _sock_i[i].tcp_data_avbl = 0;
         _sock_i[i].tcp_data_rcvd = 0;
+        _sock_i[i].send_fail = false;
     }
 
     _scan_r.res = NULL;
@@ -288,6 +294,7 @@ bool ESP8266::reset(void)
     tr_debug("reset(): Done: %s.", done ? "OK" : "FAIL");
 
     _clear_socket_packets(ESP8266_ALL_SOCKET_IDS);
+    _sock_sending_id = -1;
     set_timeout();
     _smutex.unlock();
 
@@ -511,9 +518,17 @@ nsapi_error_t ESP8266::open_udp(int id, const char *addr, int port, int local_po
     // process OOB so that _sock_i reflects the correct state of the socket
     _process_oob(ESP8266_SEND_TIMEOUT, true);
 
-    if (id >= SOCKET_COUNT || _sock_i[id].open) {
+    // Previous close() can fail with busy in sending. Usually, user will ignore the close()
+    // error code and cause 'spurious close', in which case user has closed the socket but ESP8266 modem
+    // hasn't yet. Because we don't know how long ESP8266 modem will trap in busy, enlarge retry count
+    // or timeout in close() isn't a nice way. Here, we actively re-call close() in open() to let the modem
+    // close the socket. User can re-try open() on failure. Without this active close(), open() can fail forever
+    // with previous 'spurious close', unless peer closes the socket and so ESP8266 modem closes it accordingly.
+    if (id >= SOCKET_COUNT) {
         _smutex.unlock();
         return NSAPI_ERROR_PARAMETER;
+    } else if (_sock_i[id].open) {
+        close(id);
     }
 
     for (int i = 0; i < 2; i++) {
@@ -565,9 +580,12 @@ nsapi_error_t ESP8266::open_tcp(int id, const char *addr, int port, int keepaliv
     // process OOB so that _sock_i reflects the correct state of the socket
     _process_oob(ESP8266_SEND_TIMEOUT, true);
 
-    if (id >= SOCKET_COUNT || _sock_i[id].open) {
+    // See the reason above with close()
+    if (id >= SOCKET_COUNT) {
         _smutex.unlock();
         return NSAPI_ERROR_PARAMETER;
+    } else if (_sock_i[id].open) {
+        close(id);
     }
 
     for (int i = 0; i < 2; i++) {
@@ -615,9 +633,24 @@ bool ESP8266::dns_lookup(const char *name, char *ip)
     return done;
 }
 
-nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount)
+nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount)
 {
+    if (_sock_i[id].proto == NSAPI_TCP) {
+        if (_sock_sending_id >= 0 && _sock_sending_id < SOCKET_COUNT) {
+            if (!_sock_i[id].send_fail) {
+                tr_debug("send(): Previous packet (socket %d) was not yet ACK-ed with SEND OK.", _sock_sending_id);
+                return NSAPI_ERROR_WOULD_BLOCK;
+            } else {
+                tr_debug("send(): Previous packet (socket %d) failed.", id);
+                return NSAPI_ERROR_DEVICE_ERROR;
+            }
+        }
+    }
+
     nsapi_error_t ret = NSAPI_ERROR_DEVICE_ERROR;
+    int bytes_confirmed = 0;
+    constexpr unsigned int send_ack_retries = 3;
+
     // +CIPSEND supports up to 2048 bytes at a time
     // Data stream can be truncated
     if (amount > 2048 && _sock_i[id].proto == NSAPI_TCP) {
@@ -629,7 +662,10 @@ nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount)
     }
 
     _smutex.lock();
-RETRY:
+    // Mark this socket is sending. We allow only one actively sending socket because:
+    // 1. ESP8266 AT packets 'SEND OK'/'SEND FAIL' are not associated with socket ID. No way to tell them.
+    // 2. In original implementation, ESP8266::send() is synchronous, which implies only one actively sending socket.
+    _sock_sending_id = id;
     set_timeout(ESP8266_SEND_TIMEOUT);
     _busy = false;
     _error = false;
@@ -638,52 +674,71 @@ nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount)
         goto END;
     }
 
-    //We might receive "busy s/p..." and "OK" from modem, so we need to check that also
-    _ok_received = false;
-    _parser.oob("OK", callback(this, &ESP8266::_oob_ok_received));
-
     if (!_parser.recv(">")) {
-        _parser.remove_oob("OK");
-        if (_busy) {
-            if (_ok_received) {
-                goto RETRY;
-            } else if (_parser.recv("OK")) {
-                goto RETRY;
-            }
-        }
+        // This means ESP8266 hasn't even started to receive data
         tr_debug("send(): Didn't get \">\"");
-        ret = NSAPI_ERROR_WOULD_BLOCK;
+        if (_sock_i[id].proto == NSAPI_TCP) {
+            ret = NSAPI_ERROR_WOULD_BLOCK; // Not necessarily critical error.
+        } else if (_sock_i[id].proto == NSAPI_UDP) {
+            ret = NSAPI_ERROR_NO_MEMORY;
+        }
+        goto END;
+    }
+
+    if (_parser.write((char *)data, (int)amount) < 0) {
+        tr_debug("send(): Failed to write serial data");
+        // Serial is not working, serious error, reset needed.
+        ret = NSAPI_ERROR_DEVICE_ERROR;
         goto END;
     }
-    _ok_received = false;
-    _parser.remove_oob("OK");
 
-    if (_parser.write((char *)data, (int)amount) >= 0 && _parser.recv("SEND OK")) {
-        ret = NSAPI_ERROR_OK;
+    // The "Recv X bytes" is not documented.
+    if (!_parser.recv("Recv %d bytes", &bytes_confirmed)) {
+        tr_debug("send(): Bytes not confirmed.");
+        if (_sock_i[id].proto == NSAPI_TCP) {
+            ret = NSAPI_ERROR_WOULD_BLOCK;
+        } else if (_sock_i[id].proto == NSAPI_UDP) {
+            ret = NSAPI_ERROR_NO_MEMORY;
+        }
+    } else if (bytes_confirmed != amount && _sock_i[id].proto == NSAPI_UDP) {
+        tr_debug("send(): Error: confirmed %d bytes, but expected %d.", bytes_confirmed, amount);
+        ret = NSAPI_ERROR_DEVICE_ERROR;
+    } else {
+        // TCP can accept partial writes (if they ever happen)
+        ret = bytes_confirmed;
     }
 
 END:
     _process_oob(ESP8266_RECV_TIMEOUT, true); // Drain USART receive register to avoid data overrun
 
     // error hierarchy, from low to high
-    if (_busy) {
-        ret = NSAPI_ERROR_WOULD_BLOCK;
-        tr_debug("send(): Modem busy. ");
-    }
-
-    if (ret == NSAPI_ERROR_DEVICE_ERROR) {
+    // NOTE: We cannot return NSAPI_ERROR_WOULD_BLOCK when "Recv X bytes" has reached, otherwise duplicate data send.
+    if (_busy && ret < 0) {
         ret = NSAPI_ERROR_WOULD_BLOCK;
-        tr_debug("send(): Send failed.");
+        tr_debug("send(): Modem busy.");
     }
 
     if (_error) {
+        // FIXME: Not sure clear or not of _error. See it as device error and it can recover only via reset?
+        _sock_sending_id = -1;
         ret = NSAPI_ERROR_CONNECTION_LOST;
         tr_debug("send(): Connection disrupted.");
     }
 
-    if (!_sock_i[id].open && ret != NSAPI_ERROR_OK) {
+    if (_sock_i[id].send_fail) {
+        _sock_sending_id = -1;
+        if (_sock_i[id].proto == NSAPI_TCP) {
+            ret = NSAPI_ERROR_DEVICE_ERROR;
+        } else {
+            ret = NSAPI_ERROR_NO_MEMORY;
+        }
+        tr_debug("send(): SEND FAIL received.");
+    }
+
+    if (!_sock_i[id].open && ret < 0) {
+        _sock_sending_id = -1;
         ret = NSAPI_ERROR_CONNECTION_LOST;
-        tr_debug("send(): Socket closed abruptly.");
+        tr_debug("send(): Socket %d closed abruptly.", id);
     }
 
     set_timeout();
@@ -956,6 +1011,14 @@ void ESP8266::_clear_socket_packets(int id)
     }
 }
 
+void ESP8266::_clear_socket_sending(int id)
+{
+    if (id == _sock_sending_id) {
+        _sock_sending_id = -1;
+    }
+    _sock_i[id].send_fail = false;
+}
+
 bool ESP8266::close(int id)
 {
     //May take a second try if device is busy
@@ -967,20 +1030,27 @@ bool ESP8266::close(int id)
                     _closed = false;
                     _sock_i[id].open = false;
                     _clear_socket_packets(id);
+                    // Closed, so this socket escapes from SEND FAIL status.
+                    _clear_socket_sending(id);
                     _smutex.unlock();
                     // ESP8266 has a habit that it might close a socket on its own.
+                    tr_debug("close(%d): socket close OK with UNLINK ERROR", id);
                     return true;
                 }
             } else {
                 // _sock_i[id].open set to false with an OOB
                 _clear_socket_packets(id);
+                // Closed, so this socket escapes from SEND FAIL status
+                _clear_socket_sending(id);
                 _smutex.unlock();
+                tr_debug("close(%d): socket close OK with AT+CIPCLOSE OK", id);
                 return true;
             }
         }
         _smutex.unlock();
     }
 
+    tr_debug("close(%d): socket close FAIL'ed (spurious close)", id);
     return false;
 }
 
@@ -1157,34 +1227,42 @@ void ESP8266::_oob_socket0_closed()
 {
     static const int id = 0;
     _sock_i[id].open = false;
+    // Closed, so this socket escapes from SEND FAIL status
+    _clear_socket_sending(id);
     tr_debug("_oob_socket0_closed(): Socket %d closed.", id);
 }
 
 void ESP8266::_oob_socket1_closed()
 {
     static const int id = 1;
     _sock_i[id].open = false;
+    // Closed, so this socket escapes from SEND FAIL status
+    _clear_socket_sending(id);
     tr_debug("_oob_socket1_closed(): Socket %d closed.", id);
 }
 
 void ESP8266::_oob_socket2_closed()
 {
     static const int id = 2;
     _sock_i[id].open = false;
+    _clear_socket_sending(id);
     tr_debug("_oob_socket2_closed(): Socket %d closed.", id);
 }
 
 void ESP8266::_oob_socket3_closed()
 {
     static const int id = 3;
     _sock_i[id].open = false;
+    _clear_socket_sending(id);
     tr_debug("_oob_socket3_closed(): %d closed.", id);
 }
 
 void ESP8266::_oob_socket4_closed()
 {
     static const int id = 4;
     _sock_i[id].open = false;
+    // Closed, so this socket escapes from SEND FAIL status
+    _clear_socket_sending(id);
     tr_debug("_oob_socket0_closed(): Socket %d closed.", id);
 }
 
@@ -1222,10 +1300,19 @@ void ESP8266::_oob_connection_status()
     _conn_stat_cb();
 }
 
-void ESP8266::_oob_ok_received()
+void ESP8266::_oob_send_ok_received()
 {
-    tr_debug("_oob_ok_received called");
-    _ok_received = true;
+    tr_debug("_oob_send_ok_received called for socket %d", _sock_sending_id);
+    _sock_sending_id = -1;
+}
+
+void ESP8266::_oob_send_fail_received()
+{
+    tr_debug("_oob_send_fail_received called for socket %d", _sock_sending_id);
+    if (_sock_sending_id >= 0 && _sock_sending_id < SOCKET_COUNT) {
+        _sock_i[_sock_sending_id].send_fail = true;
+    }
+    _sock_sending_id = -1;
 }
 
 int8_t ESP8266::default_wifi_mode()

components/wifi/esp8266-driver/ESP8266/ESP8266.h

@@ -255,10 +255,10 @@ class ESP8266 {
     *
     * @param id id of socket to send to
     * @param data data to be sent
-    * @param amount amount of data to be sent - max 1024
-    * @return NSAPI_ERROR_OK in success, negative error code in failure
+    * @param amount amount of data to be sent - max 2048
+    * @return number of bytes on success, negative error code in failure
     */
-    nsapi_error_t send(int id, const void *data, uint32_t amount);
+    nsapi_size_or_error_t send(int id, const void *data, uint32_t amount);
 
     /**
     * Receives datagram from an open UDP socket
@@ -444,6 +444,7 @@ class ESP8266 {
         // data follows
     } *_packets, * *_packets_end;
     void _clear_socket_packets(int id);
+    void _clear_socket_sending(int id);
     int _sock_active_id;
 
     // Memory statistics
@@ -469,7 +470,8 @@ class ESP8266 {
     void _oob_tcp_data_hdlr();
     void _oob_ready();
     void _oob_scan_results();
-    void _oob_ok_received();
+    void _oob_send_ok_received();
+    void _oob_send_fail_received();
 
     // OOB state variables
     int _connect_error;
@@ -480,7 +482,7 @@ class ESP8266 {
     bool _error;
     bool _busy;
     bool _reset_done;
-    bool _ok_received;
+    int _sock_sending_id;
 
     // Modem's address info
     char _ip_buffer[16];
@@ -495,6 +497,7 @@ class ESP8266 {
         char *tcp_data;
         int32_t tcp_data_avbl; // Data waiting on modem
         int32_t tcp_data_rcvd;
+        bool send_fail;     // Received 'SEND FAIL'. Expect user will close the socket.
     };
     struct _sock_info _sock_i[SOCKET_COUNT];
 

components/wifi/esp8266-driver/ESP8266Interface.cpp

@@ -849,7 +849,7 @@ int ESP8266Interface::socket_accept(void *server, void **socket, SocketAddress *
 
 int ESP8266Interface::socket_send(void *handle, const void *data, unsigned size)
 {
-    nsapi_error_t status;
+    nsapi_size_or_error_t status;
     struct esp8266_socket *socket = (struct esp8266_socket *)handle;
     uint8_t expect_false = false;
 
@@ -881,7 +881,7 @@ int ESP8266Interface::socket_send(void *handle, const void *data, unsigned size)
         status = NSAPI_ERROR_DEVICE_ERROR;
     }
 
-    return status != NSAPI_ERROR_OK ? status : size;
+    return status;
 }
 
 int ESP8266Interface::socket_recv(void *handle, void *data, unsigned size)