MQTT2_CLIENT Device verliert nach einiger Zeit Verbindung zu Mosquitto

Begonnen von reibuehl, 26 Juni 2020, 08:56:19

Vorheriges Thema - Nächstes Thema

reibuehl

Hallo,

verwende ein MQTT2_Client Device um FHEM an einen bestehenden Mosquitto MQTT Server anzubinden. Das lief lange zeit sehr gut, seit einem FHEM Update vor einigen Wochen ist es allerdings nicht mehr stabil: Nach einem FHEM restart läuft alles für einige Minuten, ich bekomme Statusänderungen von Mosquitto und kann publishen. Dann scheint alles auf der FHEM Seite zu stoppen. Ich bekomme keine Statusänderungen mehr und kann auch keine Befehle mer per publish senden. Am Mosquitto Server liegt es nicht, da ich mit anderen MQTT clients wie mqtt.fx oder MQTT Explorer weiterhin die Status updates sehe und auch Befehle absetzen kann. Wenn ich dann FHEM mit shutdown restart durchstarte geht es wieder einige Minuten bis zu vielleicht einer Stunde und dann ist wieder alles eingefroren.
Im Log steht:
2020.06.26 07:54:55 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 07:54:55 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 07:55:59 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 07:55:59 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 07:57:01 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 07:55:58), disconnecting
2020.06.26 07:57:01 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 07:57:02 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 07:58:05 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 07:58:05 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 07:59:07 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 07:58:04), disconnecting
2020.06.26 07:59:07 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 07:59:08 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:00:12 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:00:12 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:01:14 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:00:10), disconnecting
2020.06.26 08:01:14 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:01:14 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:02:17 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:02:17 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:03:20 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:02:17), disconnecting
2020.06.26 08:03:20 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:03:20 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:04:23 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:04:24 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:05:26 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:04:23), disconnecting
2020.06.26 08:05:26 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:05:26 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:06:30 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:06:30 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:07:32 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:06:29), disconnecting
2020.06.26 08:07:32 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:07:33 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:08:36 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:08:36 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:09:38 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:08:35), disconnecting
2020.06.26 08:09:38 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:09:38 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:10:41 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:10:42 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:11:44 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:10:41), disconnecting
2020.06.26 08:11:44 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:11:44 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:12:47 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:12:47 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:13:50 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:12:47), disconnecting
2020.06.26 08:13:50 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:13:51 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:14:54 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:14:54 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:15:57 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:14:51), disconnecting
2020.06.26 08:15:57 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:15:57 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:16:59 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:17:02 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:17:02 1: M2: Unhandled packet RESERVED_0, disconneting MQTT2Server
2020.06.26 08:17:02 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:17:02 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:18:05 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:18:05 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:19:05 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:18:02), disconnecting
2020.06.26 08:19:05 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:19:08 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:20:05 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:20:08 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:21:08 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:21:08 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:22:11 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:22:11 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:23:14 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:23:14 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:24:17 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:24:17 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:25:20 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:25:23 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:26:23 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:26:23 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:26:23 1: M2: Unhandled packet RESERVED_0, disconneting MQTT2Server
2020.06.26 08:26:23 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:26:23 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:27:30 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:27:30 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:28:29 2: MQTT2Server: No PINGRESP for last PINGREQ (at 2020-06-26 08:27:26), disconnecting
2020.06.26 08:28:29 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:28:29 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:29:32 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:29:32 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:30:35 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:30:35 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:31:38 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:31:38 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:32:41 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:32:44 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:33:44 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:33:44 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:34:47 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:34:47 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:35:50 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:35:54 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:36:53 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:36:54 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:37:57 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:38:00 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:39:00 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:39:03 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:40:03 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:40:03 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:41:06 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:41:09 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:42:09 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:42:12 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:43:12 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:43:12 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:44:15 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:44:15 1: 192.168.1.2:1883 reappeared (MQTT2Server)
2020.06.26 08:45:18 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 08:45:21 1: 192.168.1.2:1883 reappeared (MQTT2Server)
b


