00_MQTT.pm - Connection timed-out obwohl Server erreichbar

[kennymc.c]

Seit dem heutige Update des mosquitto Docker Containers bekomme ich im Fhem MQTT Modul bei Connection nur ein timed-out angezeigt. Neustart und Update von Fhem und Mosquitto bringen keine Besserung. Nach einer Minute auf connecting steht es wieder auf timed-out. Der State steht aber auf opened. Seltsamerweise haben zigbee2mqtt und auch andere Clients keine Probleme mit dem Zugriff auf den MQTT-Server. Schalter lassen sich auch noch über Fhem steuern, nur bekomme ich keine Rückmeldung darüber und auch Sensoren funktionieren dadurch nicht mehr.
Woran kann das liegen? Ich finde es irgendwie seltsam, dass ich Schalter trotzdem steuern kann. Aus dem Fhem Container lässt sich die MQTT Broker IP auch anpingen.

[buliwyf]

Ich habe hier ein ähnliches Problem nach dem heutigen Update.

Hier versucht FHEM ständig eine Verbindung aufzubauen aber das schlägt fehlt.

MQTT Log auszug

Code Auswählen Erweitern


1630693714: New client connected from 192.168.xx.xx:60116 as fhem (p1, c1, k5).
1630693714: Client fhem disconnected due to malformed packet.


MQTT Explorer kann aber weiterhin problemlos eine Verbindung aufbauen.
Genau wie einige Tasmotageräte.

[kennymc.c]

Ok, fast gelöst: Device gelöscht und neu angelegt. Dann ging es wieder. Allerdings scheint sich der Broker nach einem weiteren Neustart nun im Sekundentakt zu connecten und dann wieder disconnecten. Erst ein manuelles disconnect bringt Ruhe. Neu anlegen hilft dieses Mal leider nicht.

[buliwyf]

Ok, fast gelöst: Device gelöscht und neu angelegt. Dann ging es wieder. Allerdings scheint sich der Broker nach einem weiteren Neustart nun im Sekundentakt zu connecten und dann wieder disconnecten. Erst ein manuelles disconnect bringt Ruhe. Neu anlegen hilft dieses Mal leider nicht.

Genau so sieht es bei mir aktuell auch aus.

[kennymc.c]

Ich habe nach dem neu Anlegen des Brokers auch Probleme mit dem Fhem Neustart. Bis ich eine Fhem Config aus meinem Backup einspiele, kommt es zu einem Bootloop mit folgender Meldung:

Code Auswählen Erweitern

Undefined subroutine &XiaomiMQTT::DEVICE::send_publish called at ./FHEM/72_XiaomiMQTTDevice.pm line 484
Leider verbindet sich der Broker nach jedem Neustart wieder automatisch und spamt den Log zu. Lässt sich das irgendwie ändern?

[buliwyf]

Ich habe nach dem neu Anlegen des Brokers auch Probleme mit dem Fhem Neustart. Bis ich eine Fhem Config aus meinem Backup einspiele, kommt es zu einem Bootloop mit folgender Meldung:

Code Auswählen Erweitern

Undefined subroutine &XiaomiMQTT::DEVICE::send_publish called at ./FHEM/72_XiaomiMQTTDevice.pm line 484
Leider verbindet sich der Broker nach jedem Neustart wieder automatisch und spamt den Log zu. Lässt sich das irgendwie ändern?

Ich habe es erst einmal manuell aus der fhem.cfg entfernt. Dann abe rmit einem einfachen

Code Auswählen Erweitern

define mqttbroker MQTT 192.168.203.78:1883
hinzugefügt, danach startete er wieder. Das Reconnect Problem blieb aber.

[kennymc.c]

Zumindest die Log Nachrichten lassen sich mit dem attr verbose 0 ausblenden. Wird aber wohl trotzdem nicht so gut sein, wenn da dauernd neu verbunden wird.

Hier gab es schon die selben Probleme aber wirklich gelöst ist das nicht: https://forum.fhem.de/index.php/topic,73242.0.html
In Post https://forum.fhem.de/index.php/topic,73242.msg732520.html#msg732520 steht auch, dass beim Löschen und Neuanlagen alle MQTT Devices gelöscht werden. Das könnte den Bootloop danach erklären.
Ich tippe mittlerweile auch irgendeine Änderung in Mosquitto bei der Authentifizierung, die das Fhem Modul nicht unterstützt. Werde mal versuche auf einen alte Version zurück zu gehen.

