MQTT2_SERVER - LWT bei/nach shutdown restart

Begonnen von TomLee, 07 Juni 2024, 16:30:03

Vorheriges Thema - Nächstes Thema

rudolfkoenig

Zitatso zu verstehen das der Server dann beim zweiten Verbindungsversuch das LWT sendet oder nicht ?
Ja, beim zweiten CONNECT sollte ein Verbindungsabbruch und damit ein LWT erfolgen.
Ist im MQTT2_SEVER z.Zt. nicht korrekt implementiert, d.h. deswegen kriegst Du kein LWT.

TomLee

Weil mir das auf meinem Hauptsystem mit verbose 5 bei MQTT2_SERVER zuviel ist, hab ich das mal bei einer nackten FHEM-Installation auf einer Pi Zero w nachvollzogen und zusammengefasst.

restart nur mit der MQTT2_SERVER Definition, einem MQTT2_DEVICE und einem Debug-notify:
Tasmota-Konsole
15:19:04.968 CMD: mqttretry
15:19:04.973 MQT: stat/tasmota_D836BC/RESULT = {"MqttRetry":10}
15:19:16.671 CMD: mqttkeepalive
15:19:16.677 MQT: stat/tasmota_D836BC/RESULT = {"MqttKeepAlive":30}
15:19:28.436 MQT: Attempting connection...
15:19:28.449 MQT: Connect failed to 192.168.188.28:1883, rc -2. Retry in 10 sec
15:19:39.441 MQT: Attempting connection...
15:19:42.226 MQT: Connected
15:19:42.230 MQT: tele/tasmota_D836BC/LWT = Online (retained)
15:19:42.233 MQT: cmnd/tasmota_D836BC/POWER =

Logfile
2024-06-17_15:19:23 Logfile clear
2024.06.17 15:19:27 0: Server shutdown
2024.06.17 15:19:31 1: Including fhem.cfg
2024.06.17 15:19:33 3: WEB: port 8083 opened
2024.06.17 15:19:33 2: eventTypes: loaded 51 lines from ./log/eventTypes.txt
2024.06.17 15:19:34 3: MQTT2_Server: port 1883 opened
2024.06.17 15:19:34 1: Including ./log/fhem.save
2024.06.17 15:19:34 1: Messages collected while initializing FHEM:SecurityCheck:
  WEB is not password protected

Protect this FHEM installation by configuring the allowed device allowed
You can disable this message with attr global motd none

