MQTT Nachrichten kommen zu nicht existierenden Datenpunkten

ptweety commented 2 years ago

Hallo @mdzio,

ich habe einige HmIP-SMI (Bewegungsmelder), HmIP-SPI (Anwesenheitsmelder) und HmIP-BSM (Schaltaktor mit Taster), HmIP-BRC2 (Taster).

Ich habe nun einige Datenpunkte dieser Geräte per MQTT abonniert:

'#'
'device/status/+/1/MOTION'
'device/status/+/1/PRESENCE_DETECTION_STATE'
'device/status/+/1/PRESS_SHORT'
'device/status/+/1/PRESS_LONG'
'device/status/+/2/PRESS_SHORT'
'device/status/+/2/PRESS_LONG'

Vom CCU-Jack kommen dann allerdings Nachrichten (PRESS_SHORT) zu den HmIP-SPI (rote Box) bzw. HmIP-SPI (orange Box) an, die eigentlich zu den Tastern (grüne Box) gehören sollten:

Dieses Verhalten kann ich sowohl im MQTT-Explorer als auch in Node-Red beobachten.

mdzio commented 2 years ago

Vielen Dank für die detaillierte Fehlerbeschreibung!

Bitte mal eine detaillierte Log-Datei erstellen:

In der Web-UI des CCU-Jacks Logging auf TRACE stellen.
CCU-Jack oder CCU/RM neu starten.
Warten bis der Fehler auftritt.
Log-Datei /var/log/ccu-jack.log von der CCU herunter kopieren.
In der Web-UI des CCU-Jacks Logging wieder auf INFO stellen.
Log-Datei an info (at) ccu-historian.de schicken.

Weitere Informationen zum CCU-Dateitransfer.

ptweety commented 2 years ago

Hi,

was ich vergessen hatte zu beschreiben: CCU-Jack läuft unter Docker in Version 2.0.62

Einen Teil des Logs kann ich ja auch hier posten für den interessierten Leser:

2022-02-19 07:36:19|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>
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request received from 192.168.1.12:38848, URI /RPC2
2022-02-19 07:36:19|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>000xxxxxxxxx89: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>000xxxxxxxxx89:0</value><value>RSSI_DEVICE</value><value><i4>-63</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>000xxxxxxxxx89:0</value><value>LOW_BAT</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>000xxxxxxxxx89:0</value><value>UNREACH</value><value><boolean>0</boolean></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>
2022-02-19 07:36:19|DEBUG  |xmlrpc-server  |Call of method system.multicall with 4 elements received
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx89:0, CONFIG_PENDING, false
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx89/0/CONFIG_PENDING: {"ts":1645256179557,"v":false,"s":0}
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx89:0, RSSI_DEVICE, -63
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx89/0/RSSI_DEVICE: {"ts":1645256179557,"v":-63,"s":0}
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx89:0, LOW_BAT, false
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx89:0.CONFIG_PENDING to false
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx89/0/LOW_BAT: {"ts":1645256179557,"v":false,"s":0}
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx89:0.RSSI_DEVICE to -63
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx89:0, UNREACH, false
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx89:0.LOW_BAT to false
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx89/0/UNREACH: {"ts":1645256179558,"v":false,"s":0}
2022-02-19 07:36:19|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>
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx89:0.UNREACH to false
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request received from 192.168.1.12:38848, URI /RPC2
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request XML: <?xml version="1.0" encoding="ISO-8859-1"?><methodCall><methodName>event</methodName><params><param><value>CCU-Jack-HmIP-RF</value></param><param><value>000xxxxxxxxx89:1</value></param><param><value>PRESS_SHORT</value></param><param><value><boolean>1</boolean></value></param></params></methodCall>
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx89:1, PRESS_SHORT, true
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx89/1/PRESS_SHORT: {"ts":1645256179563,"v":true,"s":0}
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value></value></param></params></methodResponse>
2022-02-19 07:36:19|DEBUG  |devices        |Parameter for event not found: 000xxxxxxxxx89:1.PRESS_SHORT
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request received from 192.168.1.12:38848, URI /RPC2
2022-02-19 07:36:19|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>000xxxxxxxxx8F: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>000xxxxxxxxx8F:0</value><value>RSSI_DEVICE</value><value><i4>-56</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>000xxxxxxxxx8F:0</value><value>LOW_BAT</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>000xxxxxxxxx8F:0</value><value>UNREACH</value><value><boolean>0</boolean></value></data></array></value></member></struct></value></data></array></value></param></params></methodCall>
2022-02-19 07:36:19|DEBUG  |xmlrpc-server  |Call of method system.multicall with 4 elements received
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx8F:0, CONFIG_PENDING, false
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx8F/0/CONFIG_PENDING: {"ts":1645256179972,"v":false,"s":0}
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx8F:0, RSSI_DEVICE, -56
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx8F:0.CONFIG_PENDING to false
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx8F/0/RSSI_DEVICE: {"ts":1645256179972,"v":-56,"s":0}
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx8F:0, LOW_BAT, false
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx8F/0/LOW_BAT: {"ts":1645256179972,"v":false,"s":0}
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx8F:0, UNREACH, false
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx8F:0.RSSI_DEVICE to -56
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx8F/0/UNREACH: {"ts":1645256179972,"v":false,"s":0}
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx8F:0.LOW_BAT to false
2022-02-19 07:36:19|DEBUG  |devices        |Updating PV of 000xxxxxxxxx8F:0.UNREACH to false
2022-02-19 07:36:19|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>
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request received from 192.168.1.12:38848, URI /RPC2
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request XML: <?xml version="1.0" encoding="ISO-8859-1"?><methodCall><methodName>event</methodName><params><param><value>CCU-Jack-HmIP-RF</value></param><param><value>000xxxxxxxxx8F:1</value></param><param><value>PRESS_SHORT</value></param><param><value><boolean>1</boolean></value></param></params></methodCall>
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx8F:1, PRESS_SHORT, true
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx8F/1/PRESS_SHORT: {"ts":1645256179977,"v":true,"s":0}
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value></value></param></params></methodResponse>
2022-02-19 07:36:19|DEBUG  |devices        |Parameter for event not found: 000xxxxxxxxx8F:1.PRESS_SHORT

