[closed] Homematic - Entity State not updating

Hi,
it seems my Home Assistant instance discovers the Homematic HmIP entities, but doesn’t update them properly. The updates happen only after restarting the server. I run HASS via Docker (I append my docker-compose.yml in case it’s important for troubleshooting) and it’s accessible via port 8123 in my local network. Both, the Homematic Box and the Docker Host are in the same subnet.

I assume the issue is my HASS configuration, for those reasons:

  • Homematic updates the state accordingly in the interface
  • I migrate from openHab to home-assistant: it works on OpenHab (Docker container on the same host)
  • I get the following error message on HASS startup:
Logger: pyhomematic._hm
Source: /usr/local/lib/python3.8/site-packages/pyhomematic/_hm.py:681
First occurred: 2:50:52 PM (1 occurrences)
Last logged: 2:50:52 PM

Skipping init for homeassistant-ccu3

My HASS config:

# Homematic Configuration
homematic:
  interfaces:
    ip:
      host: 192.168.1.11
      port: 2010
      callback_ip: 192.168.1.2
      username: "Admin"
      password: !secret ccu_password
      #callback_port: 8123
    groups:
      host: 192.168.1.11
      port: 9292
      resolvenames: "json"
      username: "Admin"
      password: !secret ccu_password
      path: /groups
  hosts:
    ccu3:
      host: 192.168.1.11
      port: 2001
      username: "Admin"
      password: !secret ccu_password

I use callback_ip because the documentation suggests that for Docker instances. I gave full access to my Homematic box temporarily to avoid issues on that end. I’m a bit lost here, hope somebody can help me here =)

Appendix

docker-compose.yml:

version: '3'
services:
  homeassistant:
    container_name: ${SERVICE_NAME}
    image: homeassistant/home-assistant:stable
    volumes:
      - ${ROOT_DIR}/config:/config
      - /etc/localtime:/etc/localtime:ro
    restart: unless-stopped
    #network_mode: host
    ports:
      - 8123:8123
    networks:
      - reverse-proxy
    labels:
      # Reverse proxy and certificate
      - "traefik.enable=true"
      - "traefik.docker.network=reverse-proxy"
      # Website Configuration
      - "traefik.http.routers.${SERVICE_NAME}.rule=Host(`${URL}`)"
      - "traefik.http.routers.${SERVICE_NAME}.tls.certresolver=myresolver"
      - "traefik.http.routers.${SERVICE_NAME}.entrypoints=websecure"
      - "traefik.http.routers.${SERVICE_NAME}.service=${SERVICE_NAME}"
      - "traefik.http.routers.${SERVICE_NAME}.tls=true"
      - "traefik.http.services.${SERVICE_NAME}.loadBalancer.server.port=8123"
      - "traefik.http.services.${SERVICE_NAME}.loadBalancer.passHostHeader=true"
      # Middleware Configuration
      - "traefik.http.routers.${SERVICE_NAME}.middlewares=${SERVICE_NAME}-mw"
      - "traefik.http.middlewares.${SERVICE_NAME}-mw.headers.customResponseHeaders.X-Robots-Tag=noindex,nofollow,nosnippet,noarchive,notranslate,noimageindex"

networks:
  reverse-proxy:
    external: true

It seems there is some sort of communication. I get the following log every 30 seconds:

2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] ServerThread.getAllSystemVariables: Getting all System variables via JSON-RPC
2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] RPCFunctions.jsonRpcPost: Method: Session.login
2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] RPCFunctions.jsonRpcPost: API-Endpoint: http://192.168.1.11:80/api/homematic.cgi
2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] RPCFunctions.jsonRpcPost: Method: SysVar.getAll
2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] RPCFunctions.jsonRpcPost: API-Endpoint: http://192.168.1.11:80/api/homematic.cgi
2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] RPCFunctions.jsonRpcPost: Method: Session.logout
2021-04-16 20:23:30 DEBUG (SyncWorker_2) [pyhomematic._hm] RPCFunctions.jsonRpcPost: API-Endpoint: http://192.168.1.11:80/api/homematic.cgi

However, the state does not update.

Edit 1:

In addition to that, I found a weird log while restarting the server:

2021-04-16 20:34:37 INFO (SyncWorker_2) [pyhomematic._hm] Proxy for homeassistant-hm_ip initialized
2021-04-16 20:34:37 DEBUG (SyncWorker_2) [pyhomematic._hm] ServerThread.proxyInit: init('http://172.24.0.5:46557', 'homeassistant-groups')