Auf der Mosquitto Seite sehe ich dass es wohl irgendwelche timeouts gibt:
1593153666: New connection from 192.168.1.2 on port 1883.
1593153669: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593153714: Client MQTT2Server has exceeded timeout, disconnecting.
1593153729: New connection from 192.168.1.2 on port 1883.
1593153732: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593153775: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1593153777: Client MQTT2Server has exceeded timeout, disconnecting.
1593153792: New connection from 192.168.1.2 on port 1883.
1593153792: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593153837: Client MQTT2Server has exceeded timeout, disconnecting.
1593153855: New connection from 192.168.1.2 on port 1883.
1593153855: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593153900: Client MQTT2Server has exceeded timeout, disconnecting.
1593153921: New connection from 192.168.1.2 on port 1883.
1593153921: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593153966: Client MQTT2Server has exceeded timeout, disconnecting.
1593153981: New connection from 192.168.1.2 on port 1883.
1593153981: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593154026: Client MQTT2Server has exceeded timeout, disconnecting.
1593154044: New connection from 192.168.1.2 on port 1883.
1593154044: New client connected from 192.168.1.2 as MQTT2Server (p1, c1, k30).
1593154089: Client MQTT2Server has exceeded timeout, disconnecting.
1593154107: New connection from 192.168.1.2 on port 1883.


Im MQTT2_CLIENT Device "MQTT2Server" habe ich den keepaliveTimeout auf 30:
Internals:
   BUF         
   DEF        192.168.1.2:1883
   DevIoJustClosed 1
   DeviceName 192.168.1.2:1883
   FUUID      5d0f7f3d-f33f-3bc6-2b3f-3f30eeb7f8d1340d
   NAME       MQTT2Server
   NR         837
   STATE      disconnected
   TYPE       MQTT2_CLIENT
   WBCallback
   clientId   MQTT2Server
   connecting 1
   lastMsgTime 1593154296.32632
   nextOpenDelay 5
   Helper:
     DBLOG:
       state:
         logdb:
           TIME       1593154359.12499
           VALUE      DISCONNECTED
   READINGS:
     2020-06-26 08:52:39   state           disconnected
Attributes:
   keepaliveTimeout 30
   room       Device


In der /etc/mosquitto/mosquitto.conf sind keine Timeout Settings drin.

Was könnte den hier schief laufen?

Gruß,
Reiner
Reiner.

rudolfkoenig

Ich tippe auf Netzwerkprobleme, oder (unwahrscheinlich) auf ueberlasteten/blockierten FHEM.

Kannst Du bitte ein FHEM-Log Ausschnitt nach "attr global verbse 5 Log" hier zeigen, insb die Zeilen vor "disconnected" interessieren mich.

reibuehl

Hallo Rudolf!

hier die Zeilen vor einem disconnect aus dem verbose 5 log:
2020.06.26 10:17:20 4: UG_FB7490SysStat: got empty result from snmp query No response from remote host "192.168.1.1"
2020.06.26 10:17:38 4: UG_FB7490SysStat: got empty result from snmp query No response from remote host "192.168.1.1"
2020.06.26 10:17:44 4: UG_FB7490SysStat: got empty result from snmp query No response from remote host "192.168.1.1"
2020.06.26 10:17:44 5: HttpUtils url=http://192.168.1.240:80/languages_all
2020.06.26 10:17:44 5: HttpUtils request header:
GET /languages_all HTTP/1.0
Host: 192.168.1.240
User-Agent: fhem
Accept-Encoding: gzip,deflate
Cookie: AUERSessionID=TFBORYQGMMHGBUY; AUERWEB_COOKIE=sub-admin