Update: Leider auch mit der vorherigen 2.0.11 das selbe Problem.

[Beta-User]

Ich habe es erst einmal manuell aus der fhem.cfg entfernt. Dann abe rmit einem einfachen

Code Auswählen Erweitern

define mqttbroker MQTT 192.168.203.78:1883
hinzugefügt, danach startete er wieder. Das Reconnect Problem blieb aber.

Ihr habt aber nicht zufällig beide das (ungepatchte) 72_XiaomiMQTTDevice im Einsatz (und eine Vielzahl dieser "undefined subroutine"-Meldungen im Log)?

Wenn ja, ist eher das das Problem wie 00_MQTT.pm.

Vielleicht hilft es, nicht nur die o.g. Datei zu patchen, sondern v.a. auch, das IO-Modul nicht zu löschen, sondern _an der richtigen Stelle_ in die cfg einzufügen (ausnahmsweise händisch, weil das "Fremdmodul" das noch so braucht).

Ergänzend: Es wäre evtl. clever, in dem github-issue deutlicher zu machen, dass der (Konstruktions-) Fehler in dem Modul fatal ist...

[kennymc.c]

In der 72_XiaomiMQTTDevice habe ich nach dem letzten Update vor ein paar Wochen nur die 2 Stellen, die hier erwähnt wurden geändert: https://forum.fhem.de/index.php/topic,120794.msg1161044.html#msg1161044
Und dann das Modul mit exclude_from_update ausgeschlossen. Seitdem lief es eigentlich.

Der Broker ist in der cfg aus dem Backup vor allen anderen MQTT Devices definiert.

Beim Starten von Fhem sind mir bisher nur diese Zeilen zu dem Modul aufgefallen:

Code Auswählen Erweitern


PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/72_XiaomiMQTTDevice.pm line 209.
PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/72_XiaomiMQTTDevice.pm line 198.
...
PERL WARNING: Use of uninitialized value in string eq at ./FHEM/72_XiaomiMQTTDevice.pm line 332.
PERL WARNING: Use of uninitialized value in string eq at ./FHEM/72_XiaomiMQTTDevice.pm line 335.


[buliwyf]

Ihr habt aber nicht zufällig beide das (ungepatchte) 72_XiaomiMQTTDevice im Einsatz (und eine Vielzahl dieser "undefined subroutine"-Meldungen im Log)?

Wenn ja, ist eher das das Problem wie 00_MQTT.pm.

Vielleicht hilft es, nicht nur die o.g. Datei zu patchen, sondern v.a. auch, das IO-Modul nicht zu löschen, sondern _an der richtigen Stelle_ in die cfg einzufügen (ausnahmsweise händisch, weil das "Fremdmodul" das noch so braucht).

Ergänzend: Es wäre evtl. clever, in dem github-issue deutlicher zu machen, dass der (Konstruktions-) Fehler in dem Modul fatal ist...

Nein ich habe keine Xiaomi Devices per Mqtt angebunden. Das sind nur drei Shellys sowie ein C2-Monitor. Da ich die letzten tage kein Update von FHEM gemacht habe ist die Ursache sicherlich das moquitto Update. Eventuell behandelt mosquitto die  Paket die fhem sendet jetzt schickt strikter.

[kennymc.c]

...sondern v.a. auch, das IO-Modul nicht zu löschen, sondern _an der richtigen Stelle_ in die cfg einzufügen (ausnahmsweise händisch, weil das "Fremdmodul" das noch so braucht).

Das Modul nach dem neu Anlegen an die vorherige Position zu verschieben, verhindert schon mal die Bootloops. Aber leider kommt es weiterhin zu den Reconnects im Sekundentakt.

[Beta-User]

Ok, dann scheint das bei @buliwyf nicht (mehr) das Problem zu sein - war nur wegen des Log-Auszugs oben und dem "Löschen/Wiederanlegen", das nämlich dazu führt, dass die "optimale Reihenfolge" nicht eingehalten ist. @kennymc.c: Trotz des "Reihenfolge-Fixes durch Verschieben" wäre patchen sinnvoll.

Evtl. wäre es gut, wenn ihr hexenmeister mit Infos versorgt, welche Version euer mosquitto jetzt hat und wie die sonstigen Einstellungen am MQTT-IO sind (samt version-Infos zu FHEM selbst + die cpan-Modul und Perl-Versions-Infos)?

Das läuft alles unter docker (also auch FHEM)?

[buliwyf]

Ok, dann scheint das bei @buliwyf nicht (mehr) das Problem zu sein - war nur wegen des Log-Auszugs oben und dem "Löschen/Wiederanlegen", das nämlich dazu führt, dass die "optimale Reihenfolge" nicht eingehalten ist. @kennymc.c: Trotz des "Reihenfolge-Fixes durch Verschieben" wäre patchen sinnvoll.

Evtl. wäre es gut, wenn ihr hexenmeister mit Infos versorgt, welche Version euer mosquitto jetzt hat und wie die sonstigen Einstellungen am MQTT-IO sind (samt version-Infos zu FHEM selbst + die cpan-Modul und Perl-Versions-Infos)?

Das läuft alles unter docker (also auch FHEM)?

Hier läuft beides als Docker. FHEM habe ich heute aktualisiert als das Problem aufgetreten ist. Ich hatte gehofft, es würde damit behoben.
Ich habe auch im FHEM Container ein apt upgrade gemacht was das Problem aber auch nicht behoben hat.
Mosquitto läuft ebenfalls als Docker. Version (2.0.12)
Mosquitto config:

Code Auswählen Erweitern


listener 1883
allow_anonymous true
persistence true
persistence_location /mosquitto/data/
log_dest file /mosquitto/log/mosquitto.log


[kennymc.c]

@kennymc.c: Trotz des "Reihenfolge-Fixes durch Verschieben" wäre patchen sinnvoll.

Ich dachte mit den 2 Zeilen ändern wäre das Patchen gemeint? Das habe ich bereits vor Wochen gemacht und auch nicht geändert. Oder gibt es noch andere Stellen? Die erwähnten Perl Warnings treten auch mit der gepatchten Version noch auf.

Evtl. wäre es gut, wenn ihr hexenmeister mit Infos versorgt, welche Version euer mosquitto jetzt hat und wie die sonstigen Einstellungen am MQTT-IO sind (samt version-Infos zu FHEM selbst + die cpan-Modul und Perl-Versions-Infos)?

Das läuft alles unter docker (also auch FHEM)?

Sowohl Fhem als auch Mosquitto laufen über Docker auf einem Unraid Server. Die Mosquitto Version bisher müsste 2.0.11 gewesen sein zu der es heute ein Update auf 2.0.12 gab. Genau nach diesem Update trat das Time Out Problem auf. Habe es aber wie erwähnt schon mit 2.0.11 versucht und wieder die selben Probleme bekommen mit den Reconnects.

Mosquitto Config:

Code Auswählen Erweitern


persistence true
persistence_location /mosquitto/data/
autosave_on_changes true
autosave_interval 3600

listener 1883

log_dest file /mosquitto/log/mosquitto.log
log_type all

password_file /mosquitto/config/pwfile
allow_anonymous false


fhem.pl: 24810/2021-07-29
cpan Version: 1.7044
Perl Version: 5.028001

Docker Image Parameter:
CPAN_PKGS IO::Socket::SSL IO::Socket::Multicast XML::Simple Data::Peek Net::FTPSSL

[Beta-User]

OK, dann seid ihr betreffend dem Xiaomi-Ding auf dem "letzten Stand".

@Rudi (falls du hier mitliest):
Könnte es sein, dass das Problem eventuell auch was mit DevIo zu tun hat? Hintergrund dieser sehr vorsichtigen (!) Frage ist Folgendes: Ich hatte neulich etwas mit dem UBUS-Code (peer review in der Perl-Ecke) gespielt und festgestellt, dass UBUS iVm. DevIo mehrfach pro Sekunde einen Verbindungsversuch unternommen hat - erwartet hätte ich den default (alle 60 Sekunden, wenn ich das dem Code richtig entnommen habe). Hatte das auf das OS geschoben, aber evtl. ist das doch generell anders und das hier hängt damit zusammen?