2024.06.17 15:19:34 1: usb create starting
2024.06.17 15:19:34 3: Probing ZWDongle device /dev/serial1
2024.06.17 15:19:35 3: Probing CUL device /dev/ttyAMA0
2024.06.17 15:19:35 3: Probing TCM_ESP3 device /dev/ttyAMA0
2024.06.17 15:19:36 3: Probing ZWDongle device /dev/ttyAMA0
2024.06.17 15:19:36 3: Probing SIGNALDuino device /dev/ttyAMA0
2024.06.17 15:19:36 3: Probing MYSENSORS device /dev/ttyAMA0
2024.06.17 15:19:36 3: Probing ArduCounter device /dev/ttyAMA0
2024.06.17 15:19:36 3: Probing ElsnerWS device /dev/ttyAMA0
2024.06.17 15:19:37 3: Probing FRM device /dev/ttyAMA0
2024.06.17 15:19:43 1: usb create end
2024.06.17 15:19:43 0: Featurelevel: 6.3
2024.06.17 15:19:43 0: Server started with 11 defined entities (fhem.pl:28849/2024-05-07 perl:5.032001 os:linux user:fhem pid:12966)
2024.06.17 15:19:43 4: Connection accepted from MQTT2_Server_192.168.188.203_56951
2024.06.17 15:19:43 5: in@192.168.188.203:56951 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)(30)(0)(11)DVES_D836BC(0)(23)tele/tasmota_D836BC/LWT(0)(7)Offline(0)(6)Thomas(0)(9)123456789
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 cid:DVES_D836BC CONNECT V:4 keepAlive:30 LWT:tele/tasmota_D836BC/LWT:Offline usr:Thomas
2024.06.17 15:19:43 5: out@192.168.188.203:56951 CONNACK:  (2)(0)(0)
2024.06.17 15:19:43 5: in@192.168.188.203:56951 PUBLISH: 1(31)(0)(23)tele/tasmota_D836BC/LWTOnline
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC PUBLISH tele/tasmota_D836BC/LWT:Online
2024.06.17 15:19:43 5: MQTT2_Server: dispatch autocreate=simple\000DVES_D836BC\000tele/tasmota_D836BC/LWT\000Online
2024.06.17 15:19:43 5: in@192.168.188.203:56951 PUBLISH: 0(27)(0)(25)cmnd/tasmota_D836BC/POWER
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC PUBLISH cmnd/tasmota_D836BC/POWER:
2024.06.17 15:19:43 5: in@192.168.188.203:56951 SUBSCRIBE: (130)(26)(0)(2)(0)(21)cmnd/tasmota_D836BC/#(0)
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC SUBSCRIBE
2024.06.17 15:19:43 4:   topic:cmnd/tasmota_D836BC/# qos:0
2024.06.17 15:19:43 5: out@192.168.188.203:56951 SUBACK: (144)(3)(0)(2)(0)
2024.06.17 15:19:43 5: in@192.168.188.203:56951 SUBSCRIBE: (130)(20)(0)(3)(0)(15)cmnd/tasmotas/#(0)
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC SUBSCRIBE
2024.06.17 15:19:43 4:   topic:cmnd/tasmotas/# qos:0
2024.06.17 15:19:43 5: out@192.168.188.203:56951 SUBACK: (144)(3)(0)(3)(0)
2024.06.17 15:19:43 5: in@192.168.188.203:56951 SUBSCRIBE: (130)(26)(0)(4)(0)(21)cmnd/DVES_D836BC_fb/#(0)
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC SUBSCRIBE
2024.06.17 15:19:43 4:   topic:cmnd/DVES_D836BC_fb/# qos:0
2024.06.17 15:19:43 5: out@192.168.188.203:56951 SUBACK: (144)(3)(0)(4)(0)
2024.06.17 15:19:43 5: in@192.168.188.203:56951 PUBLISH: 1(132)(7)(0)%tasmota/discovery/E86BEAD836BC/config{"ip":"192.168.188.203","dn":"Tasmota","fn":["Tasmota",null,null,null,null,null,null,null],"hn":"tasmota-D836BC-5820-eth","mac":"E86BEAD836BC","md":"WT32-Eth01","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["OFF","ON","TOGGLE","HOLD"],"sw":"13.4.0","t":"tasmota_D836BC","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":0,"lt_st":0,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC PUBLISH tasmota/discovery/E86BEAD836BC/config:{"ip":"192.168.188.203","dn":"Tasmota","fn":["Tasmota",null,null,null,null,null,null,null],"hn":"tasmota-D836BC-5820-eth","mac":"E86BEAD836BC","md":"WT32-Eth01","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["OFF","ON","TOGGLE","HOLD"],"sw":"13.4.0","t":"tasmota_D836BC","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":0,"lt_st":0,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.17 15:19:43 5: in@192.168.188.203:56951 PUBLISH: 1(212)(1)(0)&tasmota/discovery/E86BEAD836BC/sensors{"sn":{"Time":"2024-06-17T15:19:42","ENERGY":{"consumption":31.3254,"supply":0.0000,"power":30,"voltage":234.6,"current":0.25,"phaseangle":335.0,"frequency":49.9}},"ver":1}
2024.06.17 15:19:43 4:   MQTT2_Server_192.168.188.203_56951 DVES_D836BC PUBLISH tasmota/discovery/E86BEAD836BC/sensors:{"sn":{"Time":"2024-06-17T15:19:42","ENERGY":{"consumption":31.3254,"supply":0.0000,"power":30,"voltage":234.6,"current":0.25,"phaseangle":335.0,"frequency":49.9}},"ver":1}

Es erfolgt kein offline, ein fehlgeschlagener Wiederverbindungsversuch direkt beim neustarten des FHEM-Server. 16 s bis zur Initialisierung.



restart zusätzlich mit einer FRITZBOX Definition:

15:35:20.142 MQT: Attempting connection...
15:35:20.157 MQT: Connect failed to 192.168.188.28:1883, rc -2. Retry in 10 sec
15:35:31.144 MQT: Attempting connection...
15:35:35.221 MQT: Connect failed to 192.168.188.28:1883, rc -4. Retry in 20 sec
15:35:56.502 MQT: Attempting connection...
15:35:56.625 MQT: Connected
15:35:56.629 MQT: tele/tasmota_D836BC/LWT = Online (retained)
15:35:56.632 MQT: cmnd/tasmota_D836BC/POWER =

2024-06-17_15:35:06 Logfile clear
2024.06.17 15:35:08 0: Server shutdown
2024.06.17 15:35:22 1: Including fhem.cfg
2024.06.17 15:35:24 3: WEB: port 8083 opened
2024.06.17 15:35:24 2: eventTypes: loaded 55 lines from ./log/eventTypes.txt
2024.06.17 15:35:24 3: MQTT2_Server: port 1883 opened
2024.06.17 15:35:28 1: Including ./log/fhem.save
2024.06.17 15:35:28 1: Messages collected while initializing FHEM:SecurityCheck:
  WEB is not password protected

Protect this FHEM installation by configuring the allowed device allowed
You can disable this message with attr global motd none

2024.06.17 15:35:28 1: usb create starting
2024.06.17 15:35:28 3: Probing ZWDongle device /dev/serial1
2024.06.17 15:35:29 3: Probing CUL device /dev/ttyAMA0
2024.06.17 15:35:29 3: Probing TCM_ESP3 device /dev/ttyAMA0
2024.06.17 15:35:30 3: Probing ZWDongle device /dev/ttyAMA0
2024.06.17 15:35:30 3: Probing SIGNALDuino device /dev/ttyAMA0
2024.06.17 15:35:30 3: Probing MYSENSORS device /dev/ttyAMA0
2024.06.17 15:35:30 3: Probing ArduCounter device /dev/ttyAMA0
2024.06.17 15:35:30 3: Probing ElsnerWS device /dev/ttyAMA0
2024.06.17 15:35:31 3: Probing FRM device /dev/ttyAMA0
2024.06.17 15:35:37 1: usb create end
2024.06.17 15:35:37 0: Featurelevel: 6.3
2024.06.17 15:35:37 0: Server started with 12 defined entities (fhem.pl:28849/2024-05-07 perl:5.032001 os:linux user:fhem pid:13064)
2024.06.17 15:35:37 3: telnetForBlockingFn_1718631337.33007: port 45381 opened
2024.06.17 15:35:37 4: Connection accepted from MQTT2_Server_192.168.188.203_56956
2024.06.17 15:35:37 5: in@192.168.188.203:56956 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)(30)(0)(11)DVES_D836BC(0)(23)tele/tasmota_D836BC/LWT(0)(7)Offline(0)(6)Thomas(0)(9)123456789
2024.06.17 15:35:37 4:   MQTT2_Server_192.168.188.203_56956 cid:DVES_D836BC CONNECT V:4 keepAlive:30 LWT:tele/tasmota_D836BC/LWT:Offline usr:Thomas
2024.06.17 15:35:37 5: out@192.168.188.203:56956 CONNACK:  (2)(0)(0)
2024.06.17 15:35:37 5: MQTT2_Server: dispatch autocreate=simple\000DVES_D836BC\000tele/tasmota_D836BC/LWT\000Offline
2024.06.17 15:35:37 1: DEBUG>Offline
2024.06.17 15:35:37 4: Connection closed for MQTT2_Server_192.168.188.203_56956: EOF
2024.06.17 15:35:46 3: [Fritzbox1 | 7490 | 113.07.57 | Set_check_APIs.6161] - BASIC:Response -> luaQuery:200 luaData:200 TR064:200
2024.06.17 15:35:56 4: Connection accepted from MQTT2_Server_192.168.188.203_56957
2024.06.17 15:35:56 5: in@192.168.188.203:56957 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)(30)(0)(11)DVES_D836BC(0)(23)tele/tasmota_D836BC/LWT(0)(7)Offline(0)(6)Thomas(0)(9)123456789
2024.06.17 15:35:56 4:   MQTT2_Server_192.168.188.203_56957 cid:DVES_D836BC CONNECT V:4 keepAlive:30 LWT:tele/tasmota_D836BC/LWT:Offline usr:Thomas
2024.06.17 15:35:56 5: out@192.168.188.203:56957 CONNACK:  (2)(0)(0)
2024.06.17 15:35:56 5: in@192.168.188.203:56957 PUBLISH: 1(31)(0)(23)tele/tasmota_D836BC/LWTOnline
2024.06.17 15:35:56 4:   MQTT2_Server_192.168.188.203_56957 DVES_D836BC PUBLISH tele/tasmota_D836BC/LWT:Online
2024.06.17 15:35:56 5: MQTT2_Server: dispatch autocreate=simple\000DVES_D836BC\000tele/tasmota_D836BC/LWT\000Online
2024.06.17 15:35:56 5: in@192.168.188.203:56957 PUBLISH: 0(27)(0)(25)cmnd/tasmota_D836BC/POWER
2024.06.17 15:35:56 4:   MQTT2_Server_192.168.188.203_56957 DVES_D836BC PUBLISH cmnd/tasmota_D836BC/POWER:
2024.06.17 15:35:56 5: in@192.168.188.203:56957 SUBSCRIBE: (130)(26)(0)(2)(0)(21)cmnd/tasmota_D836BC/#(0)
2024.06.17 15:35:56 4:   MQTT2_Server_192.168.188.203_56957 DVES_D836BC SUBSCRIBE
2024.06.17 15:35:56 4:   topic:cmnd/tasmota_D836BC/# qos:0
2024.06.17 15:35:56 5: out@192.168.188.203:56957 SUBACK: (144)(3)(0)(2)(0)
2024.06.17 15:35:56 5: in@192.168.188.203:56957 SUBSCRIBE: (130)(20)(0)(3)(0)(15)cmnd/tasmotas/#(0)
2024.06.17 15:35:56 4:   MQTT2_Server_192.168.188.203_56957 DVES_D836BC SUBSCRIBE
2024.06.17 15:35:56 4:   topic:cmnd/tasmotas/# qos:0
2024.06.17 15:35:56 5: out@192.168.188.203:56957 SUBACK: (144)(3)(0)(3)(0)
2024.06.17 15:35:56 5: in@192.168.188.203:56957 SUBSCRIBE: (130)(26)(0)(4)(0)(21)cmnd/DVES_D836BC_fb/#(0)
2024.06.17 15:35:56 4:   MQTT2_Server_192.168.188.203_56957 DVES_D836BC SUBSCRIBE
2024.06.17 15:35:56 4:   topic:cmnd/DVES_D836BC_fb/# qos:0
2024.06.17 15:35:56 5: out@192.168.188.203:56957 SUBACK: (144)(3)(0)(4)(0)

