Espressif_MQTT_Client.h parsing problem in ESP-IDF

[maheru8]

I wasn't receiving shared attribute updates at all using demo code (with server, device key and variable names changed).
When I turned on THINGSBOARD_ENABLE_DEBUG I saw weird lines in the log:

[TB] Handling received mqtt event: (MQTT_EVENT_DATA)
[TB] Received data: {"heatingTemp":21}alse} Topic: v1/devices/me/attributes{"heatingTemp":21}alse} Len: 18
[TB] Received (18) bytes of data from server over topic (v1/devices/me/attributes{"heatingTemp":21}alse})
[TB] Allocated internal JsonDocument for MQTT server response with size (128)

This is mqtt_event_handler from Espressif_MQTT_Client.h before:

/// @brief Event handler registered to receive MQTT events. Is called by the MQTT client event loop, whenever a new event occurs
    /// @param base Event base for the handler
    /// @param event_id The id for the received event
    /// @param event_data The data for the event, esp_mqtt_event_handle_t
    void mqtt_event_handler(esp_event_base_t base, esp_mqtt_event_id_t const & event_id, void * event_data) {
        esp_mqtt_event_handle_t const event = static_cast<esp_mqtt_event_handle_t>(event_data);

#if THINGSBOARD_ENABLE_DEBUG
        Logger::printfln(RECEIVED_MQTT_EVENT, esp_event_id_to_name(event_id));
#endif // THINGSBOARD_ENABLE_DEBUG
        switch (event_id) {
            case esp_mqtt_event_id_t::MQTT_EVENT_CONNECTED:
                m_connected = true;
                m_connected_callback.Call_Callback();
                break;
            case esp_mqtt_event_id_t::MQTT_EVENT_DISCONNECTED:
                m_connected = false;
                break;
            case esp_mqtt_event_id_t::MQTT_EVENT_DATA:
                // Check wheter the given message has not bee received completly, but instead would be received in multiple chunks,
                // if it were we discard the message because receiving a message over multiple chunks is currently not supported
                if (event->data_len != event->total_data_len) {
                    Logger::printfln(MQTT_DATA_EXCEEDS_BUFFER, event->total_data_len, get_buffer_size());
                    break;
                }
                m_received_data_callback.Call_Callback(event->topic, reinterpret_cast<uint8_t*>(event->data), event->data_len);
                break;
            default:
                // Nothing to do
                break;
        }
    }

and after the change:

    /// @brief Event handler registered to receive MQTT events. Is called by the MQTT client event loop, whenever a new event occurs
    /// @param base Event base for the handler
    /// @param event_id The id for the received event
    /// @param event_data The data for the event, esp_mqtt_event_handle_t
    void mqtt_event_handler(esp_event_base_t base, esp_mqtt_event_id_t const & event_id, void * event_data) {
        esp_mqtt_event_handle_t const event = static_cast<esp_mqtt_event_handle_t>(event_data);

#if THINGSBOARD_ENABLE_DEBUG
        Logger::printfln(RECEIVED_MQTT_EVENT, esp_event_id_to_name(event_id));
#endif // THINGSBOARD_ENABLE_DEBUG

        switch (event_id) {
            case esp_mqtt_event_id_t::MQTT_EVENT_CONNECTED:
                m_connected = true;
                m_connected_callback.Call_Callback();
                break;
            case esp_mqtt_event_id_t::MQTT_EVENT_DISCONNECTED:
                m_connected = false;
                break;
            case esp_mqtt_event_id_t::MQTT_EVENT_DATA: {
                // Check whether the message has been received completely
                if (event->data_len != event->total_data_len) {
                    Logger::printfln(MQTT_DATA_EXCEEDS_BUFFER, event->total_data_len, get_buffer_size());
                    break;
                }

                // Allocate a buffer for the topic and null-terminate it
                char topic[256]; // Adjust size as needed based on your maximum expected topic length
                if (event->topic_len < sizeof(topic)) {
                    memcpy(topic, event->topic, event->topic_len);
                    topic[event->topic_len] = '\0';
                } else {
                    // Handle topic length exceeding buffer size
                    memcpy(topic, event->topic, sizeof(topic) - 1);
                    topic[sizeof(topic) - 1] = '\0';
                }

                // Now pass the null-terminated topic to the callback
                m_received_data_callback.Call_Callback(topic, reinterpret_cast<uint8_t*>(event->data), event->data_len);
                break;
            }
            default:
                // Handle other events as needed
                break;
        }
    }

Now everything works, but I think it's a bug, so you can fix it in future version.

[MathewHDYT]

The output is only weird, because you print out non-terminated strings like it is a null-terminated string. If you measure the characters you can see that {"heatingTemp":21} has indeed a size of 18.
So the received data is corect and works as expected.

Which version of the library are you using, because a similair issue has been fixed previously and additionally can you enable THINGSBOARD_ENABLE_DEBUG on the top of your main.cpp file instead of a local file in the library, because you currently only enable debug mode for that specific file instead of the whole library.

[maheru8]

I use this versions:

dependencies:
  bblanchon/arduinojson:
    component_hash: 463812931f99cb7a554d64311288f537b43daaca3eed2427557b907af393447c
    dependencies: []
    source:
      registry_url: https://components.espressif.com
      type: service
    version: 6.21.5
  idf:
    source:
      type: idf
    version: 5.3.1
  thingsboard/thingsboard:
    component_hash: 9ad01bde84b322c01f36e1d3f6bb036cc86acac58c87a7f4a43328ced240fd3e
    dependencies:
    - name: idf
      registry_url: https://components.espressif.com
      require: private
      version: '*'
    - name: bblanchon/arduinojson
      registry_url: https://components.espressif.com
      require: private
      version: ^6.21.5
    source:
      registry_url: https://components.espressif.com/
      type: service
    version: 0.14.0
direct_dependencies:
- idf
- thingsboard/thingsboard
manifest_hash: fd7c1ec86f2e90e5e2b8e58fe6a6a0381e8c7d159a11ff3cb5c788a510af4ef6
target: esp32s3
version: 2.0.0

Using example named "0017-espressif_esp32_process_shared_attribute_update", which is available on ESP Component Registry under Examples, I can't get my shared attributes when I update them on thingsboard. I have THINGSBOARD_ENABLE_DEBUG enabled on top of my main.cpp and I can see in debug log that attributes are received on MQTT socket using this example script, but my callback function is never called so I didn't receive any parameters in my main code. After code change specified in my first comment everything worked.

[MathewHDYT]

The issue is exactly the case you mentioned debugged it further and confirmed it. It occurs because the EspressifMQTTClient received a non null-terminated string and therefore latter strncmp that also compare the null termination fail.

I implemented my own fix that reduces the required steps because the topic size can simply be read from the topic_len and therefore also simply used as the size of the new topic.

char topic[event->topic_len + 1] = {};
strncpy(topic, event->topic, event->topic_len);

Has been commited into the pull request, as soon as it has been merged and released the issue will be fixed. For now simply apply the patch locally.

[maheru8]

Thank you for very quick response and fix!