search

smarthomej / addons

SmartHome/J addons for openHAB
Eclipse Public License 2.0
62 stars 26 forks source link

[tuya] Reconnect issues #535

Closed Novanic closed 10 months ago

Novanic commented 12 months ago

The tuya binding has a reconnect issue. I saw a few times that my light thing (Generic Tuya Device) is offline which is really annoying when the light isn't working (and when it's dark...).

In these cases I can disable the offline displayed thing and enable it again directly. The thing gets back online and is working nornally. Therefore the binding isn't able to reconnect automatically. That should get fixed.

Today my internet router got a firmware update which caused that the internet connection was temporarily lost. Everything came back online again automatically but not the tuya binding. Maybe this is a scenario to reproduce the issue (just disconnect the internet router for a few minutes).

I'm using OpenHAB 4.0.4.

J-N-K commented 11 months ago

Do the devices get a new IP after rebooting the router?

Novanic commented 11 months ago

No. The devices get the same IP address by the router.

I had such problems with the livisismarthome binding too. Meanwhile there is a scheduled task within the binding which tries to reconnect every X minutes/seconds. Maybe such a task is missing within the tuya binding or it has a limit / timeout or is just not handling all exception types?

jsetton commented 11 months ago

I had a similar issue where the binding kept failing to reconnect with connection time out. After some investigation, it ended to be that the relevant device wasn't accessible, while still being pingable, after my Internet connection went down for a few seconds. I was able to confirm that the device was also not accessible through the Tuya Smart app. Rebooting the device fixed my issue.

As far as the reconnect logic, my logs show that the binding is trying to reconnect every 6-7 seconds.

Novanic commented 11 months ago

I had the same problem today again, again after a firmware update / reboot of the router. Hours after the update / reboot, I noticed that the tuya device isn't working anymore...

In the log file occurs this message when I try ro switch on the device: 2023-12-22 19:39:35.564 [WARN ] [a.internal.handler.TuyaDeviceHandler] - Channel 'tuya:tuyaDevice:xxx:bright_value' received a command but device is not ONLINE. Discarding command.

There are no reconnect attempt logs. Maybe the reconnect attempts are stopping after some time or the reconnect attempts aren't starting (maybe it's depending on the error which occurs). I disabled the device in Main UI and enabled it immediatelly after that again, and it gone online again. Therefore the actual error isn't existing anymore, but the tuya binding doesn't recognizes that automatically, it isn't reconnecting automatically...

Novanic commented 10 months ago

@J-N-K It happens again, and again, and again... It is sufficient to just disconnect the internet router for about 10 minutes and reconnect it again to reproduce this issue. I think the binding gets a timeout somewhere and the reconnect logic can't handle that correctly.

I would try to debug that to help, but I can't get the binding installed on my Windows machine (where I could debug it locally). When I build the binding with Maven and putting the Jar "org.smarthomej.binding.tuya-4.1.1-SNAPSHOT.jar" into the addons folder, OpenHAB can't start with that binding. There appear OSGi errors regarding the netty library...: Error starting bundle 244: Could not resolve module: org.smarthomej.binding.tuya [244] Unresolved requirement: Import-Package: io.netty.bootstrap; version="[4.1.0,5.0.0)"

