From de2896c659e734259e7f5cf831d5ce8c9db345c8 Mon Sep 17 00:00:00 2001 From: Michal Paszta Date: Fri, 20 Dec 2019 12:18:05 +0200 Subject: [PATCH 1/6] ESP8266: add a retry mechanism to avoid duplicate data sends We are now checking if ESP8266 has confirmed receiving data over serial port with an undocumented (but existing) "Recv x bytes" message. Next we are explicitly waiting for an official "SEND OK". --- .../wifi/esp8266-driver/ESP8266/ESP8266.cpp | 106 +++++++++++++----- .../wifi/esp8266-driver/ESP8266/ESP8266.h | 6 +- 2 files changed, 82 insertions(+), 30 deletions(-) diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp index b7a8f2168c..9a26abd54b 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp @@ -58,6 +58,8 @@ ESP8266::ESP8266(PinName tx, PinName rx, bool debug, PinName rts, PinName cts) _error(false), _busy(false), _reset_done(false), + _prev_send_ok_pending(false), + _send_fail_received(false), _conn_status(NSAPI_STATUS_DISCONNECTED) { _serial.set_baud(MBED_CONF_ESP8266_SERIAL_BAUDRATE); @@ -614,7 +616,16 @@ bool ESP8266::dns_lookup(const char *name, char *ip) nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount) { + if (_prev_send_ok_pending && _sock_i[id].proto == NSAPI_TCP) { + tr_debug("send(): Previous packet was not ACK-ed with SEND OK."); + return NSAPI_ERROR_WOULD_BLOCK; + } + nsapi_error_t ret = NSAPI_ERROR_DEVICE_ERROR; + _send_fail_received = false; + 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) { @@ -626,7 +637,6 @@ nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount) } _smutex.lock(); -RETRY: set_timeout(ESP8266_SEND_TIMEOUT); _busy = false; _error = false; @@ -635,42 +645,67 @@ RETRY: 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 neccesarily critical error. + } else if (_sock_i[id].proto == NSAPI_UDP) { + ret = NSAPI_ERROR_NO_MEMORY; + } 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; + 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; } + // The "Recv X bytes" is not documented. + if (!_parser.recv("Recv %d bytes", &bytes_confirmed)) { + tr_debug("send(): Bytes not confirmed."); + ret = NSAPI_ERROR_DEVICE_ERROR; + goto END; + } else if (bytes_confirmed != amount) { + tr_debug("send(): Error: confirmed %d bytes, but expected %d.", bytes_confirmed, amount); + ret = NSAPI_ERROR_DEVICE_ERROR; + goto END; + } + + //We might receive "busy s/p...", "SEND OK" or "SEND FAIL" from modem, so we need to check that also + _parser.oob("SEND FAIL", callback(this, &ESP8266::_oob_send_fail_received)); + for (unsigned int i = send_ack_retries; i > 0; i--) { + if (!_parser.recv("SEND OK")) { + if (_error || _send_fail_received) { + _parser.remove_oob("SEND FAIL"); + goto END; + } + if (_busy) { + _busy = false; + tr_debug("send(): Busy, %d retries left...", i - 1); + } else { + tr_debug("send(): Not busy, but no SEND OK. %d retries left...", i - 1); + } + } else { + ret = amount; // Got "SEND OK" - return number of bytes. + goto END; + } + } + + // ESP8266 ACKed data over serial, but did not ACK over TCP or report any error. + _prev_send_ok_pending = true; + _parser.oob("SEND OK", callback(this, &ESP8266::_oob_send_ok_received)); + ret = amount; + 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) { - ret = NSAPI_ERROR_WOULD_BLOCK; - tr_debug("send(): Send failed."); + tr_debug("send(): Modem busy."); } if (_error) { @@ -678,7 +713,16 @@ END: tr_debug("send(): Connection disrupted."); } - if (!_sock_i[id].open && ret != NSAPI_ERROR_OK) { + if (_send_fail_received) { + 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) { ret = NSAPI_ERROR_CONNECTION_LOST; tr_debug("send(): Socket closed abruptly."); } @@ -1219,10 +1263,16 @@ 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"); + _prev_send_ok_pending = false; +} + +void ESP8266::_oob_send_fail_received() +{ + tr_debug("_oob_send_fail_received called"); + _send_fail_received = true; } int8_t ESP8266::default_wifi_mode() diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.h b/components/wifi/esp8266-driver/ESP8266/ESP8266.h index 7b18e10a0c..48e66e585f 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.h +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.h @@ -469,7 +469,8 @@ private: 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 +481,8 @@ private: bool _error; bool _busy; bool _reset_done; - bool _ok_received; + bool _prev_send_ok_pending; + bool _send_fail_received; // Modem's address info char _ip_buffer[16]; From 902feddf2e98be688df4877dd8816b2d30149b74 Mon Sep 17 00:00:00 2001 From: Michal Paszta Date: Fri, 27 Dec 2019 16:03:36 +0200 Subject: [PATCH 2/6] ESP8266: Improve error handling and partial sends --- components/wifi/esp8266-driver/ESP8266/ESP8266.cpp | 11 ++++++++--- components/wifi/esp8266-driver/ESP8266/ESP8266.h | 6 +++--- components/wifi/esp8266-driver/ESP8266Interface.cpp | 4 ++-- 3 files changed, 13 insertions(+), 8 deletions(-) diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp index 9a26abd54b..1fc2ab4054 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp @@ -614,7 +614,7 @@ 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 (_prev_send_ok_pending && _sock_i[id].proto == NSAPI_TCP) { tr_debug("send(): Previous packet was not ACK-ed with SEND OK."); @@ -649,7 +649,7 @@ nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount) // This means ESP8266 hasn't even started to receive data tr_debug("send(): Didn't get \">\""); if (_sock_i[id].proto == NSAPI_TCP) { - ret = NSAPI_ERROR_WOULD_BLOCK; // Not neccesarily critical error. + ret = NSAPI_ERROR_WOULD_BLOCK; // Not necessarily critical error. } else if (_sock_i[id].proto == NSAPI_UDP) { ret = NSAPI_ERROR_NO_MEMORY; } @@ -667,6 +667,11 @@ nsapi_error_t ESP8266::send(int id, const void *data, uint32_t amount) if (!_parser.recv("Recv %d bytes", &bytes_confirmed)) { tr_debug("send(): Bytes not confirmed."); ret = NSAPI_ERROR_DEVICE_ERROR; + 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; + } goto END; } else if (bytes_confirmed != amount) { tr_debug("send(): Error: confirmed %d bytes, but expected %d.", bytes_confirmed, amount); @@ -724,7 +729,7 @@ END: if (!_sock_i[id].open && ret < 0) { ret = NSAPI_ERROR_CONNECTION_LOST; - tr_debug("send(): Socket closed abruptly."); + tr_debug("send(): Socket %d closed abruptly.", id); } set_timeout(); diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.h b/components/wifi/esp8266-driver/ESP8266/ESP8266.h index 48e66e585f..babb929e6e 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.h +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.h @@ -255,10 +255,10 @@ public: * * @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 diff --git a/components/wifi/esp8266-driver/ESP8266Interface.cpp b/components/wifi/esp8266-driver/ESP8266Interface.cpp index 3aeb82a5b9..255232386c 100644 --- a/components/wifi/esp8266-driver/ESP8266Interface.cpp +++ b/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) From d23d55c24a645966d40f25ea5feeb2cf2a947c92 Mon Sep 17 00:00:00 2001 From: Michal Paszta Date: Tue, 31 Dec 2019 15:00:10 +0200 Subject: [PATCH 3/6] ESP8266: Introduce single send_status instead of two flags --- .../wifi/esp8266-driver/ESP8266/ESP8266.cpp | 59 +++++++++++++------ .../wifi/esp8266-driver/ESP8266/ESP8266.h | 15 ++++- 2 files changed, 55 insertions(+), 19 deletions(-) diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp index 1fc2ab4054..64fa455b7a 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp @@ -58,8 +58,7 @@ ESP8266::ESP8266(PinName tx, PinName rx, bool debug, PinName rts, PinName cts) _error(false), _busy(false), _reset_done(false), - _prev_send_ok_pending(false), - _send_fail_received(false), + _send_status(SEND_STATUS_OK), _conn_status(NSAPI_STATUS_DISCONNECTED) { _serial.set_baud(MBED_CONF_ESP8266_SERIAL_BAUDRATE); @@ -290,6 +289,9 @@ bool ESP8266::reset(void) tr_debug("reset(): Done: %s.", done ? "OK" : "FAIL"); _clear_socket_packets(ESP8266_ALL_SOCKET_IDS); + _send_status = SEND_STATUS_OK; + _parser.remove_oob("SEND OK"); + _parser.remove_oob("SEND FAIL"); set_timeout(); _smutex.unlock(); @@ -616,13 +618,18 @@ bool ESP8266::dns_lookup(const char *name, char *ip) nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) { - if (_prev_send_ok_pending && _sock_i[id].proto == NSAPI_TCP) { - tr_debug("send(): Previous packet was not ACK-ed with SEND OK."); - return NSAPI_ERROR_WOULD_BLOCK; + if (_sock_i[id].proto == NSAPI_TCP) { + if (_send_status == SEND_STATUS_PENDING) { + tr_debug("send(): Previous packet was not yet ACK-ed with SEND OK."); + return NSAPI_ERROR_WOULD_BLOCK; + } else if (_send_status == SEND_STATUS_FAILED) { + tr_debug("send(): Previous packet failed."); + _send_status = SEND_STATUS_OK; + return NSAPI_ERROR_DEVICE_ERROR; + } } nsapi_error_t ret = NSAPI_ERROR_DEVICE_ERROR; - _send_fail_received = false; int bytes_confirmed = 0; constexpr unsigned int send_ack_retries = 3; @@ -666,7 +673,6 @@ nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) // The "Recv X bytes" is not documented. if (!_parser.recv("Recv %d bytes", &bytes_confirmed)) { tr_debug("send(): Bytes not confirmed."); - ret = NSAPI_ERROR_DEVICE_ERROR; if (_sock_i[id].proto == NSAPI_TCP) { ret = NSAPI_ERROR_WOULD_BLOCK; } else if (_sock_i[id].proto == NSAPI_UDP) { @@ -683,15 +689,13 @@ nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) _parser.oob("SEND FAIL", callback(this, &ESP8266::_oob_send_fail_received)); for (unsigned int i = send_ack_retries; i > 0; i--) { if (!_parser.recv("SEND OK")) { - if (_error || _send_fail_received) { + if (_error || _send_status == SEND_STATUS_FAILED) { _parser.remove_oob("SEND FAIL"); goto END; } if (_busy) { _busy = false; tr_debug("send(): Busy, %d retries left...", i - 1); - } else { - tr_debug("send(): Not busy, but no SEND OK. %d retries left...", i - 1); } } else { ret = amount; // Got "SEND OK" - return number of bytes. @@ -699,8 +703,8 @@ nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) } } - // ESP8266 ACKed data over serial, but did not ACK over TCP or report any error. - _prev_send_ok_pending = true; + // ESP8266 ACKed data over serial, but did not ACK with SEND OK or report any error. + _send_status = SEND_STATUS_PENDING; _parser.oob("SEND OK", callback(this, &ESP8266::_oob_send_ok_received)); ret = amount; @@ -718,7 +722,7 @@ END: tr_debug("send(): Connection disrupted."); } - if (_send_fail_received) { + if (_send_status == SEND_STATUS_FAILED) { if (_sock_i[id].proto == NSAPI_TCP) { ret = NSAPI_ERROR_DEVICE_ERROR; } else { @@ -1001,6 +1005,14 @@ void ESP8266::_clear_socket_packets(int id) _sock_i[id].tcp_data_avbl = 0; } } +void ESP8266::_clear_send_status(void) +{ + _smutex.lock(); // remove_oob doesn't use serial, but we don't want to race against it. + _send_status = SEND_STATUS_OK; + _parser.remove_oob("SEND OK"); + _parser.remove_oob("SEND FAIL"); + _smutex.unlock(); +} bool ESP8266::close(int id) { @@ -1203,6 +1215,7 @@ void ESP8266::_oob_socket0_closed() { static const int id = 0; _sock_i[id].open = false; + _clear_send_status(); tr_debug("_oob_socket0_closed(): Socket %d closed.", id); } @@ -1210,6 +1223,7 @@ void ESP8266::_oob_socket1_closed() { static const int id = 1; _sock_i[id].open = false; + _clear_send_status(); tr_debug("_oob_socket1_closed(): Socket %d closed.", id); } @@ -1217,6 +1231,7 @@ void ESP8266::_oob_socket2_closed() { static const int id = 2; _sock_i[id].open = false; + _clear_send_status(); tr_debug("_oob_socket2_closed(): Socket %d closed.", id); } @@ -1224,6 +1239,7 @@ void ESP8266::_oob_socket3_closed() { static const int id = 3; _sock_i[id].open = false; + _clear_send_status(); tr_debug("_oob_socket3_closed(): %d closed.", id); } @@ -1231,6 +1247,7 @@ void ESP8266::_oob_socket4_closed() { static const int id = 4; _sock_i[id].open = false; + _clear_send_status(); tr_debug("_oob_socket0_closed(): Socket %d closed.", id); } @@ -1270,14 +1287,22 @@ void ESP8266::_oob_connection_status() void ESP8266::_oob_send_ok_received() { - tr_debug("_oob_send_ok_received called"); - _prev_send_ok_pending = false; + tr_debug("_oob_send_ok_received called with _send_status %d", _send_status); + if (_send_status == SEND_STATUS_PENDING) { + _send_status = SEND_STATUS_OK; + } + _parser.remove_oob("SEND OK"); + _parser.remove_oob("SEND FAIL"); } void ESP8266::_oob_send_fail_received() { - tr_debug("_oob_send_fail_received called"); - _send_fail_received = true; + tr_debug("_oob_send_fail_received called with _send_status %d", _send_status); + if (_send_status == SEND_STATUS_PENDING) { + _send_status = SEND_STATUS_FAILED; + } + _parser.remove_oob("SEND FAIL"); + _parser.remove_oob("SEND OK"); } int8_t ESP8266::default_wifi_mode() diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.h b/components/wifi/esp8266-driver/ESP8266/ESP8266.h index babb929e6e..10a19f0590 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.h +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.h @@ -250,6 +250,17 @@ public: */ nsapi_error_t open_tcp(int id, const char *addr, int port, int keepalive = 0); + /** ESP8266 send status. + * + * There is one send status per device, because the ACKs are just simple "SEND OK/FAIL" + * with no way to tell which socket is reporting back. + */ + enum send_status { + SEND_STATUS_OK = 0, /*!< device is able to send */ + SEND_STATUS_PENDING = 1, /*!< previous send is pending for OK/FAIL */ + SEND_STATUS_FAILED = 2 /*!< previous send FAILed */ + }; + /** * Sends data to an open socket * @@ -444,6 +455,7 @@ private: // data follows } *_packets, * *_packets_end; void _clear_socket_packets(int id); + void _clear_send_status(void); int _sock_active_id; // Memory statistics @@ -481,8 +493,7 @@ private: bool _error; bool _busy; bool _reset_done; - bool _prev_send_ok_pending; - bool _send_fail_received; + send_status _send_status; // Modem's address info char _ip_buffer[16]; From 6dfa2d78ad62c3a5a1fc908b8e07e3110f0965e7 Mon Sep 17 00:00:00 2001 From: Michal Paszta Date: Tue, 31 Dec 2019 15:00:33 +0200 Subject: [PATCH 4/6] Increase UDP test timeout to 1200s This is because the ESP8266 is now waiting for SEND OK and takes much more to complete the send_repeat, and echo_burst tests in RAAS. (but has higher pass ratio). --- TESTS/netsocket/udp/udp_tests.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/TESTS/netsocket/udp/udp_tests.h b/TESTS/netsocket/udp/udp_tests.h index f52ae77dc3..ed5bba5821 100644 --- a/TESTS/netsocket/udp/udp_tests.h +++ b/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 From 4405ab46b6a1f603ec2931aa678d60b64f7c12a5 Mon Sep 17 00:00:00 2001 From: Chun-Chieh Li Date: Fri, 3 Jan 2020 16:21:34 +0800 Subject: [PATCH 5/6] ESP8266: Simplify flow control and enable per-socket reconnection 1. Fix 'spurious close' by adding close() in open(). 'spurious close' gets frequent and cannot ignore when send() changes to asynchronous. User can retry open() until 'spurious close' gets true. 2. 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. 3. Register 'SEND OK'/'SEND FAIL' oobs, like others in ESP8266::ESP8266 constructor. Don't get involved in oob management with send status because ESP8266 modem possibly doesn't reply these packets on error case. 4. Now that ESP8266::send() changes to asynchronous, drop the code with _parser.recv("SEND OK")/_parser.recv("SEND FAIL"). _parser.recv("SEND OK")/_parser.recv("SEND FAIL") and 'SEND OK'/'SEND FAIL' oobs both consume 'SEND OK'/'SEND FAIL' packets and complicate flow control. --- .../wifi/esp8266-driver/ESP8266/ESP8266.cpp | 143 ++++++++++-------- .../wifi/esp8266-driver/ESP8266/ESP8266.h | 15 +- 2 files changed, 85 insertions(+), 73 deletions(-) diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp index 64fa455b7a..26bfd1b6c8 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp @@ -58,7 +58,7 @@ ESP8266::ESP8266(PinName tx, PinName rx, bool debug, PinName rts, PinName cts) _error(false), _busy(false), _reset_done(false), - _send_status(SEND_STATUS_OK), + _sock_sending_id(-1), _conn_status(NSAPI_STATUS_DISCONNECTED) { _serial.set_baud(MBED_CONF_ESP8266_SERIAL_BAUDRATE); @@ -90,6 +90,10 @@ 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:,' 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; @@ -97,6 +101,7 @@ ESP8266::ESP8266(PinName tx, PinName rx, bool debug, PinName rts, PinName cts) _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; @@ -289,9 +294,7 @@ bool ESP8266::reset(void) tr_debug("reset(): Done: %s.", done ? "OK" : "FAIL"); _clear_socket_packets(ESP8266_ALL_SOCKET_IDS); - _send_status = SEND_STATUS_OK; - _parser.remove_oob("SEND OK"); - _parser.remove_oob("SEND FAIL"); + _sock_sending_id = -1; set_timeout(); _smutex.unlock(); @@ -515,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++) { @@ -566,9 +577,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++) { @@ -619,13 +633,14 @@ bool ESP8266::dns_lookup(const char *name, char *ip) nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) { if (_sock_i[id].proto == NSAPI_TCP) { - if (_send_status == SEND_STATUS_PENDING) { - tr_debug("send(): Previous packet was not yet ACK-ed with SEND OK."); - return NSAPI_ERROR_WOULD_BLOCK; - } else if (_send_status == SEND_STATUS_FAILED) { - tr_debug("send(): Previous packet failed."); - _send_status = SEND_STATUS_OK; - return NSAPI_ERROR_DEVICE_ERROR; + 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; + } } } @@ -644,6 +659,10 @@ nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) } _smutex.lock(); + // 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; @@ -685,44 +704,27 @@ nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) goto END; } - //We might receive "busy s/p...", "SEND OK" or "SEND FAIL" from modem, so we need to check that also - _parser.oob("SEND FAIL", callback(this, &ESP8266::_oob_send_fail_received)); - for (unsigned int i = send_ack_retries; i > 0; i--) { - if (!_parser.recv("SEND OK")) { - if (_error || _send_status == SEND_STATUS_FAILED) { - _parser.remove_oob("SEND FAIL"); - goto END; - } - if (_busy) { - _busy = false; - tr_debug("send(): Busy, %d retries left...", i - 1); - } - } else { - ret = amount; // Got "SEND OK" - return number of bytes. - goto END; - } - } - - // ESP8266 ACKed data over serial, but did not ACK with SEND OK or report any error. - _send_status = SEND_STATUS_PENDING; - _parser.oob("SEND OK", callback(this, &ESP8266::_oob_send_ok_received)); ret = amount; END: _process_oob(ESP8266_RECV_TIMEOUT, true); // Drain USART receive register to avoid data overrun // error hierarchy, from low to high - if (_busy) { + // 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(): 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 (_send_status == SEND_STATUS_FAILED) { + if (_sock_i[id].send_fail) { + _sock_sending_id = -1; if (_sock_i[id].proto == NSAPI_TCP) { ret = NSAPI_ERROR_DEVICE_ERROR; } else { @@ -732,6 +734,7 @@ END: } if (!_sock_i[id].open && ret < 0) { + _sock_sending_id = -1; ret = NSAPI_ERROR_CONNECTION_LOST; tr_debug("send(): Socket %d closed abruptly.", id); } @@ -1005,14 +1008,6 @@ void ESP8266::_clear_socket_packets(int id) _sock_i[id].tcp_data_avbl = 0; } } -void ESP8266::_clear_send_status(void) -{ - _smutex.lock(); // remove_oob doesn't use serial, but we don't want to race against it. - _send_status = SEND_STATUS_OK; - _parser.remove_oob("SEND OK"); - _parser.remove_oob("SEND FAIL"); - _smutex.unlock(); -} bool ESP8266::close(int id) { @@ -1025,20 +1020,33 @@ 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. + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; _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 + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; _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; } @@ -1215,7 +1223,11 @@ void ESP8266::_oob_socket0_closed() { static const int id = 0; _sock_i[id].open = false; - _clear_send_status(); + // Closed, so this socket escapes from SEND FAIL status + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; tr_debug("_oob_socket0_closed(): Socket %d closed.", id); } @@ -1223,7 +1235,11 @@ void ESP8266::_oob_socket1_closed() { static const int id = 1; _sock_i[id].open = false; - _clear_send_status(); + // Closed, so this socket escapes from SEND FAIL status + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; tr_debug("_oob_socket1_closed(): Socket %d closed.", id); } @@ -1231,7 +1247,11 @@ void ESP8266::_oob_socket2_closed() { static const int id = 2; _sock_i[id].open = false; - _clear_send_status(); + // Closed, so this socket escapes from SEND FAIL status + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; tr_debug("_oob_socket2_closed(): Socket %d closed.", id); } @@ -1239,7 +1259,11 @@ void ESP8266::_oob_socket3_closed() { static const int id = 3; _sock_i[id].open = false; - _clear_send_status(); + // Closed, so this socket escapes from SEND FAIL status + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; tr_debug("_oob_socket3_closed(): %d closed.", id); } @@ -1247,7 +1271,11 @@ void ESP8266::_oob_socket4_closed() { static const int id = 4; _sock_i[id].open = false; - _clear_send_status(); + // Closed, so this socket escapes from SEND FAIL status + if (id == _sock_sending_id) { + _sock_sending_id = -1; + } + _sock_i[id].send_fail = false; tr_debug("_oob_socket0_closed(): Socket %d closed.", id); } @@ -1287,22 +1315,17 @@ void ESP8266::_oob_connection_status() void ESP8266::_oob_send_ok_received() { - tr_debug("_oob_send_ok_received called with _send_status %d", _send_status); - if (_send_status == SEND_STATUS_PENDING) { - _send_status = SEND_STATUS_OK; - } - _parser.remove_oob("SEND OK"); - _parser.remove_oob("SEND FAIL"); + 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 with _send_status %d", _send_status); - if (_send_status == SEND_STATUS_PENDING) { - _send_status = SEND_STATUS_FAILED; + 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; } - _parser.remove_oob("SEND FAIL"); - _parser.remove_oob("SEND OK"); + _sock_sending_id = -1; } int8_t ESP8266::default_wifi_mode() diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.h b/components/wifi/esp8266-driver/ESP8266/ESP8266.h index 10a19f0590..249c11e989 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.h +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.h @@ -250,17 +250,6 @@ public: */ nsapi_error_t open_tcp(int id, const char *addr, int port, int keepalive = 0); - /** ESP8266 send status. - * - * There is one send status per device, because the ACKs are just simple "SEND OK/FAIL" - * with no way to tell which socket is reporting back. - */ - enum send_status { - SEND_STATUS_OK = 0, /*!< device is able to send */ - SEND_STATUS_PENDING = 1, /*!< previous send is pending for OK/FAIL */ - SEND_STATUS_FAILED = 2 /*!< previous send FAILed */ - }; - /** * Sends data to an open socket * @@ -455,7 +444,6 @@ private: // data follows } *_packets, * *_packets_end; void _clear_socket_packets(int id); - void _clear_send_status(void); int _sock_active_id; // Memory statistics @@ -493,7 +481,7 @@ private: bool _error; bool _busy; bool _reset_done; - send_status _send_status; + int _sock_sending_id; // Modem's address info char _ip_buffer[16]; @@ -508,6 +496,7 @@ private: 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]; From ea2f36eadf956200f61dd169f3ec99e23e8b3899 Mon Sep 17 00:00:00 2001 From: Michal Paszta Date: Fri, 10 Jan 2020 16:53:23 +0200 Subject: [PATCH 6/6] ESP8266: accept partial writes for TCP and clean up code --- .../wifi/esp8266-driver/ESP8266/ESP8266.cpp | 54 +++++++------------ .../wifi/esp8266-driver/ESP8266/ESP8266.h | 1 + 2 files changed, 20 insertions(+), 35 deletions(-) diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp index 26bfd1b6c8..734f53d498 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.cpp @@ -697,15 +697,14 @@ nsapi_size_or_error_t ESP8266::send(int id, const void *data, uint32_t amount) } else if (_sock_i[id].proto == NSAPI_UDP) { ret = NSAPI_ERROR_NO_MEMORY; } - goto END; - } else if (bytes_confirmed != amount) { + } 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; - goto END; + } else { + // TCP can accept partial writes (if they ever happen) + ret = bytes_confirmed; } - ret = amount; - END: _process_oob(ESP8266_RECV_TIMEOUT, true); // Drain USART receive register to avoid data overrun @@ -1009,6 +1008,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 @@ -1021,10 +1028,7 @@ bool ESP8266::close(int id) _sock_i[id].open = false; _clear_socket_packets(id); // Closed, so this socket escapes from SEND FAIL status. - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _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); @@ -1034,10 +1038,7 @@ bool ESP8266::close(int id) // _sock_i[id].open set to false with an OOB _clear_socket_packets(id); // Closed, so this socket escapes from SEND FAIL status - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _clear_socket_sending(id); _smutex.unlock(); tr_debug("close(%d): socket close OK with AT+CIPCLOSE OK", id); return true; @@ -1224,10 +1225,7 @@ void ESP8266::_oob_socket0_closed() static const int id = 0; _sock_i[id].open = false; // Closed, so this socket escapes from SEND FAIL status - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _clear_socket_sending(id); tr_debug("_oob_socket0_closed(): Socket %d closed.", id); } @@ -1236,10 +1234,7 @@ void ESP8266::_oob_socket1_closed() static const int id = 1; _sock_i[id].open = false; // Closed, so this socket escapes from SEND FAIL status - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _clear_socket_sending(id); tr_debug("_oob_socket1_closed(): Socket %d closed.", id); } @@ -1247,11 +1242,7 @@ void ESP8266::_oob_socket2_closed() { static const int id = 2; _sock_i[id].open = false; - // Closed, so this socket escapes from SEND FAIL status - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _clear_socket_sending(id); tr_debug("_oob_socket2_closed(): Socket %d closed.", id); } @@ -1259,11 +1250,7 @@ void ESP8266::_oob_socket3_closed() { static const int id = 3; _sock_i[id].open = false; - // Closed, so this socket escapes from SEND FAIL status - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _clear_socket_sending(id); tr_debug("_oob_socket3_closed(): %d closed.", id); } @@ -1272,10 +1259,7 @@ void ESP8266::_oob_socket4_closed() static const int id = 4; _sock_i[id].open = false; // Closed, so this socket escapes from SEND FAIL status - if (id == _sock_sending_id) { - _sock_sending_id = -1; - } - _sock_i[id].send_fail = false; + _clear_socket_sending(id); tr_debug("_oob_socket0_closed(): Socket %d closed.", id); } diff --git a/components/wifi/esp8266-driver/ESP8266/ESP8266.h b/components/wifi/esp8266-driver/ESP8266/ESP8266.h index 249c11e989..9c865af743 100644 --- a/components/wifi/esp8266-driver/ESP8266/ESP8266.h +++ b/components/wifi/esp8266-driver/ESP8266/ESP8266.h @@ -444,6 +444,7 @@ private: // data follows } *_packets, * *_packets_end; void _clear_socket_packets(int id); + void _clear_socket_sending(int id); int _sock_active_id; // Memory statistics