[Bugs] 00_MQTT2_SERVER / 10_MQTT2_DEVICE

Begonnen von betateilchen, 10 August 2018, 18:01:33

Vorheriges Thema - Nächstes Thema

rudolfkoenig


Mitch

FHEM im Proxmox Container

m0urs

Zitat von: rudolfkoenig am 30 Januar 2019, 21:20:16
@m0urs: Ich will kein "unclean sesssion" unterstuetzen. Aber nachdem ich die RFC nochmal genauer gelesen habe, meine ich, dass man das nicht als Fehler meldet, sondern als "ich habe kein Session, aber connect ist OK". Habe das Modul geaendert (morgen ab 8 per update verfuegbar), bitte um Feedback.

Ganz vielen Dank! Mit der neuen Version funktioniert der Connect von Owntracks, es wurde ein Device erzeugt und Readings aktualisiert. Damit komme ich sicher erst einmal weiter. Ggf. melde ich mich wieder ;-)

OppiM

Hi,

ich hab in letzter Zeit vermehrt komplette Abstürze von FHEM. Die letzten Eintrage im Log sehen in der Regel so aus:

2019.02.07 07:23:02.178 1: PERL WARNING: Wide character in print at ./FHEM/92_FileLog.pm line 214.
2019.02.07 07:23:02.178 1: stacktrace:
2019.02.07 07:23:02.178 1:     main::__ANON__                      called by ./FHEM/92_FileLog.pm (214)
2019.02.07 07:23:02.178 1:     main::FileLog_Log                   called by fhem.pl (3684)
2019.02.07 07:23:02.178 1:     main::CallFn                        called by fhem.pl (3604)
2019.02.07 07:23:02.178 1:     main::DoTrigger                     called by fhem.pl (3970)
2019.02.07 07:23:02.178 1:     main::Dispatch                      called by ./FHEM/00_MQTT2_SERVER.pm (431)
2019.02.07 07:23:02.178 1:     main::MQTT2_SERVER_doPublish        called by ./FHEM/00_MQTT2_SERVER.pm (327)
2019.02.07 07:23:02.178 1:     main::MQTT2_SERVER_Read             called by fhem.pl (3684)
2019.02.07 07:23:02.178 1:     main::CallFn                        called by fhem.pl (737)
Wide character in syswrite at FHEM/TcpServerUtils.pm line 296.


Ich hab dann mal VERBOSE 5 für das MQTT2_SERVER Device gesetzt, die letzten Einträge sahen dann so aus (komischerweise wurde dann der Stacktrace nicht mehr ausgegeben?!):