I tried to put about 6 netty jars into the addons folder too, but there appear more and more OSGi errors. I gave up with that... How can a local built version of the jar get installed (without the kar-file / addons.json which I don't have locally)?

Novanic commented 10 months ago

Ah, I found out that a simple, fast reboot of the internet router isn't sufficient to reproduce the problem. But when I disconnect the router for about 10 minutes and reconnect it again after that, reproduces the issue. The tuya thing stays offline forever in that case. When I disable it in Main UI and enable it directly after that, the status switches to online again.

I have now attached a log file of this test case. I disconnected the router (that are the first messages of the log file) and reconnected it at about 16:49 o'clock. At about 16:54 o'clock I disabled and enabled the thing manually via Main UI.

tuya-log.txt

J-N-K commented 10 months ago

You can feature:install openhab.tp-netty that should fix the missing dependencies.

J-N-K commented 10 months ago

Is it always exactly 20 times that the device tries to re-connect and then stops?

Novanic commented 10 months ago

No, this time it was 10 times. Internet router disconnected at 12:10, internet router reconnected at 12:27 (tuya thing stays offline), manually deactived and re-activated via Main UI at 12:35 o'clock (the tuya thing switches to online). tuya-log-2.txt

J-N-K commented 10 months ago 
12:21:24.088 | WARN  | ioEventLoopGroup-8-3 | rnal.local.handlers.HeartbeatHandler | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Missed more than 3 heartbeat responses. Connection seems to be dead.
12:21:24.096 | DEBUG | ioEventLoopGroup-8-3 | al.local.handlers.TuyaMessageHandler | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Connection terminated.
12:21:24.097 | INFO  | OH-eventexecutor-1-1 | ab.event.ThingStatusInfoChangedEvent | 178 | Thing 'tuya:tuyaDevice:bfd472948d99f6de52cafu' changed from ONLINE to OFFLINE
12:21:24.098 | DEBUG | ioEventLoopGroup-8-3 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:29.106 | DEBUG | ioEventLoopGroup-8-4 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:29.108 | DEBUG | ioEventLoopGroup-8-4 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:34.111 | DEBUG | ioEventLoopGroup-8-5 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:34.112 | DEBUG | ioEventLoopGroup-8-5 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:39.120 | DEBUG | ioEventLoopGroup-8-6 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:39.121 | DEBUG | ioEventLoopGroup-8-6 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:44.127 | DEBUG | ioEventLoopGroup-8-7 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:44.130 | DEBUG | ioEventLoopGroup-8-7 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:49.138 | DEBUG | ioEventLoopGroup-8-8 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:49.139 | DEBUG | ioEventLoopGroup-8-8 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:54.148 | DEBUG | ioEventLoopGroup-8-9 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:54.150 | DEBUG | ioEventLoopGroup-8-9 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:21:59.157 | DEBUG | oEventLoopGroup-8-10 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:21:59.158 | DEBUG | oEventLoopGroup-8-10 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:04.165 | DEBUG | oEventLoopGroup-8-11 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:04.166 | DEBUG | oEventLoopGroup-8-11 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:09.175 | DEBUG | oEventLoopGroup-8-12 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:09.177 | DEBUG | oEventLoopGroup-8-12 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:14.180 | DEBUG | oEventLoopGroup-8-13 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:14.181 | DEBUG | oEventLoopGroup-8-13 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:19.184 | DEBUG | oEventLoopGroup-8-14 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:19.185 | DEBUG | oEventLoopGroup-8-14 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:29.153 | DEBUG | oEventLoopGroup-8-15 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:33.162 | DEBUG | oEventLoopGroup-8-15 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:41.380 | DEBUG | oEventLoopGroup-8-16 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:41.381 | DEBUG | oEventLoopGroup-8-16 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:52.638 | DEBUG | ioEventLoopGroup-8-1 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:52.642 | DEBUG | ioEventLoopGroup-8-1 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:22:59.233 | DEBUG | ioEventLoopGroup-8-2 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:22:59.234 | DEBUG | ioEventLoopGroup-8-2 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:05.528 | DEBUG | ioEventLoopGroup-8-3 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:05.530 | DEBUG | ioEventLoopGroup-8-3 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:12.114 | DEBUG | ioEventLoopGroup-8-4 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:12.117 | DEBUG | ioEventLoopGroup-8-4 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:19.291 | DEBUG | ioEventLoopGroup-8-5 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:19.292 | DEBUG | ioEventLoopGroup-8-5 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:26.614 | DEBUG | ioEventLoopGroup-8-6 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:26.619 | DEBUG | ioEventLoopGroup-8-6 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:33.573 | DEBUG | ioEventLoopGroup-8-7 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:33.574 | DEBUG | ioEventLoopGroup-8-7 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:45.969 | DEBUG | ioEventLoopGroup-8-8 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:45.970 | DEBUG | ioEventLoopGroup-8-8 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:23:52.825 | DEBUG | ioEventLoopGroup-8-9 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:23:52.827 | DEBUG | ioEventLoopGroup-8-9 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:00.324 | DEBUG | oEventLoopGroup-8-10 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:00.325 | DEBUG | oEventLoopGroup-8-10 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:07.765 | DEBUG | oEventLoopGroup-8-11 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:07.767 | DEBUG | oEventLoopGroup-8-11 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:14.815 | DEBUG | oEventLoopGroup-8-12 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:14.816 | DEBUG | oEventLoopGroup-8-12 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:22.061 | DEBUG | oEventLoopGroup-8-13 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:22.066 | DEBUG | oEventLoopGroup-8-13 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:27.072 | DEBUG | oEventLoopGroup-8-14 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:27.073 | DEBUG | oEventLoopGroup-8-14 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:32.080 | DEBUG | oEventLoopGroup-8-15 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:32.081 | DEBUG | oEventLoopGroup-8-15 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:37.084 | DEBUG | oEventLoopGroup-8-16 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:37.086 | DEBUG | oEventLoopGroup-8-16 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:42.092 | DEBUG | ioEventLoopGroup-8-1 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:42.093 | DEBUG | ioEventLoopGroup-8-1 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:47.097 | DEBUG | ioEventLoopGroup-8-2 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:47.099 | DEBUG | ioEventLoopGroup-8-2 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:52.105 | DEBUG | ioEventLoopGroup-8-3 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:52.106 | DEBUG | ioEventLoopGroup-8-3 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:24:57.113 | DEBUG | ioEventLoopGroup-8-4 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:24:57.115 | DEBUG | ioEventLoopGroup-8-4 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:02.119 | DEBUG | ioEventLoopGroup-8-5 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:02.121 | DEBUG | ioEventLoopGroup-8-5 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:07.124 | DEBUG | ioEventLoopGroup-8-6 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:07.127 | DEBUG | ioEventLoopGroup-8-6 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:12.130 | DEBUG | ioEventLoopGroup-8-7 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:12.132 | DEBUG | ioEventLoopGroup-8-7 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:17.138 | DEBUG | ioEventLoopGroup-8-8 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:17.140 | DEBUG | ioEventLoopGroup-8-8 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:22.143 | DEBUG | ioEventLoopGroup-8-9 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:22.145 | DEBUG | ioEventLoopGroup-8-9 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:27.151 | DEBUG | oEventLoopGroup-8-10 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:27.153 | DEBUG | oEventLoopGroup-8-10 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:32.158 | DEBUG | oEventLoopGroup-8-11 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:32.161 | DEBUG | oEventLoopGroup-8-11 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:37.164 | DEBUG | oEventLoopGroup-8-12 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:37.166 | DEBUG | oEventLoopGroup-8-12 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:42.169 | DEBUG | oEventLoopGroup-8-13 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:42.170 | DEBUG | oEventLoopGroup-8-13 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:47.174 | DEBUG | oEventLoopGroup-8-14 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:47.176 | DEBUG | oEventLoopGroup-8-14 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:52.181 | DEBUG | oEventLoopGroup-8-15 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:52.182 | DEBUG | oEventLoopGroup-8-15 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:25:57.190 | DEBUG | oEventLoopGroup-8-16 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:25:57.193 | DEBUG | oEventLoopGroup-8-16 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:02.196 | DEBUG | ioEventLoopGroup-8-1 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:02.198 | DEBUG | ioEventLoopGroup-8-1 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:07.201 | DEBUG | ioEventLoopGroup-8-2 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:07.202 | DEBUG | ioEventLoopGroup-8-2 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:12.208 | DEBUG | ioEventLoopGroup-8-3 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:12.210 | DEBUG | ioEventLoopGroup-8-3 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:17.217 | DEBUG | ioEventLoopGroup-8-4 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:17.219 | DEBUG | ioEventLoopGroup-8-4 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:22.220 | DEBUG | ioEventLoopGroup-8-5 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:22.222 | DEBUG | ioEventLoopGroup-8-5 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:27.224 | DEBUG | ioEventLoopGroup-8-6 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:27.225 | DEBUG | ioEventLoopGroup-8-6 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:32.231 | DEBUG | ioEventLoopGroup-8-7 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:32.235 | DEBUG | ioEventLoopGroup-8-7 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:37.238 | DEBUG | ioEventLoopGroup-8-8 | nding.tuya.internal.local.TuyaDevice | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Failed to connect: Network is unreachable: /192.168.0.34:6668
12:26:37.240 | DEBUG | ioEventLoopGroup-8-8 | a.internal.handler.TuyaDeviceHandler | 274 | [tuya:ir-controller] stop ir learning
12:26:42.337 | DEBUG | ioEventLoopGroup-8-9 | .internal.local.handlers.TuyaEncoder | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Sending payload 6CC1F8A27727F448BD09A60A3BD57388
12:26:42.340 | TRACE | ioEventLoopGroup-8-9 | .internal.local.handlers.TuyaEncoder | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Sending encoded '000055AA000000010000000300000044F17CC40D4C5A7AFE26B70AC4C89CFCCA089886E4AD65C26C25EFC1781479135084E465D16BA6BA8891CEFCDC1BB6310ECD56E41397CA6936E16BAEEF576BC8650000AA55'
12:26:42.342 | DEBUG | ioEventLoopGroup-8-9 | al.local.handlers.TuyaMessageHandler | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Connection established.
12:26:42.342 | INFO  | OH-eventexecutor-1-1 | ab.event.ThingStatusInfoChangedEvent | 178 | Thing 'tuya:tuyaDevice:bfd472948d99f6de52cafu' changed from OFFLINE to ONLINE
12:26:42.353 | TRACE | ioEventLoopGroup-8-9 | .internal.local.handlers.TuyaDecoder | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Received encoded '000055AA0000C8F20000000400000068000000003A4ADB6EB41602892BCF338C6963EB5153948FB9DB20B2B7343A6BB5C94A0A84C941245315B4E6DEB2790ED1FBEDEC00089886E4AD65C26C25EFC17814791350CA1A55A11075BA1050198A60A1C0E8F9F092FCAB2C77FC9268AC36F904A5672C0000AA55'
12:26:42.365 | TRACE | ioEventLoopGroup-8-9 | .internal.local.handlers.TuyaDecoder | 274 | bfd472948d99f6de52cafu/192.168.0.34:6668: Decoded raw payload: 6238613739616266613630373662393724E250EAF2DAF5C41B6F2E96BB1F3F8F3F7DD748E03313836B31E3F4079D4292

It seems to work fine for me, I disabled the WiFi on my system. The timestamps at the beginning are a bit misleading, because I had a breakpoint in the debugger, so the attempts would have been faster.

Which other add-ons do you use?

Novanic commented 10 months ago

I could reproduce it with my Raspberry Pi (connected via LAN with the internet router) and not with my OpenHAB installation on a Windows machine (connected via WLAN). Maybe that makes a difference?

I have now added additional log messages within the binding and it seems that the reconnectFuture got another state which stops the reconnect attempts (the reconnectFuture is not NULL and is not done).

Log: ... 2024-01-28 12:47:18.221 [DEBUG] [a.internal.handler.TuyaDeviceHandler] - Starting reconnect attempt ... 2024-01-28 12:47:18.221 [DEBUG] [a.internal.handler.TuyaDeviceHandler] - [tuya:ir-controller] stop ir learning 2024-01-28 12:47:23.222 [DEBUG] [nding.tuya.internal.local.TuyaDevice] - dummy/192.168.178.27:6668: Failed to connect: Network is unreachable: /192.168.178.27:6668 2024-01-28 12:47:23.223 [DEBUG] [a.internal.handler.TuyaDeviceHandler] - Starting reconnect attempt ... 2024-01-28 12:47:23.223 [DEBUG] [a.internal.handler.TuyaDeviceHandler] - [tuya:ir-controller] stop ir learning 2024-01-28 12:47:28.224 [DEBUG] [nding.tuya.internal.local.TuyaDevice] - dummy/192.168.178.27:6668: Failed to connect: Network is unreachable: /192.168.178.27:6668 2024-01-28 12:47:28.224 [DEBUG] [a.internal.handler.TuyaDeviceHandler] - Stopped reconnect attempts! tuyaDevice is NULL: false, disposing: false, reconnectFuture is NULL: false, reconnectFuture is done: false 2024-01-28 12:47:28.225 [DEBUG] [a.internal.handler.TuyaDeviceHandler] - [tuya:ir-controller] stop ir learning ...

tuya-added-log-messages.patch

J-N-K commented 10 months ago

Can you try adding

    private void connectDevice() {
        TuyaDevice tuyaDevice = this.tuyaDevice;
        if (tuyaDevice == null) {
            logger.warn("Cannot connect {} because the device is not set", thing.getUID());
            return;
        }
        reconnectFuture = null;
        tuyaDevice.connect();
    }

and exchange tuyaDevice::connect with this::connectDevice? Maybe the issue is timing on slower systems. The bootstrap.connect(...) fails fast when the network is unreachable and I could imagine that the scheduled task is not yet done when the failed connect is reported.

Novanic commented 10 months ago

Yes, the fix works. :-) And the log messages are also ok, there is a reconnect attempt every 5 seconds, no stop message und the reconnect attemps don't appear anymore when the connection is back. That looks good. Thank you. :-) Can you release a new version for OpenHAB 4.1.1 with the fix?

J-N-K commented 10 months ago

Yes. There's an issue with amazonechocontrol that I need to look at, then I'll prepare a new release.