MQTT Connection Error: Mqtt state: Mqtt serialization/deserialization error

[deepcoder]

Thanks for your work on this, useful!

But I am getting the error message below on MacOS 12.2.1 Monterey, and only seeing a subset of the message on the broker.

MQTT TUI 0.16.0─────────────────────────────────────────────────────────────
MQTT Broker: 10.10.1.199 (Port 1883)                                      
Subscribed Topic: #                                                         
MQTT Connection Error: Mqtt state: Mqtt serialization/deserialization error 

[EdJoPaTo]

Does mqttui log or mqttui publish work? its probably easier to understand the error that way without all the interactive stuff going.

[deepcoder]

Output of log option below, look like a limit to the size of the MQTT message. I am not sure how to specify the 'RUST_BACKTRACE' option:

RETAINED     tasmota/discovery/4C7525C47658/config              QoS:AtMostOnce  Payload(788): {"ip":"192.168.2.230","dn":"Tasmota","fn":["Tasmota",null,null,null,null,null,null,null],"hn":"tasmota32-C47658-5720","mac":"4C7525C47658","md":"ESP32-DevKit","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["OFF","ON","TOGGLE","HOLD"],"sw":"11.0.0.3","t":"tasmota32_C47658","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[2,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":1,"lt_st":3,"sho":[0,0,0,0],"ver":1}
RETAINED     tasmota/discovery/4C7525C47658/sensors             QoS:AtMostOnce  Payload( 89): {"sn":{"Time":"2022-03-17T18:35:25","ESP32":{"Temperature":71.1},"TempUnit":"C"},"ver":1}
thread 'main' panicked at 'connection error: MqttState(Deserialization(PayloadSizeLimitExceeded(20642)))', src/log.rs:8:28
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
dproffer@graymini mqttui-v0.16.0-x86_64-apple-darwin %

[EdJoPaTo]

I am curious what payload is transferred there. Seeing the error is helpful. I think I know what could be changed to handle errors like that.

No need to specify the option here as I already know where its from but for the future you can use one of two variants to specify the environment variables:

export RUST_BACKTRACE=1
mqttui …

RUST_BACKTRACE=1 mqttui …

Its also quite helpful for arguments like the Broker as you can specify that export … in your .bashrc:

export MQTTUI_BROKER='raspberrypi.local'
mqttui

Anyway, I will look into the error when I find the time. Thanks for reporting it!

[EdJoPaTo]

This might have been improve via ad34a1551bcb3a336993c8983c180ecdb9d7fdf5. The interactive view waited 5 seconds after an error which is not helpful for this kind of error.

Its reduced to 25ms now which should still be helpful on network connection lost errors and other longer staying issues.

Thanks again for reporting, I wasn't are of these kinds of errors before. The fix is part of 0.16.1

[bentolor]

Sorry to resurrect this issue. Since I integrated Valetudo right now, I seem to stumble over the same issue.

• In the interactive mode this error is just flickering, but messages are still processed/received
• In mqttui log it just reaches the first "Connection Error: Mqtt state: Mqtt serialization/deserialization error" and then it seems to stop altogether

$ set -x RUST_BACKTRACE 1 ; set -x LOG debug ; mqttui log
RETAINED     valetudo/rockrobo/MapData/$properties              QoS:AtLeastOnce Payload( 31): map-data,segments,map-data-hass
RETAINED     valetudo/rockrobo/MapData/map-data                 QoS:AtLeastOnce Payload(2029): invalid UTF8: invalid utf-8 sequence of 1 bytes from index 1
RETAINED     valetudo/rockrobo/MapData/map-data/$name           QoS:AtLeastOnce Payload( 12): Raw map data
RETAINED     valetudo/rockrobo/MapData/map-data/$datatype       QoS:AtLeastOnce Payload(  6): string
RETAINED     valetudo/rockrobo/MapData/map-data/$settable       QoS:AtLeastOnce Payload(  5): false
RETAINED     valetudo/rockrobo/MapData/map-data/$retained       QoS:AtLeastOnce Payload(  4): true
RETAINED     valetudo/rockrobo/MapData/segments                 QoS:AtLeastOnce Payload(  2): {}
RETAINED     valetudo/rockrobo/MapData/segments/$name           QoS:AtLeastOnce Payload( 12): Map segments
RETAINED     valetudo/rockrobo/MapData/segments/$datatype       QoS:AtLeastOnce Payload(  6): string
RETAINED     valetudo/rockrobo/MapData/segments/$settable       QoS:AtLeastOnce Payload(  5): false
RETAINED     valetudo/rockrobo/MapData/segments/$retained       QoS:AtLeastOnce Payload(  4): true
RETAINED     valetudo/rockrobo/MapData/segments/$format         QoS:AtLeastOnce Payload(  4): json
Connection Error: Mqtt state: Mqtt serialization/deserialization error

In my case it seems that mqttui is not happy with the payload on the map-data which I assume is some binary content.

Is this a problem by mqttui or rather the producer? I'm not so deep into the MQTT protocol here.

[EdJoPaTo]

You can send binary content over MQTT which is supported by MQTT. mqttui should handle that correctly. It tries to get an UTF8 String from that. If that doesn't work out its just printed in that case but should continue to work. Your second line does seem to look correct: attempt was made which failed and the rest continued. (Maybe it should be states less negative like "no UTF8" instead of "invalid UTF8".)

That serialization/deserialization error should have a different reason. Whats strange is the log stopping then. Can you check with different tools like the MQTT Explorer if there are other messages? Maybe there aren't any more messages after the retained ones? I would suspect that this should work with the 0.16.1 fix (but I might be wrong).

I am not exactly sure how to get a better understanding of that specific error. I know that it originates from the MQTT library I am using. Maybe there is a bug in that lib but I don't know how to recreate it easily on another device / test case to analyze this behavior. Any ideas?

I would assume the device should be correct as the broker should already error in that case. But not even that might be true.

[bentolor]

HI @EdJoPaTo I just invested the time to create a producer. Please to the following.

How to reproduce

I assume a Linux machine with Docker

mkdir /tmp/testcase

Then copy the attached file into that directory and unzip: testcasefiles.zip

You should now have:

/tmp/testcase
├── mosquitto.conf
├── mosquitto.db
└── testcasefiles.zip

Now run a mosquitto instance with the provided configuration & data

 sudo docker run --rm -it -p 9883:1883 -v /tmp/testcase/:/mosquitto/data/ -v /tmp/testcase/:/mosquitto/config eclipse-mosquitto 

Problem 1: reconnecting TUI

Just run mqttui -p 9883 and you'll see the over and over message appear though nothing is posted at all. it crashes, rereads and counts the existing mesages as new

Problem 2: log (&publish) not working

Just run mqttui -p 9883 l in one terminal.

You are probably tempted to use sth. like mqttui -p 9883 p "test" "bar" which is not working at all.

Better user mosquitto_pub -t 'test' -m 'boppp' -p 9883 and see how this appears in the TUI but not on the CLI log.

Update: I see that I can see this new message only in MQTT Explorer. Dunno why. Saw that before in my previous testrun.

Does this help? Please let let me know. I invested quite some time into the reproducer and therefore am interested that it is valueable for you.

[EdJoPaTo]

That sounds interesting! Thank you for looking into creating a reproducable example! I will look into it when I have some time

[EdJoPaTo]

I looked into it a bit more. The publish command itself works fine, only log and the interactive view cant see whats going on. Looking with MQTT Explorer and mqttui at the same time I found out this topic in your example seems to be the cause: valetudo/rockrobo/MapData/map-data-hass. When seeing its binary content in MQTT Explorer it looks like a PNG image.

When I remove the retained message (publish a retained empty message) everything works fine.

With the changes of https://github.com/bytebeamio/rumqtt/pull/385 the error message is also a bit more helpful here:

mqttui log valetudo/rockrobo/MapData/map-data-hass    
Connection Error: Mqtt state: Mqtt serialization/deserialization error: Error = PayloadSizeLimitExceeded(21323)

Looks like the PNG is ~21kB big?

The interactive view connects again and again to the broker only to fail again with the same error of the log view. This error originates somewhere from the library rumqttc that is used here. In my opinion it shouldnt behave like this and should continue to work even if one packet has an error. I have to dig deeper into this later. Hopefully I can fix that issue with a PR for rumqttc or understand it better to provide a more useful issue report for the library.

[deepcoder]

I to still have the problem with v 0.16.1. App no longer crashes, just constantly flashes error message in interactive mode, in log mode, app seems to output all 'RETAINED' message and then just stops outputting.

[bentolor]

Yes, that sounds reasonable, @EdJoPaTo : The data source is a automatic Xiaomi vacuum robot with a patched firmware and that blob is probably the floormap build on the robot and constantly updated during the cleanup process.

I just checked the MQTT specification. Here it says:

[Maximum Packet Size](), ... Followed by a Four Byte Integer representing the Maximum Packet Size the Client is willing to accept. ... If a Client receives a packet whose size exceeds this limit, this is a Protocol Error, the Client uses DISCONNECT with Reason Code 0x95 (Packet too large), as described in section 4.13.

I think this this could explains the overall effect very well.

Not sure if rumqtt does allow to override that client size nor if this is a reasonable approach to do.

[EdJoPaTo]

7481e6ae6738387c049f87764c2a4ab963fd5521 improves the handling of the payload which should handle many and large payloads better. b272b831e591b7deab99321cfc7e4d248772b748 increases the max_packet_size to usize::MAX (32 bit or 64 bit depending on the host system) which theoretically allows for gigabytes of payloads.

I don't think people will send huge amounts of data so traffic shouldnt be an issue. Memory consumption might be when a lot of messages are valid UTF-8 Strings. Before 7481e6ae6738387c049f87764c2a4ab963fd5521 all payloads ever received would have been saved as raw bytes. With these changes only valid UTF-8 Strings and error messages are kept in memory. This should work well for binary data like the PNG from the testdata.zip. Not sure if an extra check for large payloads should be added to prevent storaging them?

(These changes are not yet released. Feel free to build yourself or use a version build from the CI in order to test these changes)

Still Missing: mqttui log does not subscribe after reconnects`

[bentolor]

Thanks, @EdJoPaTo for coming back to this issue. I can confirm that mqttui-v0.16.1-15-g0ec29e3-x86_64-unknown-linux-gnu.deb seems to completely fix this issue with no more flickering and spurious "incoming" events.

Unlike others MQTT consumers mqttui retains all received data in memory. According to my understanding MQTT aims at rather small data and keeping mqttui may be rather a edge case than the general use case. As you already prune any non-legible content I'd say it's potentially a realistic, but maybe yet not important use case to support endless 24x7 running while tons of UTF-8 strings are passed through the broker.

To really process long lists of entries for attributes you probably need further tooling like highlighting difference, text search, value search etc. Mostly it's just skimming over the first few entries or jumping to a specific timestamp one has in mind I'd guess.

[EdJoPaTo]

I had the current mqttui main branch version running in my home network (which is mostly single value content and a few JSON thingies) which ended up with 22 MB RAM after a few hours. This is by no means a busy MQTT broker but I am quite confident that it does seem to handle traffic well. The MQTT Explorer has a few hundreds of MB RAM already from the start.

Also mqttui is not that useful for 24/7 setups with its current "open and start when needed" rather than a daemon running in the background. But I think Grafana and so on are better suited for longer running things than an exploration tool like mqttui would be.

YOur list of ideas, "highlighting differences, text search, value search" is something I like thinking about. We should discuss them in separate issues!

[bentolor]

Fully d'accord.

I'm happy try to brainstorm a little and watch myself during usage and come up with feature issues as appropriate.

[EdJoPaTo]

The fix is now available with v0.16.2