MQTT2_SERVER - LWT bei/nach shutdown restart

[TomLee]

Hallo,

der MQTT2 Server setzt bei mir nach jedem restart des FHEM Server die Devices auf offline, vermute (kann auch daneben liegen, so genau hab ich mich nicht mit beschäftigt), weil entweder dann die versprochene Zeit abgelaufen ist oder der MQTT2 Server "gestartet" ist und die Devices sich noch "lange" nicht wieder mit dem Server verbunden haben. Wie auch immer, einen Grund wird es schon geben warum es zu dem Verhalten kommt.

Kann ich als User es irgendwie vermeiden das mein lwt-notify

Code Auswählen Erweitern

*:(LWT|lwt):.(Offline|offline) beim Start des FHEM Server auslöst ?

Gruß

Thomas

[rudolfkoenig]

LWT (Last Will and Testament) hat nichts mit FHEM Neustart, sondern mit "Abschied" eines verbundenen MQTT Clients zu tun.
D.h. es wird ausgeloest, wenn ein Client sich mit dem MQTT2_SERVER verbindet, und danach(!), ohne ordentlich zu verabschieden, weg ist.

Ich gehe davon aus, dass das eigentliche Problem komplizierter ist, und wir mehr Infos brauchen.

[TomLee]

Ich gehe davon aus, dass das eigentliche Problem komplizierter ist, und wir mehr Infos brauchen.]

Ist denn meine bisherige Schilderung (notify mit dem oben gezeigten Suchmuster) bei dir nicht nachvollziehbar ?
Es ist definitiv MQTT2_Server der die Readings direkt beim Start von FHEM auf "offline" setzt. Kann mir nicht vorstellen das es an meinem System liegt. Und es hat mMn. was mit LWT zu tun.

Wenn wirklich nicht dann, werde ich versuchen mich detaillierter mit zu beschäftigen, um mehr Infos zu liefern, jetzt aber nicht, später oder die Tage.

[TomLee]

Mein(e) Gedanken/Verständnis zu den hier aufgeführten Punten:

When does the MQTT Broker Send the LWT Message?

According to the MQTT 3.1.1 specification, the broker sends a client's Last Will and Testament (LWT) message in the following situations:

•     I/O error or network failure: If the broker detects any issues with the input/output or network connection, it will distribute the LWT message.
•     Failed communication within Keep Alive period: If the client fails to communicate with the broker within the specified Keep Alive period, the LWT message is sent. In Part-10 of our MQTT Essentials, we will explore the concept of MQTT Keep Alive time and delve into its significance it.
•     Client closes connection without DISCONNECT: When the client terminates the network connection without sending a DISCONNECT packet, the broker ensures the LWT message is distributed.
•     Broker closes connection due to protocol error: If the broker closes the network connection due to a protocol error, it will send the LWT message.

Understanding when and why the broker sends the Last Will and Testament (LWT) messages lays the groundwork for implementing best practices in leveraging this feature, which we will delve into in the next section.

I/O error or network failure: If the broker detects any issues with the input/output or network connection, it will distribute the LWT message.

Ist das evtl. schon der Grund? MQTT2_Server holt das halt erst bei dem Neustart nach ? "offline" wird bei mir ja erst dann gesetzt.

Failed communication within Keep Alive period: If the client fails to communicate with the broker within the specified Keep Alive period, the LWT message is sent. In Part-10 of our MQTT Essentials, we will explore the concept of MQTT Keep Alive time and delve into its significance it.

Die Message kanns ja nicht sein, die würde ja gar nicht mehr vom Server empfangen werden ?

Client closes connection without Connecticut: When the client terminates the network connection without sending a DISCONNECT packet, the broker ensures the LWT message is distributed.

Hier hat ja der Server die Verbindung beendet, scheidet für mich Laie erstmal aus.

Broker closes connection due to protocol error: If the broker closes the network connection due to a protocol error, it will send the LWT message.

Holt das MQTT2-Server dann vlt. erst wieder bei einem Neustart nach ?


Bei welchem Punkt vermutet ihr die Ursache?

[TomLee]

Hi,

ich hab zwei Tasmota-Devices und nur deren lwt-Reading wird auf offline gesetzt, das hätte ich auch gleich sehen können, wenn ich mich genauer mit beschäftigt hätte 

