Autor Thema: MQTT2_CLIENT Probleme  (Gelesen 7577 mal)

Offline HomeAlone

  • Full Member
  • ***
  • Beiträge: 255
Antw:MQTT2_CLIENT Probleme
« Antwort #105 am: 06 Dezember 2018, 09:45:25 »
Netter Versuch, aber set publish in MQTT2_CLIENT interpretiert {} nicht als Perl Ausdruck, sondern sendet es unveraendert an den Server.
Sowas ist mW auch nirgendwo dokumentiert, wenn doch, bitte sagen.
Nein, hast Du nirgends geschrieben, aber ich dachte Versuch macht kluch... ;)


Ich habe versucht die Endlosschleife nachzustellen:
- mosquitto mit SSL und aktivierten Benutzer/Passwort gestartet
- MQTT2_CLIENT passend konfiguriert.
- geprueft, dass beim falschen Passwort "Connection refused, not authorized" kommt, danach korrektes Passwort wieder gesetzt
- das erwaehnte set abgesetzt.

Mosquitto liefert das topic zurueck, wg. autocreate erweitert FHEM das angelegte MQTT2_DEVICE, das ein reading mit dem Namen test und mit dem Wert {toJSON({ 'state' => 'OFF'})} kriegt.
=> Works as designed.

Bin bereit weiter zu debuggen, wenn ich das Problem nachstellen kann.
Aktuell läuft es bei mir stabil, habe seit Deinem Posting keine Abstürze mehr gehabt. Ich habe bei mir auch kein MQTT2_DEVICE in der Config. Werde mir zu Testzwecken aber eines anlegen, da ich es vermutlich spätenstens, wenn ich nicht nur publishen sondern auch subscriben will benötigen werde.

Btw: die Perl Auswertung kann man mittels den global (d.h. fuer alle sets) verfuegbaren Set-Magic errreichen:set mosquitolocal publish fhempub/test {( toJSON({'state'=>'OFF'}) )}
Man achte auf {(...)}
Vielen Dank, habe ich ausprobiert und - oh Wunder ;) - es funktioniert. "set magic" kannte ich bisher noch nicht - muss ich mir mal genauer ansehen. Für interessierte Leser zum Ersparen der Googleanfrage: https://wiki.fhem.de/wiki/Set_magic

Noch mal vielen Dank für Deinen Einsatz, Rudi!

Offline OdfFhem

  • Sr. Member
  • ****
  • Beiträge: 565
Antw:MQTT2_CLIENT Probleme
« Antwort #106 am: 09 Dezember 2018, 14:39:22 »
Im Produktiv-System nutze ich derzeit folgende (schon etwas ältere) MQTT2-Version
00_MQTT2_CLIENT.pm    17867 2018-11-29 09:55:51Z rudolfkoenig
10_MQTT2_DEVICE.pm    17832 2018-11-24 15:24:30Z rudolfkoenig
und habe damit keine nennenswerten Probleme.

Nun wollte ich mal im Test-System mit dem aktuell verteilten MQTT2-Stand komplett neu aufsetzen.


Dabei stoße ich schon sehr früh auf folgende (ernsten) Probleme:


Ich nutze MQTT2_CLIENT mit externem mosquitto-Server. Bis man das Passwort gesetzt hat, schaltet der Status vom MQTT2_CLIENT-Device in rasantem Tempo zwischen opened bzw. disconnected hin und her und "müllt" dabei munter das Logfile zu.
Ein wirklich sehr kleiner Auszug aus dem Logfile
2018.12.09 13:27:43.932 3: Opening myMqttClient device raspberrypi:1883
2018.12.09 13:27:43.946 3: myMqttClient device opened
2018.12.09 13:27:43.968 1: raspberrypi:1883 disconnected, waiting to reappear (myMqttClient)
2018.12.09 13:27:43.976 1: raspberrypi:1883 reappeared (myMqttClient)
2018.12.09 13:27:43.980 1: raspberrypi:1883 disconnected, waiting to reappear (myMqttClient)
2018.12.09 13:27:43.987 1: raspberrypi:1883 reappeared (myMqttClient)
2018.12.09 13:27:43.991 1: myMqttClient: Connection refused, not authorized
2018.12.09 13:27:43.993 1: raspberrypi:1883 disconnected, waiting to reappear (myMqttClient)
2018.12.09 13:27:44.190 1: raspberrypi:1883 reappeared (myMqttClient)
.
.
.