2019.02.07 07:16:55.762 5: PUBLISH: 0(234)(1)(0)(21)/Tasmota_1/tele/STATE{"Time":"2019-02-07T07:16:56","Uptime":"20T11:29:22","Vcc":3.423,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"on","Wifi":{"AP":1,"SSId":"xxx","BSSId":"xxx","Channel":1,"RSSI":7
2019.02.07 07:16:55.762 4: m2s_192.168.xx.xx_52234 Tasmota_1 PUBLISH /Tasmota_1/tele/STATE:{"Time":"2019-02-07T07:16:56","Uptime":"20T11:29:22","Vcc":3.423,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"on","Wifi":{"AP":1,"SSId":"xxx","BSSId":"xxx","Channel":1,"RSSI":76}}
2019.02.07 07:16:55.763 5: m2s: dispatch autocreate\000Tasmota_1\000/Tasmota_1/tele/STATE\000{"Time":"2019-02-07T07:16:56","Uptime":"20T11:29:22","Vcc":3.423,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"POWER":"on","Wifi":{"AP":1,"SSId":"xxx","BSSId":"xxx","Channel":1,"RSSI":76}}
Wide character in syswrite at FHEM/TcpServerUtils.pm line 296.


Das die erste Zeile abgeschnitten ist ist kein Copy/Paste-Fehler, so steht es im Log.

Was kann ich tun, um die Fehlerquelle noch mehr einzugrenzen?

Gruß,
Michael

rudolfkoenig

Zitatkomischerweise wurde dann der Stacktrace nicht mehr ausgegeben?!
Dein Stacktrace gehoert zu FileLog, weil im ersten Fall noch was zu loggen war, im zweiten Fall aber nicht mehr.
Der Absturz ist anderswo (TcpServerUtils, vmtl.), und das wurde nicht abgefangen.

Das habe ich jetzt geaendert, im Problemfall wird der Text ausgegeben, und ein stacktrace generiert.
Die abgeschnittene Debug-Zeile habe ich auch gefixt.

Da ich keine Idee habe, woran das Problem liegt (ich vermute die Ursache nicht in MQTT2_SERVER, auch wenn der Stacktrace das suggeriert), schlage ich vor mit dem aktualisierten Version (ab morgen um 8 per FHEM-update) einen neuen Versuch zu starten, und die Fehlermeldung hier zu zeigen.





OppiM

Hi,

ich hatte jetzt wieder zwei Abstürze, diesmal allerdings mit anderem Fehler.



2019.02.15 22:50:03.446 5: PUBLISH: 0(135)(1)(0) /OpenMQTTGateway/OMG_3/SYStoMQTT{"uptime":24480,"freeMem":85444,"rssi":-74,"SSID":"Oppenheimer","IP":"192.168.18.223","modules":"BT"}
2019.02.15 22:50:03.446 4: m2s_192.168.18.223_64348 OMG_3 PUBLISH /OpenMQTTGateway/OMG_3/SYStoMQTT:{"uptime":24480,"freeMem":85444,"rssi":-74,"SSID":"Oppenheimer","IP":"192.168.18.223","modules":"BT"}
2019.02.15 22:50:03.447 5: m2s: dispatch autocreate\000OMG_3\000/OpenMQTTGateway/OMG_3/SYStoMQTT\000{"uptime":24480,"freeMem":85444,"rssi":-74,"SSID":"Oppenheimer","IP":"192.168.18.223","modules":"BT"}
2019.02.15 22:50:03.593 5: PUBLISH: 0k(0)$/OpenMQTTGateway/home_presence/OMG_6{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737}
2019.02.15 22:50:03.593 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH /OpenMQTTGateway/home_presence/OMG_6:{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737}
2019.02.15 22:50:03.594 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/home_presence/OMG_6\000{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737}
2019.02.15 22:50:03.914 5: PUBLISH: 0(217)(1)(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737,"servicedata":"712098008ce7ac668d7cc40d0910020000","servicedatauuid":"0000fe95-00
00-1000-8000-00805f9b34fb"}
2019.02.15 22:50:03.914 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH /OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7:{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737,"servicedata":"712098008ce7ac668d7cc40d0910020000","servicedata
uuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.15 22:50:03.915 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7\000{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737,"servicedata":"712098008ce7ac668d7cc40d0910020000","servicedat
auuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.15 22:50:03.922 5: PUBLISH: 003(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer":
2019.02.15 22:50:03.922 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH &/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer"::
2019.02.15 22:50:03.923 5: m2s: dispatch autocreate\000OMG_6\000&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer"_\000
2019.02.15 22:50:03.927 5: CONNACK: "0"}freeMem":82852,"rssi":-49,"SSID":"Oppenheimer"
2019.02.15 22:50:03.927 1: ERROR: Unhandled packet CONNACK, disconneting m2s_192.168.18.129_54398
2019.02.15 22:50:03.993 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/OMG_6/LWT\000Offline
Unescaped left brace in regex is illegal here in regex; marked by <-- HERE in m/^OMG_6:&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{ <-- HERE "fer"_:.*$/ at ./FHEM/10_MQTT2_DEVICE.pm line 104.



2019.02.16 06:20:28.712 5: PUBLISH: 0(127)(0)$/OpenMQTTGateway/home_presence/OMG_3{"id":"c4:7c:8d:66:b3:49","name":"Flower care","rssi_OMG_3":-78,"distance_OMG_3":7.85288}
2019.02.16 06:20:28.712 4: m2s_192.168.18.223_64463 OMG_3 PUBLISH /OpenMQTTGateway/home_presence/OMG_3:{"id":"c4:7c:8d:66:b3:49","name":"Flower care","rssi_OMG_3":-78,"distance_OMG_3":7.85288}
2019.02.16 06:20:28.712 5: m2s: dispatch autocreate\000OMG_3\000/OpenMQTTGateway/home_presence/OMG_3\000{"id":"c4:7c:8d:66:b3:49","name":"Flower care","rssi_OMG_3":-78,"distance_OMG_3":7.85288}
2019.02.16 06:20:28.844 5: PUBLISH: 0(135)(1)(0) /OpenMQTTGateway/OMG_6/SYStoMQTT{"uptime":50904,"freeMem":84516,"rssi":-79,"SSID":"Oppenheimer","IP":"192.168.18.129","modules":"BT"}
2019.02.16 06:20:28.844 4: m2s_192.168.18.129_61607 OMG_6 PUBLISH /OpenMQTTGateway/OMG_6/SYStoMQTT:{"uptime":50904,"freeMem":84516,"rssi":-79,"SSID":"Oppenheimer","IP":"192.168.18.129","modules":"BT"}
2019.02.16 06:20:28.845 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/OMG_6/SYStoMQTT\000{"uptime":50904,"freeMem":84516,"rssi":-79,"SSID":"Oppenheimer","IP":"192.168.18.129","modules":"BT"}
2019.02.16 06:20:28.923 5: PUBLISH: 0(237)(1)(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66B349{"id":"c4:7c:8d:66:b3:49","name":"Flower care","rssi_OMG_3":-78,"distance_OMG_3":7.85288,"servicedata":"71209800e049b3668d7cc40d0910027b00","servicedatauuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.16 06:20:28.923 4: m2s_192.168.18.223_64463 OMG_3 PUBLISH /OpenMQTTGateway/BTtoMQTT/C47C8D66B349:{"id":"c4:7c:8d:66:b3:49","name":"Flower care","rssi_OMG_3":-78,"distance_OMG_3":7.85288,"servicedata":"71209800e049b3668d7cc40d0910027b00","servicedatauuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.16 06:20:28.924 5: m2s: dispatch autocreate\000OMG_3\000/OpenMQTTGateway/BTtoMQTT/C47C8D66B349\000{"id":"c4:7c:8d:66:b3:49","name":"Flower care","rssi_OMG_3":-78,"distance_OMG_3":7.85288,"servicedata":"71209800e049b3668d7cc40d0910027b00","servicedatauuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.16 06:20:28.930 5: PUBLISH: 005(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66B349{"fer":
2019.02.16 06:20:28.930 4: m2s_192.168.18.223_64463 OMG_3 PUBLISH &/OpenMQTTGateway/BTtoMQTT/C47C8D66B349{"fer"::
2019.02.16 06:20:28.930 5: m2s: dispatch autocreate\000OMG_3\000&/OpenMQTTGateway/BTtoMQTT/C47C8D66B349{"fer"_\000
2019.02.16 06:20:28.932 5: CONNACK: "123"}eeMem":81140,"rssi":-75,"SSID":"Oppenheimer",
2019.02.16 06:20:28.932 1: ERROR: Unhandled packet CONNACK, disconneting m2s_192.168.18.223_64463
2019.02.16 06:20:28.939 5: m2s: dispatch autocreate\000OMG_3\000/OpenMQTTGateway/OMG_3/LWT\000Offline
Unescaped left brace in regex is illegal here in regex; marked by <-- HERE in m/^OMG_3:&/OpenMQTTGateway/BTtoMQTT/C47C8D66B349{ <-- HERE "fer"_:.*$/ at ./FHEM/10_MQTT2_DEVICE.pm line 104.


So sieht eine "normaler" Empfang aus (gleicher Sensor wie beim 1. Absturz).


2019.02.15 22:46:47.444 5: PUBLISH: 0k(0)$/OpenMQTTGateway/home_presence/OMG_6{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737}
2019.02.15 22:46:47.444 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH /OpenMQTTGateway/home_presence/OMG_6:{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737}
2019.02.15 22:46:47.444 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/home_presence/OMG_6\000{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737}
2019.02.15 22:46:47.541 5: PUBLISH: 0(217)(1)(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737,"servicedata":"7120980078e7ac668d7cc40d0910020000","servicedatauuid":"0000fe95-00
00-1000-8000-00805f9b34fb"}
2019.02.15 22:46:47.541 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH /OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7:{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737,"servicedata":"7120980078e7ac668d7cc40d0910020000","servicedata
uuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.15 22:46:47.542 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7\000{"id":"c4:7c:8d:66:ac:e7","rssi_OMG_6":-75,"distance_OMG_6":5.832737,"servicedata":"7120980078e7ac668d7cc40d0910020000","servicedat
auuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.15 22:46:47.545 5: PUBLISH: 03(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer":"0"}
2019.02.15 22:46:47.545 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH /OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7:{"fer":"0"}
2019.02.15 22:46:47.545 5: m2s: dispatch autocreate\000OMG_6\000/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7\000{"fer":"0"}


Gruß,
Michael

rudolfkoenig

- die Meldung sagt es eigentlich: dieser Regexp ist falsch, man muss es korrigieren.
- wurde der regexp per autocreate angelegt? Wenn ja, bitte das passende Topic/Message hier anhaengen
- perl 5.18 hat das Problem nicht, perl 5.28 meldet eine Warnung, die ich aber nicht abfangen kann(??), einen Absturz sehe ich nicht. Welche Perl Version verwendest Du?
- ich habe fuer readingsList eine Regexp-Pruefung eingebaut, damit man sowas beim Setzen der Attribute sieht: kannst du bitte pruefen, ob es hilft?

OppiM

Hi,

hier ein List des Device:
Internals:
   CHANGED   
   CID        FlowerCare_C47C8D66ACE7
   DEF        FlowerCare_C47C8D66ACE7
   DEVICETOPIC Xiaomi_FlowerCare_3
   FUUID      5c447c92-f33f-7215-12f6-6a4c60ed59c904e8
   IODev      m2s
   LASTInputDev m2s
   MSGCNT     1814
   NAME       Xiaomi_FlowerCare_3
   NR         644
   STATE      T: 21.9°C - M: 0% - L: 35 - F: 0
   TYPE       MQTT2_DEVICE
   m2s_MSGCNT 1814
   m2s_TIME   2019-02-16 15:37:27
   Helper:
     DBLOG:
       Lux:
         logdb:
           TIME       1550327588.94835
           VALUE      35
       Temperature:
         logdb:
           TIME       1550327813.84116
           VALUE      21.9
   OLDREADINGS:
     2019-02-16 15:36:53   LastMessage     Sat Feb 16 15:36:53 2019
   READINGS:
     2019-02-16 15:37:27   Fertility       0
     2019-02-16 15:37:27   LastMessage     Sat Feb 16 15:37:27 2019
     2019-02-16 15:37:27   LastOldMessage  Sat Feb 16 15:36:53 2019
     2019-02-16 15:37:27   Lux             35
     2019-02-16 15:37:27   Moisture        0
     2019-02-16 15:37:27   Temperature     21.9
     2019-02-16 15:37:27   distance_OMG_3  32.73764
     2019-02-16 15:36:53   distance_OMG_5  1.01076
     2019-02-16 15:36:45   distance_OMG_6  6.44788
     2019-02-16 15:37:27   fer             0
     2019-02-16 15:37:27   id              c4:7c:8d:66:ac:e7
     2019-02-16 15:36:27   lux             35
     2019-02-16 15:35:48   moi             0
     2019-02-16 15:37:27   name            Flower care
     2019-02-16 15:37:27   rssi_OMG_3      -94
     2019-02-16 15:36:53   rssi_OMG_5      -59
     2019-02-16 15:36:45   rssi_OMG_6      -76
     2019-02-16 15:37:27   servicedata     7120980028e7ac668d7cc40d0910020000
     2019-02-16 15:37:27   servicedatauuid 0000fe95-0000-1000-8000-00805f9b34fb
     2019-02-16 15:36:53   tem             21.9
Attributes:
   IODev      m2s
   alias      Feigen
   event-on-change-reading Temperature,Moisture,Lux,Fertility
   group      Sensoren
   oldreadings LastMessage
   readingList /OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7:.* { json2nameValue($EVENT) }
   room       FlowerCare,MQTT2_DEVICE
   stateFormat T: Temperature°C - M: Moisture% - L: Lux - F: Fertility
   userReadings LastMessage {localtime},
LastOldMessage {OldReadingsVal($name,"LastMessage","")},
Temperature {ReadingsVal($name,"tem","")},
Moisture {ReadingsVal($name,"moi","")},
Lux {ReadingsVal($name,"lux","")},
Fertility {ReadingsVal($name,"fer","")}


Perl ist v5.26.1.

Gruß,
Michael

rudolfkoenig

Sorry, kann das gemeldete Problem nicht nachstellen, ich bekomme keine Fehler.

Folgende Daten werden vom FHEM Modul offensichtlich anders interpretiert, als es beabsichtigt war:
Zitat2019.02.15 22:50:03.922 5: PUBLISH: 003(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer":
Entweder ich oder der Sender hat die Doku nicht verstanden.


Welches Programm schickt diese Daten?
Und mit welchem MQTT Protokoll Version? Auf der FHEM-Seite sieht man das in der "echten" CONNECT Meldung.

OppiM

Hi,

Der Sender ist ein OpenMQTTGateway (https://github.com/1technophile/OpenMQTTGateway).

Hier ein Mitschnitt des Connect:
2019.02.17 18:05:12.361 4: Connection accepted from m2s_192.168.18.131_65256
2019.02.17 18:05:12.373 5: CONNECT: (16)T(0)(4)MQTT(4)(230)(0)(15)(0)(5)OMG_5(0)(26)/OpenMQTTGateway/OMG_5/LWT(0)(7)Offline(0)(13)your_username(0)(13)your_password
2019.02.17 18:05:12.373 4: m2s_192.168.18.131_65256 OMG_5 CONNECT V:4 keepAlive:15 LWT:/OpenMQTTGateway/OMG_5/LWT:Offline usr:your_username


Ich habe nochmal alle in Frage kommenden MQTT2-Devices aufgeräumt und evt. falsche/überflüssige RegEx entfernt.

Hier mal ein Log von der Senderseite, die einen Absturz produziert hat, da seh ich keine Auffälligkeiten:

17:35:10.521 -> Pub json into:
17:35:10.521 -> /OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7
17:35:10.521 -> {"moi":"0"}


Hier der dazugehörige Absturz von FHEM (leider nur Verbose 4...):

2019.02.17 17:35:10.782 4: m2s_192.168.18.131_53496 OMG_5 PUBLISH &/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"moi"::
2019.02.17 17:35:10.784 1: ERROR: Unhandled packet CONNACK, disconneting m2s_192.168.18.131_53496
Unescaped left brace in regex is illegal here in regex; marked by <-- HERE in m/^OMG_5:&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{ <-- HERE "moi"_:.*$/ at ./FHEM/10_MQTT2_DEVICE.pm line 104.


Für mich sieht das so aus, als ob die Daten irgendwie verstümmelt werden, das MQTT2-Device versucht dann aber trotzdem die Daten weiterzuverarbeiten und dann kommt es zum Crash. Ich hab auch mal versucht, FHEM selber per MQTTSpy eine solche verstümmelte Nachricht zu schicken, die wird anstandslos als fehlerhaft aussortiert und FHEM läuft einfach weiter.

Wie sollte denn eine "normale" CONNACK-Nachricht aussehen? Leider find ich im Log nur die Ausgaben bei den Abstürzen. Und die sehen immer so aus, als wäre da der Rest der verstümmelten Nachricht mit drin.


2019.02.15 22:50:03.922 4: m2s_192.168.18.129_54398 OMG_6 PUBLISH &/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer"::
2019.02.15 22:50:03.927 5: CONNACK: "0"}freeMem":82852,"rssi":-49,"SSID":"Oppenheimer"


Gruß,
Michael

rudolfkoenig

(4)MQTT bedeutet Version 3.1.1, das ist genau das, was ich implementiert habe. Ich meine das gesendete PUBLISH Paket vom OpenMQTTGateway ist kaputt, da die Laengenangabe ohne gesetzten Bit 7 (wie bei 0x30) nur ein Byte ist, siehe verlinkte Dokumentation im vorherigen Beitrag.
Die nachfolgend als CONNACK interpretierte Daten sind nur eine Folge der kaputten PUBLISH-Message.

Was mich wundert, sind deine Abstuerze, die ich selbst nicht reproduzieren kann.

OppiM

Hi,

ich hab jetzt alles, was mit den OpenMQTTGateways zu tun hat, auf ein Testsystem umgezogen. Dieses läuft unter Docker mit einer anderen Perl-Version (5.24.1).

Das System geht mit der kaputten Nachricht souverän um und läuft munter weiter:
2019.02.20 08:08:43.680 5: PUBLISH: 0(127)(0)$/OpenMQTTGateway/home_presence/OMG_1{"id":"c4:7c:8d:66:2e:96","name":"Flower care","rssi_OMG_1":-88,"distance_OMG_1":19.7325}
2019.02.20 08:08:43.680 4: m2s_192.168.18.221_49180 OMG_1 PUBLISH /OpenMQTTGateway/home_presence/OMG_1:{"id":"c4:7c:8d:66:2e:96","name":"Flower care","rssi_OMG_1":-88,"distance_OMG_1":19.7325}
2019.02.20 08:08:43.682 5: m2s: dispatch autocreate\000OMG_1\000/OpenMQTTGateway/home_presence/OMG_1\000{"id":"c4:7c:8d:66:2e:96","name":"Flower care","rssi_OMG_1":-88,"distance_OMG_1":19.7325}
2019.02.20 08:08:43.919 5: PUBLISH: 0(237)(1)(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D662E96{"id":"c4:7c:8d:66:2e:96","name":"Flower care","rssi_OMG_1":-88,"distance_OMG_1":19.7325,"servicedata":"71209800d5962e668d7cc40d0910022b01","servicedatauuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.20 08:08:43.919 4: m2s_192.168.18.221_49180 OMG_1 PUBLISH /OpenMQTTGateway/BTtoMQTT/C47C8D662E96:{"id":"c4:7c:8d:66:2e:96","name":"Flower care","rssi_OMG_1":-88,"distance_OMG_1":19.7325,"servicedata":"71209800d5962e668d7cc40d0910022b01","servicedatauuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.20 08:08:43.921 5: m2s: dispatch autocreate\000OMG_1\000/OpenMQTTGateway/BTtoMQTT/C47C8D662E96\000{"id":"c4:7c:8d:66:2e:96","name":"Flower care","rssi_OMG_1":-88,"distance_OMG_1":19.7325,"servicedata":"71209800d5962e668d7cc40d0910022b01","servicedatauuid":"0000fe95-0000-1000-8000-00805f9b34fb"}
2019.02.20 08:08:43.923 5: PUBLISH: 005(0)&/OpenMQTTGateway/BTtoMQTT/C47C8D662E96{"fer":
2019.02.20 08:08:43.923 4: m2s_192.168.18.221_49180 OMG_1 PUBLISH &/OpenMQTTGateway/BTtoMQTT/C47C8D662E96{"fer"::
2019.02.20 08:08:43.924 5: m2s: dispatch autocreate\000OMG_1\000&/OpenMQTTGateway/BTtoMQTT/C47C8D662E96{"fer"_\000
2019.02.20 08:08:43.925 5: CONNACK: "299"}reeMem":80960,"rssi":-51,"SSID":"Oppenheimer",
2019.02.20 08:08:43.925 1: ERROR: Unhandled packet CONNACK, disconneting m2s_192.168.18.221_49180
2019.02.20 08:08:43.928 5: m2s: dispatch autocreate\000OMG_1\000/OpenMQTTGateway/OMG_1/LWT\000Offline
2019.02.20 08:08:43.931 4: Connection accepted from m2s_192.168.18.221_50117
2019.02.20 08:08:43.932 5: CONNECT: (16)T(0)(4)MQTT(4)(230)(0)(15)(0)(5)OMG_1(0)(26)/OpenMQTTGateway/OMG_1/LWT(0)(7)Offline(0)(13)your_username(0)(13)your_password
2019.02.20 08:08:43.932 4: m2s_192.168.18.221_50117 OMG_1 CONNECT V:4 keepAlive:15 LWT:/OpenMQTTGateway/OMG_1/LWT:Offline usr:your_username
2019.02.20 08:08:43.935 5: PUBLISH: 1"(0)(26)/OpenMQTTGateway/OMG_1/LWTOnline
2019.02.20 08:08:43.935 4: m2s_192.168.18.221_50117 OMG_1 PUBLISH /OpenMQTTGateway/OMG_1/LWT:Online
2019.02.20 08:08:43.936 5: m2s: dispatch autocreate\000OMG_1\000/OpenMQTTGateway/OMG_1/LWT\000Online


Aber ich denke, ich hab jetzt besser verstanden, was den Absturz verursacht. Durch 2019.02.20 08:08:43.924 5: m2s: dispatch autocreate\000OMG_1\000&/OpenMQTTGateway/BTtoMQTT/C47C8D662E96{"fer"_\000
wird per Autocreate ein fehlerhafter Eintrag zur readingList hinzugefügt.

In den 2 Tagen hat sich in den readingList schon einiges fehlerhaftes angesammelt. Hier mal ein Beispiel (die ersten 3 Zeilen waren von mir so definiert):
OMG_3:/OpenMQTTGateway/OMG_3/SYStoMQTT:.* { json2nameValue($EVENT) }\
OMG_3:/OpenMQTTGateway/OMG_3/LWT:.* LWT\
OMG_3:/OpenMQTTGateway/OMG_3/version:.* version\
OMG_3:&/OpenMQTTGateway/BTtoMQTT/C47C8D66ACE7{"fer"_:.* C47C8D66ACE7__fer__\
OMG_3:\$/OpenMQTTGateway/home_presence/OMG_3{"id"_"c4:.* OMG_3__id___c4\
OMG_3:8d_66_ac_e7","rssi_OMG_3"_-91,"distance_OMG_3"_25\.519:.* 8d_66_ac_e7___rssi_OMG_3__-91__distance_OMG_3__25.519\
OMG_3:168\.18\.223","modules"_"BT0k:.* 168.18.223___modules___BT0k


Ich hab jetzt bei allen OpenMQTTGateway-Devices die readingList wieder aufgeräumt und Autocreate abgeschaltet, mal sehen, ob das mein Problem behebt.

Wenn das Testsystem dann stabil läuft, versuch ich es wieder im Produktivsystem.

Gruß,
Michael

rudolfkoenig

Zitatwird per Autocreate ein fehlerhafter Eintrag zur readingList hinzugefügt.
Das kann aber MQTT2_DEVICE nicht erkennen.
Die Ursache liegt (wie vorhin geschrieben) an in bestimmten Faellen unterschiedliche Auffassung der Syntax zwischen MQTT2_SERVER und OpenMQTTGateway.
Solange das nicht geklaert ist, wuerde ich mit "produktiv" vorsichtig sein.

cc13

Hallo,

nachdem ich letzte Woche vier Gosund SP1 v23 Module bekam, habe ich eine davon mit der c't Lösung und dem Raspberry ota geflasht. Hat soweit funktioniert und auch mit Hilfe dieses Forums konnte ich die Steckdose per mqtt2 an mein fhem binden. Danke für eure Arbeit.

Wenn ich die Steckdose nun per on/off von fhem ein/ausschalten möchte, funktioniert das nicht bei jedem klick. Die Kleinschreibung habe ich schon mit StateText1 off usw. in der Gosung gesetzt.

Im Sonoff-Console-Log sind mir folgende Meldungen aufgefallen und ich frage hier mal, ob es damit zusammenhängen kann, dass fhem die Steckdose nicht immer zuverlässig ein/ausschaltet:


08:39:17 MQT: Attempting connection...
08:39:22 MQT: Connect failed to 192.168.1.3:1883, rc -2. Retry in 10 sec
...
08:39:46 MQT: Attempting connection...
08:39:46 MQT: Connect failed to 192.168.1.3:1883, rc -2. Retry in 10 sec
08:39:50 UPP: Multicast (re)joined
...
08:40:31 WIF: Connecting to AP1 MEIN_WLAN in mode 11N as sonoff-2154...
08:40:35 WIF: Connected
08:40:35 UPP: Multicast (re)joined
08:40:36 MQT: Attempting connection...
08:40:36 MQT: Connected


Ich habe probehalber mal auf einen MQTT-Server gewechselt, der in einem Container auf meinem NAS läuft und dort kommt diese Fehlermeldung nicht. Was soll/kann ich testen, um weiterzukommen?

Installiert ist mqtt2 in einer FHEM Umgebung, die auf einem ZeroW mit DietPi läuft.


rudolfkoenig

"attr mqtt2_server verbose 5" setzen, und FHEM-Log-Ausschnitt hier anhaengen.