Für jeden Verbindungsversuch (default MqttRetry=10) den diese Devices unternehmen, während FHEM neustartet, wird das Reading auf offline gesetzt. Ein Neustart dauert bei mir fast 2 Minuten. Das sind lt. Tasmota-Konsole i.d.R 4 Verbindungsversuche beim Neustart. Ein Tasmota-Device sind zwei gesplittete Devices (2 Kanäle) in FHEM. In beiden Devices hab ich das lwt-Reading abonniert. Also nur für das eine (gesplittete) Tasmota-Device dann 8 offline-Events + 4 Events des zweiten Tasmota-Device.

Jetzt hab ich MqttRetry mal auf 120 gestellt, in der Konsole sieht man das es keine fehlgeschlagenen Verbindungen mehr gibt und das notify löst beim Neustart nicht mehr aus.

Code Auswählen Erweitern

18:06:25.634 MQT: Verbindungsversuch...
18:06:25.643 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 10 s
18:06:36.644 MQT: Verbindungsversuch...
18:06:40.654 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 20 s
18:07:01.445 MQT: Verbindungsversuch...
18:07:05.455 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 30 s
18:07:36.250 MQT: Verbindungsversuch...
18:07:40.260 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 40 s
18:08:21.031 MQT: Verbindungsversuch...
18:08:21.049 MQT: verbunden
18:08:21.053 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
18:08:21.056 MQT: cmnd/tasmota_E768B3/POWER =
20:00:47.782 MQT: stat/tasmota_E768B3/RESULT = {"POWER1":"on"}
20:00:47.785 MQT: stat/tasmota_E768B3/POWER1 = on
20:06:47.791 MQT: stat/tasmota_E768B3/RESULT = {"POWER1":"off"}
20:06:47.794 MQT: stat/tasmota_E768B3/POWER1 = off
20:42:52.557 MQT: Verbindungsversuch...
20:42:52.568 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 10 s
20:43:03.535 MQT: Verbindungsversuch...
20:43:07.544 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 20 s
20:43:28.460 MQT: Verbindungsversuch...
20:43:32.470 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 30 s
20:44:03.275 MQT: Verbindungsversuch...
20:44:07.284 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 40 s
20:44:48.082 MQT: Verbindungsversuch...
20:44:48.189 MQT: verbunden
20:44:48.194 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
20:44:48.198 MQT: cmnd/tasmota_E768B3/POWER =
21:08:28.530 CMD: MqttKeepAlive 100
21:08:28.538 MQT: stat/tasmota_E768B3/RESULT = {"MqttKeepAlive":100}
21:44:59.905 CMD: MqttRetry
21:44:59.911 MQT: stat/tasmota_E768B3/RESULT = {"MqttRetry":10}
21:46:59.499 CMD: MqttRetry 60
21:46:59.506 MQT: stat/tasmota_E768B3/RESULT = {"MqttRetry":60}
21:48:29.099 MQT: Verbindungsversuch...
21:48:33.109 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 60 s
21:49:33.924 MQT: Verbindungsversuch...
21:49:33.942 MQT: verbunden
21:49:33.946 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
21:49:33.949 MQT: cmnd/tasmota_E768B3/POWER =
21:50:50.914 MQT: Verbindungsversuch...
21:50:50.924 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 60 s
21:51:51.954 MQT: Verbindungsversuch...
21:51:55.964 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 120 s
21:53:56.994 MQT: Verbindungsversuch...
21:53:57.054 MQT: verbunden
21:53:57.059 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
21:53:57.061 MQT: cmnd/tasmota_E768B3/POWER =
22:09:24.649 CMD: MqttRetry
22:09:24.656 MQT: stat/tasmota_E768B3/RESULT = {"MqttRetry":60}
22:09:44.929 CMD: MqttRetry 120
22:09:44.935 MQT: stat/tasmota_E768B3/RESULT = {"MqttRetry":120}
22:12:40.019 MQT: Verbindungsversuch...
22:12:40.046 MQT: verbunden
22:12:40.050 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)

[rudolfkoenig]

Ein Neustart dauert bei mir fast 2 Minuten.

Bei mir unter 2 Sekunden.
Welche Module brauchen so lange?

[TomLee]

Mein Logfile sieht derzeit nach einem Neustart so aus:

Code Auswählen Erweitern

