ioBroker.hm-rpc icon indicating copy to clipboard operation
ioBroker.hm-rpc copied to clipboard

Virtual Devices Port 2001 not updated or found anymore. CCU3 crashes. (Adapter not usable anymore with CCU3)

Open MarkusKress opened this issue 2 years ago • 4 comments

1.) Update from EQ-3: Problem is related to this Adapter, not CCU3.

2.) Update from EQ-3: They said: " Eine Bewertung im Zusammenhang mit externen Softwarelösungen bieten wir im Rahmen unseres Endkundensupports nicht an. Bitte wenden Sie sich hierzu an den Anbieter Ihrer Drittanbieterlösung. "

3.) Update: EQ-3 hat ein Update auf 3.65.11 für die CCU3 bereitgestellt. In den Release Notes seht zum diesem Problem nichts, aber es könnte sich gebessert haben. Auch nach über 12h keinen Absturz in der CCU3 mehr. Aber: Die HM-Adapter aktualisieren aber nicht mehr regelmäßig. Nur nach dem Start der Adapter werden die Datenpunkte aktualisiert.

4.) Update: Nach über einem Tag sind Teile der CCU3 wieder abgestützt. CCU3 musste rebootet werden und HM-Adapter bleibt wieder aus.

Aktuell kann ich Homematic nicht mehr mit dem IOBroker nutzen.

Original Post: Some days after Updating CCU3 and hm-rpc-Adapter some data of virtual device (Group of heizkörperventil and Wandthermostat) are not updated anymore. I tried to poweroff CCU3 and restart instances of adapter, but der doesn't help. Hours after restart the iob and ccu3 port 2001 on ccu3 wasn't reachable anymore.

  • hm-rpc version: 1.15.12
  • hm-rega version: 3.0.40
  • JS-Controller version: 4.0.23
  • Node version: 12.22.12 v6.2.20
  • Operating system: Linux
  • CCU model: CCU3
  • CCU firmware: 3.65.8

It seems something crashes in CCU3 internaly, so I can't change temperatures on my Groups (virtual devices) in the CCU3. CCU3 shows a warning after trying to change temperatures.

Log from IOB:

