Only first chunk of esp_mqtt_event_handle_t contains message topic (IDFGH-11179)

[tajnymag]

Answers checklist.

• I have read the documentation for esp-protocols components and the issue is not addressed there.
• I have updated my esp-protocols branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report

When mqtt client receives data in multiple chunks, events after the first chunk are missing topic. This makes it hard to distinguish, which handler should handle the incoming event.

I've tried to find more info about the expected behavior but failed to do so. The tcp example of esp_mqtt_cxx however tries to read the topic regardless of the chunk order. Same with the pure mqtt_client example.

Here's my minimal reproducible project which shows the behavior: tajnymag/esp-idf-mqtt-empty-topic-poc

The system crash in the logs is not directly related to the issue. It is only a consequence of the example trying to access the empty topic pointer.

Steps to reproduce

1. set connection options in Example Configuration in sdkconfig/menuconfig
2. build, flash and run the project binary
3. send a message to topic example/topic which doesn't fit the default mqtt message buffer. In my case sending large_payload.bin over a mosquitto broker (both local and cloud behave the same)

# in my case running
mosquitto_pub -h mqtt.eclipseprojects.io -t example/topic -f large_payload.bin

4. observe the output in the monitor

Expected output

I (45150) mqtt_client_cpp: MQTT_EVENT_DATA
I (45150) MQTT_EXAMPLE: Received message with msg_id: 0
I (45160) MQTT_EXAMPLE:  - event_id: 6
I (45160) MQTT_EXAMPLE:  - topic: example/topic
I (45160) MQTT_EXAMPLE:  - topic_len: 13
I (45170) MQTT_EXAMPLE:  - total_data_len: 1048576
I (45170) MQTT_EXAMPLE:  - data_len: 1005
I (45180) MQTT_EXAMPLE:  - current_data_offset: 0
I (45180) MQTT_EXAMPLE: Received in the messages topic
I (45190) mqtt_client_cpp: MQTT_EVENT_DATA
I (45190) MQTT_EXAMPLE: Received message with msg_id: 0
I (45200) MQTT_EXAMPLE:  - event_id: 6
I (45200) MQTT_EXAMPLE:  - topic: example/topic
I (45210) MQTT_EXAMPLE:  - topic_len: 13
I (45210) MQTT_EXAMPLE:  - total_data_len: 1048576
I (45220) MQTT_EXAMPLE:  - data_len: 1024
I (45220) MQTT_EXAMPLE:  - current_data_offset: 1005

Actual output

I (45150) mqtt_client_cpp: MQTT_EVENT_DATA
I (45150) MQTT_EXAMPLE: Received message with msg_id: 0
I (45160) MQTT_EXAMPLE:  - event_id: 6
I (45160) MQTT_EXAMPLE:  - topic: example/topic
I (45160) MQTT_EXAMPLE:  - topic_len: 13
I (45170) MQTT_EXAMPLE:  - total_data_len: 1048576
I (45170) MQTT_EXAMPLE:  - data_len: 1005
I (45180) MQTT_EXAMPLE:  - current_data_offset: 0
I (45180) MQTT_EXAMPLE: Received in the messages topic
I (45190) mqtt_client_cpp: MQTT_EVENT_DATA
I (45190) MQTT_EXAMPLE: Received message with msg_id: 0
I (45200) MQTT_EXAMPLE:  - event_id: 6
I (45200) MQTT_EXAMPLE:  - topic:
I (45210) MQTT_EXAMPLE:  - topic_len: 0
I (45210) MQTT_EXAMPLE:  - total_data_len: 1048576
I (45220) MQTT_EXAMPLE:  - data_len: 1024
I (45220) MQTT_EXAMPLE:  - current_data_offset: 1005
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Full log

monitor.log

[euripedesrocha]

Hi, @tajnymag this is the expected behavior.
When the received message is bigger than the buffer multiple data events are dispatched to deliver the message and the user is responsible for handling the situation.

We don't have an example that handles this situation. I'll work to improve that.

[tajnymag]

Hi, @tajnymag this is the expected behavior.
When the received message is bigger than the buffer multiple data events are dispatched to deliver the message and the user is responsible for handling the situation.

We don't have an example that handles this situation. I'll work to improve that.

Yes, I know that multiple data events for the same message is an expected behavior.

The topic of the issue is that topic is missing from all but the first event. Handling on the user end is then quite a bit more difficult than it has to be. Topic is usually the way to identify command handlers, without them the user code has to have a state machine to remember, which topic was the last received.

The missing topic isn't documented. If it is an expected behavior, it should be noted in the docs.

If it is expected BUT it's behavior is flexible enough, I would like to root for a change in the behavior.

[euripedesrocha]

Hi @tajnymag, you are correct that only the first event contains the topic, all the subsequent events are dispatched immediately, so should be dispatched to the same handler.
We are open to suggestions to improve this behavior, and the documentation. Unfortunately, the easy fix of adding the topic to the subsequent event is a breaking change, but we could at least made it available through a Kconfig option.

[tajnymag]

@euripedesrocha, Kconfig toggle would be the ultimate fix.

Would it be possible to describe the current behavior in the docs, and perhaps in examples as well, in the mean time?

I can try to come up with a PR for the documentation/example and see if I could do the toggle as well.