Das zum CLIENT gehörige MQTT2-Device wird automatisch angelegt, heißt aber aus meiner Sicht falsch - MQTT2_my_qtt_lient statt MQTT2_myMqttClient.
autocreate: define MQTT2_my_qtt_lient MQTT2_DEVICE myMqttClient


Dieses Problem setzt sich dann auch nach dem Setzen von bridgeRegexp für die automatisch angelegten, eigentlichen MQTT2_DEVICEs fort.
autocreate: define MQTT2_zigbee_dimmer_witch1 MQTT2_DEVICE zigbee_dimmerSwitch1


Noch ein Hinweis zum bridgeRegexp: Verwendet man die 0x-Variante für zigbee2mqtt, darf man keine friendly_names verwenden.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 21923
Antw:MQTT2_CLIENT Probleme
« Antwort #107 am: 09 Dezember 2018, 18:32:20 »
Zitat
Dabei stoße ich schon sehr früh auf folgende (ernsten) Probleme:
Unter ernst verstehe ich sowas wie "funktioniert gar nicht".

Zitat
Bis man das Passwort gesetzt hat, schaltet der Status vom MQTT2_CLIENT-Device in rasantem Tempo zwischen opened bzw. disconnected hin und her und "müllt" dabei munter das Logfile zu.
Interessant, bei mir werden nur alle 3 Sekunden Meldungen geschrieben. Laeuft dein FHEM auf Windows?
Ab sofort wird bei CONNACK mit Fehler das authError Internal gesetzt, was ein reconnect verhindert.
Dieses Internal wird entfernt, wenn man "attr m2c username" oder "set m2c password" ausfuehrt oder FHEM neu startet.

Zitat
Das zum CLIENT gehörige MQTT2-Device wird automatisch angelegt, heißt aber aus meiner Sicht falsch - MQTT2_my_qtt_lient statt MQTT2_myMqttClient.
Danke fuer den Hinweis, ich habe es gefixt.

Zitat
Noch ein Hinweis zum bridgeRegexp: Verwendet man die 0x-Variante für zigbee2mqtt, darf man keine friendly_names verwenden.
Das habe ich nicht verstanden, bitte anders formulieren, oder ein konkretes Beispiel anhaengen.

Offline OdfFhem

  • Sr. Member
  • ****
  • Beiträge: 565
Antw:MQTT2_CLIENT Probleme
« Antwort #108 am: 09 Dezember 2018, 21:51:29 »
Zitat
Unter ernst verstehe ich sowas wie "funktioniert gar nicht".
Daher hatte ich "ernst" eingeklammert und bezog sich eigentlich auch mehr auf die autocreate-Funktionalität; im Produktiv-System z.B. wären ja vermutlich lauter neue, unkonfigurierte Devices angelegt worden und die alten, bereits konfigurierten Devices würden nicht mehr aktualisiert - wären somit ohne Funktion.

Zitat
Laeuft dein FHEM auf Windows?
Nein - läuft unter Raspbian Stretch auf einem Raspberry Pi.

