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