search

mdzio / ccu-jack

CCU-Jack bietet einen einfachen und sicheren REST- und MQTT-basierten Zugriff auf die Datenpunkte der Zentrale (CCU) des Hausautomations-Systems HomeMatic. Zudem können einfach Fremdgeräte an die CCU angebunden werden.
GNU General Public License v3.0
115 stars 11 forks source link

ERROR mqtt-server Publish of event failed: Unexpected event from a device: QEQ0004233 #186

Closed djiwondee closed 3 days ago

djiwondee commented 1 week ago

Hallo Mathias,

erst mal wieder vielen Dank für diese AddOn für die CCU, das ich schon länger nutze. Leider habe ich mal wieder ein Problem. Seit kurzem habe ich sehr häufig folgende Fehlermeldungen im Log 

2024-09-14 09:39:28 WARNING mqtt    RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:28 WARNING mqtt    RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:38:41 WARNING devices Device should not send event: QEQ0004233
2024-09-14 09:38:41 ERROR   mqtt-server Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:36:41 WARNING devices Device should not send event: QEQ0004233
2024-09-14 09:36:41 ERROR   mqtt-server Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:36:26 WARNING mqtt    RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:36:25 WARNING mqtt    RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:36:19 WARNING mqtt    RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
image

Auch geht der DutyCylce der CCU3 auf 99%. Dank CCUJack kann ich im MQTT-Explorer auch sehen, dass es NUR der CCU Duty Cylce ist. Ich verwende CCU Jack 2.9.1 auf einer CCU3 mit Firmware 3.77.7

Die Änderung, die ich zum 12.9.2024 vorgenommen habe ist, dass ich mittels Node-Red von CCU-Jack ein weiteres Topic subskribiert habe.

Habe mal das Logging auf DEBUG umgestellt und werde nach kurzer Zeit dieses Issue ergänzen. Vielen Dank schon mal für Deine Unterstützung.

djiwondee commented 1 week ago

Hier ist mal ein Auszug aus dem CCU Log mit eingeschaltetem Debug Mode

2024-09-14 07:46:51|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 07:46:51|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 08:00:27|WARNING|mqtt           |(39/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics
2024-09-14 08:01:51|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 08:01:51|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 08:01:57|WARNING|mqtt           |(39/mqtt-explorer-07d6fce1) Reading from connection failed: read tcp 192.168.178.4:1883->192.168.178.105:49375: i/o timeout
2024-09-14 08:10:25|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 08:10:38|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 08:16:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 08:16:41|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 08:32:51|WARNING|mqtt           |(40/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics
2024-09-14 08:36:28|WARNING|mqtt           |(40/mqtt-explorer-07d6fce1) Reading from connection failed: read tcp 192.168.178.4:1883->192.168.178.105:49461: i/o timeout
2024-09-14 08:42:32|WARNING|mqtt           |(41/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics
2024-09-14 08:44:02|WARNING|mqtt           |(41/mqtt-explorer-07d6fce1) Reading from connection failed: read tcp 192.168.178.4:1883->192.168.178.105:49933: i/o timeout
2024-09-14 09:10:58|WARNING|mqtt           |(42/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics
2024-09-14 09:12:28|WARNING|mqtt           |(42/mqtt-explorer-07d6fce1) Reading from connection failed: read tcp 192.168.178.4:1883->192.168.178.105:50036: i/o timeout
2024-09-14 09:33:51|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:33:51|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:34:11|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:34:11|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:34:31|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:34:31|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:34:35|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:34:35|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:34:38|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:34:39|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:34:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:34:41|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:34:59|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:35:05|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:35:05|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:35:17|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:35:24|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:35:55|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:36:19|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:36:25|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:36:26|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:36:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:36:41|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:38:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:38:41|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:39:28|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:28|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:31|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:31|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:34|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:41|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:55|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:57|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:39:58|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:40:15|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:40:22|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:40:27|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:41:02|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:41:09|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:41:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:41:41|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:42:16|WARNING|mqtt           |(43/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics
2024-09-14 09:42:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:42:41|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-14 09:46:26|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:46:26|WARNING|mqtt           |RPC fault (code: -1, message: Generic error (DUTY_CYCLE))
2024-09-14 09:46:41|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-14 09:46:41|WARNING|devices        |Device should not send event: QEQ0004233

Interessant finde ich dabei u. a. diese Zeilen:

2024-09-14 08:32:51|WARNING|mqtt           |(40/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics
2024-09-14 08:36:28|WARNING|mqtt           |(40/mqtt-explorer-07d6fce1) Reading from connection failed: read tcp 192.168.178.4:1883->192.168.178.105:49461: i/o timeout

Die IP-Adresse 192.168.178.4 ist die CCU, die 192.168.178.105 mein Mac, auf dem der mqtt-explorer läuft. Der Mac geht immer mal wieder in den Ruhezustand. Kann es sein, dass diese offene aber "idle"-Verbindung Probleme macht? Wenn ich den MQTT-Explorer allerdings beende, habe ich doch immer wieder zyklisch die 99%.

mdzio commented 1 week ago

Was ist denn QEQ0004233 für ein Gerät?

2024-09-14 08:32:51|WARNING|mqtt           |(40/mqtt-explorer-07d6fce1) Error processing SUBSCRIBE: memtopics/nextTopicLevel: Cannot publish to $ topics

$-Topics werden vom CCU-Jack nicht unterstützt. Dadurch ergeben sich aber keine Einschränkungen.

2024-09-14 08:36:28|WARNING|mqtt           |(40/mqtt-explorer-07d6fce1) Reading from connection failed: read tcp 192.168.178.4:1883->192.168.178.105:49461: i/o timeout

Der MQTT-Explorer auf den Mac hat Verbindung einfach so beendet. Das kann mit dem Ruhezustand zusammen hänge. Dies ist aber nicht weiter schlimm.

djiwondee commented 1 week ago

Was ist denn QEQ0004233 für ein Gerät?

Das wüsste ich selber gerne! Das einzige, was ich auf CCUJack publish sind Requests für sysvars aller 10 min:

image

Ist das überhaupt ein Device oder ist das ein Event

2024-09-14 09:42:41|WARNING|devices |Device should not send event: QEQ0004233

djiwondee commented 1 week ago

Mir fällt gerade noch ein, dass der o. g. Termin seit dem das Verhalten auftritt, mit dem CCU-Firmware-Update auf 3.77.7 zusammenfällt.

djiwondee commented 1 week ago

Bzgl.: 2024-09-14 09:34:31|WARNING|devices |Device should not send event: QEQ0004233

Sowas ähnliches hatte schon mal jemand: https://homematic-forum.de/forum/viewtopic.php?t=78856

Das klärt es: https://homematic-forum.de/forum/viewtopic.php?f=38&t=71955&start=10 QEQXXXXXX ist das Funkmodul der CCU

image
mdzio commented 1 week ago

Weitere Log-Meldungen wären hilfreich. Könntest Du den Log-Level einmal auf TRACE stellen und dann einen Ausschnitt 20 Zeilen vor und nach den Meldungen ("Publish of event failed: Unexpected event from a device: QEQ0004233" und "Device should not send event: QEQ0004233" und "RPC fault (code: -1, message: Generic error (DUTY_CYCLE))") zur Verfügung stellen.

djiwondee commented 1 week ago

Hallo @mdzio,

und dann einen Ausschnitt 20 Zeilen vor und nach den Meldungen ("Publish of event failed: Unexpected event from a device: QEQ0004233" und "Device should not send event: QEQ0004233" und "RPC fault (code: -1, message: Generic error (DUTY_CYCLE))") zur Verfügung stellen

Ich habe eine Stelle des ccu-jack.log gewählt , an dem der DutyCycle massiv anzusteigen beginnt:

2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request XML: <?xml version='1.0' encoding='ISO-8859-1'?><methodCall><methodName>system.multicall</methodName><params><param><value><array><data><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>SECTION_STATUS</value><value><i4>0</i4></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>STATE</value><value><boolean>1</boolean></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>SECTION</value><value><i4>2</i4></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>PROCESS</value><value><i4>0</i4></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>
2024-09-15 10:22:55|DEBUG  |xmlrpc-server  |Call of method system.multicall with 4 elements received
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, SECTION_STATUS, 0
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/SECTION_STATUS: {"ts":1726388575378,"v":0,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, STATE, true
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.SECTION_STATUS to 0
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/STATE: {"ts":1726388575378,"v":true,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, SECTION, 2
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.STATE to true
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/SECTION: {"ts":1726388575379,"v":2,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, PROCESS, 0
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/PROCESS: {"ts":1726388575379,"v":0,"s":0}
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.SECTION to 2
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.PROCESS to 0
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value><array><data><value></value><value></value><value></value><value></value></data></array></value></param></params></methodResponse>
2024-09-15 10:22:55|TRACE  |xmlrpc-client  |Response XML: <?xml version='1.0' encoding='ISO-8859-1'?><methodResponse><params><param><value></value></param></params></methodResponse>
2024-09-15 10:22:55|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
2024-09-15 10:22:55|DEBUG  |itf-d-client   |Calling method setValue(0034DF29B51B79:3, STATE, true) on 127.0.0.1:2010
2024-09-15 10:22:55|TRACE  |xmlrpc-client  |Calling method setValue on 127.0.0.1:2010
2024-09-15 10:22:55|TRACE  |xmlrpc-client  |Request XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodCall><methodName>setValue</methodName><params><param><value>0034DF29B51B79:3</value></param><param><value>STATE</value></param><param><value><boolean>1</boolean></value></param></params></methodCall>
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request received from 127.0.0.1:49084, URI /RPC2
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request XML: <?xml version="1.0" encoding="iso-8859-1"?>\n<methodCall><methodName>system.multicall</methodName>\n<params><param><value><array><data><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-BidCos-RF</value><value>QEQ0004233</value><value>DUTY_CYCLE</value><value><i4>82</i4></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>\n
2024-09-15 10:22:55|DEBUG  |xmlrpc-server  |Call of method system.multicall with 1 elements received
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-BidCos-RF, QEQ0004233, DUTY_CYCLE, 82
2024-09-15 10:22:55|ERROR  |mqtt-server    |Publish of event failed: Unexpected event from a device: QEQ0004233
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value><array><data><value></value></data></array></value></param></params></methodResponse>
2024-09-15 10:22:55|WARNING|devices        |Device should not send event: QEQ0004233
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request received from 127.0.0.1:47058, URI /RPC2
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request XML: <?xml version='1.0' encoding='ISO-8859-1'?><methodCall><methodName>system.multicall</methodName><params><param><value><array><data><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:0</value><value>CONFIG_PENDING</value><value><boolean>0</boolean></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:0</value><value>RSSI_DEVICE</value><value><i4>-55</i4></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:0</value><value>DUTY_CYCLE</value><value><boolean>0</boolean></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:0</value><value>UNREACH</value><value><boolean>0</boolean></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:0</value><value>RSSI_PEER</value><value><i4>-58</i4></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>
2024-09-15 10:22:55|DEBUG  |xmlrpc-server  |Call of method system.multicall with 5 elements received
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:0, CONFIG_PENDING, false
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/0/CONFIG_PENDING: {"ts":1726388575512,"v":false,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:0, RSSI_DEVICE, -55
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/0/RSSI_DEVICE: {"ts":1726388575513,"v":-55,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:0, DUTY_CYCLE, false
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/0/DUTY_CYCLE: {"ts":1726388575513,"v":false,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:0, UNREACH, false
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/0/UNREACH: {"ts":1726388575513,"v":false,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:0, RSSI_PEER, -58
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/0/RSSI_PEER: {"ts":1726388575514,"v":-58,"s":0}
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value><array><data><value></value><value></value><value></value><value></value><value></value></data></array></value></param></params></methodResponse>
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:0.CONFIG_PENDING to false
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:0.RSSI_DEVICE to -55
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:0.DUTY_CYCLE to false
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:0.UNREACH to false
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:0.RSSI_PEER to -58
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request received from 127.0.0.1:47058, URI /RPC2
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request XML: <?xml version='1.0' encoding='ISO-8859-1'?><methodCall><methodName>system.multicall</methodName><params><param><value><array><data><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>SECTION_STATUS</value><value><i4>0</i4></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>STATE</value><value><boolean>0</boolean></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>SECTION</value><value><i4>0</i4></value></data></array></value></member></struct></value><value><struct><member><name>methodName</name><value>event</value></member><member><name>params</name><value><array><data><value>CCU-Jack-HmIP-RF</value><value>0034DF29B51B79:3</value><value>PROCESS</value><value><i4>0</i4></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>
2024-09-15 10:22:55|DEBUG  |xmlrpc-server  |Call of method system.multicall with 4 elements received
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, SECTION_STATUS, 0
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/SECTION_STATUS: {"ts":1726388575522,"v":0,"s":0}
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, STATE, false
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/STATE: {"ts":1726388575522,"v":false,"s":0}
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.SECTION_STATUS to 0
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, SECTION, 0
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/SECTION: {"ts":1726388575522,"v":0,"s":0}
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.STATE to false
2024-09-15 10:22:55|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 0034DF29B51B79:3, PROCESS, 0
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.SECTION to 0
2024-09-15 10:22:55|TRACE  |mqtt-server    |Publishing device/status/0034DF29B51B79/3/PROCESS: {"ts":1726388575522,"v":0,"s":0}
2024-09-15 10:22:55|DEBUG  |devices        |Updating PV of 0034DF29B51B79:3.PROCESS to 0
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value><array><data><value></value><value></value><value></value><value></value></data></array></value></param></params></methodResponse>
2024-09-15 10:22:55|TRACE  |xmlrpc-server  |Request received from 127.0.0.1:47058, URI /RPC2

In den syslog messages finde ich in etwa zu diesem Zeitpunkt:

2024-09-15T10:22:55+02:00 ccu3-wineglassbay rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
2024-09-15T10:22:55+02:00 ccu3-wineglassbay rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
2024-09-15T10:22:55+02:00 ccu3-wineglassbay rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
2024-09-15T10:22:55+02:00 ccu3-wineglassbay rfd: (QEQ0004233) CCU2CommController::handleIncomingSerialFrame(): Duty cycle event with value: 82.000000.2

2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Info: Event="QEQ0004233"."DUTY_CYCLE"=82 [execute():iseXmlRpc.cpp:331]
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Info: WARNING: no device object exists (interface: 1009 address:'QEQ0004233') [GetObjectByHSSAddress():iseXmlRpc.cpp:2157]

2024-09-15T10:22:55+02:00 ccu3-wineglassbay rfd: HSSXmlRpcEventDispatcher::Handle send completed
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Info: Event="0034DF29B51B79:0"."CONFIG_PENDING"=false [execute():iseXmlRpc.cpp:331]
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Verbose: call on change; id = 6192 [SetLastDPActionTime():iseDOMchn.h:288]
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Verbose: call on change; id = 6191 [SetLastActionTime():iseDOMdev.h:225]
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Verbose: wait max timeout = 240000 [ThreadFunction():iseRTEvent.cpp:69]
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Verbose: type = DP_EXACTVALUE, condition valL = 1 valR1 = 0 [Evaluate():iseCondition.cpp:352]
2024-09-15T10:22:55+02:00 ccu3-wineglassbay ReGaHss: Verbose: sc = 0, condition result = 0 [Evaluate():iseCondition.cpp:1123]

Habe hier mal die beiden vollständigen Logs drangehangen in dem Zeitraum eines DutyCycle Up/Down Zyklus drangehangen:
ccu-logs.zip

Schon interessant anzuschauen, wie das kontinuierlich hoch und runter geht. Das ist von heute ab 0:00 Uhr: DutyCycle 20240915

Ich denke nicht mehr, dass das an CCU Jack liegen könnte. Vielleicht sollte ich mich mal an eq-3 wenden, dass das seit dem FirmwareUpdate der CCU so ist. Aber wenn deren Support in die Logs schaut, dann schmeißen sie ja wieder hin, weil "Fremdsoftware" auf der CCU läuft...

Herzlichen Dank für Deine Hilfe und die Zeit die Du für mich damit aufwendest.

djiwondee commented 6 days ago

Hallo @mdzio , FYI: seit heute gibt es bei eq-3 einen Supportcase von mir zu dem Thema. Sie wollen das mit Hilfe eines Systembackup von mir bei ihnen selber nachstellen...

...Update, das erwartete Feedback:

Die Prüfung des von Ihnen beschriebenen Sachverhalts hat ergeben, dass Erweiterungen, z.B. Zusatzsoftware, auf der Smarthome Zentrale vorhanden sind. Leider können wir Ihnen daher in diesem Fall keinen Support anbieten. Beachten Sie hierzu bitte auch den Hinweis in der WebUI: "... Vom Anwender installierte Zusatzsoftware kann zu unerwünschten Ergebnissen bis hin zu Datenverlust und Systeminstabilitäten führen. Für vom Anwender installierte Zusatzsoftware übernimmt die eQ-3 AG keine Haftung. ..."

Um Ihnen weiterhelfen zu können, bitten wir Sie, einen Werksreset an der Zentrale durchzuführen und das System neu in Betrieb zu nehmen. Bitte beachten Sie jedoch, dass durch das Zurücksetzen der Zentrale Daten und Einstellungen gelöscht werden.

Beste Grüße ***** Technical Support Specialist

mdzio commented 6 days ago

Ja, das war zu erwarten. Du hättest den CCU-Jack vorher deinstallieren müssen und einmal die Zentrale neu starten.

mdzio commented 6 days ago

In Deinen Log-Files habe ich noch etwas gefunden. Es werden verschiedene Datenpunkte bei Dir über MQTT sehr sehr oft gesetzt. Wenn dies dann Funkschaltaktoren sind, dann geht natürlich der Duty-Cycle durch die Decke. Das passt zu den Diagrammen: 

2024-09-15 10:22:12|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false
... 440 Meldungen in sehr kurzer Zeit
2024-09-15 10:23:18|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false

2024-09-15 10:23:18|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
2024-09-15 10:23:19|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false
2024-09-15 10:23:19|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
2024-09-15 10:23:19|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false
2024-09-15 10:23:23|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
2024-09-15 10:23:23|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false
2024-09-15 10:23:23|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
2024-09-15 10:23:38|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false
2024-09-15 10:23:38|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true

2024-09-15 10:25:07|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false
2024-09-15 10:25:07|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
2024-09-15 10:33:59|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, true
2024-09-15 10:35:07|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, false
2024-09-15 10:35:13|TRACE  |mqtt-server    |Set device message received: device/set/0001DBE99EE3DF/3/STATE, true
2024-09-15 10:35:14|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/4/STATE, false
2024-09-15 10:35:24|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, true
2024-09-15 10:35:40|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, false
2024-09-15 10:35:47|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/4/STATE, false
2024-09-15 10:37:04|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, true
2024-09-15 10:37:19|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, false
2024-09-15 10:37:26|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/4/STATE, false
2024-09-15 10:37:33|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, true
2024-09-15 10:37:58|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, false
2024-09-15 10:38:03|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, true
2024-09-15 10:38:05|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/4/STATE, false
2024-09-15 10:38:38|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, false
2024-09-15 10:38:45|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/4/STATE, false
2024-09-15 10:46:03|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B94BFB/3/STATE, true
2024-09-15 10:46:03|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B94BFB/3/STATE, true
2024-09-15 10:49:02|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/8/STATE, false
2024-09-15 10:49:09|TRACE  |mqtt-server    |Set device message received: device/set/00315F298E52AA/4/STATE, false
2024-09-15 10:53:10|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B94BAF/3/STATE, false
2024-09-15 11:08:35|TRACE  |mqtt-server    |Set device message received: device/set/00085D89B913F0/4/STATE, false
2024-09-15 11:08:35|TRACE  |mqtt-server    |Set device message received: device/set/00085BE9A00F0D/4/STATE, false
2024-09-15 11:48:02|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, false

2024-09-15 11:48:03|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true
... 550 Meldungen in sehr kurzer Zeit
2024-09-15 11:49:29|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B51B79/3/STATE, true

2024-09-15 11:52:05|TRACE  |mqtt-server    |Set device message received: device/set/0034DF29B94BAF/3/STATE, false

Generell kannst Du die Warnung

2024-09-15 10:22:55|WARNING|devices        |Device should not send event: QEQ0004233

ignorieren. Der CCU-Jack geht davon aus, dass nur Kanalparameter Werteänderungen senden. Hier hat aber ein Gerät selbst eine Wertänderung gesendet. Dies entspricht nicht dem Standard.

djiwondee commented 5 days ago

Hallo @mdzio

...Datenpunkte bei Dir über MQTT sehr sehr oft gesetzt....

Herzlichen Dank. Das muss ich mir in der Tat mal genau anschauen. Wird aber nicht die nächsten zwei Tage, da ich beruflich unterwegs bin. Nicht, dass ich einen Aktor mehrfach einschalte, wenn er bspw. schon ein ist...

djiwondee commented 3 days ago

Hallo lieber @mdzio , es mag sein, es vielleicht zu früh zum Jubeln ist, es sieht aber so aus, als wäre die Serie gebrochen:

image

Deine Hinweis oben war Gold wert und der entsprechende HmIP-Equipment schnell identifiziert.

image

Es ist eine HmIP-PSM Schalt/-Messdose, die ich für meine Warmwasser-Zirkulationspumpe nutze. Die hat ein umfangreiches Wochenprogramm konfiguriert und befindet sich im Keller. Das habe ich NIE "klackern" hören, vom vielen Ein- und Ausschalten. Abziehen und wieder einstecken hat das Problem (erstmal) beseitigt. Mal sehen, ob es wieder auftaucht. Würde mich nicht wundern, wenn diese HmIP-PSM einen Schaden hat. Wäre nicht die erste Dose...

Ganz herzlichen Dank!

mdzio commented 3 days ago

Dann schließe ich mal diesen Eintrag.