hm-rpc.0 2022-09-16 08:02:24.525 | info | Terminated (NO_ERROR): Without reason hm-rpc.0 2022-09-16 08:02:24.522 info terminating hm-rpc.0 2022-09-16 08:02:24.474 error Cannot call init: [http://server:2001, ""] Unknown XML-RPC tag 'TITLE' hm-rpc.0 2022-09-16 08:02:24.457 info xmlrpc -> ccu3-webui:2001/ init ["http://server:2001",""] hm-rpc.0 2022-09-16 08:02:24.454 error Init not possible, going to stop: Unknown XML-RPC tag 'TITLE'

Found errors in CCU3 log right after start hm-rpc-Adapter on Port 2001:

2022-09-20 01:12:20,744 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-3] SYSTEM: Permanent-/Burstlistener Handler utilization: 0/50 used 2022-09-20 01:12:20,744 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO [vert.x-eventloop-thread-3] SYSTEM: Eventlistener Handler utilization: 0/50 used 2022-09-20 01:14:38,180 io.vertx.core.impl.ContextImpl ERROR [vert.x-worker-thread-3] Unhandled exception 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:110) ~[HMIPServer.jar:?] at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.sendRequest(RpcClient.java:94) ~[HMIPServer.jar:?] at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.invoke(RpcClient.java:82) ~[HMIPServer.jar:?] at com.sun.proxy.$Proxy39.event(Unknown Source) ~[?:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker.handleEvent(RegaClientWorker.java:73) ~[HMIPServer.jar:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker.access$000(RegaClientWorker.java:13) ~[HMIPServer.jar:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker$1.handle(RegaClientWorker.java:35) ~[HMIPServer.jar:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker$1.handle(RegaClientWorker.java:26) ~[HMIPServer.jar:?] at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100) ~[HMIPServer.jar:?] at io.vertx.core.impl.WorkerContext.lambda$emit$0(WorkerContext.java:59) ~[HMIPServer.jar:?] at io.vertx.core.impl.WorkerContext.lambda$execute$2(WorkerContext.java:104) ~[HMIPServer.jar:?] at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76) ~[HMIPServer.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_202] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_202] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_202] Caused by: java.net.ConnectException: Connection refused (Connection refused) at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_202] at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_202] at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_202] at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_202] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_202] at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_202] at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:120) ~[HMIPServer.jar:?] at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:179) ~[HMIPServer.jar:?] at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:144) ~[HMIPServer.jar:?] at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:134) ~[HMIPServer.jar:?] at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:612) ~[HMIPServer.jar:?] at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:447) ~[HMIPServer.jar:?] at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:884) ~[HMIPServer.jar:?] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[HMIPServer.jar:?] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) ~[HMIPServer.jar:?] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) ~[HMIPServer.jar:?] at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:106) ~[HMIPServer.jar:?] ... 15 more 2022-09-20 01:14:38,191 io.vertx.core.impl.ContextImpl ERROR [vert.x-worker-thread-3] Unhandled exception 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:110) ~[HMIPServer.jar:?] at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.sendRequest(RpcClient.java:94) ~[HMIPServer.jar:?] at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.invoke(RpcClient.java:82) ~[HMIPServer.jar:?] at com.sun.proxy.$Proxy39.event(Unknown Source) ~[?:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker.handleEvent(RegaClientWorker.java:73) ~[HMIPServer.jar:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker.access$000(RegaClientWorker.java:13) ~[HMIPServer.jar:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker$1.handle(RegaClientWorker.java:35) ~[HMIPServer.jar:?] at de.eq3.ccu.virtualdevice.service.internal.rega.vertx.RegaClientWorker$1.handle(RegaClientWorker.java:26) ~[HMIPServer.jar:?] at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100) ~[HMIPServer.jar:?] at io.vertx.core.impl.WorkerContext.lambda$emit$0(WorkerContext.java:59) ~[HMIPServer.jar:?] at io.vertx.core.impl.WorkerContext.lambda$execute$2(WorkerContext.java:104) ~[HMIPServer.jar:?] at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76) ~[HMIPServer.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_202] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_202] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?] at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_202] Caused by: java.net.ConnectException: Connection refused (Connection refused) at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_202] at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_202] at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_202] at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_202] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_202] at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_202] at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:120) ~[HMIPServer.jar:?] at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:179) ~[HMIPServer.jar:?] at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:144) ~[HMIPServer.jar:?] at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:134) ~[HMIPServer.jar:?] at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:612) ~[HMIPServer.jar:?] at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:447) ~[HMIPServer.jar:?] at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:884) ~[HMIPServer.jar:?] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[HMIPServer.jar:?] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) ~[HMIPServer.jar:?] at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) ~[HMIPServer.jar:?] at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:106) ~[HMIPServer.jar:?] ... 15 more

In parallel if have opened a ticket at homematic.

MarkusKress avatar Sep 14 '22 07:09 MarkusKress

Think i have the same problem.

Shortly after starting rpc you cannot log into the Homematic Gui. Also a stop of iobroker is not enough. The Homematic must be rebooted again. The failure is 100% reproducible.

Use iobroker-docker from docs.buanet.de And Raspberrymatic 3.67.10.20230225

So at the moment iobroker is not usable.

ecsgh avatar Mar 29 '23 11:03 ecsgh

Now i use Raspberrymati 3.69.6.20230407

In 3 hours i have in WebUI: 8 times WatchDog: rfd-restart.

When i stop rpc no more errors. Working is possible after restarting the CCU or waiting for a long time.

What is the reason? What is the solution?

ecsgh avatar Apr 29 '23 13:04 ecsgh

Port 2001 with virtual devices sounds strange to me. Are you sure that you are running a correct configuration?

foxriver76 avatar May 05 '23 09:05 foxriver76

Actually, it is. After the last update of the Raspberrymati to just 3.69.6.20230407, I went through my settings again. These I have then reset to the old values that were logical for me. Now the error no longer occurs. See, very funny. Decisive are possibly the following:

HomeMatic address: This is the actual hardware address of the ccu

Adapter address: This is the address of the iobroker docker container.

Adapter Callback Address: This is the server address on which docker itself is running

I changed the adapter callback address in the meantime for testing. But after I changed everything back to the above addresses, it works now since a few days. If I don't write anything next week, I think you can close this entry.

ecsgh avatar May 05 '23 10:05 ecsgh