2024.06.10 17:46:19 1: Server shutdown delayed due to alexa for max 10 sec
2024.06.10 17:46:19 3: alexa: read: end of file reached while sysread
2024.06.10 17:46:19 3: alexa: stopped
2024.06.10 17:46:20 0: Server shutdown
2024.06.10 17:46:20 3: mc_shalarm: logged out
2024.06.10 17:46:20 3: mc_shalarm: Disconnected
2024.06.10 17:46:20 3: mc_shalarm: connected to secureimap.t-online.de
2024.06.10 17:46:21 3: mc_shalarm: logged in to bla@t-online.de
2024.06.10 17:46:21 1: Timeout for SIP_ListenStart reached, terminated process 159751
2024.06.10 17:46:23 1: Including fhem.cfg
2024.06.10 17:46:23 3: WEB: port 8083 opened
2024.06.10 17:46:23 2: eventTypes: loaded 6338 lines from ./log/eventTypes.txt
2024.06.10 17:46:25 3: LGTV_WebOS (TV_Wohnzimmer) - defined with host 192.168.188.54
2024.06.10 17:46:25 3: LGTV_WebOS (TV_Fr_Raum) - defined with host 192.168.188.53
2024.06.10 17:46:25 3: LGTV_WebOS (TV_Fr_Raum) - disabled
2024.06.10 17:46:25 3: MQTT2_Server: port 1883 opened
2024.06.10 17:46:25 3: Opening OWX device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_DAE069Vt-if00-port0
2024.06.10 17:46:25 3: OWX device opened
2024.06.10 17:46:25 3: OWX_SER: opened serial device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_DAE069Vt-if00-port0: Illegal seek
2024.06.10 17:46:25 3: OWTHERM:  Device OG_Innensensor_Schlafzimmer defined.
2024.06.10 17:46:25 3: OWTHERM:  Device EG_Innensensor_blaraum defined.
2024.06.10 17:46:25 3: OWTHERM:  Device EG_Innensensor_Buero defined.
2024.06.10 17:46:25 3: OWTHERM:  Device OG_Innensensor_Wohnzimmer defined.
2024.06.10 17:46:25 3: OWTHERM:  Device EG_Innensensor_EingangKueche defined.
2024.06.10 17:46:25 3: OWTHERM:  Device KG_Innensensor_WWSpeicher_oben defined.
2024.06.10 17:46:25 3: OWTHERM:  Device EG_Innensensor_FBH_EingangFlur defined.
2024.06.10 17:46:25 3: OWTHERM:  Device KG_Innensensor_Rlauf_Hinter_Mittelhaus defined.
2024.06.10 17:46:25 3: OWTHERM:  Device KG_Innensensor_VorlaufVorderhaus defined.
2024.06.10 17:46:25 3: OWTHERM:  Device KG_Innensensor_RlaufVorderhaus defined.
2024.06.10 17:46:25 3: OWTHERM:  Device HF_Aussensensor_Vorderhaus defined.
2024.06.10 17:46:25 3: AMADCommBridge (AMADBridge) - defined AMADCommBridge with Socketport 8090
2024.06.10 17:46:25 3: AMADBridge: port 8090 opened
2024.06.10 17:46:25 3: AMADCommBridge (AMADBridge) - Socket opened.
2024.06.10 17:46:26 3: Opening cm_bla device 192.168.198.1:1012
2024.06.10 17:46:26 0: [echodevice_Define] load ECHO Devicename=OG_Echo_Wohnzimmer Devicetype=A3S5BH2HU6VAYF Devicemodel=Echo Dot
2024.06.10 17:46:26 3: AMADDevice (TABA) - I/O device is AMADBridge
2024.06.10 17:46:26 3: AMADDevice (TABA) - set remoteServer to Automagic
2024.06.10 17:46:26 3: AMADDevice (TABA) - defined with AMAD_ID: 1601886842422 on port 8090
2024.06.10 17:46:26 3: AMADDevice (TABA) - set remoteServer to Automagic
2024.06.10 17:46:26 0: [echodevice_Define] load ECHO Devicename=EG_Echo_Kueche Devicetype=A3S5BH2HU6VAYF Devicemodel=Echo Dot
2024.06.10 17:46:26 3: TABLETUI: new ext defined infix:ftui/: dir:./www/tablet:
2024.06.10 17:46:26 3: Registering HTTPSRV TABLETUI for URL /ftui   and assigned link ftui/ ...
2024.06.10 17:46:26 3: Jet: Defined with URL http://www.clever-tanken.de/tankstelle_details/bli and interval 300 featurelevel 6.3
2024.06.10 17:46:26 3: Real: Defined with URL http://www.clever-tanken.de/tankstelle_details/bla and interval 300 featurelevel 6.3
2024.06.10 17:46:26 3: Globus: Defined with URL https://www.clever-tanken.de/tankstelle_details/blib and interval 300 featurelevel 6.3
2024.06.10 17:46:27 3: Opening cm_bla device 192.168.188.1:1012
2024.06.10 17:46:27 3: AutoShuttersControl (ASC) - defined
2024.06.10 17:46:27 3: telnetPort: port 7072 opened
2024.06.10 17:46:27 3: hmod_sq_x: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 180 featurelevel 6.3
2024.06.10 17:46:27 3: hmod_sq_x: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 180 featurelevel 6.3
2024.06.10 17:46:27 3: HourCounter HourCounter Initialize.220 Init Done with Version 1.0.1.2 - 24.12.2014
2024.06.10 17:46:27 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.10 17:46:27 3: AMADDevice (WT_Flur_Kueche) - I/O device is AMADBridge
2024.06.10 17:46:27 3: AMADDevice (WT_Flur_Kueche) - set remoteServer to Automagic
2024.06.10 17:46:27 3: AMADDevice (WT_Flur_Kueche) - defined with AMAD_ID: 1601887495950 on port 8090
2024.06.10 17:46:27 3: AMADDevice (WT_Flur_Kueche) - set remoteServer to Automagic
2024.06.10 17:46:27 3: hmod_sq_byd: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 180 featurelevel 6.3
2024.06.10 17:46:27 3: hmod_sq_xinyi: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 180 featurelevel 6.3
2024.06.10 17:46:27 0: HourCounter hc_hc_Brennerzeiten Define.228 parameters: hc_hc_Brennerzeiten HourCounter MQTT2_ebusd_bai:1_Pumpe:.on MQTT2_ebusd_bai:1_Pumpe:.off
2024.06.10 17:46:27 3: hmod_sq_x: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 180 featurelevel 6.3
2024.06.10 17:46:27 3: WEBs2m: port 8084 opened
2024.06.10 17:46:27 3: hmod_sq_x: Defined with URL https://www.boerse.de/aktien/AFRICAN-MIN-EX-Aktie/GB00B647W791 and interval 180 featurelevel 6.3
2024.06.10 17:46:28 3: hmod_sq_x: Defined with URL https://traderfox.de/aktien/10420439-luckin-coffee-inc-adrs and interval 600 featurelevel 6.3
2024.06.10 17:46:28 3: hmod_sq_x: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 180 featurelevel 6.3
2024.06.10 17:46:28 3: TelegramBot_Define tb_TelegramBot: called
2024.06.10 17:46:29 3: hmod_sq_x: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 240 featurelevel 6.3
2024.06.10 17:46:29 3: hmod_Wetter: Defined with URL https://www.wunderground.com/dashboard/pws/IMUTTE11 and interval 300 featurelevel 6.3
2024.06.10 17:46:29 3: hmod_sq_bb: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 900 featurelevel 6.3
2024.06.10 17:46:29 3: Heizoelpreis: Defined with URL https://www.heizoel24.de/DailyPriceXml.ashx?zipcode=%%PLZ%%&litre=%%MENGE%%&unloadingpoints=%%ENTLADESTELLEN%%&oilgrade=standard and interval 1800 featurelevel 6.3
2024.06.10 17:46:29 3: hmod_sq_b: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 900 featurelevel 6.3
2024.06.10 17:46:29 3: OWTHERM:  Device OG_Innensensor_bla1 defined.
2024.06.10 17:46:29 3: OWTHERM:  Device OG_Innensensor_bla6 defined.
2024.06.10 17:46:29 3: OWTHERM:  Device OG_Innensensor_bla8 defined.
2024.06.10 17:46:29 3: OWTHERM:  Device EG_Innensensor_bla2 defined.
2024.06.10 17:46:29 3: OWTHERM:  Device KG_Innensensor_RlaufHinterhaus defined.
2024.06.10 17:46:31 3: Opening sduino device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AL01GVC4-if00-port0
2024.06.10 17:46:31 1: sduino: Can't open /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AL01GVC4-if00-port0: No such file or directory
2024.06.10 17:46:31 3: Opening SIGNALESP device 192.168.188.175:23
2024.06.10 17:46:31 3: TABLETUI3: new ext defined infix:ftui3/: dir:./www/ftui/:
2024.06.10 17:46:31 3: Registering HTTPSRV TABLETUI3 for URL /ftui3   and assigned link ftui3/ ...
2024.06.10 17:46:32 3: OWTHERM:  Device DG_Innensensor_Dach_Hinterhaus defined.
2024.06.10 17:46:32 3: OWTHERM:  Device OG_Innensensor_bla5 defined.
2024.06.10 17:46:32 3: OWTHERM:  Device EG_Innensensor_bla4 defined.
2024.06.10 17:46:32 3: hmod_sq_x: Defined with URL https://www.tradegate.de/orderbuch.php?isin=bla and interval 900 featurelevel 6.3
2024.06.10 17:46:32 3: Opening myJeeLink_sirene device /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AI02MHZO-if00-port0
2024.06.10 17:46:32 1: myJeeLink_sirene: Can't open /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_AI02MHZO-if00-port0: No such file or directory
2024.06.10 17:46:33 3: OWTHERM:  Device KG_Innensensor_Rlauf_Mittelhaus defined.
2024.06.10 17:46:33 3: OWTHERM:  Device KG_Innensensor_Rlauf_Hinterhaus_Flur defined.
2024.06.10 17:46:33 3: OWTHERM:  Device EG_Innensensor_WC defined.
2024.06.10 17:46:33 3: OWTHERM:  Device OG_Innensensor_bla9 defined.
2024.06.10 17:46:33 3: hmod_x_shorts: Defined with URL https://shortsell.nl/short/bla/90/archived and interval 180 featurelevel 6.3
2024.06.10 17:46:33 1: Including ./log/fhem.save
2024.06.10 17:46:33 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.10 17:46:33 3: Opening HMUART1 device /dev/ttyAMA0
2024.06.10 17:46:33 3: Setting HMUART1 serial parameters to 115200,8,N,1
2024.06.10 17:46:33 3: HMUART1 device opened
2024.06.10 17:46:34 3: monitoring (Batterie_monitoring) set Batterie_monitoring active
2024.06.10 17:46:34 2: alexa: starting alexa-fhem: /usr/bin/alexa-fhem -c ./alexa/alexa-fhem.cfg -a xx:xx
2024.06.10 17:46:34 3: alexa: starting
2024.06.10 17:46:34 3: alexa: using logfile: ./log/alexa-2024-06-10.log
2024.06.10 17:46:43 3: [cm_bla | readPhonebook.1410] - EVENT: read 2 contacts from remote phonebook "Telefonbuch"
2024.06.10 17:46:45 3: [cm_bla | readPhonebook.1410] - EVENT: read 9 contacts from remote phonebook "Werbung"
2024.06.10 17:46:58 3: [cm_bla | readPhonebook.1410] - EVENT: read 3 contacts from remote phonebook "Telefonbuch"
2024.06.10 17:47:00 3: [cm_bla | readPhonebook.1410] - EVENT: read 193 contacts from remote phonebook "Mobil"
2024.06.10 17:47:01 3: [cm_bla | readPhonebook.1410] - EVENT: read 123 contacts from remote phonebook "Iphone-Kontakte"
2024.06.10 17:47:04 3: mc_shalarm: connected to secureimap.t-online.de
2024.06.10 17:47:04 3: mc_shalarm: logged in to blaruth@t-online.de
2024.06.10 17:47:04 3: mc_shalarmgm: connected to imap.gmail.com
2024.06.10 17:47:05 3: mc_shalarmgm: logged out
2024.06.10 17:47:05 3: mc_shalarmgm: Disconnected
2024.06.10 17:47:05 1: PERL WARNING: Argument "power" isn't numeric in numeric eq (==) at (eval 1394) line 1.
2024.06.10 17:47:05 1: PERL WARNING: Use of uninitialized value $VALUE in numeric eq (==) at (eval 1395) line 1.
2024.06.10 17:47:06 3: inotify (inot_bla): startet watching /opt/fhem with the file pattern UMFHEM.csv
2024.06.10 17:47:06 3: inotify (inot_print_queue): startet watching /var/spool/cups/tmp/ with the file pattern foomatic-.*
2024.06.10 17:47:06 0: Featurelevel: 6.3
2024.06.10 17:47:06 0: Server started with 564 defined entities (fhem.pl:28666/2024-03-16 perl:5.036000 os:linux user:fhem pid:179396)
2024.06.10 17:47:06 3: sduino: getAttrDevelopment, IdList ### Attribute development is in this version ignored ###
2024.06.10 17:47:06 3: sduino: IdList, attr whitelist: 0,3,4,5,17,72
2024.06.10 17:47:06 3: sduino: IdList, MS 0 3 4 17
2024.06.10 17:47:06 3: sduino: IdList, MU 5 72
2024.06.10 17:47:06 3: sduino: IdList, MC
2024.06.10 17:47:06 3: sduino: IdList, MN
2024.06.10 17:47:06 3: SIGNALESP: getAttrDevelopment, IdList ### Attribute development is in this version ignored ###
2024.06.10 17:47:06 3: SIGNALESP: IdList, attr whitelist: 72
2024.06.10 17:47:06 3: SIGNALESP: IdList, MS
2024.06.10 17:47:06 3: SIGNALESP: IdList, MU 72
2024.06.10 17:47:06 3: SIGNALESP: IdList, MC
2024.06.10 17:47:06 3: SIGNALESP: IdList, MN
2024.06.10 17:47:07 3: inotify (inot_bla): startet watching /opt/fhem with the file pattern UMFHEM.csv
2024.06.10 17:47:07 3: inotify (inot_print_queue): startet watching /var/spool/cups/tmp/ with the file pattern foomatic-.*
2024.06.10 17:47:07 0: HourCounter hc_WW_Brennerzeiten Run.598 first run done countsOverall:2304
2024.06.10 17:47:07 0: HourCounter hc_hc_Brennerzeiten Run.598 first run done countsOverall:4235
2024.06.10 17:47:37 3: cm_bla device opened
2024.06.10 17:47:37 3: cm_bla device opened
2024.06.10 17:47:37 1: SIGNALESP: Can't connect to 192.168.188.175:23: Operation now in progress
2024.06.10 17:47:37 1: SIGNALESP: Can't connect to 192.168.188.175:23: 192.168.188.175: Keine Route zum Zielrechner (113)
2024.06.10 17:47:37 3: SIGNALESP: Connect, 192.168.188.175: Keine Route zum Zielrechner (113)
2024.06.10 17:47:37 1: OWX_Init called for bus OWX with interface state opened, now going for detect
2024.06.10 17:47:37 1: OWX_SER::Detect 1-Wire bus OWX: interface master DS2480 re-detected
2024.06.10 17:47:42 1: OWX_Discover: 1-Wire devices found on bus OWX (OG_Innensensor_bla6,DG_Innensensor_Dach_Hinterhaus,OG_Innensensor_Schlafbla,EG_Innensensor_blaraum,EG_Innensensor_Buero,OG_Innensensor_Wohnbla,EG_Innensensor_EingangKueche,KG_Innensensor_WWSpeicher_oben,KG_Innensensor_Rlauf_Mittelhaus,KG_Innensensor_Rlauf_Hinterhaus_Flur,OG_Innensensor_bla1,OG_Innensensor_bla5,EG_Innensensor_bla4,OG_Innensensor_bla9,EG_Innensensor_WC,EG_Innensensor_bla2,EG_Innensensor_FBH_EingangFlur,KG_Innensensor_Rlauf_Hinter_Mittelhaus,KG_Innensensor_VorlaufVorderhaus,KG_Innensensor_RlaufVorderhaus,KG_Innensensor_RlaufHinterhaus,HF_Aussensensor_Vorderhaus,OG_Innensensor_bla8)
2024.06.10 17:47:45 1: PERL WARNING: Use of uninitialized value in subroutine entry at ./FHEM/99_Utils.pm line 21.
2024.06.10 17:47:45 3: eval: {au_nwd($NAME)}
454717105124116112024.06.10 17:47:45 3: CUL_HM start Queues
Ja, ich seh auch das die MQTT2_Server-Definition nach 6 Sekunden wieder startklar ist/wäre. Ich weiß es nicht was der Grund ist, beim schreiben jetzt kommt mir das es evtl. OWX für die "Verzögerung" verantwortlich ist ?

[rudolfkoenig]

Die groessten Abstaende sehe ich im Zusammenhang mit cm_bla.
Was ist das?

[TomLee]

Das sind zwei FB_CALLMONITOR Definitionen. Die blockieren, aber so war das Modul bisher gebaut. Ich meine gelesen zu haben das geplant ist das irgendwann mal umzubauen.

[rudolfkoenig]

Strenggenommen ist das Problem nicht beim Initialisieren (dazu zaehlt fuer mich alles bis zur Meldung "Server started with..."), weil FHEM Connect-Versuche von aussen erst danach entgegennimmt, und die keepalive-timeouts erst nach dem MQTT-Connect zaehlen.
D.h. irgendwer blockiert FHEM nach dem Connect solange, dass die Keepalive-Timeouts zuschlagen, und das Modul die LWT Nachrichten verschickt.
Hab z.Zt. keine Idee, wie ich das vermeiden koennte.

Den Workaround (keepalive beim Client hochzusetzen) hast Du ja schon selbst gefunden.

[TomLee]

Den Workaround (keepalive beim Client hochzusetzen) hast Du ja schon selbst gefunden.

Workaround ist MqttRetry hochzusetzen, nicht MqttKeepAlive.

Solange es keine vergeblichen Verbindungsversuche gibt, wird auch nix auf offline gesetzt:

