Keine Verbindung zu Tasmota Devices

Begonnen von roelleke, 29 September 2020, 15:40:10

Vorheriges Thema - Nächstes Thema

roelleke

Hallo,
ich weiß nicht ob ich hier richtig bin, aber ich versuche es mal.

Nach dem heutigen Update hat sich kein Tasmota Device und andere Devices die auf dem Arduino PubSubclient basieren mehr mit FHEM verbunden.
Bei den Shelly Devices war kein Problem festzustellen.

Ich benutze den MQTT2_Server von FHEM.

Nachdem ich die TcpServerUtils.pm aus dem Restore Verzeichnis zurück ins FHEM Verzeichnis kopiert habe und den FHEM Server neu gestartet habe funktioniert wieder alles.
Ich denke bei den TcpServerUtils hat sich ein Fehler eingeschlichen.

rudolfkoenig

Was ist Versionsnummer der alten Datei? Steht in der zweiten Zeile.

roelleke

Das ist die zweite Zeile, ich hoffe, das ist so ok:
# $Id: TcpServerUtils.pm 22726 2020-09-03 21:56:29Z rudolfkoenig $

rudolfkoenig

Die Aenderung sollte hoechstens leichte Performance-Probleme verursachen, wenn man sehr viele Geraete hat.
Kannst Du bitte ein Problemfall mit "attr MQT2_Server verbose 5" prokollieren, und das Log hier anhaengen?

roelleke

Hallo,
ich habe jetzt das Log erzeugt. Ich habe dazu die TcpServerUtils.pm wieder auf den neuesten Stand gebracht und den Server neu mit attr MQTT2_Server verbose 5 gestartet.
Das Log ist im Anhang, da es doch sehr umfangreich ist.
Ich hoffe, dass du hier etwas erkennen kannst.

rudolfkoenig

Das Log ist in etwas 4 Minuten lang.

