Stability MQTT

[lg.lindstrom]

Hi
I running a application that uses MQTT client to send data to a MQTT broker. The broker is running on a Raspberry Pi 4. The broker is Mosquitto. I am using VsCode and ESP-IDF 5.

I created a test bench which publish a message every second. The message is a integer value that is increased every loop. The integer is converted to ascii before publishing. qos = 0;

Depending on ?? this test can go for minutes or hours but never days.

This is the output from the console log.

Code: Select all

I (00:03:23.765) TEST_MQTT_WRAPPER: publishTestData:94 Publishing topic: testCounter  payload: 200
D (00:03:24.773) mqtt_client: esp_mqtt_handle_transport_read_error: transport_read(): call timed out before data was ready!
I (00:03:24.775) TEST_MQTT_WRAPPER: publishTestData:94 Publishing topic: testCounter  payload: 201
D (00:03:25.783) mqtt_client: esp_mqtt_handle_transport_read_error: transport_read(): call timed out before data was ready!
I (00:03:25.785) TEST_MQTT_WRAPPER: publishTestData:94 Publishing topic: testCounter  payload: 202

assert failed: xQueueGenericSend queue.c:837 (pxQueue->pcHead != ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == xTaskGetCurrentTaskHandle())


Backtrace: 0x40081e12:0x3ffcc660 0x40089931:0x3ffcc680 0x40090591:0x3ffcc6a0 0x4008a264:0x3ffcc7c0 0x40082e39:0x3ffcc800 0x40082ee9:0x3ffcc830 0x40082f5a:0x3ffcc850 0x40178ab9:0x3ffcc880 0x4017093c:0x3ffcc8a0 0x401914a0:0x3ffcc8c0 0x400e8a6a:0x3ffcc930 0x4018b0d9:0x3ffcc990 0x400dc019:0x3ffcc9b0 0x4008cad2:0x3ffcc9f0
0x40081e12: panic_abort at C:/Users/lglin/esp/esp-idf/components/esp_system/panic.c:412

0x40089931: esp_system_abort at C:/Users/lglin/esp/esp-idf/components/esp_system/esp_system.c:135

0x40090591: __assert_func at C:/Users/lglin/esp/esp-idf/components/newlib/assert.c:78

0x4008a264: xQueueGenericSend at C:/Users/lglin/esp/esp-idf/components/freertos/FreeRTOS-Kernel/queue.c:837 (discriminator 8)

0x40082e39: lock_release_generic at C:/Users/lglin/esp/esp-idf/components/newlib/locks.c:192

0x40082ee9: _lock_release at C:/Users/lglin/esp/esp-idf/components/newlib/locks.c:198

0x40082f5a: __retarget_lock_release at C:/Users/lglin/esp/esp-idf/components/newlib/locks.c:334

0x40178ab9: __tz_unlock at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/time/tzlock.c:50

0x4017093c: localtime_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/time/lcltime_r.c:123

0x401914a0: esp_log_system_timestamp at C:/Users/lglin/esp/esp-idf/components/log/log_freertos.c:84

0x400e8a6a: base_poll_read at C:/Users/lglin/esp/esp-idf/components/tcp_transport/transport_ssl.c:172 (discriminator 9)

0x4018b0d9: esp_transport_poll_read at C:/Users/lglin/esp/esp-idf/components/tcp_transport/transport.c:156

0x400dc019: esp_mqtt_task at C:/Users/lglin/esp/esp-idf/components/mqtt/esp-mqtt/mqtt_client.c:1583

0x4008cad2: vPortTaskWrapper at C:/Users/lglin/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:151

Two questions:
Why a error after every publish ?? Is there a timeout parameter I can change.

Code: Select all

D (00:03:25.783) mqtt_client: esp_mqtt_handle_transport_read_error: transport_read(): call timed out before data was ready!

My fault,,???

Code: Select all

assert failed: xQueueGenericSend queue.c:837 (pxQueue->pcHead != ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == xTaskGetCurrentTaskHandle())

[ESP_YJM]

Code: Select all

D (00:03:25.783) mqtt_client: esp_mqtt_handle_transport_read_error: transport_read(): call timed out before data was ready!

For question one, i think it is not a problem. We want to read data and no data received. This is only a debug log level.You can ignore it.

Code: Select all

assert failed: xQueueGenericSend queue.c:837 (pxQueue->pcHead != ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == xTaskGetCurrentTaskHandle())

For the question two, it is similar with https://github.com/espressif/esp-idf/issues/9441. Could you please try disable CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM and retest whether can reproduce it.

[lg.lindstrom]

Changed according to your suggestion.

The test is running as we speak but it is far to early to tell anything about the final result.

My other question, do you have anything to comment about that. It is still there but don't seems to affect anything.

Code: Select all

I (2945839) TEST_MQTT_WRAPPER: publishTestData:94 Publishing topic: testCounter  payload: 2936
D (2946849) mqtt_client: esp_mqtt_handle_transport_read_error: transport_read(): call timed out before data was ready!

[ESP_YJM]

Yes, As I explained above, this is not a problem. You can ignore it for esp_mqtt_handle_transport_read_error print.

[lg.lindstrom]

Okay

I will get back to you in a few hours after running my tests.

[ESP_YJM]

Any update for your test?

[lg.lindstrom]

Sorry no.

We are at christmas vacation and I dont have my setup with me.

I get back to you early next year.

[lg.lindstrom]

Hi

I have been running this back and forth a couple of days,,,
It is very clear that CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM=y affects the error. If I disable the setting I can run much longer with no problems at all. Unfortunately other problems shows up. Wifi network is not completely stable and something happens in the app that I not fully recover from.

Will disabling CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM affect some other parts of ESP-IDF as ntp sync and logging with timestamp ??

[ESP_YJM]

CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM is disabled as default and will not affect other parts of ESP-IDF. Could you please share more details about the issue when you disable CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM.