search

espressif / esp-mqtt

ESP32 mqtt component
Apache License 2.0
603 stars 255 forks source link

Locking issues during message publishing (IDFGH-3974) #169

Closed flamedmg closed 4 years ago

flamedmg commented 4 years ago

Sometimes i'm getting this during application startup where it tries to publish ~90 topics

Here is an example of that 

I (2289) mqtt: Free memory: 199020 bytes
W (2289) mqtt: Unknown event, id: 7
I (2289) homie: Going to push initial messages

abort() was called at PC 0x40082c1e on core 0
0x40082c1e: lock_acquire_generic at /Users/dmg/esp/esp-idf/components/newlib/locks.c:142

Backtrace:0x40087343:0x3ffc1c80 0x40087aa1:0x3ffc1ca0 0x4008e856:0x3ffc1cc0 0x40082c1e:0x3ffc1d30 0x40082d41:0x3ffc1d60 0x40160aa5:0x3ffc1d80 0x4015916d:0x3ffc2040 0x401590f5:0x3ffc2090 0x400d73cd:0x3ffc20c0 0x400d6fc7:0x3ffc20e0 0x400d719c:0x3ffc2100 0x40082dc8:0x3ffc2120 0x401604ed:0x3ffc2140 0x400e16ba:0x3ffc2160 0x400e0c3b:0x3ffc2190 0x400dcc05:0x3ffc21d0 0x400dadcb:0x3ffc2270 0x400db3e6:0x3ffc2660 0x400d8529:0x3ffc2690 0x40087aa9:0x3ffc2bb0
0x40087343: panic_abort at /Users/dmg/esp/esp-idf/components/esp_system/panic.c:349

0x40087aa1: esp_system_abort at /Users/dmg/esp/esp-idf/components/esp_system/system_api.c:104

0x4008e856: abort at /Users/dmg/esp/esp-idf/components/newlib/abort.c:46

0x40082c1e: lock_acquire_generic at /Users/dmg/esp/esp-idf/components/newlib/locks.c:142

0x40082d41: _lock_acquire_recursive at /Users/dmg/esp/esp-idf/components/newlib/locks.c:170

0x40160aa5: _vfiprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vfprintf.c:853 (discriminator 2)

0x4015916d: fiprintf at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fiprintf.c:48

0x401590f5: __assert_func at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/stdlib/assert.c:58 (discriminator 8)

0x400d73cd: spinlock_release at /Users/dmg/esp/esp-idf/components/soc/include/soc/spinlock.h:145
 (inlined by) esp_time_impl_get_boot_time at /Users/dmg/esp/esp-idf/components/newlib/port/esp_time_impl.c:131

0x400d6fc7: adjust_boot_time at /Users/dmg/esp/esp-idf/components/newlib/time.c:63

0x400d719c: get_adjusted_boot_time at /Users/dmg/esp/esp-idf/components/newlib/time.c:104

0x40082dc8: _gettimeofday_r at /Users/dmg/esp/esp-idf/components/newlib/time.c:178

0x401604ed: gettimeofday at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/syscalls/sysgettod.c:11

0x400e16ba: platform_tick_get_ms at /Users/dmg/esp/esp-idf/components/mqtt/esp-mqtt/lib/platform_esp32_idf.c:30

0x400e0c3b: esp_mqtt_client_publish at /Users/dmg/esp/esp-idf/components/mqtt/esp-mqtt/mqtt_client.c:1613

0x400dcc05: essentials::Mqtt::publish(std::basic_string_view<char, std::char_traits<char> >, std::basic_string_view<char, std::char_traits<char> >, essentials::Mqtt::Qos, bool) at /Users/dmg/Projects/home-auto/stove/build/../components/essentials/source/mqtt.cpp:43
 (inlined by) essentials::Mqtt::publish(std::basic_string_view<char, std::char_traits<char> >, std::basic_string_view<char, std::char_traits<char> >, essentials::Mqtt::Qos, bool) at /Users/dmg/Projects/home-auto/stove/build/../components/essentials/source/mqtt.cpp:129

0x400dadcb: Homie::Connect() at /Users/dmg/Projects/home-auto/stove/build/../main/Homie.cpp:75

0x400db3e6: Homie::Start() at /Users/dmg/Projects/home-auto/stove/build/../main/Homie.cpp:10

0x400d8529: exampleApp(void*) at /Users/dmg/Projects/home-auto/stove/build/../main/main.cpp:73

0x40087aa9: vPortTaskWrapper at /Users/dmg/esp/esp-idf/components/freertos/xtensa/port.c:169

Please let me know if you need more details

repo to reproduce the issue: https://github.com/flamedmg/stove_demo

Please build / flash and run it with monitor enabled. If everything works you should see long list of published messages like this: https://user-images.githubusercontent.com/416393/93013685-6a530c00-f5b3-11ea-8b21-1ce3f4d4a499.png

In that case just hit reset button on esp32 and give it another try. 2-3 from 10 attempts fail, may be different on your hardware - this is totally random.

Issue goes away if i set CONFIG_FREERTOS_UNICORE to true and use just 1 core of esp32

I'm using lastest ESP-IDF (master branch)

ESP-Marius commented 4 years ago

Hi!

This is a known issue, see https://github.com/espressif/esp-idf/issues/5762 for explanation and patch. It will be fixed as soon as our internal master branch gets pushed to Github.