Ich sehe 43 unterschiedliche MQTT-Geraete (genauer ClientIDs), davon haben sich 14 (shelly, awtrix*") nur einmal verbunden, eins (wlancul) 10-mal, der Rest (Tasmota?) 3-4mal.

Laut clientid haben die shellies und awtrix* keine Probleme, da ist ein reger Verkehr (SUBSCRIBE, PUBLISH, PINGREQ, etc) zu sehen.

Die clientids der Sorte DVES_XXXXXX (typisch Tasmota) setzen nach dem TCP-Verbindungsaufbau eine MQTT-CONNECT Meldung ab, was FHEM mit CONNACK(ok) bestaetigt. Danach kommt aber kein SUBSCRIBE, und die Verbindung wird nach 3 Sekunden geschlossen, ohne ein MQTT DISCONNECT (unhoeflich). D.h. die Verbindung wird einfach unterbrochen, das kann vom MQTT-Client ausgehen, aber auch von einer zwischengeschalteten Netzwerkkomponente.

Ich kann in FHEM keinen Grund fuer einen Fehler erkennen, insb nicht wegen dem erwaehnten Update.

Wird beim Wechsel wirklich nur diese Datei ausgeatauscht?
Gibt es mit der alten TcpServerUtils.pm gar kein Problem?
Kann man in den Tasmota-Logs eine Meldung/Begruendung erkennen?

Ohne die Vorgeschichte wuerde ich auf WLAN Probleme tippen: so viele Clients verursachen normalerweise Probleme mit einem "Wald-und-Wiesen" WLAN router.

rudolfkoenig

#6
Nachtrag:
- wie hoch ist die CPU Belastung mit der neuen und mit der alten Datei?
- gibt es Probleme auch ohne freezemon?

roelleke

Also ich tausche wirklich nur die TcpServerUtils.pm aus.
Mit der alten Datei kann ich keine Probleme erkennen. Alles funktioniert reibungslos und schnell.
Aus dem Tasmota Log lässt sich leider nichts erkennen:

11:38:54 MQT: Verbindungsversuch...
11:38:59 MQT: Verbindung fehlgeschlagen aufgrund von 10.0.0.27:1884, rc -2. Wiederversuch in 10 s


Wlan Problem habe ich keine. Ich habe wine Fritzbox 7590, zwei Repeater Fritz 1200 über LAN angebunden und eine Repeater Fritz 1750e über Wlan angebunden. Die Wlan Versorgung in meinem Haus ist überall gut.

Freezmon inactive: Keine Veränderung
Freezmon gelöscht: Keine Veränderung
mit gelöschtem Freezemon neu gestartet: keine Veränderung

Die alte  TcpServerUtils.pm wieder zurück kopiert und Server neu gestartet: Alles wieder OK.

Die Prozessorlast mit der neuen TcpServerUtils.pm liegt so bei 31%
Die Die Prozessorlast mit der neuen TcpServerUtils.pm liegt Zwischen 10% bis 20% mit kurzen Peaks bis 35%

rudolfkoenig

Die Angaben passen weiterhin nicht zum Code, oder meine Fantasie ist begrenzt.
Laut Tasmota Source-Code kommt -2, falls die Verbindung nicht aufgebaut werden kann, noch vor dem MQTT CONNECT Nachricht, was wiederum laut FHEM-Log kommt.

Kannst Du bitte eine weitere Runde mit dem neuen TcpServerUtils.pm, drehen, aber vorher "attr global mseclog 1" setzen, und in fhem.pl folgende Zeile direkt nach Zeile 778 (eval...syswrite...) einfuegen:
Log 1, "WB: $hash->{NAME}: $ret";


ZitatDie Prozessorlast mit der neuen TcpServerUtils.pm liegt so bei 31%
Die Die Prozessorlast mit der neuen TcpServerUtils.pm liegt Zwischen 10% bis 20% mit kurzen Peaks bis 35%
Welcher der beiden ist alt?

roelleke

Ja mit dem Kopieren ist dass einw Sache. Richtig ist:

Die Prozessorlast mit der neuen TcpServerUtils.pm liegt so bei 31%
Die Die Prozessorlast mit der alten TcpServerUtils.pm liegt Zwischen 10% bis 20% mit kurzen Peaks bis 35%

Das Log habe ich nach deinen Vorgaben erzeugt. Da ich nicht wußte ob Beim MQTT Server noch verbose 5 gesetzte sein sollte habe ich mal beide erzeugt.
Die Dateien sind wieder im Anhang.
Könnte da ein Zusammenhang mit der Version der Perl Module liegen? Ich habe gerade vor ein paar Tagen alle Module upgedated, nachdem das Installer Modul mal wieder einen Parsing Error gemeldet hatte.



rudolfkoenig

Falsche Kombination: ich brauche den erweiterten fhem.pl zusammen mit "attr MQTT2_SERVER verbose 5". Die angehaengten Logs sind mal mit dem einem, mal mit dem anderen erstellt.

Ein Zusammenhang mit Perl-Modulen ist unwahrscheinlich, dann duerfte keiner der Geraete funktionieren.

roelleke

Das hatte ich eigentlich so liefern wollen, aber ich habe übersehen, dass die Updatefunktion die fhem.pl überschreibt, wenn sie gändert wurde.
Ich hoffe jetzt ist alles richtig.

rudolfkoenig

Ja, danke.

Die Clients verabschieden sich, weil FHEM die CONNACKs erst nach 3+ Sekunden rausschreibt.

Das kann ich z.Zt. nur mit einem ueberlasteten System erklaeren, mein Fix war vmtl. der letzte Tropfen, was den Fass zum Ueberlaufen gebracht hat. Ich gehe davon aus, dass mit 31% die Totalauslastung eines 4+ CPU Systems gemeint ist, d.h. ein CPU ist bei 100% wg. FHEM.

Mich wuerde ein "attr global verbose 5" Log interessieren, um erstens die Zeit fuer createNotifyHash zu sehen (das wird wg. meinem Fix nach jedem Tcp-Close jetzt aufgerufen), und zweitens um rauszukriegen, womit das System so ueberlastet ist. Kann sein, dass die Menge der Geraete fuer FHEM auf dieser CPU einfach zu viel ist, aber ich wuerde das gerne verhindern.

OT: perl 5.24 ist bekannt als Speicherloch, das hat aber nichts mit dem aktuellen Problem zu tun.

roelleke

#13
Ich bin leider erst jetzt dazu gekommen das Log zu erstellen.
Ich habe es wieder in den Anhang gepackt.

Zusätzlich habe ich mir die CPU-Last noch mit htop angeschaut.
Es ist so, dass mir der neuen TcpServerUtils.pm die LAst einer CPU fast immer bei 100% liegt. Mit der alten TcpServerUtils.pm liegt die Last aller CPU's immer unter 50% wobei es zwar peaks gibt, die auch mal bei 90% liegen, aber wirklich nur kurz aufblitzen. Der Tropfen der das Fass zu Überlauf bring scheint mir da schon etwas groß zu sein.

rudolfkoenig

createNotifyHash dauert auf diesem Rechner 0.5+ Sekunden, damit kann man die CPU leicht saettigen.
Ich habe jetzt eine optimierte Version eingecheckt, was vmtl. die CPU Belastung auf die alten Levels reduziert.

Und bitte diese Anlage entfernen, sie enthaelt zu viele Daten fuer die Nachwelt.