That seems to be the Docker container IP address and not the hosts one.

Edit 2:
According to this thread, I checked CCUs logs in /var/log/hmserver.log and it seems I get a timeout:

Apr 16 20:46:40 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer ERROR [vert.x-worker-thread-4] IO Exception: Could
 not add interface: homeassistant-hm_ip
de.eq3.cbcs.legacy.communication.rpc.RpcIOException: java.net.ConnectException: Connection timed out (Connection timed out)
	at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:110)
	at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.sendRequest(RpcClient.java:94)
	at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.invoke(RpcClient.java:82)
	at com.sun.proxy.$Proxy21.listDevices(Unknown Source)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient.listDevices(LegacyBackendClient.java:139)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.DeviceUtil.synchronizedBackendDevices(DeviceUtil.java:148)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer.handle(InterfaceInitializer.java:109)
	at de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer.handle(InterfaceInitializer.java:26)
	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 timed out (Connection timed out)
	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:106)
	... 15 more
Apr 16 20:49:47 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-6] SYSTEM: 0 Acces
spoints in Queue
Apr 16 20:49:47 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-6] SYSTEM: Permane
nt-/Burstlistener Handler utilization: 0/50 used
Apr 16 20:49:47 de.eq3.cbcs.server.core.otau.DeviceBackgroundUpdateSubsystem INFO  [vert.x-eventloop-thread-6] SYSTEM: Eventli
stener Handler utilization: 0/50 used

However, I have the latest firmware installed.

It seems I found the culprit, but I still need help to get it fixed.

Since I use a Docker network instead of network_mode: host, the Proxy init gets the container IP and a random port. I can change the random port to a static one with local_port and open that for the docker network. However, I struggle to set the local_ip to my docker host, since I get an error message.

Since I want to expose my instance via URL, and I use traefik as a reverse proxy, I can’t use the network_mode: host option.

Is there any possibility to force ServerThread.proxyInit: init('http://172.24.0.5:46557', 'homeassistant-groups') to my Docker hosts IP?

Well, it was easier than expected. I needed to add the same callback_port to ip and groups and everything works fine. So, in case somebody runs in the same issue as me here is my HASS config:

# Homematic Configuration
homematic:
  local_port: 8124
  interfaces:
    hm_ip:
      host: 192.168.1.11
      port: 2010
      username: "Admin"
      password: !secret ccu_password
      callback_ip: 192.168.1.2
      callback_port: 8124
    hm_groups:
      host: 192.168.1.11
      port: 9292
      callback_ip: 192.168.1.2
      callback_port: 8124
      resolvenames: "json"
      username: "Admin"
      password: !secret ccu_password
      path: /groups
  hosts:
    ccu3:
      host: 192.168.1.11
      port: 2010
      username: "Admin"
      password: !secret ccu_password

For the sake of completion, here is my docker-compose file:

version: '3'
services:
  homeassistant:
    container_name: ${SERVICE_NAME}
    image: homeassistant/home-assistant:stable
    volumes:
      - ${ROOT_DIR}/config:/config
      - /etc/localtime:/etc/localtime:ro
    restart: unless-stopped
    #network_mode: host
    ports:
      - 8123:8123
      - 8124:8124
    networks:
      - reverse-proxy
    labels:
      # Reverse proxy and certificate
      - "traefik.enable=true"
      - "traefik.docker.network=reverse-proxy"
      # Website Configuration
      - "traefik.http.routers.${SERVICE_NAME}.rule=Host(`${URL}`)"
      - "traefik.http.routers.${SERVICE_NAME}.tls.certresolver=myresolver"
      - "traefik.http.routers.${SERVICE_NAME}.entrypoints=websecure"
      - "traefik.http.routers.${SERVICE_NAME}.service=${SERVICE_NAME}"
      - "traefik.http.routers.${SERVICE_NAME}.tls=true"
      - "traefik.http.services.${SERVICE_NAME}.loadBalancer.server.port=8123"
      - "traefik.http.services.${SERVICE_NAME}.loadBalancer.passHostHeader=true"
      # Middleware Configuration
      - "traefik.http.routers.${SERVICE_NAME}.middlewares=${SERVICE_NAME}-mw"
      - "traefik.http.middlewares.${SERVICE_NAME}-mw.headers.customResponseHeaders.X-Robots-Tag=noindex,nofollow,nosnippet,noarchive,notranslate,noimageindex"

networks:
  reverse-proxy:
    external: true