offline erfolgt einmal, siehe Debug Ausgabe. Zwei fehlgeschlagene Wiederverbindungsversuche, einmal der direkt beim neustarten und einmal noch vor kurz vor der Initialisierung. 29 s bis zur Initialisierung.



restart zusätzlich noch eine FB_CALLMONITOR

15:54:22.539 MQT: Attempting connection...
15:54:22.551 MQT: Connect failed to 192.168.188.28:1883, rc -2. Retry in 10 sec
15:54:33.544 MQT: Attempting connection...
15:54:37.560 MQT: Connect failed to 192.168.188.28:1883, rc -4. Retry in 20 sec
15:54:58.530 MQT: Attempting connection...
15:55:02.547 MQT: Connect failed to 192.168.188.28:1883, rc -4. Retry in 30 sec
15:55:33.635 MQT: Attempting connection...
15:55:33.777 MQT: Connected
15:55:33.780 MQT: tele/tasmota_D836BC/LWT = Online (retained)
15:55:33.784 MQT: cmnd/tasmota_D836BC/POWER =

2024-06-17_15:54:17 Logfile clear
2024.06.17 15:54:20 0: Server shutdown
2024.06.17 15:54:24 1: Including fhem.cfg
2024.06.17 15:54:26 3: WEB: port 8083 opened
2024.06.17 15:54:27 2: eventTypes: loaded 57 lines from ./log/eventTypes.txt
2024.06.17 15:54:27 3: MQTT2_Server: port 1883 opened
2024.06.17 15:54:31 3: Opening cm_bla1 device 192.168.188.1:1012
2024.06.17 15:54:31 1: Including ./log/fhem.save
2024.06.17 15:54:31 1: Messages collected while initializing FHEM:SecurityCheck:
  WEB is not password protected

Protect this FHEM installation by configuring the allowed device allowed
You can disable this message with attr global motd none

2024.06.17 15:54:51 3: [cm_bla1 | readPhonebook.1410] - EVENT: read 3 contacts from remote phonebook "Telefonbuch"
2024.06.17 15:54:54 3: [cm_bla1 | readPhonebook.1410] - EVENT: read 193 contacts from remote phonebook "Mobil"
2024.06.17 15:54:56 3: [cm_bla1 | readPhonebook.1410] - EVENT: read 123 contacts from remote phonebook "Iphone-Kontakte"
2024.06.17 15:55:00 1: usb create starting
2024.06.17 15:55:00 3: Probing ZWDongle device /dev/serial1
2024.06.17 15:55:01 3: Probing CUL device /dev/ttyAMA0
2024.06.17 15:55:01 3: Probing TCM_ESP3 device /dev/ttyAMA0
2024.06.17 15:55:02 3: Probing ZWDongle device /dev/ttyAMA0
2024.06.17 15:55:02 3: Probing SIGNALDuino device /dev/ttyAMA0
2024.06.17 15:55:02 3: Probing MYSENSORS device /dev/ttyAMA0
2024.06.17 15:55:02 3: Probing ArduCounter device /dev/ttyAMA0
2024.06.17 15:55:02 3: Probing ElsnerWS device /dev/ttyAMA0
2024.06.17 15:55:03 3: Probing FRM device /dev/ttyAMA0
2024.06.17 15:55:09 1: usb create end
2024.06.17 15:55:09 0: Featurelevel: 6.3
2024.06.17 15:55:09 0: Server started with 13 defined entities (fhem.pl:28849/2024-05-07 perl:5.032001 os:linux user:fhem pid:13218)
2024.06.17 15:55:09 3: telnetForBlockingFn_1718632509.29074: port 35577 opened
2024.06.17 15:55:09 4: Connection accepted from MQTT2_Server_192.168.188.203_56966
2024.06.17 15:55:09 3: cm_bla1 device opened
2024.06.17 15:55:09 4: Connection accepted from MQTT2_Server_192.168.188.203_56967
2024.06.17 15:55:09 5: in@192.168.188.203:56966 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)(30)(0)(11)DVES_D836BC(0)(23)tele/tasmota_D836BC/LWT(0)(7)Offline(0)(6)Thomas(0)(9)123456789
2024.06.17 15:55:09 4:   MQTT2_Server_192.168.188.203_56966 cid:DVES_D836BC CONNECT V:4 keepAlive:30 LWT:tele/tasmota_D836BC/LWT:Offline usr:Thomas
2024.06.17 15:55:09 5: out@192.168.188.203:56966 CONNACK:  (2)(0)(0)
2024.06.17 15:55:09 5: MQTT2_Server: dispatch autocreate=simple\000DVES_D836BC\000tele/tasmota_D836BC/LWT\000Offline
2024.06.17 15:55:09 1: DEBUG>Offline
2024.06.17 15:55:09 4: Connection closed for MQTT2_Server_192.168.188.203_56966: EOF
2024.06.17 15:55:09 5: in@192.168.188.203:56967 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)(30)(0)(11)DVES_D836BC(0)(23)tele/tasmota_D836BC/LWT(0)(7)Offline(0)(6)Thomas(0)(9)123456789
2024.06.17 15:55:09 4:   MQTT2_Server_192.168.188.203_56967 cid:DVES_D836BC CONNECT V:4 keepAlive:30 LWT:tele/tasmota_D836BC/LWT:Offline usr:Thomas
2024.06.17 15:55:09 5: out@192.168.188.203:56967 CONNACK:  (2)(0)(0)
2024.06.17 15:55:09 5: MQTT2_Server: dispatch autocreate=simple\000DVES_D836BC\000tele/tasmota_D836BC/LWT\000Offline
2024.06.17 15:55:09 1: DEBUG>Offline
2024.06.17 15:55:09 4: Connection closed for MQTT2_Server_192.168.188.203_56967: EOF
2024.06.17 15:55:15 3: [Fritzbox1 | 7490 | 113.07.57 | Set_check_APIs.6161] - BASIC:Response -> luaQuery:200 luaData:200 TR064:200
2024.06.17 15:55:33 4: Connection accepted from MQTT2_Server_192.168.188.203_56968
2024.06.17 15:55:33 5: in@192.168.188.203:56968 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)(30)(0)(11)DVES_D836BC(0)(23)tele/tasmota_D836BC/LWT(0)(7)Offline(0)(6)Thomas(0)(9)123456789
2024.06.17 15:55:33 4:   MQTT2_Server_192.168.188.203_56968 cid:DVES_D836BC CONNECT V:4 keepAlive:30 LWT:tele/tasmota_D836BC/LWT:Offline usr:Thomas
2024.06.17 15:55:33 5: out@192.168.188.203:56968 CONNACK:  (2)(0)(0)
2024.06.17 15:55:33 5: in@192.168.188.203:56968 PUBLISH: 1(31)(0)(23)tele/tasmota_D836BC/LWTOnline
2024.06.17 15:55:33 4:   MQTT2_Server_192.168.188.203_56968 DVES_D836BC PUBLISH tele/tasmota_D836BC/LWT:Online
2024.06.17 15:55:33 5: MQTT2_Server: dispatch autocreate=simple\000DVES_D836BC\000tele/tasmota_D836BC/LWT\000Online
2024.06.17 15:55:33 5: in@192.168.188.203:56968 PUBLISH: 0(27)(0)(25)cmnd/tasmota_D836BC/POWER
2024.06.17 15:55:33 4:   MQTT2_Server_192.168.188.203_56968 DVES_D836BC PUBLISH cmnd/tasmota_D836BC/POWER:
2024.06.17 15:55:33 5: in@192.168.188.203:56968 SUBSCRIBE: (130)(26)(0)(2)(0)(21)cmnd/tasmota_D836BC/#(0)
2024.06.17 15:55:33 4:   MQTT2_Server_192.168.188.203_56968 DVES_D836BC SUBSCRIBE
2024.06.17 15:55:33 4:   topic:cmnd/tasmota_D836BC/# qos:0
2024.06.17 15:55:33 5: out@192.168.188.203:56968 SUBACK: (144)(3)(0)(2)(0)
2024.06.17 15:55:33 5: in@192.168.188.203:56968 SUBSCRIBE: (130)(20)(0)(3)(0)(15)cmnd/tasmotas/#(0)
2024.06.17 15:55:33 4:   MQTT2_Server_192.168.188.203_56968 DVES_D836BC SUBSCRIBE
2024.06.17 15:55:33 4:   topic:cmnd/tasmotas/# qos:0
2024.06.17 15:55:33 5: out@192.168.188.203:56968 SUBACK: (144)(3)(0)(3)(0)
2024.06.17 15:55:33 5: in@192.168.188.203:56968 SUBSCRIBE: (130)(26)(0)(4)(0)(21)cmnd/DVES_D836BC_fb/#(0)
2024.06.17 15:55:33 4:   MQTT2_Server_192.168.188.203_56968 DVES_D836BC SUBSCRIBE
2024.06.17 15:55:33 4:   topic:cmnd/DVES_D836BC_fb/# qos:0
2024.06.17 15:55:33 5: out@192.168.188.203:56968 SUBACK: (144)(3)(0)(4)(0)

