fix(modem): Consume buffer after handled URC (IDFGH-15245)

[dgrochowalski]

• return DTE::command_cb::process_line true if urc_handler command_result::OK

After getting URC event it was still in the buffer and after calling next AT command it was analyzing it again, which was causing doubled call of urc_handler.

[CLAassistant]

All committers have signed the CLA.

[dgrochowalski]

@david-cermak please verify if this change makes sense.

[david-cermak]

Good point, thanks.
Makes sense to consume the buffer if the lambda "says" ok.

[lolrobbe2]

@dgrochowalski, @david-cermak can't the if statement be simplefied to:

  if (urc_handler && urc_handler(data, consumed + len) == command_result::OK) {
    return true;
  }

What if URC's come seperated, or there are multiple URC's. it might be better to return the amount of bytes that ma be consumed

[david-cermak]

What if URC's come seperated?

This is still okay, we can choose to consume it (if we got all the pieces) are return OK from the handler or not (yet and return TIMEOUT) -- which is in line with how command lib parses partial responses.

The problem could be if the we get the URC and a potential command reply within a single callback -- if we choose consume it, we'd invalidate the simultaneous AT command -- this makes it harder for the application URC parser implementation.

[lolrobbe2]

normally all URC's are denoted by a + sign:

esp_modem::command_result KastaarModem::urcCallback(uint8_t *data, size_t len) 
{
    
    char *mutableData = reinterpret_cast<char *>(data);

    std::string_view view(mutableData, len);
    if(!view.ends_with("\r\n"))
      return esp_modem::command_result::TIMEOUT;
    /* We iterate over the view until no more URC's have been found */
    while (!view.empty()) {
        /* Attempt to find the end of the urc*/
        size_t start = view.find("\r\n");

        if (start == std::string_view::npos) {
            break;
        }

        // Remove everything before and including first \r\n
        view.remove_prefix(start + 2);

        // Step 2: Look for the next \r\n (end of URC)
        size_t end = view.find("\r\n");
        if (end == std::string_view::npos) {
            break;
        }

        std::string_view line = view.substr(0, end);
        if(line.starts_with("+"))
        {
          urcHandler(line);
        }
        
        view.remove_prefix(end + 2); // Move past the line and \r\n
    }
    return esp_modem::command_result::OK;
}

this function seperates the URC's for individual handeling and works if i temporaly disable the urc-handler during the AT-command and reenable afterwards, and it can handle multiple simultanious URC's togheter.

[lolrobbe2]

@david-cermak otherwise LGTM now

[david-cermak]

if i temporaly disable the urc-handler during the AT-command

This still worries me, though. Maybe we could just save the urc_handler()'s return value and return it instead of false later.
I'll think about it, thanks @lolrobbe2 for chiming in!

[david-cermak]

something like:

Suggested change

	if (urc_handler(data, consumed + len) == command_result::OK) {
	return true;
	}
	#define FALSE_OR_URC_RET (ret == command_result::OK ? true : false)
	auto ret = urc_handler(data, consumed + len);

and later

#ifndef CONFIG_ESP_MODEM_URC_HANDLER
#define FALSE_OR_URC_RET false
#else
...
...
return FALSE_OR_URC_RET

[lolrobbe2]

@david-cermak i think maby we just keep a seperate offset for the URC handler and when it is consumed we reset it.
that way when the got_line forces the buffer to be consumed we can be sure AT commands can still listen for them.

I also stumbled on the same problem writing the modem ofloading for Walter.

as the SQNGM02S uses URC's to read the data from example a socket, it would be nice to have control over wich URC's are passed allong, consumed.

(TX) AT+SQNSRECV: 1,1500 \r\n
(RX) +SQNSRECV: 1,300\r\n<DATA>\r\nOK\r\n

AT+SQNSRECV: <ID>,<MAX_BYTES><CRLF>
+SQNSRECV: <ID>,<BYTES_READ><CRLF><DATA><OK>

[lolrobbe2]

@david-cermak gonna try a couple ideas and report back!

[lolrobbe2]

@david-cermak turns out the solution was rather simple:

instead of returning imediatly we store the result of the urc_handler, and then later on we let the got_line function go trough, if they both are finished.
then we consume the buffer.

bool DTE::command_cb::process_line(uint8_t *data, size_t consumed, size_t len)
{
#ifdef CONFIG_ESP_MODEM_URC_HANDLER
    command_result commandResult = command_result::FAIL;
    if (urc_handler) {
        commandResult = urc_handler(data , consumed + len);
    }
    if (result != command_result::TIMEOUT && got_line == nullptr) {
        return false;
    }
#endif
    if (memchr(data + consumed, separator, len)) {
        result = got_line(data + consumed, consumed + len);
        if (result == command_result::OK || result == command_result::FAIL) {
            signal.set(GOT_LINE);
#ifdef CONFIG_ESP_MODEM_URC_HANDLER
            return commandResult == command_result::OK;
#else
            return true;
#endif
        }
    }
    return false;
}

[david-cermak]

Thanks for the investigation! Looks nice (that's what I "kind of" meant by the FALSE_OR_URC_RET macro -- but only in general ideas -- now you turned it into a working code)

[lolrobbe2]

@david-cermak as promised i did some testing and the following is very promosing, and has been tested:

by adding an urc_offset we can controll when the buffer should be consumed but consumation happens after the AT-COMMAND or when everything has been consumed.

there a re probably some parts i have missed, but this works reliably.

updated process_line:

bool DTE::command_cb::process_line(uint8_t *data, size_t consumed, size_t len)
{
#ifdef CONFIG_ESP_MODEM_URC_HANDLER
    if (urc_handler) {
        urc_offset += urc_handler(data + urc_offset, consumed + len - urc_offset);
    }
    if (result != command_result::TIMEOUT || got_line == nullptr) {
        return false;   // this line has been processed already (got OK or FAIL previously)
    }
#endif
    if (memchr(data + consumed, separator, len)) {
        result = got_line(data + urc_offset, consumed + len - urc_offset);
        if (result == command_result::OK || result == command_result::FAIL) {
            signal.set(GOT_LINE);
            return true;
        }
    }
    return false;
}

updated command_cb struct

    /**
     * @brief This abstracts command callback processing and implements its locking, signaling of completion and timeouts.
     */
    struct command_cb {
#ifdef CONFIG_ESP_MODEM_URC_HANDLER
        urc_line_cb urc_handler {};                             /*!< URC callback if enabled */
        uint32_t urc_offset = 0;                                /*!< URC callback buffer offset if enabled */
#endif

added URC line handler:

typedef std::function<command_result(uint8_t *data, size_t len)> got_line_cb;
#ifdef CONFIG_ESP_MODEM_URC_HANDLER
    typedef std::function<uint32_t(uint8_t *data, size_t len)> urc_line_cb;
#endif

updated URC line handler with blacklisting:

uint32_t KastaarModem::urcCallback(uint8_t *data, size_t len) 
{
    static const std::list<std::string_view> urcBlacklist = {
        "SQNSRECV",
        "CEREG: 5"
    };
    
    char *mutableData = reinterpret_cast<char *>(data);
    uint32_t bytesRead = 0;
    std::string_view view(mutableData, len);
    if(!view.ends_with("\r\n"))
      return 0;
    /* We iterate over the view until no more URC's have been found */
    while (!view.empty()) {
        
        /* Attempt to find the end of the urc*/
        size_t start = view.find("\r\n");

        if (start == std::string_view::npos) {
            break;
        }

        // Remove everything before and including first \r\n
        view.remove_prefix(start + 2);

        // Step 2: Look for the next \r\n (end of URC)
        size_t end = view.find("\r\n");
        if (end == std::string_view::npos) {
            break;
        }

        std::string_view line = view.substr(0, end);
        if(line.starts_with("+"))
        {
          for (const std::string_view &prefix : urcBlacklist) {
            if (line.contains(prefix)) {
              return bytesRead;
            }
          }
          urcHandler(line);
          bytesRead += line.size() + 4 + start;
        } else {
          break;
        }
        
        view.remove_prefix(end + 2); // Move past the line and \r\n
    }
    return bytesRead;
}