Zitat
Das habe ich nicht verstanden, bitte anders formulieren, oder ein konkretes Beispiel anhaengen.
Bei zigbee2mqtt wird jedes Gerät über eine eindeutige Hex-ID (z.B. 0x123456789) identifiziert. Dieser doch sehr technische Name kann durch die rename-Funktionalität mit einem etwas sprechenderen Namen (z.B. dimmerSwitch1) - dem friendly_name -  versehen werden. Macht man dies, werden die MQTT-Publish-Meldungen von zigbee2mqtt zukünftig unter dem friendly_name und nicht mehr unter der Hex-ID verbreitet, was unmittelbar Auswirkung auf bridgeRegexp, readingList, usw. hat.

Statt
zigbee2mqtt/0x123456789:.* { json2nameValue($EVENT) }
müsste das readingList-Attribut beim FHEM-Device dann so aussehen
zigbee2mqtt/dimmerSwitch1:.* { json2nameValue($EVENT) }

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 21923
Antw:MQTT2_CLIENT Probleme
« Antwort #109 am: 10 Dezember 2018, 09:10:48 »
Zitat
Dieser doch sehr technische Name kann durch die rename-Funktionalität mit einem etwas sprechenderen Namen (z.B. dimmerSwitch1) - dem friendly_name -  versehen werden. Macht man dies, werden die MQTT-Publish-Meldungen von zigbee2mqtt zukünftig unter dem friendly_name und nicht mehr unter der Hex-ID verbreitet, was unmittelbar Auswirkung auf bridgeRegexp, readingList, usw. hat.
Das Problem in diesem Fall ist einen Algorithmus zu finden, was den bridge vom Rest unterscheidet.
Wenn jemand eine Idee hat, bitte melden.

Offline Beta-User

  • Developer
  • Hero Member
  • ****
  • Beiträge: 9693
  • eigentlich eher "user" wie "developer"
Antw:MQTT2_CLIENT Probleme
« Antwort #110 am: 10 Dezember 2018, 09:22:36 »
Eine Idee habe ich dazu nicht, (mal abgesehen davon, dass alle Statusmeldungen über "zigbee2mqtt/log" reinkommen, man also eine Art negativer Auslese machen könnte).
Aber in's Wiki kommt der deutliche Hinweis, dass man nach Möglichkeit die Devices an der Stelle (friendly name) entweder unbearbeitet lassen sollte oder eben ein "0x" voranstellen. M.E. ist es ausreichend, dass man in FHEM einen "sprechenden Namen" vergeben kann.
Wer unbedingt will (z.B., weil das für eine andere HA-Software erforderlich ist), kann immer noch die bridgeRegexp erweitern; da sind ja auch mehrere Einträge zulässig...
Server: HP-T620@Debian 10, aktuelles FHEM + ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | BT@OpenMQTTGateway
svn:MySensors, WeekdayTimer, RandomTimer, AttrTemplate => {mqtt2, mysensors, httpmod}

Offline Wallmeier

  • Full Member
  • ***
  • Beiträge: 132
Antw:MQTT2_CLIENT Probleme
« Antwort #111 am: 03 Januar 2019, 12:32:14 »
Ich hatte heute wieder die Situation, dass sich die Logzeilen "127.0.0.1:1883 reappeared (mqtt2)" und "127.0.0.1:1883 disconnected, waiting to reappear (mqtt2)" immer wieder abgewechselt haben. Nachdem ich Verbose für mqtt2 auf 5 gesetzt habe, bin ich noch nicht weiter gekommen und habe daraufhin noch einen tcpdump gemacht...

2019.01.03 12:16:37.697 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt2)
2019.01.03 12:16:37.726 5: HttpUtils url=http://127.0.0.1:1883/
2019.01.03 12:16:37.728 4: IP: 127.0.0.1 -> 127.0.0.1
2019.01.03 12:16:37.732 1: 127.0.0.1:1883 reappeared (mqtt2)
2019.01.03 12:18:07.698 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt2)

Der dazugehörige tcpdump ist angehängt...

Für mich sieht der dump so aus, dass der tcp-connect sauber durchgeführt wird, aber danach MQTT2_CLIENT keine CONNECT Nachricht an den Broker (mosquitto) schickt... Nach 90 Sekunden ohne Aktivität auf dem Socket schliesst dann Mosquitto den Socket...