Code Auswählen Erweitern

18:44:40.144 CMD: MqttKeepAlive
18:44:40.149 RSL: RESULT = {"MqttKeepAlive":30}
18:45:07.994 CMD: MqttRetry
18:45:07.000 RSL: RESULT = {"MqttRetry":120}
18:46:06.310 MQT: Verbindungsversuch...
18:46:06.327 MQT: verbunden
18:46:06.331 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
18:46:06.334 MQT: cmnd/tasmota_E768B3/POWER =
das "offline" setzen erfolgt nur wegen der vergeblichen Verbindungsversuche:

Code Auswählen Erweitern

19:12:57.624 MQT: Verbindungsversuch...
19:12:57.632 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -2. Wiederversuch in 10 s
19:13:08.644 MQT: Verbindungsversuch...
19:13:12.655 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 20 s
19:13:33.440 MQT: Verbindungsversuch...
19:13:37.451 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 30 s
19:14:08.254 MQT: Verbindungsversuch...
19:14:12.265 MQT: Verbindung fehlgeschlagen aufgrund von 192.168.188.26:1883, rc -4. Wiederversuch in 40 s
19:14:53.080 MQT: Verbindungsversuch...
19:14:53.111 MQT: verbunden
19:14:53.116 MQT: tele/tasmota_E768B3/LWT = Online (beibehalten)
19:14:53.119 MQT: cmnd/tasmota_E768B3/POWER =
19:14:59.144 CMD: MqttKeepAlive
19:14:59.152 MQT: stat/tasmota_E768B3/RESULT = {"MqttKeepAlive":30}
19:15:09.058 CMD: MqttRetry
19:15:09.065 MQT: stat/tasmota_E768B3/RESULT = {"MqttRetry":10}
Das sind die Zeitstempel dazu in welchem Abstand das offline setzen erfolgt:
Mal erfolgen drei, mal vier Events.
Wegen:

