Error MQTT2 Server received bogus data.

[EinEinfach]

Hallo zusammen,

ich habe einen ESP32 der via MQTT mit fhem die Daten austauscht. Als MQTT Server nutze ich das fhem Modul MQTT2_Server. Öfters sehe ich im fhem log folgende Fehlermeldung:

Code Auswählen Erweitern

2022.11.02 12:20:11 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62654 Krobi received bogus data, disconnecting
2022.11.02 12:20:12 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62655 Krobi received bogus data, disconnecting
2022.11.02 12:20:13 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62656 Krobi received bogus data, disconnecting
2022.11.02 12:20:14 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62657 Krobi received bogus data, disconnecting
2022.11.02 12:20:15 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62658 Krobi received bogus data, disconnecting
2022.11.02 12:20:16 3: MQTT2_FHEM_Server: MQTT2_FHEM_Server_192.168.2.55_62653/Krobi left us (keepalive check)
2022.11.02 12:20:17 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62659 Krobi received bogus data, disconnecting
2022.11.02 12:20:18 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62660 Krobi received bogus data, disconnecting
2022.11.02 12:20:19 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62661 Krobi received bogus data, disconnecting
2022.11.02 12:20:20 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62662 Krobi received bogus data, disconnecting
2022.11.02 12:20:21 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62663 Krobi received bogus data, disconnecting
2022.11.02 12:20:22 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62664 Krobi received bogus data, disconnecting
2022.11.02 12:20:23 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62665 Krobi received bogus data, disconnecting
2022.11.02 12:20:24 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62666 Krobi received bogus data, disconnecting
2022.11.02 12:20:25 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62667 Krobi received bogus data, disconnecting
2022.11.02 12:20:26 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62668 Krobi received bogus data, disconnecting
2022.11.02 12:20:27 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62669 Krobi received bogus data, disconnecting
2022.11.02 12:20:28 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62670 Krobi received bogus data, disconnecting
2022.11.02 12:20:29 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62671 Krobi received bogus data, disconnecting
2022.11.02 12:20:30 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62672 Krobi received bogus data, disconnecting
2022.11.02 12:20:31 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62673 Krobi received bogus data, disconnecting
2022.11.02 12:20:32 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62674 Krobi received bogus data, disconnecting
2022.11.02 12:20:33 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_62675 Krobi received bogus data, disconnecting

Kann ich die Anzahl dieser Einträge reduzieren? Wenn ja wie? Der Fehler scheint die korrekte Funktion des Geräts nicht zu beeinflussen.

Gruß
Alexander

[rudolfkoenig]

Um die Ursache einzugrenzen brauche ich ein "attr MQTT2_SERVER verbose 5" Log, die Zeilen zwischen zwei "disconnecting" reicht.
Vorher bitte sicherstellen, dass FHEM aktuell ist.
Ist die MQTT Verbindung verschluesselt?

[EinEinfach]

Hallo Rudi,

so fhem upgedatet und mit verbose 5 mitgelauscht:

Code Auswählen Erweitern

2022.11.02 15:54:19 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_63509 Krobi received bogus data, disconnecting
2022.11.02 15:54:19 5: MQTT2_FHEM_Server: dispatch autocreate=no\000Krobi\000\000\000\000\000�B�?\003\000\000\000\000false
2022.11.02 15:54:20 4: Connection accepted from MQTT2_FHEM_Server_192.168.2.55_63510
2022.11.02 15:54:20 5: in@192.168.2.55:63510 CONNECT: (16)&(0)(4)MQTT(4)(6)(0)(10)(0)(5)Krobi(0)(12)(0)(0)(0)(255)lB(255)?(3)(0)(0)(0)(0)(5)false
2022.11.02 15:54:20 4:   MQTT2_FHEM_Server_192.168.2.55_63510 cid:Krobi CONNECT V:4 keepAlive:10 LWT:�lB�?:false
2022.11.02 15:54:20 5: out@192.168.2.55:63510 CONNACK:  (2)(0)(0)
2022.11.02 15:54:20 2: ERROR: MQTT2_FHEM_Server_192.168.2.55_63510 Krobi received bogus data, disconnecting

Die Kommunikation ist nicht verschlüsselt.

Gruß
Alexander

[rudolfkoenig]

2022.11.02 15:54:20 5: in@192.168.2.55:63510 CONNECT: (16)&(0)(4)MQTT(4)(6)(0)(10)(0)(5)Krobi(0)(12)(0)(0)(0)(255)lB(255)?(3)(0)(0)(0)(0)(5)false
2022.11.02 15:54:20 4:   MQTT2_FHEM_Server_192.168.2.55_63510 cid:Krobi CONNECT V:4 keepAlive:10 LWT:�lB�?:false

Das Geraet spezifiziert in den Flags (das ist der (6) nach MQTT in der ersten Zeile) mit dem "Will"-Bit, dass diese Nachricht ein Last-Will & Testament enthaelt.
LWT Topic+Message wird direkt nach der ClientID (Krobi) spezifiziert, zuerst 12 Bytes fuer Topic, und dann 5 Bytes fuer Message (false).

MQTT2_SERVER schliesst die Verbindung, weil der Topic 0-Zeichen enthaelt, was laut RFC nicht erlaubt ist.
Siehe http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html, Kapitel 4.7.3:

Topic Names and Topic Filters MUST NOT include the null character (Unicode U+0000) [Unicode] [MQTT-4.7.3-2]

Ich meine die Ursache bei der ESP zu suchen.

[EinEinfach]

Danke für die Analyse.

Ich schaue mir das im ESP an

[EinEinfach]

Hallo Rudi,

eine Frage habe ich noch

MQTT2_SERVER schliesst die Verbindung, weil der Topic 0-Zeichen enthaelt, was laut RFC nicht erlaubt ist.

In dem LWT steht String "false", somit ist die Nachricht nicht leer und die Verbindung darf nicht geschlossen werden. Oder habe ich was missverstanden.

Gruß
Alexander

[rudolfkoenig]

LWT Topic: (0)(12)(0)(0)(0)(255)lB(255)?(3)(0)(0)(0)
LWT Message: (0)(5)false
Message kann beliebiges an "Muell" enthalten, aber der Topic nicht.
Das ist kein 0-terminierter String, die Laenge steht jeweils vorne (256*0+12).