MQTT Packet Size TCP Corruption about esphome-core HOT 11 CLOSED

How do you disable to logging to mqtt ?

The documentation mentions calling the app.init_log(115200, Optional()); but those are already the default and I do get logs on the mqtt.

from esphome-core.

After a closer look, the reported nullptr is because of using a ledc_component for a binary light which is not compatible.

from esphome-core.

From my program with mqtt packet 1024 :

[D][ota_component.cpp:15] setup(): Setting up OTA...
[D][mqtt_json_light_component.cpp:20] setup(): Setting up MQTT light...
[V][mqtt_component.cpp:72] send_discovery(): Sending discovery...
[V][mqtt_client_component.cpp:146] publish(): Publish(topic='discovery/light/kyk385/led/config' payload='{"name":"Led","platform":"mqtt_json","state_topic":"kyk385/light/led/state","command_topic":"kyk385/light/led/command","availability_topic":"kyk385/status","brightness":true,"rgb":true,"xy":true,"flash":true,"effect":true,"effect_list":["None","Random"]}' retain=1)
[D][mqtt_client_component.cpp:81] subscribe_json(): Subscribing to topic='kyk385/light/led/command' qos=0 with JSON...
[D][mqtt_json_light_component.cpp:20] setup(): Setting up MQTT light...
[V][mqtt_component.cpp:72] send_discovery(): Sending discovery...
[V][mqtt_client_component.cpp:146] publish(): Publish(topic='discovery/light/kyk385/lamp/config' payload='{"name":"Lamp","platform":"mqtt_json","state_topic":"kyk385/light/lamp/state","command_topic":"kyk385/light/lamp/command","availability_topic":"kyk385/status","brightness":true,"flash":true,"effect":true,"effect_list":["None"]}' retain=1)
[D][mqtt_client_component.cpp:81] subscribe_json(): Subscribing to topic='kyk385/light/lamp/command' qos=0 with JSON...
[V][application.cpp:36] setup(): Sorting components by loop priority...
Guru Meditation Error: Core 1 panic'ed (InstrFetchProhibited)
. Exception was unhandled.
Register dump:
PC : 0xa5a5a501 PS : 0x00060230 A0 : 0x800d1e28 A1 : 0x3ffd4730
A2 : 0x3ffcff9c A3 : 0x0000009c A4 : 0x00000003 A5 : 0x3ffcfb0c
A6 : 0xc4ec4ec5 A7 : 0xff000000 A8 : 0x800d2c9b A9 : 0x3ffd4710
A10 : 0x3ffcfb30 A11 : 0x3ffd00f4 A12 : 0x3ffd00f8 A13 : 0x3ffd0128
A14 : 0x00000000 A15 : 0x3ffd2820 SAR : 0x00000004 EXCCAUSE: 0x00000014
EXCVADDR: 0xa5a5a500 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xffffffff

Backtrace: 0x65a5a501:0x3ffd4730 0x400d1e25:0x3ffd4750 0x400d18ee:0x3ffd4770 0x4011e78c:0x3ffd4790

Rebooting...

from esphome-core.

From livingroom example with mqtt packet 1024 :

[V][mqtt_client_component.cpp:103] reconnect(): Reconnecting to MQTT...
[V][mqtt_client_component.cpp:106] reconnect(): Attempting MQTT connection...
[V][mqtt_client_component.cpp:127] reconnect(): Connected!
[V][mqtt_client_component.cpp:146] publish(): Publish(topic='livingroom/status' payload='online' retain=1)
[D][ota_component.cpp:15] setup(): Setting up OTA...
CORRUPT HEAP: Bad head at 0x3ffcfd6c. Expected 0xabba1234 got 0xabba0001
assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/./multi_heap_poisoning.c", line 199, function: multi_heap_free
abort() was called at PC 0x400da2bb on core 1

Backtrace: 0x40087f20:0x3ffd4510 0x4008801f:0x3ffd4530 0x400da2bb:0x3ffd4550 0x40087c49:0x3ffd4580 0x40083c7e:0x3ffd45a0 0x40084209:0x3ffd45c0 0x4000bec7:0x3ffd45e0 0x401010a9:0x3ffd4600 0x4011d25d:0x3ffd4620 0x4011d298:0x3ffd4640 0x4011d2d3:0x3ffd4660 0x40152a79:0x3ffd4690 0x4011dded:0x3ffd46b0 0x400d67c9:0x3ffd4700 0x400d29d9:0x3ffd4750 0x400d2542:0x3ffd4770 0x400d19d8:0x3ffd47a0 0x4011e53f:0x3ffd4840

Rebooting...

from esphome-core.

With mqtt packet size 512, the issue is not present.

from esphome-core.

app.init_log(115200, Optional());

It's not the default, the default is Optional<std::string>(""), which means "use the default MQTT topic for MQTT logging". Next some compilers don't support the automatic types, so you might need to type app.init_log(115200, Optional<std::string>()); (will update the docs for that).

I just tested with app.init_log(115200, Optional<std::string>()); and it successfully disabled MQTT logs.

b'{"name":"Livi\xfc\xec\xfc?[\x07 Light","platform":"mqtt_json","state_topic":"kyk385/light/livi_light/state","command_topic":"kyk385/light/livi_light/command","availability_topic":"kyk385/status","brightness":true,"rgb":true,"xy":true,"flash":true,"effect":true,"effect_list":["None","Random"]}'

Could you please post your application code, specifically app.make_*_light()? It seems like the string in there is either malformed or there's some sort of memory corruption happening.

From my program with mqtt packet 1024 :

I've seen some weird things happening with bigger packet sizes, but I've never found a specific cause (still waiting for my debugging kit to arrive). I fear the only fix will be to rewrite PubSubClient to be more efficient, which I'm not looking forward to. Right now I'd advise to stick with 512 bytes of payload size and maybe use smaller friendly names or even disabling discovery for certain components to decrease payload size.

What ESP32 are you using? How much RAM does it have? How big is the application code/how many components are created?

from esphome-core.

I am using a ESP32-WROOM-32 solder to a breakout board with a step down power supply.

In term of the application, I used the livingroom example present in the library. My own example had 2 component. Those examples do work find with the buffer at 512.

Since the issue appears when the buffer size is increased I would think there are issue with the definition and allocation of the buffer. Hard to pin point, perhaps a bit more cores synchronization could help.

from esphome-core.

Oh noes 🤕 I just found the issue, woohoo

https://github.com/OttoWinter/esphomelib/blob/95ff3365bbedf28cbe9be60201f16c3d383b700e/src/esphomelib/mqtt/mqtt_component.cpp#L58-L60

This json to string conversion code is using a hard-coded 512 length string buffer and not the MQTT_MAX_PACKET_SIZE.

I'm currently in the process of releasing another version, I think I can push that one out today.

from esphome-core.

Interesting, I also had strange errors when I tried increasing the MQTT_MAX_PACKET_SIZE beyond 512

from esphome-core.

Hmmm, today I investigated this a bit more and it seems very low level (I think the TCP stream from esp-idf). I now removed the comment in the README, as it wasn't helping.

I mean the comment in the FAQ was originally there from the days where the MQTT_MAX_PACKET_SIZE was something like 128 and where Home Assistant discovery would sometimes have more than that. I think 512 should be more than enough, at least it's working for me quite well.

Thanks for reporting this! I will leave this open so that I can take a closer look at the lower level stuff at some other point. It's not a huge priority for me though as per above paragraph.

from esphome-core.

I've now rewritten the MQTT client to use the internal TCP buffer in version 1.3.0 - And I've not seen this error (and similar ones since). Closing...

from esphome-core.