weil FHEM Connect-Versuche von aussen erst danach entgegennimmt

schätz ich mal, bekommt FHEM den 1. Versuch mal mit, mal nicht ?

Code Auswählen Erweitern

2024.06.11 19:14:37 1: DEBUG>2024-06-11 19:14:37
2024.06.11 19:14:39 1: DEBUG>2024-06-11 19:14:39
2024.06.11 19:14:39 1: DEBUG>2024-06-11 19:14:39

[rudolfkoenig]

Ich versuche den Vorgang in FHEM zu skizzieren.
- beim "define MQTT2_SERVER" oeffnet FHEM den TCP Port 1883.
- Verbindungen werden auf TCP Ebene erst nach dem Abschluss der Initalisierung (nach "Server started..." im FHEM-Log) akzeptiert.
  Bis dahin koennen sich bis zu 10 Anfragenden in die Betriebsystem-Schlange stellen.
- erst danach kann der Client per MQTT-Connect Nachricht sein LWT dem MQTT2_SERVER mitteilen.
- wenn die MQTT-Connect Nachricht vom MQTT2_SERV gelesen und bestaetigt wurde, ist LWT "gueltig".

Wann die LWT Nachricht verteilt wird, hast Du im Beitrag #3 genau beschrieben, die Punkte treffen auch fuer MQTT2_SERVER zu.

