esp-rs / esp-idf-svc

Type-Safe Rust Wrappers for various ESP-IDF services (WiFi, Network, Httpd, Logging, etc.)
https://docs.esp-rs.org/esp-idf-svc/
Apache License 2.0
333 stars 183 forks source link

mqtt demo can't connect #441

Closed muei closed 4 months ago

muei commented 5 months ago

Attempted multiple mqtt servers, but were unable to connect,logs below

I (4712) s3: Wifi netif up
I (4712) s3: Wifi created
I (4712) s3: MQTT client created
I (4722) s3: About to start the MQTT client
I (4722) s3: MQTT Listening for messages
I (4732) s3: [Queue] Event: BeforeConnect
E (4732) mqtt_client: Client has not connected
kgv commented 5 months ago

The same problem. After update to esp-idf-svc version 0.49.0, it's been working fine with 0.48.

```sh ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x1 (POWERON),boot:0xf (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:2 load:0x3fcd5820,len:0x1714 load:0x403cc710,len:0x968 load:0x403ce710,len:0x2f9c entry 0x403cc710 I (32) boot: ESP-IDF v5.1.2-342-gbcf1645e44 2nd stage bootloader I (32) boot: compile time Dec 12 2023 10:50:58 I (32) boot: chip revision: v0.3 I (36) boot.esp32c3: SPI Speed : 40MHz I (41) boot.esp32c3: SPI Mode : DIO I (46) boot.esp32c3: SPI Flash Size : 4MB I (50) boot: Enabling RNG early entropy source... I (56) boot: Partition Table: I (59) boot: ## Label Usage Type ST Offset Length I (67) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (74) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (81) boot: 2 factory factory app 00 00 00010000 003f0000 I (89) boot: End of partition table I (93) esp_image: segment 0: paddr=00010020 vaddr=3c0e0020 size=3ed38h (257336) map I (159) esp_image: segment 1: paddr=0004ed60 vaddr=3fc90c00 size=012b8h ( 4792) load I (160) esp_image: segment 2: paddr=00050020 vaddr=42000020 size=de9dch (911836) map I (366) esp_image: segment 3: paddr=0012ea04 vaddr=3fc91eb8 size=01758h ( 5976) load I (368) esp_image: segment 4: paddr=00130164 vaddr=40380000 size=10be4h ( 68580) load I (395) boot: Loaded app from partition at offset 0x10000 I (395) boot: Disabling RNG early entropy source... I (406) cpu_start: Unicore app I (415) cpu_start: Pro cpu start user code I (415) cpu_start: cpu freq: 160000000 Hz I (415) cpu_start: Application information: I (418) cpu_start: Project name: libespidf I (423) cpu_start: App version: e3bf697-dirty I (429) cpu_start: Compile time: Jul 4 2024 18:22:41 I (435) cpu_start: ELF file SHA256: 000000000... I (440) cpu_start: ESP-IDF: v5.2.2 I (445) cpu_start: Min chip rev: v0.3 I (450) cpu_start: Max chip rev: v1.99 I (455) cpu_start: Chip rev: v0.3 I (459) heap_init: Initializing. RAM available for dynamic allocation: I (467) heap_init: At 3FC97D50 len 000282B0 (160 KiB): RAM I (473) heap_init: At 3FCC0000 len 0001C710 (113 KiB): Retention RAM I (480) heap_init: At 3FCDC710 len 00002950 (10 KiB): Retention RAM I (487) heap_init: At 50000010 len 00001FD8 (7 KiB): RTCRAM I (494) spi_flash: detected chip: generic I (498) spi_flash: flash io: dio W (502) timer_group: legacy driver is deprecated, please migrate to `driver/gptimer.h` I (510) sleep: Configure to isolate all GPIO pins in sleep state I (517) sleep: Enable automatic switching of GPIO sleep configuration I (524) main_task: Started on CPU0 I (524) main_task: Calling app_main() I (534) pp: pp rom version: 9387209 I (534) net80211: net80211 rom version: 9387209 I (544) wifi:wifi driver task: 3fca0770, prio:23, stack:6656, core=0 I (544) wifi:wifi firmware version: 3e0076f I (554) wifi:wifi certification version: v7.0 I (554) wifi:config NVS flash: enabled I (554) wifi:config nano formating: disabled I (554) wifi:Init data frame dynamic rx buffer num: 32 I (564) wifi:Init static rx mgmt buffer num: 10 I (564) wifi:Init management short buffer num: 32 I (574) wifi:Init dynamic tx buffer num: 32 I (574) wifi:Init static tx FG buffer num: 2 I (584) wifi:Init static rx buffer size: 1600 I (584) wifi:Init static rx buffer num: 10 I (584) wifi:Init dynamic rx buffer num: 32 I (594) wifi_init: rx ba win: 6 I (594) wifi_init: tcpip mbox: 32 I (604) wifi_init: udp mbox: 6 I (604) wifi_init: tcp mbox: 6 I (604) wifi_init: tcp tx win: 5760 I (614) wifi_init: tcp rx win: 5760 I (614) wifi_init: tcp mss: 1440 I (614) wifi_init: WiFi IRAM OP enabled I (624) wifi_init: WiFi RX IRAM OP enabled I (634) phy_init: phy_version 1170,f4aea9b,Apr 30 2024,10:49:24 I (674) wifi:mode : sta (7c:df:a1:61:f1:48) I (674) wifi:enable tsf I (674) exec: Wifi started I (3084) wifi:new:<9,2>, old:<1,0>, ap:<255,255>, sta:<9,2>, prof:1 I (3094) wifi:state: init -> auth (b0) I (3094) wifi:state: auth -> assoc (0) I (3104) wifi:state: assoc -> run (10) I (3124) wifi:connected with lipids, aid = 2, channel 9, 40D, bssid = 98:25:4a:90:83:fb I (3124) wifi:security: WPA2-PSK, phy: bgn, rssi: -40 I (3124) wifi:pm start, type: 1 I (3124) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us I (3134) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 25000, mt_pti: 0, mt_time: 10000 I (3144) wifi:AP's beacon interval = 102400 us, DTIM period = 1 I (3154) exec: Wifi connected I (3154) wifi:idx:0 (ifx:0, 98:25:4a:90:83:fb), tid:7, ssn:0, winSize:64 I (4154) esp_netif_handlers: sta ip: 192.168.0.148, mask: 255.255.255.0, gw: 192.168.0.1 I (4154) exec: Wifi netif up I (4154) exec: Wifi created I (4154) exec: MQTT client created I (4164) exec: About to start the MQTT client I (4164) exec: MQTT Listening for messages I (4174) exec: [Queue] Event: BeforeConnect E (4174) mqtt_client: Client has not connected I (4184) wifi:idx:1 (ifx:0, 98:25:4a:90:83:fb), tid:0, ssn:0, winSize:64 E (4194) mqtt_client: Client has not connected I (4194) wifi:state: run -> init (0) I (4194) wifi:pm stop, total sleep time: 794684 us / 1068139 us I (4204) wifi:idx:1, tid:0 I (4204) wifi:idx:0, tid:7 I (4204) wifi:new:<9,0>, old:<9,2>, ap:<255,255>, sta:<9,2>, prof:1 I (4244) wifi:flush txq I (4244) wifi:stop sw txq I (4244) wifi:lmac stop hw txq I (4244) esp_idf_svc::wifi: EspWifi dropped I (4244) esp_idf_svc::netif: Dropped I (4244) esp_idf_svc::netif: Dropped I (4254) wifi:Deinit lldesc rx mblock:10 thread 'main' panicked at src/main.rs:44:6: called `Result::unwrap()` on an `Err` value: ESP_FAIL (error code -1) note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace abort() was called at PC 0x42035133 on core 0 0x42035133 - panic_abort::__rust_start_panic::abort at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/panic_abort/src/lib.rs:49 Core 0 register dump: MEPC : 0x403815ea RA : 0x40385518 SP : 0x3fc9ba10 GP : 0x3fc91400 0x403815ea - panic_abort at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/esp_system/panic.c:466 0x40385518 - __ubsan_include at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/esp_system/ubsan.c:313 0x3fc91400 - __global_pointer$ at ??:?? TP : 0x3fc5d1c8 T0 : 0x37363534 T1 : 0x7271706f T2 : 0x33323130 S0/FP : 0x3fc9ba4c S1 : 0x3fc9ba4c A0 : 0x3fc9ba4c A1 : 0x3fc9ba2e A2 : 0x00000000 A3 : 0x3fc9ba79 A4 : 0x00000001 A5 : 0x3fc98000 A6 : 0x7a797877 A7 : 0x76757473 S2 : 0x3fc9ba30 S3 : 0x3fc9bb48 S4 : 0x00000000 S5 : 0x00000001 S6 : 0x00000000 S7 : 0x00000000 S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000 T3 : 0x6e6d6c6b T4 : 0x6a696867 T5 : 0x66656463 T6 : 0x62613938 MSTATUS : 0x00001801 MTVEC : 0x40380001 MCAUSE : 0x00000007 MTVAL : 0x00000000 0x40380001 - _vector_table at ??:?? MHARTID : 0x00000000 Stack memory: 3fc9ba10: 0x0000000f 0x00000001 0x3fc9ba4c 0x4038c814 0x3fc9babf 0x3c0f124c 0x3fc9ba9c 0x42020030 0x4038c814 - __assert_func at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/newlib/assert.c:34 0x3c0f124c - $d.285 at ??:?? 0x42020030 - core::ptr::drop_in_place at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ptr/mod.rs:542 3fc9ba30: 0x33303234 0x33333135 0x65235200 0x3fc92e44 0x3fc9ba30 0x3fc92e60 0x3fc9ba2c 0x726f6261 3fc9ba50: 0x20292874 0x20736177 0x6c6c6163 0x61206465 0x43502074 0x34783020 0x35333032 0x20333331 3fc9ba70: 0x63206e6f 0x2065726f 0x00000030 0x42020000 0x3c0ef36c 0x3fc93644 0x3fc93644 0x42035136 0x42020000 - core::ptr::drop_in_place>]>> at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ptr/mod.rs:542 0x3c0ef36c - $d.294 at ??:?? 0x3fc93644 - $d.277 at ??:?? 0x3fc93644 - $d.277 at ??:?? 0x42035136 - core::result::Result::map_err at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/result.rs:852 3fc9ba90: 0x3fc9c7b0 0x3c0e76b8 0x3fc90c20 0x4201bd30 0x3fc9ba84 0x3fc9ba88 0x00000000 0x42018ba4 0x3c0e76b8 - $d.318 at ??:?? 0x3fc90c20 - log::LOGGER.1 at ??:?? 0x4201bd30 - std::sys::thread_local::key::racy::LazyKey::force at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/thread_local/key/racy.rs:40 0x42018ba4 - core::ptr::write at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/ub_checks.rs:75 3fc9bab0: 0x3c0ef36c 0x3fc93644 0x3fca9908 0x42018f64 0x00000009 0x3fc93644 0x3fc93644 0x420300ec 0x3c0ef36c - $d.294 at ??:?? 0x3fc93644 - $d.277 at ??:?? 0x42018f64 - std::thread::local::LocalKey::try_with at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/thread/local.rs:282 0x3fc93644 - $d.277 at ??:?? 0x3fc93644 - $d.277 at ??:?? 0x420300ec - core::fmt::Arguments::new_const at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/fmt/mod.rs:343 3fc9bad0: 0x3c0e0ed4 0x00000004 0x3c0e0fbc 0x3fc9bb48 0x3c0ef36c 0x3c0e1e24 0x00000006 0x6970694c 0x3c0e0ed4 - $d.66 at ??:?? 0x3c0e0fbc - $d.74 at ??:?? 0x3c0ef36c - $d.294 at ??:?? 0x3c0e1e24 - $d.11 at ??:?? 3fc9baf0: 0x35377364 0x38373239 0x3fc93930 0x3fc9d89c 0x3fc9bb54 0x4200d1fe 0x3fc9bb48 0x3c0f1318 0x3fc93930 - pxReadyTasksLists at ??:?? 0x4200d1fe - as core::convert::TryFrom<&str>>::try_from at /home/.../.cargo/registry/src/index.crates.io-6f17d22bba15001f/heapless-0.8.0/src/string.rs:407 0x3c0f1318 - $d.294 at ??:?? 3fc9bb10: 0x3c0e1e24 0x00000001 0xffffffff 0x3fc9bc08 0x00000003 0x00000000 0x00000000 0x00000000 0x3c0e1e24 - $d.11 at ??:?? 3fc9bb30: 0x00000000 0x3c0e1e24 0x3fc9bb64 0x420261a0 0x3fc9bc08 0x00000003 0x00000056 0x3fcad7f8 0x3c0e1e24 - $d.11 at ??:?? 0x420261a0 - std::panicking::begin_panic_handler::{{closure}} at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:666 3fc9bb50: 0x00000045 0x3fc9bb64 0x3fc9bb98 0x42026070 0x00000000 0x3c0fae54 0x00000002 0x3fc9bbf0 0x42026070 - std::sys::backtrace::output_filename at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/backtrace.rs:182 0x3c0fae54 - $d.135 at ??:?? 3fc9bb70: 0x00000002 0x00000000 0x00000000 0x3c0e1e24 0x3fc9bb98 0x3fc9bdb8 0x3c0e1e24 0x4204587e 0x3c0e1e24 - $d.11 at ??:?? 0x3c0e1e24 - $d.11 at ??:?? 0x4204587e - core::panicking::panic_nounwind_fmt at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/panicking.rs:122 3fc9bb90: 0x3c0e0ed4 0x3fc9d89c 0x3c0fae54 0x00000002 0x3fc9bbf0 0x00000002 0x00000000 0x00000000 0x3c0e0ed4 - $d.66 at ??:?? 0x3c0fae54 - $d.135 at ??:?? 3fc9bbb0: 0x3c0e1e24 0x00000001 0x3fc9bd80 0x42045b2a 0x3c0e52c0 0x3f00bdb8 0x3c0e1dcc 0x0000002b 0x3c0e1e24 - $d.11 at ??:?? 0x42045b2a - ::write_str at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/fmt/builders.rs:31 0x3c0e52c0 - $d.147 at ??:?? 0x3c0e1dcc - $d.7 at ??:?? 3fc9bbd0: 0x3fc9bc10 0x3c0e1dbc 0x3c0fae54 0x00000002 0x3fc9bbf0 0x00000002 0x00000000 0x00000000 0x3c0e1dbc - $d.6 at ??:?? 0x3c0fae54 - $d.135 at ??:?? 3fc9bbf0: 0x3fc9bbc8 0x4204207e 0x3fc9bbd0 0x4204204e 0xa5a5a5a5 0xa5a5a5a5 0x3fc9d89c 0x3fc9da90 0x4204207e - <&T as core::fmt::Display>::fmt at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/fmt/mod.rs:2360 0x4204204e - <&T as core::fmt::Debug>::fmt at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/fmt/mod.rs:2360 3fc9bc10: 0xffffffff 0x3fc9bd3b 0x3fc9bc0c 0xc0380000 0x00000000 0x3fc98000 0x00060000 0xc0380000 3fc9bc30: 0x00000000 0x3fc98000 0x00060000 0x00000000 0x00000008 0x00000004 0x3fc97d50 0xc0380000 3fc9bc50: 0x00000000 0x3fc98000 0x00060000 0x00000000 0x00000010 0x0000000c 0x3fc97d50 0x4038a19c 0x4038a19c - multi_heap_malloc_impl at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/heap/multi_heap.c:218 3fc9bc70: 0x00000000 0x3fc98000 0x00060000 0x0000000c 0x00000000 0x0000000c 0x00001800 0x4038188e 0x4038188e - heap_caps_malloc_base at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/heap/heap_caps.c:180 3fc9bc90: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fc9bcb0: 0x00000000 0x00000000 0x00000000 0x00000003 0x00001800 0x0000000c 0x00000000 0x403818a8 0x403818a8 - heap_caps_malloc at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/heap/heap_caps.c:202 3fc9bcd0: 0x3fc9c8e0 0x3fc9c8f0 0x00000000 0x420483c2 0x00001800 0x00000008 0x00000008 0x00000000 0x420483c2 - pthread_setspecific at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/pthread/pthread_local_storage.c:230 3fc9bcf0: 0x00000003 0x3fc9c8e0 0x00000000 0x4201bd56 0x00000000 0x00000008 0x00000004 0x4201b25c 0x4201bd56 - std::sys::thread_local::key::unix::set at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/thread_local/key/unix.rs:14 0x4201b25c - alloc::alloc::exchange_malloc at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/alloc/src/alloc.rs:332 3fc9bd10: 0x3fc9c7b8 0x00000000 0x00000000 0x4201bab6 0x00000000 0x3fc9c7b0 0x3fc9c8e0 0x00000000 0x4201bab6 - std::sys::thread_local::os::Storage::try_initialize at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/sys/thread_local/os.rs:109 3fc9bd30: 0x00000000 0x3fc9c7b0 0x3c0e1244 0x42003068 0x00000003 0x3fc9c7b0 0x00000000 0x42002300 0x3c0e1244 - $d.3 at ??:?? 0x42003068 - core::hint::black_box at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/hint.rs:338 0x42002300 - std::rt::lang_start::{{closure}} at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/rt.rs:159 3fc9bd50: 0x00000000 0x3fc9bdb8 0x3c0e1244 0x4202fbe6 0x3fc9bdb8 0x3c0e1244 0x3fc9bd98 0x4202fba2 0x3c0e1244 - $d.3 at ??:?? 0x4202fbe6 - std::panicking::try at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/std/src/panicking.rs:518 0x3c0e1244 - $d.3 at ??:?? 0x4202fba2 - core::result::Result::unwrap_or at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/result.rs:1433 3fc9bd70: 0x00000000 0x3fc9bdb8 0x3fc9bdb8 0x3c0e1244 0x00000000 0x3c0e13d0 0x3c0e1244 0x42020130 0x3c0e1244 - $d.3 at ??:?? 0x3c0e13d0 - $d.345 at ??:?? 0x3c0e1244 - $d.3 at ??:?? 0x42020130 - core::result::Result::map_err at /home/.../.rustup/toolchains/nightly-x86_64-unknown-linux-gnu/lib/rustlib/src/rust/library/core/src/result.rs:852 3fc9bd90: 0x3fc9bdc4 0x00000000 0x00000000 0x3c0e13d0 0x00000000 0x00000000 0x3c0fe000 0x420022ec 0x3c0e13d0 - $d.345 at ??:?? 0x420022ec - std::rt::lang_start at ??:?? 3fc9bdb0: 0x3c0fe5c4 0x0000020c 0x4200382c 0x420ddc66 0x00000000 0x00001388 0x00000001 0x00000000 0x4200382c - exec::main at /home/.../temp/src/main.rs:26 0x420ddc66 - main_task at /home/.../temp/.embuild/espressif/esp-idf/v5.2.2/components/freertos/app_startup.c:209 3fc9bdd0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fc9bdf0: 0x00000000 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0x00000150 0x3fc9b880 ELF file SHA256: 000000000 Rebooting... ESP-ROM:esp32c3-api1-20210207 ```