2020.06.26 10:17:44 4: http://192.168.1.240:80/languages_all: HTTP response code 200
2020.06.26 10:17:44 5: HttpUtils http://192.168.1.240:80/languages_all: Got data, length: 86
2020.06.26 10:17:44 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: GoAhead-Webs
Expires: 0
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Pragma: no-cache
Content-Type: text/html; charset=iso-8859-1;
2020.06.26 10:17:44 5: HttpUtils url=http://192.168.1.240:80/app_ext_ports_status
2020.06.26 10:17:44 4: IP: 192.168.1.240 -> 192.168.1.240
2020.06.26 10:17:44 5: HttpUtils url=http://192.168.1.240:80/app_konfig_list
2020.06.26 10:17:44 4: IP: 192.168.1.240 -> 192.168.1.240
2020.06.26 10:17:44 5: HMUARTLGW HMLAN3 checking credits (from timer)
2020.06.26 10:17:44 5: HMUARTLGW HMLAN3 send: 00 08
2020.06.26 10:17:44 5: HMUARTLGW HMLAN3 send: (8): fd00030040081835
2020.06.26 10:17:44 5: SW: fd00030040081835
2020.06.26 10:17:44 5: HMUARTLGW HMLAN4 checking credits (from timer)
2020.06.26 10:17:44 5: HMUARTLGW HMLAN4 send: 00 08
2020.06.26 10:17:44 5: HMUARTLGW HMLAN4 send: (8): fd0003006108de35
2020.06.26 10:17:44 5: SW: fd0003006108de35
2020.06.26 10:17:44 5: HMUARTLGW HMLAN5 checking credits (from timer)
2020.06.26 10:17:44 5: HMUARTLGW HMLAN5 send: 00 08
2020.06.26 10:17:44 5: HMUARTLGW HMLAN5 send: (8): fd0003006f087a36
2020.06.26 10:17:44 5: SW: fd0003006f087a36
2020.06.26 10:17:44 4: <hidden>: HTTP response code 200
2020.06.26 10:17:44 5: HttpUtils <hidden>: Got data, length: 23
2020.06.26 10:17:44 5: HttpUtils response header:
HTTP/1.1 200 OK
Server: nginx/1.16.1
Date: Fri, 26 Jun 2020 08:17:34 GMT
Content-Type: application/json
Content-Length: 23
Connection: close
Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
Access-Control-Allow-Origin: *
Access-Control-Allow-Methods: GET, POST, OPTIONS
Access-Control-Expose-Headers: Content-Length,Content-Type,Date,Server,Connection
2020.06.26 10:17:44 5: TelegramBot_Callback TelegramMessenger: called from Polling
2020.06.26 10:17:44 5: TelegramBot_Callback TelegramMessenger: data returned :{"ok":true,"result":[]}:
2020.06.26 10:17:44 5: TelegramBot_Deepencode TelegramMessenger: encoded a String from :1: to :1:
2020.06.26 10:17:44 5: TelegramBot_Deepencode TelegramMessenger: found an ARRAY
2020.06.26 10:17:44 5: TelegramBot_Deepencode TelegramMessenger: found a HASH
2020.06.26 10:17:44 5: TelegramBot_Callback TelegramMessenger: after encoding
2020.06.26 10:17:44 5: TelegramBot_Callback TelegramMessenger: polling returned result? 0
2020.06.26 10:17:44 5: UpdatePoll TelegramMessenger: number of results 0
2020.06.26 10:17:44 5: TelegramBot_UpdatePoll TelegramMessenger: called
2020.06.26 10:17:44 5: TelegramBot_UpdatePoll TelegramMessenger: - Initiate non blocking polling - With callback set
2020.06.26 10:17:44 5: TelegramBot_readToken: Read Telegram API token from file
2020.06.26 10:17:44 4: TelegramBot_UpdatePoll TelegramMessenger: initiate polling with nonblockingGet with 120s
2020.06.26 10:17:44 5: HttpUtils url=<hidden>
2020.06.26 10:17:44 4: IP: api.telegram.org -> 149.154.167.220
2020.06.26 10:17:44 5: TelegramBot_UpdatePoll TelegramMessenger: - Ende > next polling started
2020.06.26 10:17:44 4: TelegramBot_Callback TelegramMessenger: resulted in SUCCESS from Polling
2020.06.26 10:17:44 5: TelegramBot_Callback TelegramMessenger: - Ende > Control back to FHEM
2020.06.26 10:17:44 5: HMLAN/RAW: /E270AE2,0000,40979E2E,FF,FFA1,05865A270AE2000000610A2C
E2E1A05,0000,4097BF50,FF,FFA4,25845E2E1A0500000085498C0000340066094BFD

