Happened again today, and this time I actually found something in the logs:
2021-01-30 11:19:12.349 [WARN ] [ommunicator.AbstractHomematicGateway] - Connection lost on gateway ‘KEQ0384588’, cause: “IOException java.util.concurrent.TimeoutException: Total timeout 15000 ms elapsed”
2021-01-30 11:20:07.378 [INFO ] [ommunicator.AbstractHomematicGateway] - Connection resumed on gateway ‘KEQ0384588’
This is right around the time the sensors didn’t get any updates anymore, you can see the flatline at shortly after 11:00:
You wrote there’s a known problem after a re-connect. Do you have any more detailed info about that?
Is there a workaround to detect this reconnects and restart the binding? The problem is solved if I disable the homematic binding in the karaf console and activate it again.
Guess a higher timeout would help already, but that’s not a definitive solution.
I have enhanced the automatic reconnect. You can get a test version here GitHub - MHerbst/openhab-addons-test You can use it with OH version 3.0 and above.
Perfect, your test version works correctly for me. I disconnected the CCU2 until I got the message in the logs, then reconnected it. Now after 12 hours I checked all HmIP sensors that failed in the past, and the all send updates.
Can you create a PR to have this included in the next official release?
Thanks a lot for your work!
Bindings that are only stored in the addons folder are not visible in the list.
You can check whether it is working in the Karaf Console. Run bundle:list | grep Homematic to get the binding’s state. If it shows “active” then everything is fine. If the state is “installed”, you can try to start it with bundle:start <number>. You will see an error message if it can’t be started.
BTW: the test version of the binding requires a snapshot version. It won’t run on 3.0.1.
same issue here with Homematic IP Device HmIP-eTRV-C-2 and Openhab 3.2.0 (build: 2473) and Homematic Binding 3.2.0-SNAPSHOT.
In the openhab log i see no errors, but success changed state from CCU. Current round about 24° Degrees. But, Openhab shows always 22.1° Degrees since more than 2 Days. I will not do a restart now. Possible we can debug the current state… ? It is not a duty cycle issue. DC at 2-3%
2021-10-11 16:15:21.064 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 25 °C to 25.5 °C
2021-10-11 16:15:52.410 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 26
2021-10-11 16:15:52.411 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 26
2021-10-11 16:15:52.419 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 25.5 °C to 26 °C
2021-10-11 16:15:54.039 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 25.5
2021-10-11 16:15:54.042 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 25.5
2021-10-11 16:15:54.051 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 26 °C to 25.5 °C
2021-10-11 16:15:55.332 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 25
2021-10-11 16:15:55.334 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 25
2021-10-11 16:15:55.342 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 25.5 °C to 25 °C
2021-10-11 16:15:59.205 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 24.5
2021-10-11 16:15:59.207 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 24.5
2021-10-11 16:15:59.215 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 25 °C to 24.5 °C
2021-10-11 16:16:00.494 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 24
2021-10-11 16:16:00.548 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 24
2021-10-11 16:16:00.551 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 24.5 °C to 24 °C
2021-10-12 11:30:31.778 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 24.5
2021-10-12 11:30:31.782 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 24.5
2021-10-12 11:30:31.790 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 24 °C to 24.5 °C
2021-10-12 11:30:33.246 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 25
2021-10-12 11:30:33.248 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 25
2021-10-12 11:30:33.255 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 24.5 °C to 25 °C
2021-10-12 15:55:19.570 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 24.5
2021-10-12 15:55:19.574 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 24.5
2021-10-12 15:55:19.583 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 25 °C to 24.5 °C
2021-10-12 15:55:20.490 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' received command 24
2021-10-12 15:55:20.491 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' predicted to become 24
2021-10-12 15:55:20.499 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HmIPeTRVC2***geheim***_SetPointTemperature' changed from 24.5 °C to 24 °C
Do you know whether the connection between OH and the CCU was interrupted? In this case there is a general problem with HmIP devices. I have created a test version of the binding where I try to fix this problem. See my post from Jan 30 here in this thread.
What kind of CCU do you have? For a CCU2 the fix is probably not sufficient, becaut it nees longer until all HmIP devices are online again.
@MHerbst
I have the same problem. I’m using Raspberrymatic in a Docker container and since some versions there is a monitoring of the various services. When monitoring decides to restart a service, no more events arrive in openHab. In my case, the HMIPServer get’s restarted sometimes per day and the connection is lost.
So we need to modify the connection tracker so that it not only tests the client, but also whether the server receives events. The best way i think is to send a ping and check if a pong is received. If there is no pong event, the RPC server must be restarted. I had already implemented this for the RF interface, but you removed it in January
I think we need the ping/pong for the RF and the HMIP interface. I am very busy, so I would like to ask you if you can implement these checks.
@gerrieg
I think the current way of detecting a lost connection is sufficent. The re-connect for the RF interface is OK and worked during my tests perfectly.
The big problem is the re-connect for the HmIP interface. It can take quite a while until this process is available and ready to register a callback. In the release version the add-on tried to register the callback for HmIP too early.
Therefore I have already modified the (re)connect handling.
I have already implemented a test version of the binding with a retry for the event registration. I have not created a PR for it yet, because I wanted to get more test results.
I also have to make the retry mechanism more flexible, because a CCU2 needs much longer than a CCU3 until the HmIP process is completely restarted.
Would be great if you could test it in your environement (it needs at least the latest 3.2 milestone version).
If the solution is not sufficient, I would (re)add a ping/pong mechanism.
I would like to give feedback:
I tried the upper patch within OH 3.1.0 as an addon after uninstalling the originally homatic binding.
After a while the bridge was initializing but still none of the homatic things/items receives updates.
But still e.g. changes on switches are still sent correctly to homematic.
Are the switches “old” HM devices or HmIP? The problem only occurs with HmIP.
Is it a CCU3 or CCU2? The CCU2 probably needs more retries. Therefore I will make it configurable.
Maybe you can enable DEBUG log mode, try again what happens and attach the log file. It would be interesting to see if the maximum number of retries is reached.
I have uploaded a new test version (https://github.com/MHerbst/openhab-addons-test). You can now configure the number of retries and the wait time as advanced options in the Bridge configuration.
I replied to [openHAB] [Add-ons/Bindings] Debugging Homematic IP: no updates on some HmIP devices after some time from [openHAB] [Add-ons/Bindings] Debugging Homematic IP: no updates on some HmIP devices after some time.