Offline Papaloewe

  • Sr. Member
  • ****
  • Beiträge: 623
Antw:MQTT2_CLIENT Probleme
« Antwort #112 am: 03 Januar 2019, 13:34:21 »
Ich habe den keepalive = 120 jetzt einmal testweise laufen und zumindest bis heute morgen lief es ohne Fehlermeldungen druch.
...mal abwarten.

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 21923
Antw:MQTT2_CLIENT Probleme
« Antwort #113 am: 03 Januar 2019, 20:10:00 »
Zitat
Für mich sieht der dump so aus, dass der tcp-connect sauber durchgeführt wird, aber danach MQTT2_CLIENT keine CONNECT Nachricht an den Broker (mosquitto) schickt...
Hier haette mich noch das "attr MQTT2_CLIENT verbose 5" Output interessiert.
Was fuer ein OS is das?
Eigentlich sendet MQTT2_CLIENT alle 30 Sekunden zusaetzlich auch ein PINGREQ, das haette man in deinem dump auch sehen sollen.
Die Daten gehen normalerweise ueber den select(write) Filter, damit FHEM sich wegen einem toten mosquitto nicht aufhaengt, evtl. haengt das Problem damit zusammen.

Ich habe jetzt eine Weile mit "kaputten" mosquitto (falsches password, SSL vs keins, usw) rumexperimentiert, und ich kann das Problem nur dann reproduzieren, falls mosquitto SSL erwartet, im FHEM das SSL Attribut aber nicht gesetzt ist.

Offline Wallmeier

  • Full Member
  • ***
  • Beiträge: 132
Antw:MQTT2_CLIENT Probleme
« Antwort #114 am: 03 Januar 2019, 21:30:29 »
Verbose war bereits auf 5 gesetzt... Mehr als die Zeilen, die in meinem ersten Post zu dem Thema standen, gibt es schlicht nicht.

FHEM läuft bei mir auf Raspbian Strech (Raspberry Pi 3).

Ich gehe davon aus, dass der PINGREQ aber erst nach einem CONNECT überhaupt geschickt wird - und schon dieser fehlt.

Reproduzieren kann ich dieses zuverlässig in der Nacht - dort läuft um 3:00 von DbLog ein reduceLog, was dazu führt das fhem für ca. 92 Sekunden blockiert ist... Danach steht im Log ein "disconnected, waiting to reappear (mqtt2)" und es gibt die Endlosschleife aus "reappeared" und 90 Sekunden später "disconnected, waiting to reappear".

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 21923
Antw:MQTT2_CLIENT Probleme
« Antwort #115 am: 03 Januar 2019, 22:21:00 »
Zitat
dort läuft um 3:00 von DbLog ein reduceLog, was dazu führt das fhem für ca. 92 Sekunden blockiert ist
Das sollte vermieden, bzw. dringend gefixt werden.

Ich habe die Ursache mit einem { sleep(60) } nachgestellt, und mosquitto hat erwartungsgemaess die Verbindung zugemacht.
Danach gibg es aber bei mir weiter. Hier ist die Ausgabe  nach dem sleep:
Zitat
2019.01.03 22:17:44 5: mc: keepalive 30
2019.01.03 22:17:44 5: mc: sending PINGREQ (192)(0)
2019.01.03 22:17:44 1: localhost:1883 disconnected, waiting to reappear (mc)
2019.01.03 22:17:49 5: HttpUtils url=https://localhost:1883/
2019.01.03 22:17:49 4: IP: localhost -> 127.0.0.1
2019.01.03 22:17:49 5: mc: sending CONNECT (16) (0)(6)MQIsdp(3)(194)(0)(30)(0)(2)mc(0)(4)user(0)(8)password
2019.01.03 22:17:49 5: SW: 102000064d514973647003c2001e00026d63000475736572000870617373776f7264
2019.01.03 22:17:49 1: localhost:1883 reappeared (mc)
2019.01.03 22:17:49 5: mc: received CONNACK (0)(0)
2019.01.03 22:17:49 5: mc: sending SUBSCRIBE (128)(6)(0)(4)(0)(1)#(0)
2019.01.03 22:17:49 5: mc: received PINGRESP
2019.01.03 22:17:49 5: mc: received SUBACK (0)(4)(0)
2019.01.03 22:18:19 5: mc: keepalive 30
2019.01.03 22:18:19 5: mc: sending PINGREQ (192)(0)...

