Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tuya Device cycles briefly ONLINE than back OFFLINE #600

Open
BigGeorgeTx opened this issue Nov 26, 2024 · 3 comments
Open

Tuya Device cycles briefly ONLINE than back OFFLINE #600

BigGeorgeTx opened this issue Nov 26, 2024 · 3 comments

Comments

@BigGeorgeTx
Copy link

BigGeorgeTx commented Nov 26, 2024

I installed a new Gosund Wallswitch today. The binding automatically created the Thing and I created the linked items using the UI.

Running OH 4.2.2 Release on a Pi4B using openhabian.

In the log I see the following at DEBUG,

2024-11-26 12:35:10.879 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44c4f/10.0.0.128:6668: Sending HEART_BEAT, payload {devId=06787636600194a44c4f, uid=06787636600194a44c4f, t=1732649710, dps=, gwId=06787636600194a44c4f} 2024-11-26 12:35:10.879 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44c4f/10.0.0.128:6668: Sending encoded '000055AA000028F90000000900000097332E33000000000000000000000000F03DC41A0A73C2367385C3D9E5B02E9B0B3F7BF80AF5FD9626B331B692133275EDB78A41CD95974ABD8E19F28DB26D97EEFB288BFDFB76C21D258B79984CF2B2055B630D4E1DC0AC6EDE0FE773B564B242EE189935615A3AF3F12CFD996F3BD344B00D9F42364E241E989BBC5C0D0936709EA32CADD26AB0CCFD72643C95C8329F53A1940000AA55' 2024-11-26 12:35:10.891 [TRACE] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44c4f/10.0.0.128:6668: Received encoded '000055AA00000000000000090000000C00000000B051AB030000AA55' 2024-11-26 12:35:10.891 [TRACE] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44c4f/10.0.0.128:6668: Decoded raw payload: 2024-11-26 12:35:10.891 [DEBUG] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44c4f/10.0.0.128:6668: Received MessageWrapper{commandType=HEART_BEAT, content='[B@1b5fc83e'} 2024-11-26 12:35:10.891 [TRACE] [rnal.local.handlers.HeartbeatHandler] - 06787636600194a44c4f/10.0.0.128:6668: Received pong 2024-11-26 12:35:11.659 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending DP_QUERY, payload {devId=06787636600194a44810, uid=06787636600194a44810, t=1732649711, dps={}, gwId=06787636600194a44810} 2024-11-26 12:35:11.660 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending encoded '000055AA000000010000000A0000007B7B226465764964223A223036373837363336363030313934613434383130222C22756964223A223036373837363336363030313934613434383130222C2274223A313733323634393731312C22647073223A7B7D2C2267774964223A223036373837363336363030313934613434383130227DE4FA265B0000AA55' 2024-11-26 12:35:11.660 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection established. 2024-11-26 12:35:11.667 [DEBUG] [rnal.local.handlers.UserEventHandler] - 06787636600194a44810/10.0.0.247:6668: IOException caught, closing channel. java.net.SocketException: Connection reset at sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:394) ~[?:?] at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:426) ~[?:?] at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:255) ~[bundleFile:4.1.104.Final] at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1132) ~[bundleFile:4.1.104.Final] at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:357) ~[bundleFile:4.1.104.Final] at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) [bundleFile:4.1.104.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) [bundleFile:4.1.104.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.104.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.104.Final] at java.lang.Thread.run(Thread.java:840) [?:?] 2024-11-26 12:35:11.668 [DEBUG] [rnal.local.handlers.UserEventHandler] - IOException caught: java.net.SocketException: Connection reset at sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:394) ~[?:?] at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:426) ~[?:?] at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:255) ~[bundleFile:4.1.104.Final] at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1132) ~[bundleFile:4.1.104.Final] at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:357) ~[bundleFile:4.1.104.Final] at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) [bundleFile:4.1.104.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) [bundleFile:4.1.104.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) [bundleFile:4.1.104.Final] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.104.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.104.Final] at java.lang.Thread.run(Thread.java:840) [?:?] 2024-11-26 12:35:11.669 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection terminated. ==> /var/log/openhab/events.log <== 2024-11-26 12:35:11.661 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from OFFLINE to ONLINE 2024-11-26 12:35:11.669 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from ONLINE to OFFLINE 2024-11-26 12:35:12.041 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RemoteopenHABServermyopenhaborg_ItemLocalTimeDate' changed from 2024-11-26T13:34:11.886-0600 to 2024-11-26T13:35:11.887-0600 ==> /var/log/openhab/openhab.log <== 2024-11-26 12:35:12.728 [TRACE] [.internal.local.handlers.TuyaDecoder] - udpListener: Received encoded '000055AA00000000000000130000009C000000009E48FD861BAE64CD0E7538CF529ADD87F9F485FA79A3F289F80A8548E409BBA95D3601DE06AA476780AD532E849DD34D77BB6C9BCD33ED4F591FF9114B283767A483BE81E77F2E71F4307BD81685095E7E6FD47351A96972BDC91A04690E1EE139748132FE628885EED0E7AD9054446E03A041A1CB4D19ADA50F5E78DFF432964B95AC1F0A68B021B552634BAF99A3C50DF8D4680000AA55' 2024-11-26 12:35:12.730 [TRACE] [.internal.local.handlers.TuyaDecoder] - udpListener: Decoded raw payload: 7B226970223A2231302E302E302E313234222C2267774964223A2265623333613937326233613733336464356479696C6E222C22616374697665223A322C2261626C696C7479223A302C22656E6372797074223A747275652C2270726F647563744B6579223A226B657967673839376B7274356B6B3474222C2276657273696F6E223A22332E33227D07070707070707 2024-11-26 12:35:12.732 [DEBUG] [.internal.local.handlers.TuyaDecoder] - udpListener: Received MessageWrapper{commandType=UDP_NEW, content='DiscoveryMessage{ip='10.0.0.124', deviceId='eb33a972b3a733dd5dyiln', active=2, ability=0, mode=0, encrypt=true, productKey='keygg897krt5kk4t', version='3.3', token= true, wf_cfg=true}'} 2024-11-26 12:35:12.829 [TRACE] [rnal.local.handlers.HeartbeatHandler] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Sending ping 2024-11-26 12:35:12.830 [DEBUG] [.internal.local.handlers.TuyaEncoder] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Sending HEART_BEAT, payload {devId=eb0a689d8036ebc469nmsj, uid=eb0a689d8036ebc469nmsj, t=1732649712, dps=, gwId=eb0a689d8036ebc469nmsj} 2024-11-26 12:35:12.830 [TRACE] [.internal.local.handlers.TuyaEncoder] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Sending encoded '000055AA000007EC0000000900000097332E330000000000000000000000003E8D5C74CEF06E88EC94108DB18D57191626CF62F27390EDA2531BF7FC79DFD1558B941E7AE0967FB2CB733B0909518FD450154CFE462CB6B1321861DA1FA35BBFC5A386F5439DD83244A94A39F60F99C7B369EA098AA61C562B47977AC38B7EE0A6F1E92A30F1037E58D0C445B6058FBD805AE88B4F0BFBB43C370C23632FAFDDAAE3250000AA55' 2024-11-26 12:35:12.916 [TRACE] [.internal.local.handlers.TuyaDecoder] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Received encoded '000055AA00000000000000090000000C00000000B051AB030000AA55' 2024-11-26 12:35:12.917 [TRACE] [.internal.local.handlers.TuyaDecoder] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Decoded raw payload: 2024-11-26 12:35:12.917 [DEBUG] [.internal.local.handlers.TuyaDecoder] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Received MessageWrapper{commandType=HEART_BEAT, content='[B@6e54621f'} 2024-11-26 12:35:12.917 [TRACE] [rnal.local.handlers.HeartbeatHandler] - eb0a689d8036ebc469nmsj/10.0.0.214:6668: Received pon

There is a lot of information because I have numerous Tuya devices, but I think the above captures the root of the problem. This is what I see with the log filtered by the device ID, which shows the cycling but doesn't catch the error.
2024-11-26 12:38:47.659 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection established. 2024-11-26 12:38:47.667 [DEBUG] [rnal.local.handlers.UserEventHandler] - 06787636600194a44810/10.0.0.247:6668: IOException caught, closing channel. 2024-11-26 12:38:47.670 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection terminated. 2024-11-26 12:38:47.661 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from OFFLINE to ONLINE 2024-11-26 12:38:47.672 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from ONLINE to OFFLINE 2024-11-26 12:38:50.261 [TRACE] [rnal.local.handlers.HeartbeatHandler] - 06787636600194a44810/10.0.0.247:6668: Sending ping 2024-11-26 12:38:50.262 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending HEART_BEAT, payload {devId=06787636600194a44810, uid=06787636600194a44810, t=1732649930, dps=, gwId=06787636600194a44810} 2024-11-26 12:38:50.262 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending encoded '000055AA00000153000000090000007B7B226465764964223A223036373837363336363030313934613434383130222C22756964223A223036373837363336363030313934613434383130222C2274223A313733323634393933302C22647073223A22222C2267774964223A223036373837363336363030313934613434383130227D732E07640000AA55' 2024-11-26 12:38:50.269 [TRACE] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44810/10.0.0.247:6668: Received encoded '000055AA00000000000000090000000C00000000B051AB030000AA55' 2024-11-26 12:38:50.270 [TRACE] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44810/10.0.0.247:6668: Decoded raw payload: 2024-11-26 12:38:50.270 [DEBUG] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44810/10.0.0.247:6668: Received MessageWrapper{commandType=HEART_BEAT, content='[B@275b2cfe'} 2024-11-26 12:38:50.270 [TRACE] [rnal.local.handlers.HeartbeatHandler] - 06787636600194a44810/10.0.0.247:6668: Received pong 2024-11-26 12:38:52.682 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending DP_QUERY, payload {devId=06787636600194a44810, uid=06787636600194a44810, t=1732649932, dps={}, gwId=06787636600194a44810} 2024-11-26 12:38:52.683 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending encoded '000055AA000000010000000A0000007B7B226465764964223A223036373837363336363030313934613434383130222C22756964223A223036373837363336363030313934613434383130222C2274223A313733323634393933322C22647073223A7B7D2C2267774964223A223036373837363336363030313934613434383130227D82A413240000AA55' 2024-11-26 12:38:52.683 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection established. 2024-11-26 12:38:52.693 [DEBUG] [rnal.local.handlers.UserEventHandler] - 06787636600194a44810/10.0.0.247:6668: IOException caught, closing channel. 2024-11-26 12:38:52.694 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection terminated. 2024-11-26 12:38:52.684 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from OFFLINE to ONLINE 2024-11-26 12:38:52.696 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from ONLINE to OFFLINE 2024-11-26 12:38:57.701 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending DP_QUERY, payload {devId=06787636600194a44810, uid=06787636600194a44810, t=1732649937, dps={}, gwId=06787636600194a44810} 2024-11-26 12:38:57.701 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending encoded '000055AA000000010000000A0000007B7B226465764964223A223036373837363336363030313934613434383130222C22756964223A223036373837363336363030313934613434383130222C2274223A313733323634393933372C22647073223A7B7D2C2267774964223A223036373837363336363030313934613434383130227D7C0FCD830000AA55' 2024-11-26 12:38:57.702 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection established. 2024-11-26 12:38:57.714 [DEBUG] [rnal.local.handlers.UserEventHandler] - 06787636600194a44810/10.0.0.247:6668: IOException caught, closing channel. 2024-11-26 12:38:57.715 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection terminated. 2024-11-26 12:38:57.703 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from OFFLINE to ONLINE 2024-11-26 12:38:57.717 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from ONLINE to OFFLINE 2024-11-26 12:39:00.263 [TRACE] [rnal.local.handlers.HeartbeatHandler] - 06787636600194a44810/10.0.0.247:6668: Sending ping 2024-11-26 12:39:00.264 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending HEART_BEAT, payload {devId=06787636600194a44810, uid=06787636600194a44810, t=1732649940, dps=, gwId=06787636600194a44810} 2024-11-26 12:39:00.265 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending encoded '000055AA00000154000000090000007B7B226465764964223A223036373837363336363030313934613434383130222C22756964223A223036373837363336363030313934613434383130222C2274223A313733323634393934302C22647073223A22222C2267774964223A223036373837363336363030313934613434383130227D350176C60000AA55' 2024-11-26 12:39:00.272 [TRACE] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44810/10.0.0.247:6668: Received encoded '000055AA00000000000000090000000C00000000B051AB030000AA55' 2024-11-26 12:39:00.273 [TRACE] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44810/10.0.0.247:6668: Decoded raw payload: 2024-11-26 12:39:00.274 [DEBUG] [.internal.local.handlers.TuyaDecoder] - 06787636600194a44810/10.0.0.247:6668: Received MessageWrapper{commandType=HEART_BEAT, content='[B@2251f0ed'} 2024-11-26 12:39:00.274 [TRACE] [rnal.local.handlers.HeartbeatHandler] - 06787636600194a44810/10.0.0.247:6668: Received pong 2024-11-26 12:39:02.725 [DEBUG] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending DP_QUERY, payload {devId=06787636600194a44810, uid=06787636600194a44810, t=1732649942, dps={}, gwId=06787636600194a44810} 2024-11-26 12:39:02.725 [TRACE] [.internal.local.handlers.TuyaEncoder] - 06787636600194a44810/10.0.0.247:6668: Sending encoded '000055AA000000010000000A0000007B7B226465764964223A223036373837363336363030313934613434383130222C22756964223A223036373837363336363030313934613434383130222C2274223A313733323634393934322C22647073223A7B7D2C2267774964223A223036373837363336363030313934613434383130227D53EA812C0000AA55' 2024-11-26 12:39:02.726 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection established. 2024-11-26 12:39:02.734 [DEBUG] [rnal.local.handlers.UserEventHandler] - 06787636600194a44810/10.0.0.247:6668: IOException caught, closing channel. 2024-11-26 12:39:02.735 [DEBUG] [al.local.handlers.TuyaMessageHandler] - 06787636600194a44810/10.0.0.247:6668: Connection terminated. 2024-11-26 12:39:02.728 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from OFFLINE to ONLINE 2024-11-26 12:39:02.737 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'tuya:tuyaDevice:06787636600194a44810' changed from ONLINE to OFFLINE

Functionally what I see is that it will track switch activity but cannot control the switch.

Happy to help troubleshoot but I have no idea where to begin.

@BigGeorgeTx BigGeorgeTx changed the title Device cycles breifly ONLINE than back OFFLINE Tuya Device cycles breifly ONLINE than back OFFLINE Nov 26, 2024
@BigGeorgeTx BigGeorgeTx changed the title Tuya Device cycles breifly ONLINE than back OFFLINE Tuya Device cycles briefly ONLINE than back OFFLINE Nov 27, 2024
@tkarle
Copy link

tkarle commented Dec 18, 2024

Hi there!
Same here. all my tuya devices have gone offline:waiting or IP.
In my case they do not get the local IP automatically, so I have added this manually in things setup per each device. After that it works!
I even reinstalled the Tuya Cloud version (and deleted the old one) and have the same behaviour. Devices are detected in Tuya Cloud, they can be created with Thing Scan, but are not accessible locally.
I believe that Tuya has done extensive work on their API. New UI in the APP, new protocol version (3.5) introduced for devices and maybe many more things.
It will be exciting.

Copy link

stale bot commented Feb 14, 2025

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale An issue is marked stale after four weeks without activity and will be closed one week later. label Feb 14, 2025
@BigGeorgeTx
Copy link
Author

BigGeorgeTx commented Feb 14, 2025 via email

@stale stale bot removed the stale An issue is marked stale after four weeks without activity and will be closed one week later. label Feb 14, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants