MQTT disconnects and won't connect until restart

Palonso
Posts: 95
Joined: Tue Sep 24, 2019 8:43 pm

MQTT disconnects and won't connect until restart

Postby Palonso » Fri Feb 26, 2021 8:46 pm

Hi,

I'm running an ESP WROVER-B module reporting data through MQTT over WiFi, and the device is also running a web server.

After a while the device disconnects from MQTT broker and won't send any data, the device seems to keep the connection to wifi but I'm not able to access to its webserver. Here is what I get from the log:

Code: Select all

[0;32mI (23:48:47.122) mqtt: mqtt_publish[0m
[0;32mI (23:48:47.153) mqtt: Publish log: {"ts":1614296927000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (23:48:47.162) mqtt: mqtt_publish on topic v1/devices/me/telemetry, payload {"ts":1614296927000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (23:48:47.197) mqtt: MQTT_EVENT_PUBLISHED, msg_id=53683[0m
[0;32mI (23:48:57.080) mqtt: mqtt_publish[0m
[0;32mI (23:48:57.115) mqtt: Publish log: {"ts":1614296937000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (23:48:57.124) mqtt: mqtt_publish on topic v1/devices/me/telemetry, payload {"ts":1614296937000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (23:49:02.132) mqtt: mqtt_disconnect[0m
[0;32mI (23:49:02.173) mqtt: MQTT_EVENT_DISCONNECTED[0m
[0;32mI (23:49:07.172) mqtt: Connecting...[0m
[0;32mI (23:49:07.172) mqtt: mqtt_connect[0m
[0;32mI (23:49:07.172) mqtt: Certificate config[0m
[0;32mI (23:49:12.172) mqtt: Connecting...[0m
[0;32mI (23:49:12.172) mqtt: mqtt_connect[0m
[0;32mI (23:49:12.173) mqtt: Certificate config[0m
[0;32mI (23:49:17.172) mqtt: Connecting...[0m
and stays like that.
Once restarted, this is what I get:

Code: Select all

[0;32mI (14:26:56.894) mqtt: Connecting...[0m
[0;32mI (14:26:56.895) mqtt: mqtt_connect[0m
I (61780644) wifi:state: run -> init (0)
I (61780644) wifi:pm stop, total sleep time: 41975664710 us / 61777455594 us

I (61780644) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
[0;32mI (14:27:00.303) wifi: wifi_update_status: status 1[0m
[0;32mI (14:27:00.307) wifi: Disconnected. Connecting to the AP again...[0m
[0;32mI (14:27:00.314) wifi: wifi_update_status: status 2[0m
W (61780664) wifi:hmac tx: stop, discard
I (61780684) wifi:flush txq
I (61780684) wifi:stop sw txq
I (61780684) wifi:lmac stop hw txq
[0;32mI (13) boot: ESP-IDF v4.2-dirty 2nd stage bootloader[0m
[0;32mI (13) boot: compile time 12:27:02[0m
[0;32mI (13) boot: chip revision: 1[0m
[0;32mI (15) boot_comm: chip revision: 1, min. bootloader chip revision: 0[0m
[0;32mI (22) boot.esp32: SPI Speed      : 40MHz[0m
[0;32mI (27) boot.esp32: SPI Mode       : DIO[0m
[0;32mI (31) boot.esp32: SPI Flash Size : 16MB[0m
[0;32mI (36) boot: Enabling RNG early entropy source...[0m
[0;32mI (41) boot: Partition Table:[0m
[0;32mI (45) boot: ## Label            Usage          Type ST Offset   Length[0m
[0;32mI (52) boot:  0 nvs              WiFi data        01 02 00009000 00050000[0m
[0;32mI (60) boot:  1 log              WiFi data        01 02 00059000 00630000[0m
[0;32mI (67) boot:  2 otadata          OTA data         01 00 00689000 00002000[0m
[0;32mI (75) boot:  3 phy_init         RF data          01 01 0068b000 00001000[0m
[0;32mI (82) boot:  4 factory          factory app      00 00 00690000 00320000[0m
[0;32mI (89) boot:  5 ota_0            OTA app          00 10 009b0000 00320000[0m
[0;32mI (97) boot:  6 ota_1            OTA app          00 11 00cd0000 00320000[0m
[0;32mI (104) boot: End of partition table[0m
[0;32mI (109) boot: Defaulting to factory image[0m
[0;32mI (113) boot_comm: chip revision: 1, min. application chip revision: 0[0m
[0;32mI (121) esp_image: segment 0: paddr=0x00690020 vaddr=0x3f400020 size=0x31658 (202328) map[0m
[0;32mI (214) esp_image: segment 1: paddr=0x006c1680 vaddr=0x3ffbdb60 size=0x04538 ( 17720) load[0m
[0;32mI (222) esp_image: segment 2: paddr=0x006c5bc0 vaddr=0x40080000 size=0x00404 (  1028) load[0m
[0;32mI (223) esp_image: segment 3: paddr=0x006c5fcc vaddr=0x40080404 size=0x0a04c ( 41036) load[0m
[0;32mI (250) esp_image: segment 4: paddr=0x006d0020 vaddr=0x400d0020 size=0x10e9f0 (1108464) map[0m
[0;32mI (712) esp_image: segment 5: paddr=0x007dea18 vaddr=0x4008a450 size=0x14b40 ( 84800) load[0m
[0;32mI (753) esp_image: segment 6: paddr=0x007f3560 vaddr=0x400c0000 size=0x00068 (   104) load[0m
[0;32mI (754) esp_image: segment 7: paddr=0x007f35d0 vaddr=0x50000400 size=0x00b10 (  2832) load[0m
[0;32mI (761) esp_image: segment 8: paddr=0x007f40e8 vaddr=0x00000000 size=0x0be98 ( 48792) [0m
[0;32mI (807) boot: Loaded app from partition at offset 0x690000[0m
[0;32mI (807) boot: Disabling RNG early entropy source...[0m
[0;32mI (808) psram: This chip is ESP32-D0WD[0m
[0;32mI (813) spiram: Found 64MBit SPI RAM device[0m
[0;32mI (817) spiram: SPI RAM mode: flash 40m sram 40m[0m
[0;32mI (822) spiram: PSRAM initialized, cache is in low/high (2-core) mode.[0m
[0;32mI (829) cpu_start: Pro cpu up.[0m
[0;32mI (833) cpu_start: Application information:[0m
[0;32mI (838) cpu_start: Project name:     project[0m
[0;32mI (843) cpu_start: App version:      1[0m
[0;32mI (849) cpu_start: Compile time:     Feb 24 2021 16:21:52[0m
[0;32mI (855) cpu_start: ELF file SHA256:  6a412c54b5095a87...[0m
[0;32mI (861) cpu_start: ESP-IDF:          v4.2-dirty[0m
[0;32mI (866) cpu_start: Starting app cpu, entry point is 0x400821c0[0m
[0;32mI (867) cpu_start: App cpu up.[0m
[0;32mI (1758) spiram: SPI SRAM memory test OK[0m
[0;32mI (1759) heap_init: Initializing. RAM available for dynamic allocation:[0m
[0;32mI (1759) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM[0m
[0;32mI (1765) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM[0m
[0;32mI (1771) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM[0m
[0;32mI (1777) heap_init: At 3FFCEA70 len 00011590 (69 KiB): DRAM[0m
[0;32mI (1784) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM[0m
[0;32mI (1790) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM[0m
[0;32mI (1797) heap_init: At 4009EF90 len 00001070 (4 KiB): IRAM[0m
[0;32mI (1803) cpu_start: Pro cpu start user code[0m
[0;32mI (1808) spiram: Adding pool of 4096K of external SPI memory to heap allocator[0m
[0;32mI (1830) spi_flash: detected chip: gd[0m
[0;32mI (1830) spi_flash: flash io: dio[0m
[0;32mI (1830) cpu_start: Starting scheduler on PRO CPU.[0m
[0;32mI (0) cpu_start: Starting scheduler on APP CPU.[0m
[0;32mI (1838) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations[0m
[0;32mI (14:16:19.618) flash: init_flash[0m
[0;32mI (14:16:19.713) flash: flash_load_configuration[0m
[0;32mI (14:16:19.714) flash: Count: UsedEntries = (796), FreeEntries = (9284), AllEntries = (10080)
[0m
[0;32mI (14:16:19.717) flash: factory_default[0m
[0;32mI (14:16:19.762) mqtt: factory_default_mqtt[0m
[0;32mI (14:16:19.777) wifi: factory_default_wifi[0m
[0;32mI (14:16:20.063) wifi: wifi_update_status: status 0[0m
[0;32mI (14:16:20.107) mqtt: init_mqtt[0m
[0;32mI (14:16:20.113) mqtt: apply_changes_mqtt[0m
[0;32mI (14:16:20.116) mqtt: Connecting...[0m
[0;32mI (14:16:20.124) mqtt: mqtt_connect[0m
[0;32mI (2518) phy: phy_version: 4500, 0cd6843, Sep 17 2020, 15:37:07, 0, 0[0m
Coex register schm btdm cb faild
[0;32mI (14:16:20.601) wifi: init_wifi[0m
I (2858) wifi:wifi driver task: 3ffd6734, prio:23, stack:3584, core=0
I (2888) wifi:wifi firmware version: 1865b55
I (2888) wifi:wifi certification version: v7.0
I (2888) wifi:config NVS flash: enabled
I (2888) wifi:config nano formating: disabled
I (2888) wifi:Init data frame dynamic rx buffer num: 32
I (2898) wifi:Init management frame dynamic rx buffer num: 32
I (2898) wifi:Init management short buffer num: 32
I (2908) wifi:Init static tx buffer num: 16
I (2908) wifi:Init tx cache buffer num: 32
I (2908) wifi:Init static rx buffer size: 1600
I (2918) wifi:Init static rx buffer num: 10
I (2918) wifi:Init dynamic rx buffer num: 32
[0;32mI (14:16:20.689) wifi: apply_changes_wifi[0m
[0;32mI (14:16:20.692) wifi: config changed[0m
[0;32mI (14:16:20.696) wifi: wifi_update_status: status 1[0m
[0;32mI (14:16:20.701) wifi: Configure STA mode - DHCP[0m
I (2958) wifi:mode : sta (a8:03:2a:5e:2d:e0)
[0;32mI (14:16:20.725) wifi: wifi_update_status: status 2[0m
[0;32mI (14:16:20.726) wifi: wifi_update_status: status 2[0m
I (3078) wifi:new:<2,0>, old:<1,0>, ap:<255,255>, sta:<2,0>, prof:1
I (3088) wifi:state: init -> auth (b0)
I (3088) wifi:state: auth -> assoc (0)
I (3098) wifi:state: assoc -> run (10)
I (3138) wifi:connected with <my_ssid>, aid = 134, channel 2, BW20, bssid = 84:d8:1b:db:a5:73
I (3138) wifi:security: WPA2-PSK, phy: bgn, rssi: -43
I (3138) wifi:pm start, type: 1

I (3288) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[0;32mI (14:16:21.613) wifi: got ip:192.168.86.155[0m
[0;32mI (14:16:21.614) wifi: wifi_update_status: status 3[0m
[0;32mI (14:16:21.627) mqtt: MQTT_EVENT_BEFORE_CONNECT[0m
[0;32mI (14:16:22.094) mqtt: MQTT_EVENT_CONNECTED[0m
[0;32mI (14:16:22.126) mqtt: Connected[0m
[0;32mI (14:16:22.127) mqtt: mqtt_publish_log[0m
[0;32mI (14:16:22.179) mqtt: Publish log: {"ts":1614296937000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (14:16:22.188) mqtt: mqtt_publish on topic v1/devices/me/telemetry, payload {"ts":1614296937000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (14:16:22.230) mqtt: MQTT_EVENT_PUBLISHED, msg_id=28741[0m
[0;32mI (14:16:22.313) mqtt: mqtt_publish[0m
[0;32mI (14:16:22.372) mqtt: Publish log: {"ts":1614296947000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (14:16:22.381) mqtt: mqtt_publish on topic v1/devices/me/telemetry, payload {"ts":1614296947000,"values":{"bateria":107,"status_bateria":0}}[0m
[0;32mI (14:16:22.417) mqtt: MQTT_EVENT_PUBLISHED, msg_id=16994[0m
And after some time:

Code: Select all

[0;32mI (14:48:21.113) mqtt: mqtt_publish_log[0m
[0;32mI (14:48:21.144) mqtt: Publish log: {"ts":1614342230000,"values":{"status_bateria":1}}[0m
[0;32mI (14:48:21.152) mqtt: mqtt_publish on topic v1/devices/me/telemetry, payload {"ts":1614342230000,"values":{"status_bateria":1}}[0m
[0;32mI (14:48:21.650) mqtt: MQTT_EVENT_PUBLISHED, msg_id=1446[0m
[0;32mI (14:48:21.673) mqtt: mqtt_publish_log[0m
[0;32mI (14:48:21.722) mqtt: Publish log: {"ts":1614342240000,"values":{"bateria":110,"status_bateria":1}}[0m
[0;32mI (14:48:21.731) mqtt: mqtt_publish on topic v1/devices/me/telemetry, payload {"ts":1614342240000,"values":{"bateria":110,"status_bateria":1}}[0m
[0;32mI (14:48:21.762) mqtt: MQTT_EVENT_PUBLISHED, msg_id=26625[0m
[0;32mI (14:48:21.809) mqtt: MQTT_EVENT_ERROR[0m
[0;32mI (14:48:21.812) mqtt: MQTT_EVENT_DISCONNECTED[0m
[0;32mI (14:48:21.869) mqtt: mqtt_disconnect[0m
[0m
[0;32mI (14:48:31.806) mqtt: Connecting...[0m
[0;32mI (14:48:31.807) mqtt: mqtt_connect[0m
[0;32mI (14:48:31.808) mqtt: MQTT_EVENT_BEFORE_CONNECT[0m
[0m
[0;32mI (14:48:41.846) mqtt: MQTT_EVENT_ERROR[0m
[0;32mI (14:48:41.847) mqtt: MQTT_EVENT_DISCONNECTED[0m
[0;32mI (14:48:46.906) mqtt: Connecting...[0m
[0;32mI (14:48:46.907) mqtt: mqtt_connect[0m
[0;32mI (14:48:46.909) mqtt: MQTT_EVENT_BEFORE_CONNECT[0m
[0;32mI (14:48:51.906) mqtt: Connecting...[0m
[0;32mI (14:48:51.907) mqtt: mqtt_connect[0m
[0m
[0;32mI (14:49:00.837) mqtt: MQTT_EVENT_ERROR[0m
[0;32mI (14:49:00.838) mqtt: MQTT_EVENT_DISCONNECTED[0m
[0;32mI (14:49:00.840) mqtt: MQTT_EVENT_BEFORE_CONNECT[0m
[0;32mI (14:49:01.689) mqtt: MQTT_EVENT_CONNECTED[0m
[0;32mI (14:49:05.836) mqtt: Connecting...[0m
[0;32mI (14:49:05.837) mqtt: mqtt_connect[0m
[0;32mI (14:49:10.836) mqtt: Connecting...[0m
[0;32mI (14:49:10.837) mqtt: mqtt_connect[0m
[0m
[0;32mI (14:49:15.514) mqtt: MQTT_EVENT_ERROR[0m
[0;32mI (14:49:15.517) mqtt: MQTT_EVENT_DISCONNECTED[0m
[0;32mI (14:49:15.836) mqtt: Connecting...[0m
[0;32mI (14:49:15.837) mqtt: mqtt_connect[0m
[0;32mI (14:49:15.839) mqtt: MQTT_EVENT_BEFORE_CONNECT[0m
[0;32mI (14:49:15.928) mqtt: MQTT_EVENT_CONNECTED[0m
[0;32mI (14:49:20.836) mqtt: Connecting...[0m
[0;32mI (14:49:20.837) mqtt: mqtt_connect[0m
[0;32mI (14:49:22.687) mqtt: MQTT_EVENT_ERROR[0m
[0;32mI (14:49:22.690) mqtt: MQTT_EVENT_DISCONNECTED[0m
Any idea of what could be the problem?

Regards,
P

UPDATE:

I found that the ESP32 is not receiving the PUBACK message from the broker. I tried incrementing the timeout time, yet that doesn't explain why it won't connect again.

Who is online

Users browsing this forum: No registered users and 131 guests