Offline Wallmeier

  • Full Member
  • ***
  • Beiträge: 132
Antw:MQTT2_CLIENT Probleme
« Antwort #116 am: 03 Januar 2019, 22:47:11 »
War bei dem Test die SVN Rev. 18127 schon aktiv?

Offline rudolfkoenig

  • Administrator
  • Hero Member
  • *****
  • Beiträge: 21923
Antw:MQTT2_CLIENT Probleme
« Antwort #117 am: 04 Januar 2019, 00:01:42 »
Zitat
War bei dem Test die SVN Rev. 18127 schon aktiv?
Ja, das wird aber dein Problem nicht loesen.
Die Aenderung in 18127 wuerde ein select-Problem umschiffen, soweit kommt es aber laut dem Log gar nicht.

Offline Wallmeier

  • Full Member
  • ***
  • Beiträge: 132
Antw:MQTT2_CLIENT Probleme
« Antwort #118 am: 04 Januar 2019, 08:33:43 »
Ich hatte gestern Abend die Änderung von Rev. 18127 in meine Installation manuell reingepatcht gehabt - und heute Nacht hatte ich zwar auch wieder folgende Logzeilen
2019.01.04 03:01:36.668 1: 127.0.0.1:1883 disconnected, waiting to reappear (mqtt2)
2019.01.04 03:01:36.692 1: 127.0.0.1:1883 reappeared (mqtt2)
Aber diesmal mit dem großen Unterschied, dass es jetzt keine Endlosschleife geworden ist und die mqtt2-Instanz benutzbar ist  ;D

Offline Reinhart

  • Hero Member
  • *****
  • Beiträge: 2064
Antw:MQTT2_CLIENT Probleme
« Antwort #119 am: 04 Januar 2019, 10:53:22 »
@Wallmeier

hast die eine SQLite Datenbank die du um 03:00 komprimierst bzw. alte Einträge löscht ( reduceLogNbl ) ?
Ich hatte den selben Fehler und die kamen eindeutig von dem Datenbank Job. Wenn ja, dann mach in der myDblog einen "configCheck" und befolge die Ratschläge, dann sind die Fehler im MQTT2_Client weg. Durch setzen des Attributes "asyncMode 1" ist das dann behoben.

2019.01.02 01:02:34 1: localhost:1883 disconnected, waiting to reappear (ebusMQTT)
2019.01.02 01:02:34 1: localhost:1883 reappeared (ebusMQTT)
2019.01.02 01:04:04 1: localhost:1883 disconnected, waiting to reappear (ebusMQTT)
2019.01.02 01:04:04 1: localhost:1883 reappeared (ebusMQTT)
2019.01.02 01:05:34 1: localhost:1883 disconnected, waiting to reappear (ebusMQTT)
das waren meine Fehlermeldungen im MQTT2_Client

2019.01.02 01:00:00 3: DbLog myDbLog -> Deletion of records older than 30 days in database /opt/fhem/fhem.db requestedund das der Auslöser wenn "asyncMode" nicht "1" ist.

LG
Reinhart

FHEM auf Raspy4 mit Buster + SSD, mit FS20, Homematic, ESP8266, Sonoff, Electrodragon, eBus, RPi mit COC,NanoCUL, MapleCUL, HM-CFG-LAN Adapter, MQTT2, Alexa