[SOLVED] Partial no updates from homematic binding

e36Alex · September 16, 2018, 8:52am

Hello,

i am playing around with the homematic binding the last days and got a problem with it dont really understand.

i am using two things with it right now, a radiator valve and a door sensor. if a value of the radiator valve changes, it gets updated in openhab. if the door sensor changes its state, there is no update to openhab - i have to “reload from gateway” to get the new values.

in the log i got no errors, so i even integrated homematic in an test-installation of iobroker - there the state of the sensor changes immidiatly, so it should be a problem on openhab.

do you have ideas to solve this?

thanks, alex

MHerbst · September 16, 2018, 10:36am

Hi Alexander,

I never had any problems with the Homematic door sensors that I am using. But my openHAB production environment is quite old.

Can you provide us with some additional information:

Which openHAB version are you using?
There are different types of HomeMatic door senses. Which one are you using?
Are there any messages in openhab.log resp. events.log when you open/close a door?

e36Alex · September 16, 2018, 12:51pm

Hi,

I am using 2.4M3.

The Sensor is HmIP-SRH and there are no entries in the log-files. Its just like the state didnt change.

hmerk · September 16, 2018, 1:04pm

I am running 2.4M3 with homematic binding and homegear on the same machine. In that constellation, my MAX! contacts attached to a reflashed Cube (now a Cun) report any changes and I can see those immediately in openHAB.

Please give a bit more precise description on your installation.

e36Alex · September 16, 2018, 1:21pm

System is Running in a Debian Linux and Homematic ins CCU3.

The HM-CC-RT-DN is working Fine and all values get an Update on change.

hmerk · September 16, 2018, 1:36pm

I guess you should open an issue at

as the homematic binding is an ESH binding.
Out of the docs I did not find any hint on supporting CCU3…

MHerbst · September 16, 2018, 3:10pm

I don’t think that the problem is caused by CCU3 I am running a system that is quite similar to the CCU3 hardware (the new RPI-RF-MOD on Raspi).
I remember that there was a problem with the HMIP devices. https://github.com/eclipse/smarthome/issues/6053 . I am not sure whether the solution of this issue is not contained in M3 or not.

e36Alex · September 16, 2018, 5:33pm

maybe its similar, but in my case all things are correctly online and i also get the values - but for this one device just if i catch them from the ccu.

do you have an advise for me?

ps: just changed from snapshot to m3 because i hat even troubles at the snapshot-release with homematic.

MHerbst · September 16, 2018, 5:57pm

In this case I would recommend to create an issue for this problem. Maybe the last fix for the IP devices was not sufficient.
It would probably help if you active the debug log and then attach its output to the issue.
I am also using some door contacts, but no IP contacts and they are working correctly. Therefore I assume that there is a problem with the IP devices.

e36Alex · September 16, 2018, 6:27pm

thanks you.

of course, i already checked the log - even at level debug, but theres nothing. only entry i get is:

[ommunicator.AbstractHomematicGateway] - Received new (String) value 'ccu3' for 'CENTRAL:0#PONG' from gateway with id 'ccu3'

hmerk · September 16, 2018, 6:50pm

You could set log level to TRACE, which might give some more relevant information

e36Alex · September 16, 2018, 7:04pm

even did it - but nothing about the door sensor:

==> /var/log/openhab2/openhab.log <==

2018-09-16 20:59:13.736 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71'

2018-09-16 20:59:13.736 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.internal.items.ItemUpdater@15bdf866'

2018-09-16 20:59:13.736 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71' for asynchronous execution

==> /var/log/openhab2/events.log <==

2018-09-16 20:59:13.736 [vent.ItemStateChangedEvent] - ZWaveSerialController_StartFrames changed from 504 to 505

==> /var/log/openhab2/openhab.log <==

2018-09-16 20:59:13.736 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71' for asynchronous execution

2018-09-16 20:59:13.736 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:13.737 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71'

2018-09-16 20:59:13.737 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161'