My last working Cargo.toml:

[dependencies]
anyhow = "1.0.86"
embassy-futures = "0.1.1"
# esp-idf-svc = { version = "0.48", default-features = false }
esp-idf-svc = { git = "https://github.com/esp-rs/esp-idf-svc", rev = "b6c85f0c0b15fd823ba61119fe1361c227eee504" }
log = { version = "0.4.21", default-features = false }
thiserror = "1.0.61"

[build-dependencies]
embuild = "0.31.3"

# https://github.com/esp-rs/std-training/issues/253
[patch.crates-io]
embedded-svc = { git = "https://github.com/esp-rs/embedded-svc", rev = "7cf5654d685830879656d5c7f987de659ba3e587" }
esp-idf-hal = { git = "https://github.com/esp-rs/esp-idf-hal", rev = "e4e608908ed3deaa0be09d3de6bcc2478ba796ac" }

My last working config.toml:

[build]
target = "riscv32imc-esp-espidf"

[target.riscv32imc-esp-espidf]
linker = "ldproxy"
# runner = "espflash --monitor" # Select this runner for espflash v1.x.x
runner = "espflash flash --monitor" # Select this runner for espflash v2.x.x
rustflags = [ "--cfg",  "espidf_time64"] # Extending time_t for ESP IDF 5: https://github.com/esp-rs/rust/issues/110