2020.06.26 10:17:44 5: HMLAN_Parse: HMLAN2 R:E270AE2   stat:0000 t:40979E2E d:FF r:FFA1     m:05 865A 270AE2 000000 610A2C
2020.06.26 10:17:44 5: HMLAN2: dispatch A0C05865A270AE2000000610A2C::-95:HMLAN2
2020.06.26 10:17:44 5: Starting notify loop for OG_BD_ThermostatDisplay_Climate, 1 event(s), first is measured-temp: 26.6
2020.06.26 10:17:44 5: Activitaetsstatus: not on any display, ignoring notify
2020.06.26 10:17:44 5: Batteriestatus: not on any display, ignoring notify
2020.06.26 10:17:44 5: OG_BD_Raumklima: not on any display, ignoring notify
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> ###              start of new Logcycle                       ###
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> number of events received: 1 for device: OG_BD_ThermostatDisplay_Climate
2020.06.26 10:17:44 4: DbLog logdb -> check Device: OG_BD_ThermostatDisplay_Climate , Event: measured-temp: 26.6
2020.06.26 10:17:44 5: DbLog logdb -> parsed Event: OG_BD_ThermostatDisplay_Climate , Event: measured-temp: 26.6
2020.06.26 10:17:44 5: DbLog logdb -> DbLogExclude of "OG_BD_ThermostatDisplay_Climate": .*
2020.06.26 10:17:44 5: DbLog logdb -> DbLogInclude of "OG_BD_ThermostatDisplay_Climate": desired-temp,measured-temp,humidity
2020.06.26 10:17:44 4: DbLog logdb -> added event - Timestamp: 2020-06-26 10:17:44, Device: OG_BD_ThermostatDisplay_Climate, Type: CUL_HM, Event: measured-temp: 26.6, Reading: measured-temp, Value: 26.6, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> ###         New database processing cycle - synchronous      ###
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> DbLogType is: History
2020.06.26 10:17:44 4: DbLog logdb -> AutoCommit mode: ON, Transaction mode: ON
2020.06.26 10:17:44 4: DbLog logdb -> Insert mode: Array
2020.06.26 10:17:44 4: DbLog logdb -> Primary Key used in history: none
2020.06.26 10:17:44 4: DbLog logdb -> Primary Key used in current: DEVICE,READING
2020.06.26 10:17:44 4: DbLog logdb -> processing event Timestamp: 2020-06-26 10:17:44, Device: OG_BD_ThermostatDisplay_Climate, Type: CUL_HM, Event: measured-temp: 26.6, Reading: measured-temp, Value: 26.6, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> 1 of 1 events inserted into table history
2020.06.26 10:17:44 4: DbLog logdb -> insert table history committed by autocommit
2020.06.26 10:17:44 5: mqttPublishList: not on any display, ignoring notify
2020.06.26 10:17:44 5: Triggering n_publish_mqtt
2020.06.26 10:17:44 4: n_publish_mqtt exec {
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');;

    if ($mqttName ne '') {
        my $reading = "";;
        my $message = "";;
        my $persist = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

my $topic = "";;
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";;
} else {
$topic = "/SmartHome/$mqttName/$reading";;
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");;
    }
}
2020.06.26 10:17:44 5: Cmd: >{
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');
    my $mqttName = AttrVal($NAME, 'mqttName', '');
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');

    if ($mqttName ne '') {
        my $reading = "";
        my $message = "";
        my $persist = "";

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;
            $message = $2;
        } else {
            $reading = "state";
            $message = $EVENT;
        }

my $topic = "";
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";
} else {
$topic = "/SmartHome/$mqttName/$reading";
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");
    }
}<
2020.06.26 10:17:44 5: End notify loop for OG_BD_ThermostatDisplay_Climate
2020.06.26 10:17:44 5: HMLAN_Parse: HMLAN2 R:E2E1A05   stat:0000 t:4097BF50 d:FF r:FFA4     m:25 845E 2E1A05 000000 85498C0000340066094BFD
2020.06.26 10:17:44 5: HMLAN2: dispatch A1425845E2E1A0500000085498C0000340066094BFD::-92:HMLAN2
2020.06.26 10:17:44 5: Starting notify loop for OG_Leistungsmesser3_Pwr, 2 event(s), first is eState: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97
2020.06.26 10:17:44 5: Activitaetsstatus: not on any display, ignoring notify
2020.06.26 10:17:44 5: Batteriestatus: not on any display, ignoring notify
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> ###              start of new Logcycle                       ###
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> number of events received: 2 for device: OG_Leistungsmesser3_Pwr
2020.06.26 10:17:44 4: DbLog logdb -> check Device: OG_Leistungsmesser3_Pwr , Event: eState: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97
2020.06.26 10:17:44 5: DbLog logdb -> parsed Event: OG_Leistungsmesser3_Pwr , Event: eState: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97
2020.06.26 10:17:44 4: DbLog logdb -> added event - Timestamp: 2020-06-26 10:17:44, Device: OG_Leistungsmesser3_Pwr, Type: CUL_HM, Event: eState: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97, Reading: eState, Value: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> check Device: OG_Leistungsmesser3_Pwr , Event: power: 0.52
2020.06.26 10:17:44 5: DbLog logdb -> parsed Event: OG_Leistungsmesser3_Pwr , Event: power: 0.52
2020.06.26 10:17:44 4: DbLog logdb -> added event - Timestamp: 2020-06-26 10:17:44, Device: OG_Leistungsmesser3_Pwr, Type: CUL_HM, Event: power: 0.52, Reading: power, Value: 0.52, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> ###         New database processing cycle - synchronous      ###
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> DbLogType is: History
2020.06.26 10:17:44 4: DbLog logdb -> AutoCommit mode: ON, Transaction mode: ON
2020.06.26 10:17:44 4: DbLog logdb -> Insert mode: Array
2020.06.26 10:17:44 4: DbLog logdb -> Primary Key used in history: none
2020.06.26 10:17:44 4: DbLog logdb -> Primary Key used in current: DEVICE,READING
2020.06.26 10:17:44 4: DbLog logdb -> processing event Timestamp: 2020-06-26 10:17:44, Device: OG_Leistungsmesser3_Pwr, Type: CUL_HM, Event: eState: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97, Reading: eState, Value: E: 34650.8 P: 0.52 I: 102 U: 237.9 f: 49.97, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> processing event Timestamp: 2020-06-26 10:17:44, Device: OG_Leistungsmesser3_Pwr, Type: CUL_HM, Event: power: 0.52, Reading: power, Value: 0.52, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> 2 of 2 events inserted into table history
2020.06.26 10:17:44 4: DbLog logdb -> insert table history committed by autocommit
2020.06.26 10:17:44 5: mqttPublishList: not on any display, ignoring notify
2020.06.26 10:17:44 5: Triggering n_OG_GZ_3DDrucker_An
2020.06.26 10:17:44 4: n_OG_GZ_3DDrucker_An exec {fhem ("set OG_GZ_3DDrucker_Status aktiv") if (ReadingsVal("OG_Leistungsmesser3_Pwr","power","") >= 300 && Value("OG_GZ_3DDrucker_Status") ne "aktiv")}
2020.06.26 10:17:44 5: Cmd: >{fhem ("set OG_GZ_3DDrucker_Status aktiv") if (ReadingsVal("OG_Leistungsmesser3_Pwr","power","") >= 300 && Value("OG_GZ_3DDrucker_Status") ne "aktiv")}<
2020.06.26 10:17:44 5: Triggering n_OG_GZ_3DDrucker_Aus
2020.06.26 10:17:44 4: n_OG_GZ_3DDrucker_Aus exec {fhem ("set OG_GZ_3DDrucker_Status inaktiv") if (ReadingsVal("OG_Leistungsmesser3_Pwr","power","") < 250 && Value("OG_GZ_3DDrucker_Status") ne "inaktiv")}
2020.06.26 10:17:44 5: Cmd: >{fhem ("set OG_GZ_3DDrucker_Status inaktiv") if (ReadingsVal("OG_Leistungsmesser3_Pwr","power","") < 250 && Value("OG_GZ_3DDrucker_Status") ne "inaktiv")}<
2020.06.26 10:17:44 5: Triggering n_publish_mqtt
2020.06.26 10:17:44 4: n_publish_mqtt exec {
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');;

    if ($mqttName ne '') {
        my $reading = "";;
        my $message = "";;
        my $persist = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

my $topic = "";;
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";;
} else {
$topic = "/SmartHome/$mqttName/$reading";;
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");;
    }
}
2020.06.26 10:17:44 5: Cmd: >{
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');
    my $mqttName = AttrVal($NAME, 'mqttName', '');
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');

    if ($mqttName ne '') {
        my $reading = "";
        my $message = "";
        my $persist = "";

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;
            $message = $2;
        } else {
            $reading = "state";
            $message = $EVENT;
        }

my $topic = "";
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";
} else {
$topic = "/SmartHome/$mqttName/$reading";
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");
    }
}<
2020.06.26 10:17:44 5: Triggering n_publish_mqtt
2020.06.26 10:17:44 4: n_publish_mqtt exec {
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');;

    if ($mqttName ne '') {
        my $reading = "";;
        my $message = "";;
        my $persist = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

my $topic = "";;
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";;
} else {
$topic = "/SmartHome/$mqttName/$reading";;
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");;
    }
}
2020.06.26 10:17:44 5: Cmd: >{
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');
    my $mqttName = AttrVal($NAME, 'mqttName', '');
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');

    if ($mqttName ne '') {
        my $reading = "";
        my $message = "";
        my $persist = "";

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;
            $message = $2;
        } else {
            $reading = "state";
            $message = $EVENT;
        }

my $topic = "";
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";
} else {
$topic = "/SmartHome/$mqttName/$reading";
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");
    }
}<
2020.06.26 10:17:44 5: End notify loop for OG_Leistungsmesser3_Pwr
2020.06.26 10:17:44 5: HMLAN/RAW: /E270AE2,0000,065ED20F,FF,FFBB,05865A270AE2000000610A2C
E2E1A05,0000,065EF331,FF,FFAB,25845E2E1A0500000085498C0000340066094BFD