mdzio commented 2 years ago

Der CCU-Jack leitet die über XML-RPC von der CCU empfangenen Wertänderungen/-aktualisierungen ohne weitere Prüfung an den MQTT-Server weiter. Die CCU verschickt also PRESS_SHORT-Aktualisierungen für Parameter, die nicht existieren.

Das ist auch aus den folgenden zwei Beispielen ersichtlich:

2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request XML: <?xml version="1.0" encoding="ISO-8859-1"?><methodCall><methodName>event</methodName><params><param><value>CCU-Jack-HmIP-RF</value></param><param><value>000xxxxxxxxx89:1</value></param><param><value>PRESS_SHORT</value></param><param><value><boolean>1</boolean></value></param></params></methodCall>
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx89:1, PRESS_SHORT, true
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx89/1/PRESS_SHORT: {"ts":1645256179563,"v":true,"s":0}
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value></value></param></params></methodResponse>
2022-02-19 07:36:19|DEBUG  |devices        |Parameter for event not found: 000xxxxxxxxx89:1.PRESS_SHORT

Es wird für den Parameter 000xxxxxxxxx89:1.PRESS_SHORT eine Aktualisierung empfangen und an MQTT weitergeleitet. Später merkt der CCU-Jack aber an, dass für die REST-API der Parameter nicht gefunden wird: Parameter for event not found: 000xxxxxxxxx89:1.PRESS_SHORT

2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Request XML: <?xml version="1.0" encoding="ISO-8859-1"?><methodCall><methodName>event</methodName><params><param><value>CCU-Jack-HmIP-RF</value></param><param><value>000xxxxxxxxx8F:1</value></param><param><value>PRESS_SHORT</value></param><param><value><boolean>1</boolean></value></param></params></methodCall>
2022-02-19 07:36:19|DEBUG  |itf-server     |Call of method event received: CCU-Jack-HmIP-RF, 000xxxxxxxxx8F:1, PRESS_SHORT, true
2022-02-19 07:36:19|TRACE  |mqtt-server    |Publishing device/status/000xxxxxxxxx8F/1/PRESS_SHORT: {"ts":1645256179977,"v":true,"s":0}
2022-02-19 07:36:19|TRACE  |xmlrpc-server  |Response XML: <?xml version="1.0" encoding="ISO-8859-1"?>\n<methodResponse><params><param><value></value></param></params></methodResponse>
2022-02-19 07:36:19|DEBUG  |devices        |Parameter for event not found: 000xxxxxxxxx8F:1.PRESS_SHORT

Wie oben, aber mit 000xxxxxxxxx8F.

mdzio commented 2 years ago

Die nicht zuordenbaren Wertaktialisierungen sind auch in einem anderen Werkzeug (HomeMatic-Manager) zu beobachten. Ich denke nicht, dass der CCU-Jack diese Nachrichten herausfiltern sollte, eventuell haben sie einen Zweck.

mdzio / ccu-jack

MQTT Nachrichten kommen zu nicht existierenden Datenpunkten #78