fix(modem): More error handling in cmux protocol

Add error path to all CMUX protocol potential issues, checks for
consistency and add recovery.

components/esp_modem/Kconfig

@@ -36,4 +36,13 @@ menu "esp-modem"
             The typical reason for failing SABM request without a delay is that
             some devices (SIM800) send MSC requests just after opening a new DLCI.
 
+    config ESP_MODEM_CMUX_USE_SHORT_PAYLOADS_ONLY
+        bool "CMUX to support only short payloads (<128 bytes)"
+        default n
+        help
+            If enabled, the CMUX protocol would only use 1 byte size field.
+            You can use this option for devices that support only short CMUX payloads
+            to make the protocol more robust on noisy environments or when underlying
+            transport gets corrupted often (for example by Rx buffer overflows)
+
 endmenu

components/esp_modem/include/cxx_include/esp_modem_cmux.hpp

@@ -1,5 +1,5 @@
 /*
- * SPDX-FileCopyrightText: 2021-2022 Espressif Systems (Shanghai) CO LTD
+ * SPDX-FileCopyrightText: 2021-2023 Espressif Systems (Shanghai) CO LTD
  *
  * SPDX-License-Identifier: Apache-2.0
  */
@@ -86,9 +86,30 @@ class CMux {
      */
     int write(int i, uint8_t *data, size_t len);
 
+    /**
+     * @brief Recovers the protocol
+     *
+     * This restarts the CMUX state machine, which could have been in a wrong state due to communication
+     * issue on a lower layer.
+     *
+     * @return true on success
+     */
+    bool recover();
+
 private:
+
+    enum class protocol_mismatch_reason {
+        MISSED_LEAD_SOF,
+        MISSED_TRAIL_SOF,
+        WRONG_CRC,
+        UNEXPECTED_HEADER,
+        UNEXPECTED_DATA,
+        READ_BEHIND_BUFFER,
+        UNKNOWN
+    };
+
     static uint8_t fcs_crc(const uint8_t frame[6]);     /*!< Utility to calculate FCS CRC */
-    void data_available(uint8_t *data, size_t len);     /*!< Called when valid data available */
+    bool data_available(uint8_t *data, size_t len);     /*!< Called when valid data available (returns false on unexpected data format) */
     void send_sabm(size_t i);                           /*!< Sending initial SABM */
     void send_disconnect(size_t i);                     /*!< Sending closing request for each virtual or control terminal */
     bool on_cmux_data(uint8_t *data, size_t len);       /*!< Called from terminal layer when raw CMUX protocol data available */
@@ -105,6 +126,7 @@ class CMux {
     bool on_header(CMuxFrame &frame);
     bool on_payload(CMuxFrame &frame);
     bool on_footer(CMuxFrame &frame);
+    void recover_protocol(protocol_mismatch_reason reason);
 
     std::function<bool(uint8_t *data, size_t len)> read_cb[MAX_TERMINALS_NUM];  /*!< Function pointers to read callbacks */
     std::shared_ptr<Terminal> term;                   /*!< The original terminal */

components/esp_modem/include/cxx_include/esp_modem_dce.hpp

@@ -84,6 +84,11 @@ class DCE_T {
         return mode.set(dte.get(), device.get(), netif, m);
     }
 
+    bool recover()
+    {
+        return dte->recover();
+    }
+
 protected:
     std::shared_ptr<DTE> dte;
     std::shared_ptr<SpecificModule> device;

components/esp_modem/include/cxx_include/esp_modem_dte.hpp

@@ -1,5 +1,5 @@
 /*
- * SPDX-FileCopyrightText: 2021-2022 Espressif Systems (Shanghai) CO LTD
+ * SPDX-FileCopyrightText: 2021-2023 Espressif Systems (Shanghai) CO LTD
  *
  * SPDX-License-Identifier: Apache-2.0
  */
@@ -115,6 +115,13 @@ class DTE : public CommandableIf {
      */
     command_result command(const std::string &command, got_line_cb got_line, uint32_t time_ms, char separator) override;
 
+    /**
+     * @brief Allows this DTE to recover from a generic connection issue
+     *
+     * @return true if success
+     */
+    bool recover();
+
 protected:
     /**
      * @brief Allows for locking the DTE
@@ -130,6 +137,7 @@ class DTE : public CommandableIf {
     friend class Scoped<DTE>;                               /*!< Declaring "Scoped<DTE> lock(dte)" locks this instance */
 private:
 
+    void handle_error(terminal_error err);                  /*!< Performs internal error handling */
     [[nodiscard]] bool setup_cmux();                        /*!< Internal setup of CMUX mode */
     [[nodiscard]] bool exit_cmux();                         /*!< Exit of CMUX mode and cleanup  */
     void exit_cmux_internal();                              /*!< Cleanup CMUX */
@@ -141,6 +149,7 @@ class DTE : public CommandableIf {
     std::shared_ptr<Terminal> secondary_term;               /*!< Secondary terminal for this DTE */
     modem_mode mode;                                        /*!< DTE operation mode */
     std::function<bool(uint8_t *data, size_t len)> on_data; /*!< on data callback for current terminal */
+    std::function<void(terminal_error err)> user_error_cb;  /*!< user callback on error event from attached terminals */
 
 #ifdef CONFIG_ESP_MODEM_USE_INFLATABLE_BUFFER_IF_NEEDED
     /**
@@ -189,14 +198,22 @@ class DTE : public CommandableIf {
         command_result result{};                                /*!< Command return code */
         SignalGroup signal;                                     /*!< Event group used to signal request-response operations */
         bool process_line(uint8_t *data, size_t consumed, size_t len);  /*!< Lets the processing callback handle one line (processing unit) */
-        bool wait_for_line(uint32_t time_ms);                   /*!< Waiting for command processing */
+        bool wait_for_line(uint32_t time_ms)                    /*!< Waiting for command processing */
+        {
+            return signal.wait_any(command_cb::GOT_LINE, time_ms);
+        }
         void set(got_line_cb l, char s = '\n')                  /*!< Sets the command callback atomically */
         {
             Scoped<Lock> lock(line_lock);
             if (l) {
                 // if we set the line callback, we have to reset the signal and the result
                 signal.clear(GOT_LINE);
                 result = command_result::TIMEOUT;
+            } else {
+                // if we clear the line callback, we check consistency (since we've locked the line processing)
+                if (signal.is_any(command_cb::GOT_LINE) && result == command_result::TIMEOUT) {
+                    ESP_MODEM_THROW_IF_ERROR(ESP_ERR_INVALID_STATE);
+                }
             }
             got_line = std::move(l);
             separator = s;

components/esp_modem/src/esp_modem_cmux.cpp

@@ -1,5 +1,5 @@
 /*
- * SPDX-FileCopyrightText: 2021-2022 Espressif Systems (Shanghai) CO LTD
+ * SPDX-FileCopyrightText: 2021-2023 Espressif Systems (Shanghai) CO LTD
  *
  * SPDX-License-Identifier: Apache-2.0
  */
@@ -113,7 +113,7 @@ struct CMux::CMuxFrame {
     }
 };
 
-void CMux::data_available(uint8_t *data, size_t len)
+bool CMux::data_available(uint8_t *data, size_t len)
 {
     if (data && (type & FT_UIH) == FT_UIH && len > 0 && dlci > 0) { // valid payload on a virtual term
         int virtual_term = dlci - 1;
@@ -128,32 +128,38 @@ void CMux::data_available(uint8_t *data, size_t len)
 #else
             read_cb[virtual_term](data, len);
 #endif
+        } else {
+            return false;
         }
-    } else if (data == nullptr && type == 0x73 && len == 0) { // notify the initial SABM command
+    } else if (data == nullptr && type == (FT_UA | PF) && len == 0) { // notify the initial SABM command
         Scoped<Lock> l(lock);
         sabm_ack = dlci;
-    } else if (data == nullptr) {
+    } else if (data == nullptr && dlci > 0) {
         int virtual_term = dlci - 1;
         if (virtual_term < MAX_TERMINALS_NUM && read_cb[virtual_term]) {
 #ifdef DEFRAGMENT_CMUX_PAYLOAD
             read_cb[virtual_term](payload_start, total_payload_size);
 #endif
+        } else {
+            return false;
         }
     } else if ((type & FT_UIH) == FT_UIH && dlci == 0) { // notify the internal DISC command
         if (len > 0 && (data[0] & 0xE1) == 0xE1) {
             // Not a DISC, ignore (MSC frame)
-            return;
+            return true;
         }
         Scoped<Lock> l(lock);
         sabm_ack = dlci;
+    } else {
+        return false;
     }
+    return true;
 }
 
 bool CMux::on_init(CMuxFrame &frame)
 {
     if (frame.ptr[0] != SOF_MARKER) {
-        ESP_LOGW("CMUX", "Protocol mismatch: Missed leading SOF, recovering...");
-        state = cmux_state::RECOVER;
+        recover_protocol(protocol_mismatch_reason::MISSED_LEAD_SOF);
         return true;
     }
     if (frame.len > 1 && frame.ptr[1] == SOF_MARKER) {
@@ -206,6 +212,7 @@ bool CMux::on_header(CMuxFrame &frame)
     }
     size_t payload_offset = std::min(frame.len, 4 - frame_header_offset);
     memcpy(frame_header + frame_header_offset, frame.ptr, payload_offset);
+#ifndef ESP_MODEM_CMUX_USE_SHORT_PAYLOADS_ONLY
     if ((frame_header[3] & 1) == 0) {
         if (frame_header_offset + frame.len <= 4) {
             frame_header_offset += frame.len;
@@ -215,12 +222,21 @@ bool CMux::on_header(CMuxFrame &frame)
         memcpy(frame_header + frame_header_offset, frame.ptr, payload_offset);
         payload_len = frame_header[4] << 7;
         frame_header_offset += payload_offset - 1; // rewind frame_header back to hold only 6 bytes size
-    } else {
+    } else
+#endif // ! ESP_MODEM_CMUX_USE_SHORT_PAYLOADS_ONLY
+    {
         payload_len = 0;
         frame_header_offset += payload_offset;
     }
     dlci = frame_header[1] >> 2;
     type = frame_header[2];
+    // Sanity check for expected values of DLCI and type,
+    // since CRC could be evaluated after the frame payload gets received
+    if (dlci > MAX_TERMINALS_NUM || (frame_header[1] & 0x01) == 0 ||
+            (((type & FT_UIH) != FT_UIH) &&  type != (FT_UA | PF) ) ) {
+        recover_protocol(protocol_mismatch_reason::UNEXPECTED_HEADER);
+        return true;
+    }
     payload_len += (frame_header[3] >> 1);
     frame.advance(payload_offset);
     state = cmux_state::PAYLOAD;
@@ -232,12 +248,18 @@ bool CMux::on_payload(CMuxFrame &frame)
     ESP_LOGD("CMUX", "Payload frame: dlci:%02x type:%02x payload:%d available:%d", dlci, type, payload_len, frame.len);
     if (frame.len < payload_len) { // payload
         state = cmux_state::PAYLOAD;
-        data_available(frame.ptr, frame.len); // partial read
+        if (!data_available(frame.ptr, frame.len)) { // partial read
+            recover_protocol(protocol_mismatch_reason::UNEXPECTED_DATA);
+            return true;
+        }
         payload_len -= frame.len;
         return false;
     } else { // complete
         if (payload_len > 0) {
-            data_available(&frame.ptr[0], payload_len); // rest read
+            if (!data_available(&frame.ptr[0], payload_len)) { // rest read
+                recover_protocol(protocol_mismatch_reason::UNEXPECTED_DATA);
+                return true;
+            }
         }
         frame.advance((payload_len));
         state = cmux_state::FOOTER;
@@ -257,16 +279,23 @@ bool CMux::on_footer(CMuxFrame &frame)
         footer_offset = std::min(frame.len, 6 - frame_header_offset);
         memcpy(frame_header + frame_header_offset, frame.ptr, footer_offset);
         if (frame_header[5] != SOF_MARKER) {
-            ESP_LOGW("CMUX", "Protocol mismatch: Missed trailing SOF, recovering...");
-            payload_start = nullptr;
-            total_payload_size = 0;
-            state = cmux_state::RECOVER;
+            recover_protocol(protocol_mismatch_reason::MISSED_TRAIL_SOF);
             return true;
         }
+#ifdef ESP_MODEM_CMUX_USE_SHORT_PAYLOADS_ONLY
+        uint8_t crc = 0xFF - fcs_crc(frame_header);
+        if (crc != frame_header[4]) {
+            recover_protocol(protocol_mismatch_reason::WRONG_CRC);
+            return true;
+        }
+#endif
         frame.advance(footer_offset);
         state = cmux_state::INIT;
         frame_header_offset = 0;
-        data_available(nullptr, 0);
+        if (!data_available(nullptr, 0)) {
+            recover_protocol(protocol_mismatch_reason::UNEXPECTED_DATA);
+            return true;
+        }
         payload_start = nullptr;
         total_payload_size = 0;
     }
@@ -280,7 +309,28 @@ bool CMux::on_cmux_data(uint8_t *data, size_t actual_len)
         auto data_to_read = buffer.size - 128; // keep 128 (max CMUX payload) backup buffer)
         if (payload_start) {
             data = payload_start + total_payload_size;
-            data_to_read = payload_len + 2;
+            auto data_end = buffer.get() + buffer.size;
+            data_to_read = payload_len + 2; // 2 -- CMUX protocol footer
+            if (data + data_to_read >= data_end) {
+                ESP_LOGW("CUMX", "Failed to defragment longer payload (payload=%d)", payload_len);
+                // If you experience this error, your device uses longer payloads while
+                // the configured buffer is too small to defragment the payload properly.
+                // To resolve this issue you can:
+                // * Either increase `dte_buffer_size`
+                // * Or disable `ESP_MODEM_CMUX_DEFRAGMENT_PAYLOAD` in menuconfig
+
+                // Attempts to process the data accumulated so far (rely on upper layers to process correctly)
+                data_available(nullptr, 0);
+                if (payload_len > total_payload_size) {
+                    payload_start = nullptr;
+                    total_payload_size = 0;
+                } else {
+                    // cannot continue with this payload, give-up and recover the protocol
+                    recover_protocol(protocol_mismatch_reason::READ_BEHIND_BUFFER);
+                }
+                data_to_read = buffer.size;
+                data = buffer.get();
+            }
         } else {
             data = buffer.get();
         }
@@ -435,3 +485,19 @@ std::pair<std::shared_ptr<Terminal>, unique_buffer> CMux::detach()
 {
     return std::make_pair(std::move(term), std::move(buffer));
 }
+
+void esp_modem::CMux::recover_protocol(protocol_mismatch_reason reason)
+{
+    ESP_LOGW("CMUX", "Restarting CMUX state machine (reason: %d)", static_cast<int>(reason));
+    payload_start = nullptr;
+    total_payload_size = 0;
+    frame_header_offset = 0;
+    state = cmux_state::RECOVER;
+}
+
+bool CMux::recover()
+{
+    Scoped<Lock> l(lock);
+    recover_protocol(protocol_mismatch_reason::UNKNOWN);
+    return true;
+}

components/esp_modem/src/esp_modem_dte.cpp

@@ -1,5 +1,5 @@
 /*
- * SPDX-FileCopyrightText: 2021-2022 Espressif Systems (Shanghai) CO LTD
+ * SPDX-FileCopyrightText: 2021-2023 Espressif Systems (Shanghai) CO LTD
  *
  * SPDX-License-Identifier: Apache-2.0
  */
@@ -115,6 +115,19 @@ void DTE::set_command_callbacks()
         return true;
 #endif
     });
+    primary_term->set_error_cb([this](terminal_error err) {
+        if (user_error_cb) {
+            user_error_cb(err);
+        }
+        handle_error(err);
+    });
+    secondary_term->set_error_cb([this](terminal_error err) {
+        if (user_error_cb) {
+            user_error_cb(err);
+        }
+        handle_error(err);
+    });
+
 }
 
 command_result DTE::command(const std::string &command, got_line_cb got_line, uint32_t time_ms, const char separator)
@@ -272,8 +285,8 @@ void DTE::set_read_cb(std::function<bool(uint8_t *, size_t)> f)
 
 void DTE::set_error_cb(std::function<void(terminal_error err)> f)
 {
-    secondary_term->set_error_cb(f);
-    primary_term->set_error_cb(f);
+    user_error_cb = std::move(f);
+    set_command_callbacks();
 }
 
 int DTE::read(uint8_t **d, size_t len)
@@ -330,13 +343,21 @@ bool DTE::command_cb::process_line(uint8_t *data, size_t consumed, size_t len)
     return false;
 }
 
-bool DTE::command_cb::wait_for_line(uint32_t time_ms)
+bool DTE::recover()
+{
+    if (mode == modem_mode::CMUX_MODE || mode == modem_mode::CMUX_MANUAL_MODE || mode == modem_mode::DUAL_MODE) {
+        return cmux_term->recover();
+    }
+    return false;
+}
+
+void DTE::handle_error(terminal_error err)
 {
-    auto got_lf = signal.wait(command_cb::GOT_LINE, time_ms);
-    if (got_lf && result == command_result::TIMEOUT) {
-        ESP_MODEM_THROW_IF_ERROR(ESP_ERR_INVALID_STATE);
+    if (err == terminal_error::BUFFER_OVERFLOW ||
+            err == terminal_error::CHECKSUM_ERROR ||
+            err == terminal_error::UNEXPECTED_CONTROL_FLOW) {
+        recover();
     }
-    return got_lf;
 }
 
 #ifdef CONFIG_ESP_MODEM_USE_INFLATABLE_BUFFER_IF_NEEDED