2018-09-16 20:59:13.737 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71'

2018-09-16 20:59:13.737 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161'

2018-09-16 20:59:13.842 [DEBUG] [i.internal.protocol.KodiClientSocket] - send message: {"jsonrpc":"2.0","id":286,"method":"Application.GetProperties","params":{"properties":["version","name"]}}

2018-09-16 20:59:13.845 [DEBUG] [i.internal.protocol.KodiClientSocket] - Message received from server: {"id":286,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":6,"revision":"20171115-d69a54a","tag":"stable"}}}

2018-09-16 20:59:13.846 [DEBUG] [i.internal.protocol.KodiClientSocket] - callMethod returns {"id":286,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":6,"revision":"20171115-d69a54a","tag":"stable"}}}

2018-09-16 20:59:16.590 [TRACE] [me.storage.json.internal.JsonStorage] - deserialized value 'DiscoveryResult [thingUID=astro:sun:local, properties={geolocation=53.13853299128647,8.91320351511238,0}, representationProperty=geolocation, flag=NEW, label=Local Sun, bridgeUID=null, ttl=-1, timestamp=1536959192131]' from Json

2018-09-16 20:59:17.099 [TRACE] [nal.communicator.client.BinRpcClient] - Client BinRpcRequest:

ping()

ccu3

2018-09-16 20:59:17.100 [TRACE] [al.communicator.client.SocketHandler] - Returning socket for port 2001

2018-09-16 20:59:17.103 [TRACE] [nal.communicator.client.BinRpcClient] - Client BinRpcResponse:

[

	true

]

2018-09-16 20:59:17.104 [TRACE] [nicator.server.BinRpcResponseHandler] - Event BinRpcMessage: system.multicall()

[

	{

		methodName=event

		params=

		[

			RF-ccu3

			CENTRAL

			PONG

			ccu3

		]

	}

]

2018-09-16 20:59:17.105 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (String) value 'ccu3' for 'CENTRAL:0#PONG' from gateway with id 'ccu3'

2018-09-16 20:59:17.104 [TRACE] [nal.communicator.client.BinRpcClient] - Client BinRpcRequest:

listBidcosInterfaces()

2018-09-16 20:59:17.106 [TRACE] [al.communicator.client.SocketHandler] - Returning socket for port 2001

2018-09-16 20:59:17.109 [TRACE] [nal.communicator.client.BinRpcClient] - Client BinRpcResponse:

[

	{

		ADDRESS=PEQ1099331

		CONNECTED=true

		DEFAULT=true

		DESCRIPTION=

		DUTY_CYCLE=31

		FIRMWARE_VERSION=3.4.8

		TYPE=CCU2

	}

]

2018-09-16 20:59:17.111 [TRACE] [me.core.internal.events.EventHandler] - Handle OSGi event (event: org.osgi.service.event.Event [topic=smarthome] {topic=smarthome/items/Duty_Cycle/state, source=homematic:bridge:ccu3:DUTY_CYCLE_RATIO, type=ItemStateEvent, payload={"type":"Decimal","value":"31"}, timestamp=1537124357110})

2018-09-16 20:59:17.111 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.openhab.io.openhabcloud.internal.CloudService@53c45f44'

2018-09-16 20:59:17.111 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.openhab.io.openhabcloud.internal.CloudService@53c45f44' for asynchronous execution

2018-09-16 20:59:17.112 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.openhab.io.openhabcloud.internal.CloudService@53c45f44' for asynchronous execution

2018-09-16 20:59:17.112 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161'

2018-09-16 20:59:17.112 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.112 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161' for asynchronous execution

2018-09-16 20:59:17.113 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161' for asynchronous execution

2018-09-16 20:59:17.113 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.113 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71'

2018-09-16 20:59:17.113 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.openhab.io.openhabcloud.internal.CloudService@53c45f44'

2018-09-16 20:59:17.113 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71' for asynchronous execution

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71' for asynchronous execution

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.openhab.io.openhabcloud.internal.CloudService@53c45f44'

==> /var/log/openhab2/events.log <==

2018-09-16 20:59:17.113 [thome.event.ItemStateEvent] - Received event of type 'ItemStateEvent' under the topic 'smarthome/items/Duty_Cycle/state' with payload: '{"type":"Decimal","value":"31"}'

2018-09-16 20:59:17.114 [thome.event.ItemStateEvent] - Duty_Cycle updated to 31

==> /var/log/openhab2/openhab.log <==

==> /var/log/openhab2/events.log <==

==> /var/log/openhab2/openhab.log <==

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@6337b94d'

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161'

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@6337b94d' for asynchronous execution

2018-09-16 20:59:17.114 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.monitor.internal.EventLogger@23a03161'

2018-09-16 20:59:17.115 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@6337b94d' for asynchronous execution

2018-09-16 20:59:17.115 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.115 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.openhab.core.events.internal.EventBridge@202d3bf7'

2018-09-16 20:59:17.115 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@6337b94d'

2018-09-16 20:59:17.115 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.openhab.core.events.internal.EventBridge@202d3bf7' for asynchronous execution

2018-09-16 20:59:17.115 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@6337b94d'

2018-09-16 20:59:17.116 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.openhab.core.events.internal.EventBridge@202d3bf7' for asynchronous execution

2018-09-16 20:59:17.116 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.116 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.internal.items.ItemUpdater@15bdf866'

2018-09-16 20:59:17.116 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.openhab.core.events.internal.EventBridge@202d3bf7'

2018-09-16 20:59:17.116 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71'

2018-09-16 20:59:17.117 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.core.internal.items.ItemUpdater@15bdf866' for asynchronous execution

2018-09-16 20:59:17.117 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@66a2bb71'

2018-09-16 20:59:17.117 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.openhab.core.events.internal.EventBridge@202d3bf7'

2018-09-16 20:59:17.117 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.core.internal.items.ItemUpdater@15bdf866' for asynchronous execution

2018-09-16 20:59:17.117 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.117 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@29b3080c'

2018-09-16 20:59:17.118 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@29b3080c' for asynchronous execution

2018-09-16 20:59:17.118 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@29b3080c' for asynchronous execution

2018-09-16 20:59:17.118 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.119 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@6477f578'

2018-09-16 20:59:17.119 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@29b3080c'

2018-09-16 20:59:17.119 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@29b3080c'

2018-09-16 20:59:17.119 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling invocation of 'receive()' on 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@6477f578' for asynchronous execution

2018-09-16 20:59:17.119 [TRACE] [.internal.common.SafeCallManagerImpl] - Submitted invocation of 'receive()' on 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@6477f578' for asynchronous execution

2018-09-16 20:59:17.119 [TRACE] [.internal.common.SafeCallManagerImpl] - Scheduling timeout watcher in 5000ms

2018-09-16 20:59:17.120 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.core.internal.items.ItemUpdater@15bdf866'

2018-09-16 20:59:17.121 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.internal.items.ItemUpdater@15bdf866'

2018-09-16 20:59:17.120 [TRACE] [.internal.common.SafeCallManagerImpl] - Finished invocation of 'receive()' on 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@6477f578'

2018-09-16 20:59:17.121 [TRACE] [.internal.common.SafeCallManagerImpl] - Triggering submissions for 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@6477f578'

2018-09-16 20:59:18.635 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-09-16 20:59:20.552 [TRACE] [nicator.server.BinRpcResponseHandler] - Event BinRpcMessage: system.multicall()

[

	{

		methodName=event

		params=

		[

			RF-ccu3

			CENTRAL

			PONG

			hm-rpc.0

		]

	}

]

2018-09-16 20:59:20.552 [DEBUG] [ommunicator.AbstractHomematicGateway] - Received new (String) value 'hm-rpc.0' for 'CENTRAL:0#PONG' from gateway with id 'ccu3'

e36Alex · September 17, 2018, 7:29pm

hmerk · September 18, 2018, 5:02pm

wrong place, should be eclipse/smarthome

e36Alex · September 23, 2018, 4:57pm

hello,

i still got the same problem after a fresh install of openhab. actually i think it has to be a problem depending on my debian-system, because at my openhab test-environment on a vm (running on the debian system) and a iobroker test-installation on a windows-device i get the state-updates of the ccu.

do you have an idea that could help me to find the problem?

MHerbst · September 23, 2018, 5:22pm

If you are running a vm on the same machine, you probably have two IP addresses on your main debian system. In this case the Homematic binding sometimes using the wrong IP adress as “Callback” address. You can see in the openhab log file which one is used and you can configure the correct callback address in Paper UI.

You should also check the firewall settings and make sure that all necessary ports are open.

e36Alex · September 23, 2018, 6:21pm

i already set the callback-host at the thing-file, but maybe you can have a look at it:

Bridge homematic:bridge:ccu3 [ gatewayAddress="192.168.178.65", callbackHost="192.168.178.11"]
{
    Thing HM-RCV-50           BidCoS-RF         "HM Virtuellle Fernbedienung"
    Thing HM-CC-RT-DN         OEQ1875799        "HM Heizkörper-Thermostat Wohnzimmer Links"
    Thing HmIP-SRH            0007D7099D00AB    "HM Türkontakt Terrassentür"
    Thing GATEWAY-EXTRAS-CCU3 GWE00000000       "Gateway Extras"
}

This are my firewall settings at the ccu3 - but i think that this is not the problem, because the manual reload works fine:

e36Alex · September 25, 2018, 7:28pm

Hello,

today i got a few more hmip-devices for testing - it seems like the problem is depending on homematic ip, because i got the same problem with all hm-ip devices.

now i tried out to set some parameters in the thing-file to the default values. and now i get the following message in the logs:

Bridge homematic:bridge:ccu3 [ gatewayAddress="192.168.178.65", callbackHost="192.168.178.11", xmlCallbackPort="9125", hmIpPort="2010"]

21:26:11.705 [ERROR] [unicator.server.BinRpcResponseHandler] - No BinX signature
java.io.UnsupportedEncodingException: No BinX signature
        at org.eclipse.smarthome.binding.homematic.internal.communicator.message.BinRpcMessage.validateBinXSignature(BinRpcMessage.java:106) [203:org.eclipse.smarthome.binding.homematic:0.10.0.oh240M3]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.message.BinRpcMessage.<init>(BinRpcMessage.java:82) [203:org.eclipse.smarthome.binding.homematic:0.10.0.oh240M3]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.server.BinRpcResponseHandler.run(BinRpcResponseHandler.java:48) [203:org.eclipse.smarthome.binding.homematic:0.10.0.oh240M3]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
21:26:11.725 [ERROR] [unicator.server.BinRpcResponseHandler] - No BinX signature
java.io.UnsupportedEncodingException: No BinX signature
        at org.eclipse.smarthome.binding.homematic.internal.communicator.message.BinRpcMessage.validateBinXSignature(BinRpcMessage.java:106) [203:org.eclipse.smarthome.binding.homematic:0.10.0.oh240M3]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.message.BinRpcMessage.<init>(BinRpcMessage.java:82) [203:org.eclipse.smarthome.binding.homematic:0.10.0.oh240M3]
        at org.eclipse.smarthome.binding.homematic.internal.communicator.server.BinRpcResponseHandler.run(BinRpcResponseHandler.java:48) [203:org.eclipse.smarthome.binding.homematic:0.10.0.oh240M3]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

MHerbst · September 26, 2018, 5:32pm

I will set a test environment for the latest milestone builds and will test it. I have got only one IP device but maybe I can reproduce the problem
Please add the information from your last post also to the github issue.

e36Alex · September 26, 2018, 5:42pm

thanks for your help!

here is the right issue at github - i already added the last informations.