fix(esp_modem): DTE command race of timeout vs reply's signal

Race condtion:
* First command timeouted, but the reply came just after evaluation and
set signal variable to GOT_LINE
* Second command should timeout too, but a consistency check validates
that it timeouted and at the same time GOT_LINE (from previous step) and
throws an exception

STR:
* Revert change in esp_modem_dte.cpp
* Run TEST_CASE("DTE command races", "[esp_modem]")

Closes https://github.com/espressif/esp-protocols/issues/110

components/esp_modem/src/esp_modem_dte.cpp

@@ -36,6 +36,7 @@ command_result DTE::command(const std::string &command, got_line_cb got_line, ui
 {
     Scoped<Lock> l(internal_lock);
     command_result res = command_result::TIMEOUT;
+    signal.clear(GOT_LINE);
     command_term->set_read_cb([&](uint8_t *data, size_t len) {
         if (!data) {
             data = buffer.get();

components/esp_modem/test/host_test/main/LoopbackTerm.cpp

@@ -17,6 +17,7 @@ int LoopbackTerm::write(uint8_t *data, size_t len)
 {
     if (inject_by) {    // injection test: ignore what we write, but respond with injected data
         auto ret = std::async(&LoopbackTerm::batch_read, this);
+        async_results.push_back(std::move(ret));
         return len;
     }
     if (len > 2 && (data[len - 1] == '\r' || data[len - 1] == '+') ) { // Simple AT responder
@@ -99,7 +100,7 @@ LoopbackTerm::LoopbackTerm(bool is_bg96): loopback_data(), data_len(0), pin_ok(f
 
 LoopbackTerm::LoopbackTerm(): loopback_data(), data_len(0), pin_ok(false), is_bg96(false), inject_by(0) {}
 
-int LoopbackTerm::inject(uint8_t *data, size_t len, size_t injected_by)
+int LoopbackTerm::inject(uint8_t *data, size_t len, size_t injected_by, size_t delay_before, size_t delay_after)
 {
     if (data == nullptr) {
         inject_by = 0;
@@ -110,14 +111,20 @@ int LoopbackTerm::inject(uint8_t *data, size_t len, size_t injected_by)
     memcpy(&loopback_data[0], data, len);
     data_len = len;
     inject_by = injected_by;
+    delay_after_inject = delay_after;
+    delay_before_inject = delay_before;
     return len;
 }
 
 void LoopbackTerm::batch_read()
 {
     while (data_len > 0) {
+        Task::Delay(delay_before_inject);
+        {
+            Scoped<Lock> lock(on_read_guard);
             on_read(nullptr, std::min(inject_by, data_len));
-        Task::Delay(1);
+        }
+        Task::Delay(delay_after_inject);
     }
 }
 

components/esp_modem/test/host_test/main/LoopbackTerm.h

@@ -17,7 +17,7 @@ public:
      * inject_by defines batch sizes: the read callback is called multiple times
      * with partial data of `inject_by` size
      */
-    int inject(uint8_t *data, size_t len, size_t inject_by);
+    int inject(uint8_t *data, size_t len, size_t inject_by,size_t delay_before=0, size_t delay_after=1);
 
     void start() override;
     void stop() override;
@@ -26,6 +26,12 @@ public:
 
     int read(uint8_t *data, size_t len) override;
 
+    void set_read_cb(std::function<bool(uint8_t *data, size_t len)> f) override
+    {
+        Scoped<Lock> lock(on_read_guard);
+        on_read = std::move(f);
+    }
+
 private:
     enum class status_t {
         STARTED,
@@ -39,4 +45,9 @@ private:
     bool pin_ok;
     bool is_bg96;
     size_t inject_by;
+    size_t delay_before_inject;
+    size_t delay_after_inject;
+    std::vector<std::future<void>> async_results;
+    Lock on_read_guard;
+
 };

components/esp_modem/test/host_test/main/test_modem.cpp

@@ -7,6 +7,28 @@
 
 using namespace esp_modem;
 
+TEST_CASE("DTE command races", "[esp_modem]") {
+    auto term = std::make_unique<LoopbackTerm>(true);
+    auto loopback = term.get();
+    auto dte = std::make_shared<DTE>(std::move(term));
+    CHECK(term == nullptr);
+    esp_modem_dce_config_t dce_config = ESP_MODEM_DCE_DEFAULT_CONFIG("APN");
+    esp_netif_t netif{};
+    auto dce = create_BG96_dce(&dce_config, dte, &netif);
+    CHECK(dce != nullptr);
+    uint8_t resp[] = {'O', 'K', '\n'};
+    // run many commands in succession with the timeout set exactly to the timespan of injected reply
+    // (checks for potential exception, data races, recycled local variables, etc.)
+    for (int i=0; i<1000; ++i) {
+        loopback->inject(&resp[0], sizeof(resp), sizeof(resp), /* 1ms before injecting reply */1, 0);
+        auto ret = dce->command("AT\n", [&](uint8_t *data, size_t len) {
+            return command_result::OK;
+        }, 1);
+        // this command should either timeout or finish successfully
+        CHECK((ret == command_result::TIMEOUT || ret == command_result::OK));
+    }
+}
+
 TEST_CASE("Test polymorphic delete for custom device/dte", "[esp_modem]")
 {
     auto term = std::make_unique<LoopbackTerm>(true);