wie man sieht, offline wird jetzt zweimal gesetzt. Drei fehlgeschlagene Wiederverbindungsversuche, einmal der direkt beim neustarten und jetzt zwei mal vor der Initialisierung, weils jetzt 49 s bis zur Initialisierung sind.



rudolfkoenig

Das Problem kann man auch einfacher nachstellen, mit fhem.cfg:
define m2s MQTT2_SERVER 1883
attr m2s verbose 5
{ sleep 15 }
und der FHEM-Start sofort gefolgt von
mosquitto_sub -k 5 --will-topic LWTopic --will-payload LWmsg -v -t #

Leider hat etwas Experimentieren damit mein Weltbild erschuettert: accept genehmigt keineswegs den Connect der anderen Seite, das macht der Kernel, und nimmt auch gerne schon Daten entgegen.
Bis FHEM zum accept kommt, hat mosquitto_sub drei Verbindungen aufgebaut, MQTT-CONNECT Nachrichten geschickt, und die ersten zwei auch schon zugemacht.
Fuer FHEM schaut das so aus, als ob schnell hintereinander 3 CONNECTs kommen, diese werden mit CONNACK beantwortet (write meldet kein Fehler!), und danach zwei Verbindungen sofort zugemacht werden ohne DISCONNECT. Deswegen wird das LWT fuer beide brav verteilt.

Ich habe dieses Problem jetzt entschaerft, indem ich den Port erst oeffne, nachdem die Initialisierung fertig ist.
Bin gespannt auf die Nebeneffekte.

TomLee

Auf dem Testsystem bekomme ich nach dem update kein LWT mehr.

Aber auf meinem Hauptsystem, wo es ein kleines bisschen länger dauert bis zur Initialisierung, kommt für jedes Device einmal noch das LWT, obwohl ich bei allen MqttKeepAlive auf das maximum von 100 gestellt habe und der Port nach 78 Sekunden doch wieder geöffnet ist. Da bin ich bis jetzt noch nicht dahinter gestiegen warum das so ist.

Ich hoffe ich hab nicht zuviel aus dem Log entfernt und man noch alles nachvollziehen kann, verbose 5 ist mir wie gesagt bei so viel MQTT-Traffic too_much hier.

2024.06.19 18:00:19 1: Server shutdown delayed due to alexa for max 10 sec

2024.06.19 18:00:19 3: alexa: read: end of file reached while sysread
2024.06.19 18:00:19 3: alexa: stopped
2024.06.19 18:00:21 0: Server shutdown

2024.06.19 18:00:23 1: Including fhem.cfg
2024.06.19 18:00:24 3: WEB: port 8083 opened
2024.06.19 18:00:24 2: eventTypes: loaded 6440 lines from ./log/eventTypes.txt

2024.06.19 18:00:25 3: Opening OWX device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_DAE069Vt-if00-port0
2024.06.19 18:00:25 3: OWX device opened
2024.06.19 18:00:25 3: OWX_SER: opened serial device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_DAE069Vt-if00-port0: Illegal seek

2024.06.19 18:00:26 3: AMADCommBridge (AMADBridge) - defined AMADCommBridge with Socketport 8090
2024.06.19 18:00:26 3: AMADBridge: port 8090 opened
2024.06.19 18:00:26 3: AMADCommBridge (AMADBridge) - Socket opened.
2024.06.19 18:00:26 3: Opening cm_Damm device 192.168.198.1:1012
2024.06.19 18:00:27 0: [echodevice_Define] load ECHO Devicename=OG_Echo_Wohnzimmer Devicetype=A3S5BH2HU6VAYF Devicemodel=Echo Dot
2024.06.19 18:00:27 3: AMADDevice (TABA) - I/O device is AMADBridge
2024.06.19 18:00:27 3: AMADDevice (TABA) - set remoteServer to Automagic
2024.06.19 18:00:27 3: AMADDevice (TABA) - defined with AMAD_ID: 1601886842422 on port 8090
2024.06.19 18:00:27 3: AMADDevice (TABA) - set remoteServer to Automagic
2024.06.19 18:00:27 0: [echodevice_Define] load ECHO Devicename=EG_Echo_Kueche Devicetype=A3S5BH2HU6VAYF Devicemodel=Echo Dot
2024.06.19 18:00:27 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet:
2024.06.19 18:00:27 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...

2024.06.19 18:00:27 3: Opening cm_bla1 device 192.168.188.1:1012
2024.06.19 18:00:27 3: AutoShuttersControl (ASC) - defined
2024.06.19 18:00:28 3: telnetPort: port 7072 opened

