treban / pimatic-tradfri

This plugin provides a tradfri interface for pimatic.
https://pimatic.org/plugins/pimatic-tradfri/
GNU General Public License v2.0
11 stars 3 forks source link

When connection to gateway is lost it never is able to reconnect #8

Closed sverrevh closed 7 years ago

sverrevh commented 7 years ago

error [pimatic-tradfri]: Tradfri gateway is not reachable anymore!

After this it is never able to reconnect to the hub, unless the hub is power-cycled. Could be some stability issue with the gateway, or something else. Had it happening when I was setting a lot of dim and color changes every 1 minute, but also at 1pm when the hub was idle.

treban commented 7 years ago

It's difficult to say what the problem is. Please check if the tradfri app also couldn't connect to the gateway at this time. And if the tradfri app works please only restart pimatic, to see if the plugin then works correctly. I have rarely a connection lost, but always a successful reconnect.

sverrevh commented 7 years ago

I discovered something interesting. I started monitoring the behaviour of the gateway with pimatic and noticed that the hub went offline exactly 48h after it was turned on. I turned it off and on again at 11:13PM on July 14, and just now at 11:13PM it went offline. After a power cycle it is back online again. The hub keeps responding to ping requests when it is offline in pimatic. Didn't have a chance yet to test with tradfri app.

sverrevh commented 7 years ago

Did a full reset of all bulbs, remote and bridge. Still happens... Gonna disable the automatic power cycle rule I made in pimatic, to check if the app still works after it goes offline in pimatic.

This is a (curated) part of my pimatic-daemon.log file: pimatic-daemon.txt

sverrevh commented 7 years ago

confirmed that bridge is also not reachable via app after 24h edit: it came back up by itself. Not sure what is happening...

16:30:20.135 [pimatic-tradfri] error: Tradfri gateway is not reachable anymore! [...] 16:44:31.559 [pimatic-tradfri] debug: Gateway online - Firmware: 1.1.0015

Log shows that pimatic-tradfri is trying to connect for 10 seconds, if that fails it immediately tries again to connect. Maybe slow that down a bit?

16:43:21.419 [pimatic-tradfri] debug: Try to connect to Tradfri
16:43:31.432 [pimatic-tradfri] debug: ...connection error!
CLEANUP
16:43:31.436 [pimatic-tradfri] debug: Try to connect to Tradfri
16:43:41.445 [pimatic-tradfri] debug: ...connection error!
CLEANUP
16:43:41.450 [pimatic-tradfri] debug: Try to connect to Tradfri
16:43:51.462 [pimatic-tradfri] debug: ...connection error!
CLEANUP
16:43:51.466 [pimatic-tradfri] debug: Try to connect to Tradfri

Edit2:

Aug 13 17:15:07 OpenWrt daemon.info dnsmasq[1166]: query[A] pool.ntp.org from 192.168.1.125
Aug 13 17:15:07 OpenWrt daemon.info dnsmasq[1166]: forwarded pool.ntp.org to 208.67.222.222
Aug 13 17:15:07 OpenWrt daemon.info dnsmasq[1166]: reply pool.ntp.org is 88.159.1.196
Aug 13 17:15:07 OpenWrt daemon.info dnsmasq[1166]: reply pool.ntp.org is 5.79.108.34
Aug 13 17:15:07 OpenWrt daemon.info dnsmasq[1166]: reply pool.ntp.org is 85.144.98.149
Aug 13 17:15:07 OpenWrt daemon.info dnsmasq[1166]: reply pool.ntp.org is 88.159.1.197
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: query[A] fw.ota.homesmart.ikea.net from 192.168.1.125
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: forwarded fw.ota.homesmart.ikea.net to 208.67.222.222
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.33
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.248
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.74
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.28
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.101
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.125
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.253
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: reply d262cmbxmzphsu.cloudfront.net is 54.192.93.139
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: query[A] TradfriGateway.lan from 192.168.1.201
Aug 13 17:15:09 OpenWrt daemon.info dnsmasq[1166]: DHCP TradfriGateway.lan is 192.168.1.125
Aug 13 17:15:12 OpenWrt daemon.info dnsmasq[1166]: query[A] pool.ntp.org from 192.168.1.125
Aug 13 17:15:12 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 88.159.1.197
Aug 13 17:15:12 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 85.144.98.149
Aug 13 17:15:12 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 5.79.108.34
Aug 13 17:15:12 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 88.159.1.196
Aug 13 17:15:17 OpenWrt daemon.info dnsmasq[1166]: query[A] pool.ntp.org from 192.168.1.125
Aug 13 17:15:17 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 88.159.1.196
Aug 13 17:15:17 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 88.159.1.197
Aug 13 17:15:17 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 85.144.98.149
Aug 13 17:15:17 OpenWrt daemon.info dnsmasq[1166]: cached pool.ntp.org is 5.79.108.34

These are the requests it makes right before it crashes. Don't think it has anything to do with your pimatic implementation @treban. It's weird because it makes the same requests when booting, without crashing.

treban commented 7 years ago

You problem is really special. I am suffering with you. Stability problems are difficult to troubleshoot Maybe change the power supply. But the cyclic problem contradict it. There is a firmware update from Ikea for the tradfri system coming soon. i hope for the gateway also.

But I will implement your hint with the not so aggressiv reconnect.