MQTT2_SERVER - LWT bei/nach shutdown restart

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

Vorheriges Thema - Nächstes Thema

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 *:(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

ZitatIch 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:

ZitatWhen 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.

ZitatI/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.

ZitatFailed 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 ?

ZitatClient 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.

ZitatBroker 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.

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

ZitatEin Neustart dauert bei mir fast 2 Minuten.
Bei mir unter 2 Sekunden.
Welche Module brauchen so lange?

TomLee

#6
Mein Logfile sieht derzeit nach einem Neustart so aus:

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

#8
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

#10
ZitatDen 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:
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:

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:
Zitatweil FHEM Connect-Versuche von aussen erst danach entgegennimmt
schätz ich mal, bekommt FHEM den 1. Versuch mal mit, mal nicht ?
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?

ZitatWorkaround ist MqttRetry hochzusetzen, nicht MqttKeepAlive.
Ich habe jetzt 'ne Weile gegruebelt, und ich kann das nicht erklaeren.

TomLee

ZitatIst LWT in Tasmota mit dem retain Flag versehen?

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

ZitatIst beim Server respectRetain gesetzt?

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

ZitatIch 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

Zitat3.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

ZitatNach 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

ZitatSelbst 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:

ZitatThe 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 ?

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.