2020.06.26 10:17:44 5: HMLAN_Parse: HMLAN1 R:E270AE2   stat:0000 t:065ED20F d:FF r:FFBB     m:05 865A 270AE2 000000 610A2C
2020.06.26 10:17:44 5: HMLAN1: dispatch A0C05865A270AE2000000610A2C::-69:HMLAN1
2020.06.26 10:17:44 4: CUL_HM OG_BD_ThermostatDisplay_Device dupe: dont process
2020.06.26 10:17:44 5: HMLAN_Parse: HMLAN1 R:E2E1A05   stat:0000 t:065EF331 d:FF r:FFAB     m:25 845E 2E1A05 000000 85498C0000340066094BFD
2020.06.26 10:17:44 5: HMLAN1: dispatch A1425845E2E1A0500000085498C0000340066094BFD::-85:HMLAN1
2020.06.26 10:17:44 4: CUL_HM OG_Leistungsmesser3 dupe: dont process
2020.06.26 10:17:44 1: 192.168.1.2:1883 disconnected, waiting to reappear (MQTT2Server)
2020.06.26 10:17:44 5: Starting notify loop for MQTT2Server, 1 event(s), first is DISCONNECTED
2020.06.26 10:17:44 5: Activitaetsstatus: not on any display, ignoring notify
2020.06.26 10:17:44 5: Batteriestatus: not on any display, ignoring notify
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> ###              start of new Logcycle                       ###
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> number of events received: 1 for device: MQTT2Server
2020.06.26 10:17:44 4: DbLog logdb -> check Device: MQTT2Server , Event: DISCONNECTED
2020.06.26 10:17:44 5: DbLog logdb -> parsed Event: MQTT2Server , Event: DISCONNECTED
2020.06.26 10:17:44 4: DbLog logdb -> added event - Timestamp: 2020-06-26 10:17:44, Device: MQTT2Server, Type: MQTT2_CLIENT, Event: DISCONNECTED, Reading: state, Value: DISCONNECTED, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> ###         New database processing cycle - synchronous      ###
2020.06.26 10:17:44 4: DbLog logdb -> ################################################################
2020.06.26 10:17:44 4: DbLog logdb -> DbLogType is: History
2020.06.26 10:17:44 4: DbLog logdb -> AutoCommit mode: ON, Transaction mode: ON
2020.06.26 10:17:44 4: DbLog logdb -> Insert mode: Array
2020.06.26 10:17:44 4: DbLog logdb -> Primary Key used in history: none
2020.06.26 10:17:44 4: DbLog logdb -> Primary Key used in current: DEVICE,READING
2020.06.26 10:17:44 4: DbLog logdb -> processing event Timestamp: 2020-06-26 10:17:44, Device: MQTT2Server, Type: MQTT2_CLIENT, Event: DISCONNECTED, Reading: state, Value: DISCONNECTED, Unit:
2020.06.26 10:17:44 4: DbLog logdb -> 1 of 1 events inserted into table history
2020.06.26 10:17:44 4: DbLog logdb -> insert table history committed by autocommit
2020.06.26 10:17:44 5: mqttPublishList: not on any display, ignoring notify
2020.06.26 10:17:44 5: Triggering n_publish_mqtt
2020.06.26 10:17:44 4: n_publish_mqtt exec {
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');;

    if ($mqttName ne '') {
        my $reading = "";;
        my $message = "";;
        my $persist = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

my $topic = "";;
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";;
} else {
$topic = "/SmartHome/$mqttName/$reading";;
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");;
    }
}
2020.06.26 10:17:44 5: Cmd: >{
    my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');
    my $mqttName = AttrVal($NAME, 'mqttName', '');
    my $mqttPersist = AttrVal($NAME, 'mqttPersist', '');

    if ($mqttName ne '') {
        my $reading = "";
        my $message = "";
        my $persist = "";

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;
            $message = $2;
        } else {
            $reading = "state";
            $message = $EVENT;
        }

my $topic = "";
        if ($mqttRoom ne ''){
$topic = "/SmartHome/$mqttRoom/$mqttName/$reading";
} else {
$topic = "/SmartHome/$mqttName/$reading";
}

        if ($mqttPersist ne '') {
            $persist = "retain:1"
        }

        fhem("set Mosquitto publish $persist $topic $message");
    }
}<
2020.06.26 10:17:44 5: End notify loop for MQTT2Server


Netzwerkprobleme würde ich eigentlich ausschließen, da FHEM und Mosquitto auf dem selben Server laufen und der Intel Core i5 eigentlich genug Luft haben müsste um TCP Pakete über das externe Interface an sich selbst zu schicken.

Gruß,
Reiner 
Reiner.

rudolfkoenig

Leider sehe ich in diesem Log nichts Auffaelliges.
Zweiter Versuch: bitte um FHEM-Log-Ausschnitt, diesmal (nur) mit "attr MQTT2Server verbose 5", die eine Minute vor dem disconnect, wg. 2* keepaliveTimeout.

reibuehl

Als nach 24 Stunden mit MQTT2Server auf verbose 5 und ich hatte keine weiteren disconnects... das muss ein äußerst scheues Problem sein... wenn man es näher anschaut ist es weg :-)

Ich werde den Verbose level jetzt mal wieder auf default zurück setzen und testen, ob dann das Problem wieder auftaucht.
Reiner.