2024.06.19 18:00:28 0: HourCounter hc_WW_Brennerzeiten Define.228 parameters: hc_WW_Brennerzeiten HourCounter MQTT2_ebusd_bai:1_Pumpe:.68 MQTT2_ebusd_bai:1_Pumpe:.64
2024.06.19 18:00:28 3: AMADDevice (WT_Flur_Kueche) - I/O device is AMADBridge
2024.06.19 18:00:28 3: AMADDevice (WT_Flur_Kueche) - set remoteServer to Automagic
2024.06.19 18:00:28 3: AMADDevice (WT_Flur_Kueche) - defined with AMAD_ID: 1601887495950 on port 8090
2024.06.19 18:00:28 3: AMADDevice (WT_Flur_Kueche) - set remoteServer to Automagic

2024.06.19 18:00:28 3: WEBs2m: port 8084 opened

2024.06.19 18:00:28 3: TelegramBot_Define tb_TelegramBot: called



2024.06.19 18:00:31 3: Opening SIGNALESP device 192.168.188.175:23
2024.06.19 18:00:31 3: TABLETUI3: new ext defined infix:ftui3/: dir:./www/ftui/:
2024.06.19 18:00:31 3: Registering HTTPSRV TABLETUI3 for URL /ftui3   and assigned link ftui3/ ...


2024.06.19 18:00:33 1: Including ./log/fhem.save
2024.06.19 18:00:34 1: Messages collected while initializing FHEM:SecurityCheck:
  WEBs2m is not password protected
  telnetPort is not password protected

Protect this FHEM installation by configuring the allowed device allowedWEBs2m
You can disable this message with attr global motd none

2024.06.19 18:00:34 3: Opening HMUART1 device /dev/ttyAMA0
2024.06.19 18:00:34 3: Setting HMUART1 serial parameters to 115200,8,N,1
2024.06.19 18:00:34 3: HMUART1 device opened

2024.06.19 18:00:35 2: alexa: starting alexa-fhem: /usr/bin/alexa-fhem -c ./alexa/alexa-fhem.cfg -a xx:xx
2024.06.19 18:00:35 3: alexa: starting
2024.06.19 18:00:35 3: alexa: using logfile: ./log/alexa-2024-06-19.log
2024.06.19 18:00:44 3: [cm_bla2 | readPhonebook.1410] - EVENT: read 2 contacts from remote phonebook "Telefonbuch"
2024.06.19 18:00:45 3: [cm_bla2 | readPhonebook.1410] - EVENT: read 9 contacts from remote phonebook "Werbung"
2024.06.19 18:01:21 3: [cm_bla | readPhonebook.1410] - EVENT: read 3 contacts from remote phonebook "Telefonbuch"
2024.06.19 18:01:28 3: [cm_bla | readPhonebook.1410] - EVENT: read 193 contacts from remote phonebook "Mobil"
2024.06.19 18:01:31 3: [cm_bla | readPhonebook.1410] - EVENT: read 123 contacts from remote phonebook "Iphone-Kontakte"

2024.06.19 18:01:37 0: Featurelevel: 6.3
2024.06.19 18:01:37 0: Server started with 569 defined entities (fhem.pl:28849/2024-05-07 perl:5.036000 os:linux user:fhem pid:408296)
2024.06.19 18:01:37 3: MQTT2_Server: port 1883 opened


2024.06.19 18:01:39 0: HourCounter hc_WW_Brennerzeiten Run.598 first run done countsOverall:2359
2024.06.19 18:01:39 0: HourCounter hc_hc_Brennerzeiten Run.598 first run done countsOverall:4235

2024.06.19 18:02:12 3: cm_bla device opened
2024.06.19 18:02:12 3: cm_bla1 device opened
2024.06.19 18:02:13 3: CUL_HM start Queues

2024.06.19 18:02:17 3: [Fritzbox3 | 0000 | 100.06.35 | Set_check_APIs.5982] - BASIC:API luaData does not exist (404 Not Found)
2024.06.19 18:02:17 1: DEBUG>offline
2024.06.19 18:02:17 3: [Fritzbox3 | 7320 | 100.06.35 | Set_check_APIs.6161] - BASIC:Response -> luaQuery:200 luaData:404 TR064:200 boxModelJason:200
2024.06.19 18:02:18 2: AttrTemplates: got 275 entries


2024.06.19 18:02:19 1: DEBUG>offline
2024.06.19 18:02:19 1: DEBUG>Offline

rudolfkoenig

Mich wuerde eher das "attr MQTT2_SERVER verbose 5" Log interessieren.

TomLee

Wie kann ich denn FHEM beim Start am einfachsten für eine definierte Zeit blockieren ( ohne das ich die Definitionen die für das blockieren zuständig sind aus dem Hauptsystem kopiere), damit ich das an nur einem Device auf dem Testsystem nachvollziehen kann ? Sry, ich weiß es sonst nicht anders anzugehen.

rudolfkoenig


TomLee

#22
Hab ich gestern probiert gehabt, aber testweise wie oben bwpw. gezeigt nach der MQTT2_SERVER Definition, da hing dann FHEM und ich habs kein zweites mal versucht.

Einfach ganz oben das sleep ?

rudolfkoenig

Genau an der Stelle, wo es haengen soll.
Mein Beispiel aus Beitrag #17 ist ein komplettes fhem.cfg, kein Ausschnitt.

TomLee

Jetzt hab ichs  ::) Sry.

Werde mich im laufe des Abends mit beschäftigen.

TomLee

Erstmal seh ich auf der Test-Pi kein LWT mit Werten > 60 Sekunden, weiß der Teufel warum.
Jetzt muss ich mal ganz genau am Hauptsystem schauen, die Tage irgendwann.

Danke auf jeden Fall das Du das Thema überhaupt angeschaut/nachvollzogen hast.

TomLee

#26
So sieht das auf dem Hauptsystem mit verbose 5 aus, ich kann mir keinen Reim daraus machen.
Alle Tasmota-Devices haben jetzt die aktuellste Version 14.1.0, MqttRetry steht auf 10 und MqttKeepAlive auf 60 wie man ja auch unten sieht.

Die Meldungen vor der Initialisierung sind ja die gleichen wie oben, die hab ich ausgeschnitten, sowie die Meldungen aller anderen MQTT-Devices, hoffe das macht nix.

