Partial no updates from homematic binding


(Alexander) #5

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.


(Hans-Jörg Merk) #6

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…


(Martin Herbst) #7

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.


(Alexander) #8

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.


(Martin Herbst) #9

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.


(Alexander) #10

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'

(Hans-Jörg Merk) #11

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


(Alexander) #12

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'

(Alexander) #13

(Hans-Jörg Merk) #14

wrong place, should be eclipse/smarthome


(Alexander) #15

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?


(Martin Herbst) #16

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.


(Alexander) #17

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:


(Alexander) #18

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) [?:?]

(Martin Herbst) #19

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.


(Alexander) #20

thanks for your help!

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


(Alexander) #21

Today i set up my whole system completely new - but i got still the same problem. i have a fresh install of openmediavault (on debian) and OH2.4M4


(Martin Herbst) #22

It does not seem to be a general problem of HmIP devices. I only have a HmIP-PDT (dimmer). This device works fine with 2.4 M4. I have added Invormation about my test environment and results to the issue.


(Alexander) #23

i think its no generel problem with the devices, too - it has to be something at my configuration, cause in the vm, for excample, the hmip devices are updating the states.

i checked the logs of the ccu3, as well - maybe this could be a hint to the error in my config?

Sep 30 18:12:04 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-0] (un)registerCallback on LegacyServiceHandler called from url: http://127.0.0.1:9292/bidcos 
Sep 30 18:12:04 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-0] init finished 
Sep 30 18:12:04 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO  [vert.x-worker-thread-3] Added InterfaceId: HmIP-RF_java 
Sep 30 18:12:04 de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil INFO  [vert.x-worker-thread-3] updateDevicesForClient HmIP-RF_java -> 24 device addresses will be added 
Sep 30 18:12:05 de.eq3.ccu.server.BaseHMServer INFO  [Thread-2] Starting HMServer done 
Sep 30 18:12:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-4] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.178.11:9125 
Sep 30 18:12:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-4] init finished 
Sep 30 18:12:08 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-4] (un)registerCallback on VirtualDeviceHandlerRega called from url: http://192.168.178.11:9125 
Sep 30 18:12:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-0] (un)registerCallback on LegacyServiceHandler called from url: http://192.168.178.11:9125 
Sep 30 18:12:08 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-0] init finished 
Sep 30 18:12:08 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO  [vert.x-worker-thread-3] Added InterfaceId: HMIP-ccu3 
Sep 30 18:12:08 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-4] (un)registerCallback on VirtualDeviceHandlerRega called from url: http://192.168.178.11:9125 
Sep 30 18:12:08 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-4] Added InterfaceId: GROUP-ccu3 
Sep 30 18:12:08 de.eq3.ccu.virtualdevice.service.internal.rega.BackendWorker INFO  [vert.x-worker-thread-11] Execute BackendCommand: de.eq3.ccu.virtualdevice.service.internal.rega.BackendUpdateDevicesCommand 
Sep 30 18:12:08 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer ERROR [vert.x-worker-thread-3] IO Exception: Could not add interface: HMIP-ccu3 
de.eq3.cbcs.legacy.communication.rpc.RpcIOException: java.net.ConnectException: Connection refused (Connection refused)
	at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:90)
	at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.sendRequest(RpcClient.java:99)
	at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.invoke(RpcClient.java:87)
	at com.sun.proxy.$Proxy21.listDevices(Unknown Source)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient.listDevices(LegacyBackendClient.java:140)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil.synchronizedBackendDevices(DeviceUtil.java:116)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer.handle(InterfaceInitializer.java:107)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer.handle(InterfaceInitializer.java:31)
	at io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:212)
	at io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:191)
	at io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$3(EventBusImpl.java:505)
	at io.vertx.core.impl.ContextImpl.lambda$wrapTask$2(ContextImpl.java:337)
	at io.vertx.core.impl.TaskQueue.lambda$new$0(TaskQueue.java:60)
	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)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:120)
	at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:179)
	at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:144)
	at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:134)
	at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:612)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:447)
	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:884)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
	at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:86)
	... 15 more
Sep 30 18:12:18 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-4] (un)registerCallback on VirtualDeviceHandlerRega called from url: xmlrpc_bin://127.0.0.1:1999 
Sep 30 18:12:18 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-4] Added InterfaceId: 1008 
Sep 30 18:12:18 de.eq3.ccu.virtualdevice.service.internal.rega.BackendWorker INFO  [vert.x-worker-thread-12] Execute BackendCommand: de.eq3.ccu.virtualdevice.service.internal.rega.BackendUpdateDevicesCommand 
Sep 30 18:12:28 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-3] (un)registerCallback on LegacyServiceHandler called from url: xmlrpc_bin://127.0.0.1:1999 
Sep 30 18:12:28 de.eq3.cbcs.legacy.bidcos.rpc.LegacyServiceHandler INFO  [vert.x-worker-thread-3] init finished 
Sep 30 18:12:28 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer INFO  [vert.x-worker-thread-1] Added InterfaceId: 1009 

(Martin Herbst) #24

I am not sure which connection causes the error. It could be a connection to a HmIP device or the connection to openHAB: I would guess its the latter. Is it possible that the firewall of openmediavault blocks part of the communication?