Ist LWT in Tasmota mit dem retain Flag versehen?
Ist beim Server respectRetain gesetzt?

Workaround ist MqttRetry hochzusetzen, nicht MqttKeepAlive.

Ich habe jetzt 'ne Weile gegruebelt, und ich kann das nicht erklaeren.

[TomLee]

Ist LWT in Tasmota mit dem retain Flag versehen?

Stehe gerade auf dem Schlauch wie ich das prüfe ?

Ist beim Server respectRetain gesetzt?

Code Auswählen Erweitern

defmod MQTT2_Server MQTT2_SERVER 1883 global
attr MQTT2_Server hideRetain 0
attr MQTT2_Server ignoreRegexp shellies/[^:"]+/command|shellies/[^:"]+/command|cmnd/[^:"]+:|homeassistant/[^:"]+/config|tasmota/discovery/[^/:]+/(config|sensors)|devcontrol/[0-8]+/[0-8]+
attr MQTT2_Server respectRetain 0

Ich habe jetzt 'ne Weile gegruebelt, und ich kann das nicht erklaeren.

Ich hab doch drei Tasmota-Devices, nicht zwei, bei allen verhält es sich gleich. Versionsunabhängig, 2x 8.1.0, 1x 13.3.0 und seit zweit Tagen hab ich zum Test sogar ein viertes mit 13.4.0 .
Ich kann doch nicht so eine ungewöhnliche Installation haben, dass das niemand nachvollziehen kann ?