[unstable]
build-std = ["std", "panic_abort"]

[env]
MCU="esp32c3"
# Note: this variable is not used by the pio builder (`cargo build --features pio`)
ESP_IDF_VERSION = "v5.1.3"

# Workaround for https://github.com/esp-rs/esp-idf-template/issues/174 until
# https://github.com/esp-rs/esp-idf-hal/pull/387 gets released and the template
# updated.
CRATE_CC_NO_DEFAULTS = "1"
ivmarkov commented 4 months ago

This has fortunately nothing to do with new vs old esp-idf-svc version and is actually caused by the speed (and number of re-connect attempts) with which the MQTT examples you are trying happen to work in your concrete network.

In the MQTT blocking and async examples, there was a race condition between the client trying to connect, and our code trying to call client.subscribe(...)?.

The thing is, if the client fails to connect fast enough (or tries to connect, fails, and then re-tries after a while), we may end up calling client.subscribe(...)? when the client is not (yet) connected, and as a result, the subscribe call would fail, and the whole example would fail.

I updated the examples to just call subscribe in a loop and re-try on unsuccessful subscribe every 0.5s, so it should work for you now (I was able to reproduce your problem with a c3 and ESP IDF 5.2.2; couldn't reproduce it with an xtensa esp32 and ESP-IDF 5.1.2).

Here's my log, and how it should hopefully look the same for you with the updated examples:

I (3323) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 25000, mt_pti: 14, mt_time: 10000
I (3333) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (3343) mqtt_client: Wifi connected
I (3343) wifi:<ba-add>idx:0 (ifx:0, c4:ad:34:30:cf:a9), tid:0, ssn:3, winSize:64
I (4343) esp_netif_handlers: sta ip: 192.168.30.150, mask: 255.255.255.0, gw: 192.168.30.1
I (4343) mqtt_client: Wifi netif up
I (4353) mqtt_client: About to start the MQTT client
I (4363) mqtt_client: MQTT Listening for messages
I (4363) mqtt_client: [Queue] Event: BeforeConnect
E (4373) mqtt_client: Client has not connected
E (4373) mqtt_client: Failed to subscribe to topic "esp-mqtt-demo": ESP_FAIL, retrying...
E (4873) mqtt_client: Client has not connected
E (4873) mqtt_client: Failed to subscribe to topic "esp-mqtt-demo": ESP_FAIL, retrying...
I (4963) mqtt_client: [Queue] Event: Connected(session: false)
I (5373) mqtt_client: Subscribed to topic "esp-mqtt-demo"
I (5573) mqtt_client: [Queue] Event: Subscribed(12331)
I (5873) mqtt_client: Published "Hello from esp-mqtt-demo!" to topic "esp-mqtt-demo"

The E (4373) mqtt_client: Failed to subscribe to topic "esp-mqtt-demo": ESP_FAIL, retrying... is key. It used to fail the whole example before. Now it would just re-try until it (hopefully) succeeds.