2024.06.22 17:22:06 0: Server shutdown
...
2024.06.22 17:22:53 0: Featurelevel: 6.3
2024.06.22 17:22:53 0: Server started with 567 defined entities (fhem.pl:28849/2024-05-07 perl:5.036000 os:linux user:fhem pid:4422)
2024.06.22 17:22:53 3: MQTT2_Server: port 1883 opened
2024.06.22 17:22:54 3: sduino: getAttrDevelopment, IdList ### Attribute development is in this version ignored ###
2024.06.22 17:22:54 3: sduino: IdList, attr whitelist: 0,3,4,5,17,72
2024.06.22 17:22:54 3: sduino: IdList, MS 0 3 4 17
2024.06.22 17:22:54 3: sduino: IdList, MU 5 72
2024.06.22 17:22:54 3: sduino: IdList, MC
2024.06.22 17:22:54 3: sduino: IdList, MN
2024.06.22 17:22:54 3: SIGNALESP: getAttrDevelopment, IdList ### Attribute development is in this version ignored ###
2024.06.22 17:22:54 3: SIGNALESP: IdList, attr whitelist: 72
2024.06.22 17:22:54 3: SIGNALESP: IdList, MS
2024.06.22 17:22:54 3: SIGNALESP: IdList, MU 72
2024.06.22 17:22:54 3: SIGNALESP: IdList, MC
2024.06.22 17:22:54 3: SIGNALESP: IdList, MN
2024.06.22 17:22:54 3: inotify (inot_bla): startet watching /opt/fhem with the file pattern UMFHEM.csv
2024.06.22 17:22:55 0: HourCounter hc_WW_Brennerzeiten Run.598 first run done countsOverall:2394
2024.06.22 17:22:55 0: HourCounter hc_hc_Brennerzeiten Run.598 first run done countsOverall:4235
2024.06.22 17:23:24 4: Connection accepted from MQTT2_Server_192.168.188.161_57384
2024.06.22 17:23:24 3: cm_bla1 device opened
2024.06.22 17:23:24 1: SIGNALESP: DoInit, 192.168.188.175:23
2024.06.22 17:23:24 3: SIGNALESP device opened
2024.06.22 17:23:24 3: cm_bla2 device opened
2024.06.22 17:23:25 1: OWX_Init called for bus OWX with interface state opened, now going for detect
2024.06.22 17:23:25 1: OWX_SER::Detect 1-Wire bus OWX: interface master DS2480 re-detected
2024.06.22 17:23:29 1: OWX_Discover: 1-Wire devices found on bus OWX (...)
2024.06.22 17:23:32 1: PERL WARNING: Use of uninitialized value in subroutine entry at ./FHEM/99_Utils.pm line 21.
2024.06.22 17:23:32 3: eval: {au_nwd($NAME)}
322317225124617312024.06.22 17:23:32 3: SIGNALESP: SimpleWrite_XQ, disable receiver (XQ)
2024.06.22 17:23:32 3: SIGNALESP: StartInit, get version, retry = 0
2024.06.22 17:23:32 3: CUL_HM set HM_F30101 getConfig noArg
2024.06.22 17:23:32 3: CUL_HM start Queues
2024.06.22 17:23:32 1: c4c0ae10xxx07809b.s1.eu.hivemq.cloud:8883 reappeared (mqtt2Cloud)
2024.06.22 17:23:32 1: ec55xxx523.s1.eu.hivemq.cloud:8883 reappeared (f2f)
2024.06.22 17:23:32 2: SIGNALESP: CheckVersionResp, initialized 3.5.5
2024.06.22 17:23:33 2: AttrTemplates: got 275 entries
2024.06.22 17:23:35 4: Connection accepted from MQTT2_Server_192.168.188.80_58196
2024.06.22 17:23:35 5: in@192.168.188.80:58196 CONNECT: (16)I(0)(4)MQTT(4)(238)(0)<(0)(11)DVES_104A25(0)(20)tele/tasmotairwz/LWT(0)(7)Offline(0)(6)Thomas(0)(9)XXX
2024.06.22 17:23:35 4:   MQTT2_Server_192.168.188.80_58196 cid:DVES_104A25 CONNECT V:4 keepAlive:60 LWT:tele/tasmotairwz/LWT:Offline usr:Thomas
2024.06.22 17:23:35 5: out@192.168.188.80:58196 CONNACK:  (2)(0)(0)
2024.06.22 17:23:35 4: Connection accepted from MQTT2_Server_192.168.188.82_57128
2024.06.22 17:23:35 5: in@192.168.188.82:57128 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)<(0)(11)DVES_0C7A27(0)(23)tele/tasmota_0C7A27/LWT(0)(7)Offline(0)(6)Thomas(0)(9)XXX
2024.06.22 17:23:35 4:   MQTT2_Server_192.168.188.82_57128 cid:DVES_0C7A27 CONNECT V:4 keepAlive:60 LWT:tele/tasmota_0C7A27/LWT:Offline usr:Thomas
2024.06.22 17:23:35 5: out@192.168.188.82:57128 CONNACK:  (2)(0)(0)
2024.06.22 17:23:36 5: MQTT2_Server: dispatch autocreate=simple\000DVES_104A25\000tele/tasmotairwz/LWT\000Offline
2024.06.22 17:23:36 1: DEBUG>offline
2024.06.22 17:23:36 4: Connection closed for MQTT2_Server_192.168.188.80_58196: EOF
2024.06.22 17:23:36 4: Connection accepted from MQTT2_Server_192.168.188.81_51630
2024.06.22 17:23:36 5: MQTT2_Server: dispatch autocreate=simple\000DVES_0C7A27\000tele/tasmota_0C7A27/LWT\000Offline
2024.06.22 17:23:36 1: DEBUG>offline
2024.06.22 17:23:36 4: Connection closed for MQTT2_Server_192.168.188.82_57128: EOF
2024.06.22 17:23:36 2: After sleep: done
2024.06.22 17:23:36 5: in@192.168.188.81:51630 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)<(0)(11)DVES_E768B3(0)(23)tele/tasmota_E768B3/LWT(0)(7)Offline(0)(6)Thomas(0)(9)XXX
2024.06.22 17:23:36 4:   MQTT2_Server_192.168.188.81_51630 cid:DVES_E768B3 CONNECT V:4 keepAlive:60 LWT:tele/tasmota_E768B3/LWT:Offline usr:Thomas
2024.06.22 17:23:36 5: out@192.168.188.81:51630 CONNACK:  (2)(0)(0)
2024.06.22 17:23:37 3: [Fritzbox_bla1 | 7490 | 113.07.57 | Set_check_APIs.6161] - BASIC:Response -> luaQuery:200 luaData:200 TR064:200
2024.06.22 17:23:37 5: MQTT2_Server: dispatch autocreate=simple\000DVES_E768B3\000tele/tasmota_E768B3/LWT\000Offline
2024.06.22 17:23:37 1: DEBUG>offline
2024.06.22 17:23:37 4: Connection closed for MQTT2_Server_192.168.188.81_51630: EOF
2024.06.22 17:23:57 4: Connection accepted from MQTT2_Server_192.168.188.80_51197
2024.06.22 17:23:57 5: in@192.168.188.80:51197 CONNECT: (16)I(0)(4)MQTT(4)(238)(0)<(0)(11)DVES_104A25(0)(20)tele/tasmotairwz/LWT(0)(7)Offline(0)(6)Thomas(0)(9)XXX
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 cid:DVES_104A25 CONNECT V:4 keepAlive:60 LWT:tele/tasmotairwz/LWT:Offline usr:Thomas
2024.06.22 17:23:57 5: out@192.168.188.80:51197 CONNACK:  (2)(0)(0)
2024.06.22 17:23:57 5: in@192.168.188.80:51197 PUBLISH: 1(28)(0)(20)tele/tasmotairwz/LWTOnline
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 PUBLISH tele/tasmotairwz/LWT:Online
2024.06.22 17:23:57 5: MQTT2_Server: dispatch autocreate=simple\000DVES_104A25\000tele/tasmotairwz/LWT\000Online
2024.06.22 17:23:57 5: in@192.168.188.80:51197 PUBLISH: 0(24)(0)(22)cmnd/tasmotairwz/POWER
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 PUBLISH cmnd/tasmotairwz/POWER:
2024.06.22 17:23:57 5: in@192.168.188.80:51197 SUBSCRIBE: (130)(23)(0)(2)(0)(18)cmnd/tasmotairwz/#(0)
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 SUBSCRIBE
2024.06.22 17:23:57 4:   topic:cmnd/tasmotairwz/# qos:0
2024.06.22 17:23:57 5: out@192.168.188.80:51197 SUBACK: (144)(3)(0)(2)(0)
2024.06.22 17:23:57 5: in@192.168.188.80:51197 SUBSCRIBE: (130)(19)(0)(3)(0)(14)cmnd/sonoffs/#(0)
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 SUBSCRIBE
2024.06.22 17:23:57 4:   topic:cmnd/sonoffs/# qos:0
2024.06.22 17:23:57 5: out@192.168.188.80:51197 SUBACK: (144)(3)(0)(3)(0)
2024.06.22 17:23:57 5: in@192.168.188.80:51197 SUBSCRIBE: (130)(26)(0)(4)(0)(21)cmnd/DVES_104A25_fb/#(0)
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 SUBSCRIBE
2024.06.22 17:23:57 4:   topic:cmnd/DVES_104A25_fb/# qos:0
2024.06.22 17:23:57 5: out@192.168.188.80:51197 SUBACK: (144)(3)(0)(4)(0)
2024.06.22 17:23:57 5: in@192.168.188.80:51197 PUBLISH: 1(244)(6)(0)%tasmota/discovery/A020A6104A25/config{"ip":"192.168.188.80","dn":"Sonoff","fn":["Sonoff",null,null,null,null,null,null,null],"hn":"tasmotairwz-2597","mac":"A020A6104A25","md":"Generic","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["off","on","toggle","hold"],"sw":"14.1.0","t":"tasmotairwz","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":0,"lt_st":0,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 PUBLISH tasmota/discovery/A020A6104A25/config:{"ip":"192.168.188.80","dn":"Sonoff","fn":["Sonoff",null,null,null,null,null,null,null],"hn":"tasmotairwz-2597","mac":"A020A6104A25","md":"Generic","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["off","on","toggle","hold"],"sw":"14.1.0","t":"tasmotairwz","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":0,"lt_st":0,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.22 17:23:57 5: in@192.168.188.80:51197 PUBLISH: 1U(0)&tasmota/discovery/A020A6104A25/sensors{"sn":{"Time":"2024-06-22T16:23:56"},"ver":1}
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.80_51197 DVES_104A25 PUBLISH tasmota/discovery/A020A6104A25/sensors:{"sn":{"Time":"2024-06-22T16:23:56"},"ver":1}
2024.06.22 17:23:57 4: Connection accepted from MQTT2_Server_192.168.188.82_62566
2024.06.22 17:23:57 5: in@192.168.188.82:62566 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)<(0)(11)DVES_0C7A27(0)(23)tele/tasmota_0C7A27/LWT(0)(7)Offline(0)(6)Thomas(0)(9)XXX
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.82_62566 cid:DVES_0C7A27 CONNECT V:4 keepAlive:60 LWT:tele/tasmota_0C7A27/LWT:Offline usr:Thomas
2024.06.22 17:23:57 5: out@192.168.188.82:62566 CONNACK:  (2)(0)(0)
2024.06.22 17:23:57 5: in@192.168.188.82:62566 PUBLISH: 1(31)(0)(23)tele/tasmota_0C7A27/LWTOnline
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 PUBLISH tele/tasmota_0C7A27/LWT:Online
2024.06.22 17:23:57 5: MQTT2_Server: dispatch autocreate=simple\000DVES_0C7A27\000tele/tasmota_0C7A27/LWT\000Online
2024.06.22 17:23:57 5: in@192.168.188.82:62566 PUBLISH: 0(27)(0)(25)cmnd/tasmota_0C7A27/POWER
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 PUBLISH cmnd/tasmota_0C7A27/POWER:
2024.06.22 17:23:57 5: in@192.168.188.82:62566 SUBSCRIBE: (130)(26)(0)(2)(0)(21)cmnd/tasmota_0C7A27/#(0)
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 SUBSCRIBE
2024.06.22 17:23:57 4:   topic:cmnd/tasmota_0C7A27/# qos:0
2024.06.22 17:23:57 5: out@192.168.188.82:62566 SUBACK: (144)(3)(0)(2)(0)
2024.06.22 17:23:57 5: in@192.168.188.82:62566 SUBSCRIBE: (130)(20)(0)(3)(0)(15)cmnd/tasmotas/#(0)
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 SUBSCRIBE
2024.06.22 17:23:57 4:   topic:cmnd/tasmotas/# qos:0
2024.06.22 17:23:57 5: out@192.168.188.82:62566 SUBACK: (144)(3)(0)(3)(0)
2024.06.22 17:23:57 5: in@192.168.188.82:62566 SUBSCRIBE: (130)(26)(0)(4)(0)(21)cmnd/DVES_0C7A27_fb/#(0)
2024.06.22 17:23:57 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 SUBSCRIBE
2024.06.22 17:23:57 4:   topic:cmnd/DVES_0C7A27_fb/# qos:0
2024.06.22 17:23:57 5: out@192.168.188.82:62566 SUBACK: (144)(3)(0)(4)(0)
2024.06.22 17:23:58 5: in@192.168.188.82:62566 PUBLISH: 1(243)(6)(0)%tasmota/discovery/B4E62D0C7A27/config{"ip":"192.168.188.82","dn":"Orange","fn":["Orange",null,null,null,null,null,null,null],"hn":"TasmotaBulb1","mac":"B4E62D0C7A27","md":"Generic","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["off","on","toggle","hold"],"sw":"14.1.0","t":"tasmota_0C7A27","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[2,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":1,"lt_st":3,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.22 17:23:58 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 PUBLISH tasmota/discovery/B4E62D0C7A27/config:{"ip":"192.168.188.82","dn":"Orange","fn":["Orange",null,null,null,null,null,null,null],"hn":"TasmotaBulb1","mac":"B4E62D0C7A27","md":"Generic","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["off","on","toggle","hold"],"sw":"14.1.0","t":"tasmota_0C7A27","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[2,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":1,"lt_st":3,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.22 17:23:58 5: in@192.168.188.82:62566 PUBLISH: 1U(0)&tasmota/discovery/B4E62D0C7A27/sensors{"sn":{"Time":"2024-06-22T16:23:57"},"ver":1}
2024.06.22 17:23:58 4:   MQTT2_Server_192.168.188.82_62566 DVES_0C7A27 PUBLISH tasmota/discovery/B4E62D0C7A27/sensors:{"sn":{"Time":"2024-06-22T16:23:57"},"ver":1}
2024.06.22 17:24:00 4: Connection accepted from MQTT2_Server_192.168.188.81_59451
2024.06.22 17:24:00 5: in@192.168.188.81:59451 CONNECT: (16)L(0)(4)MQTT(4)(238)(0)<(0)(11)DVES_E768B3(0)(23)tele/tasmota_E768B3/LWT(0)(7)Offline(0)(6)Thomas(0)(9)XXX
2024.06.22 17:24:00 4:   MQTT2_Server_192.168.188.81_59451 cid:DVES_E768B3 CONNECT V:4 keepAlive:60 LWT:tele/tasmota_E768B3/LWT:Offline usr:Thomas
2024.06.22 17:24:00 5: out@192.168.188.81:59451 CONNACK:  (2)(0)(0)
2024.06.22 17:24:01 5: in@192.168.188.81:59451 PUBLISH: 1(31)(0)(23)tele/tasmota_E768B3/LWTOnline
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 PUBLISH tele/tasmota_E768B3/LWT:Online
2024.06.22 17:24:01 5: MQTT2_Server: dispatch autocreate=simple\000DVES_E768B3\000tele/tasmota_E768B3/LWT\000Online
2024.06.22 17:24:01 5: in@192.168.188.81:59451 PUBLISH: 0(27)(0)(25)cmnd/tasmota_E768B3/POWER
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 PUBLISH cmnd/tasmota_E768B3/POWER:
2024.06.22 17:24:01 5: in@192.168.188.81:59451 SUBSCRIBE: (130)(26)(0)(2)(0)(21)cmnd/tasmota_E768B3/#(0)
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 SUBSCRIBE
2024.06.22 17:24:01 4:   topic:cmnd/tasmota_E768B3/# qos:0
2024.06.22 17:24:01 5: out@192.168.188.81:59451 SUBACK: (144)(3)(0)(2)(0)
2024.06.22 17:24:01 5: in@192.168.188.81:59451 SUBSCRIBE: (130)(20)(0)(3)(0)(15)cmnd/tasmotas/#(0)
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 SUBSCRIBE
2024.06.22 17:24:01 4:   topic:cmnd/tasmotas/# qos:0
2024.06.22 17:24:01 5: out@192.168.188.81:59451 SUBACK: (144)(3)(0)(3)(0)
2024.06.22 17:24:01 5: in@192.168.188.81:59451 SUBSCRIBE: (130)(26)(0)(4)(0)(21)cmnd/DVES_E768B3_fb/#(0)
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 SUBSCRIBE
2024.06.22 17:24:01 4:   topic:cmnd/DVES_E768B3_fb/# qos:0
2024.06.22 17:24:01 5: out@192.168.188.81:59451 SUBACK: (144)(3)(0)(4)(0)
2024.06.22 17:24:01 5: in@192.168.188.81:59451 PUBLISH: 1(134)(7)(0)%tasmota/discovery/5CCF7FE768B3/config{"ip":"192.168.188.81","dn":"Tasmota","fn":["Tasmota","Tasmota2",null,null,null,null,null,null],"hn":"tasmota-E768B3-2227","mac":"5CCF7FE768B3","md":"Sonoff Dual","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["off","on","toggle","hold"],"sw":"14.1.0","t":"tasmota_E768B3","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[1,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":0,"lt_st":0,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 PUBLISH tasmota/discovery/5CCF7FE768B3/config:{"ip":"192.168.188.81","dn":"Tasmota","fn":["Tasmota","Tasmota2",null,null,null,null,null,null],"hn":"tasmota-E768B3-2227","mac":"5CCF7FE768B3","md":"Sonoff Dual","ty":0,"if":0,"ofln":"Offline","onln":"Online","state":["off","on","toggle","hold"],"sw":"14.1.0","t":"tasmota_E768B3","ft":"%prefix%/%topic%/","tp":["cmnd","stat","tele"],"rl":[1,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"swc":[-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1,-1],"swn":[null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"btn":[1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"so":{"4":0,"11":0,"13":0,"17":0,"20":0,"30":0,"68":0,"73":0,"82":0,"114":0,"117":0},"lk":0,"lt_st":0,"bat":0,"dslp":0,"sho":[],"sht":[],"ver":1}
2024.06.22 17:24:01 5: in@192.168.188.81:59451 PUBLISH: 1U(0)&tasmota/discovery/5CCF7FE768B3/sensors{"sn":{"Time":"2024-06-22T17:24:00"},"ver":1}
2024.06.22 17:24:01 4:   MQTT2_Server_192.168.188.81_59451 DVES_E768B3 PUBLISH tasmota/discovery/5CCF7FE768B3/sensors:{"sn":{"Time":"2024-06-22T17:24:00"},"ver":1}


192.168.188.80
16:22:08.868 MQT: Verbindungsversuch...
17:22:08.875 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 10 s
17:22:19.849 MQT: Verbindungsversuch...
17:22:19.857 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 20 s
17:22:40.842 MQT: Verbindungsversuch...
17:22:40.850 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 30 s
17:23:11.855 MQT: Verbindungsversuch...
17:23:15.865 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 40 s
17:23:56.663 MQT: Verbindungsversuch...
17:23:56.684 MQT: verbunden
17:23:56.688 MQT: tele/tasmotairwz/LWT = Online (beibehalten)
17:23:56.690 MQT: cmnd/tasmotairwz/POWER =


192.168.188.81
17:22:08.588 MQT: Verbindungsversuch...
17:22:12.602 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 10 s
17:22:23.388 MQT: Verbindungsversuch...
17:22:23.401 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 20 s
17:22:44.379 MQT: Verbindungsversuch...
17:22:44.388 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 30 s
17:23:15.367 MQT: Verbindungsversuch...
17:23:19.383 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 40 s
17:24:00.164 MQT: Verbindungsversuch...
17:24:00.226 MQT: verbunden
17:24:00.230 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
17:24:00.232 MQT: cmnd/tasmota_E768B3/POWER =


192.168.188.82
17:22:09.581 MQT: Verbindungsversuch...
17:22:09.593 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 10 s
17:22:20.576 MQT: Verbindungsversuch...
17:22:20.585 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 20 s
17:22:41.594 MQT: Verbindungsversuch...
17:22:41.605 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 30 s
17:23:12.562 MQT: Verbindungsversuch...
17:23:16.573 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 40 s
17:23:57.366 MQT: Verbindungsversuch...
17:23:57.389 MQT: verbunden
17:23:57.393 MQT: tele/tasmota_0C7A27/LWT = Online (beibehalten)
17:23:57.396 MQT: cmnd/tasmota_0C7A27/POWER =


rudolfkoenig

Das Problem ist vmtl. das Gleiche, wie in meinem Beitrag #17 beschrieben:
Der MQTT2_SERVER oeffnet den Port um 17:22.53, FHEM ist aber danach bis 17:23:35 blockiert, das heisst er kann eingehende Nachrichten erst danach verarbeiten.
In der Zwischenzeit haben aber alle 3 Clients ein CONNECT Message "reingestopft" (der Linux kernel hat alles gepuffert), und haben die Verbindung ohne disconnect wieder geschlossen.
Letzteres veranlasst FHEM das offline Event zu versenden.

Ich kenne z.Zt. keine Methode, mit dem ich feststellen kann, dass die Verbindung schon beim Lesen der Nachricht "tot" ist, und FHEM die Daten nur aus dem Kernel-Puffer liest.