Ich, der nur einen kleinen Teil von dem ganzen versteht, versuch es mir so erklären das mit "Netzwerkverbindung schliessen" auch ein auf "offline setzen erfolgt. Nach der Initialisierung werden diese bis zu 10 CONNECT Anfragen "nachgeholt/abgearbeitet" und weil jedes zweite Connect-Packet vom Server als Fehler interpretiert werden muss, erfolgt halt für jeden MQTT-Verbindungsversuch das auf "offline" setzen ?

Kann es damit zu tun haben ?

https://docs.oasis-open.org/mqtt/mqtt/v5.0/os/mqtt-v5.0-os.html#_Toc3901033

3.1 CONNECT – Connection Request

After a Network Connection is established by a Client to a Server, the first packet sent from the Client to the Server MUST be a CONNECT packet [MQTT-3.1.0-1].

 

A Client can only send the CONNECT packet once over a Network Connection. The Server MUST process a second CONNECT packet sent from a Client as a Protocol Error and close the Network Connection [MQTT-3.1.0-2]. Refer to section 4.13 for information about handling errors.

 

The Payload contains one or more encoded fields. They specify a unique Client identifier for the Client, a Will Topic, Will Payload, User Name and Password. All but the Client identifier can be omitted and their presence is determined based on flags in the Variable Header.

[rudolfkoenig]

Nach der Initialisierung werden diese bis zu 10 CONNECT Anfragen "nachgeholt/abgearbeitet"

Tasmota kann doch kein CONNECT schicken, bevor die TCP-IP Verbindung von der anderen Seite (MQTT2_SERVER) akzeptiert wurde.
Selbst wenn doch, soweit ich sehe hat MQTT2_SERVER nichts gegen mehrfache CONNECT Meldungen.
Ist zwar nicht ganz fein, spricht aber hier nochmals gegen die obige Hypothese.

[TomLee]

Selbst wenn doch, soweit ich sehe hat MQTT2_SERVER nichts gegen mehrfache CONNECT Meldungen.

Nur angenommen das es so ist und für mein Verständnis, ist:

The Server MUST process a second CONNECT packet sent from a Client as a Protocol Error and close the Network Connection

so zu verstehen das der Server dann beim zweiten Verbindungsversuch das LWT sendet oder nicht ?