Unable to reconnect after power loss

alex-phillips commented 3 years ago

The problem

I have a Gosund RGBW bulb. I retrieved the ID and local key just fine, configured HA to talk to the bulb without issue and it worked great. But it seems as though if the power to the bulb is lost and restored (such as the light switch cutting power or the bulb being unscrewed and moved to another light), the integration can no longer talk to the device. I have to start the process over by retrieving a new local key to regain control. The HA logs show the following when it fails to connect:

2021-04-13 19:25:32 ERROR (MainThread) [custom_components.localtuya.common] [673...ca7] Connect to 192.168.1.108 failed
Traceback (most recent call last):
  File "/config/custom_components/localtuya/common.py", line 149, in _make_connection
    status = await self._interface.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 472, in status
    status = await self.exchange(STATUS)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 467, in exchange
    return await self.exchange(command, dps)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 451, in exchange
    msg = await self.dispatcher.wait_for(seqno)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 240, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 501, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

Environment

Localtuya version: 3.2.2
Last working localtuya version (if known and relevant):
Home Assistant Core version: 2021.4.3
[x] Are you using the Home Assistant Tuya Cloud component ?
[] Are you using the Tuya App in parallel ?

Steps to reproduce

Set up device in HA
Remove power from device and then power back on
Attempt to control device

Configuration `configuration.yaml` or `config_flow`

localtuya:
  - host: 192.168.1.108
    device_id: REMOVED
    local_key: REMOVED
    friendly_name: LIGHT_NAME
    protocol_version: "3.3"
    entities:
      - platform: light
        friendly_name: ENTITY_NAME
        id: 20 # Usually 1 or 20
        color_mode: 21 # Optional, usually 2 or 21, default: "none"
        brightness: 22 # Optional, usually 3 or 22, default: "none"
        # color_temp: 23 # Optional, usually 4 or 23, default: "none"
        color: 24 # Optional, usually 5 (RGB_HSV) or 24 (HSV), default: "none"
        brightness_lower: 29 # Optional, usually 0 or 29, default: 29
        brightness_upper: 1000 # Optional, usually 255 or 1000, default: 1000
        color_temp_min_kelvin: 2700 # Optional, default: 2700
        color_temp_max_kelvin: 6500 # Optional, default: 6500
        scene: 25 # Optional, usually 6 (RGB_HSV) or 25 (HSV), default: "none"
        music_mode: False # Optional, some use internal mic, others, phone mic. Only internal mic is supported, default: "False"

DP dump

INFO:localtuya:Detecting list of available DPS of device 3013761250029115dc9d [192.168.1.108], protocol 3.3.
DEBUG:localtuya.pytuya:Sending command status (device type: type_0a)
DEBUG:localtuya.pytuya:paylod=b'{"gwId":"3013761250029115dc9d","devId":"3013761250029115dc9d"}'
DEBUG:localtuya.pytuya:DATA RECEIVED!
DEBUG:localtuya.pytuya:decode payload=b'u\xfb\x91\xc4?M\xf7P~T\xc3\xcapV\xdbzley\xdch\x7f\x9a2\x17P\x8a\x1e\x8a\xf6\xee"5\x85\x1b4\xec%\x9a\xa2\xe7\r\xda:\x8a\xf3\xd6\xdb\xdf\x95G\x03\xb7\xc1T\xa5K\x9a\xd7\xc5\xdd\x07o\xa9\xe6\xa1C\x19QA\xc8l\xf8\xf9U\'\xdc\xd6\r\xeb\x9f\xe7r\xf4\xf8\x10\\\x88\xbe\x07 4KvP7X\x1b\xe2g>\x15\x95\xbe7f\x9d]\xb40\x1ayt\xf7\xb0\x84\x88\xf4:\x0c\xdfV5\x1b\xd87v\x18w\x020&\x9b\xf8\xae\x19\xf3\xe0\xe1k\xc5P=\x80'
DEBUG:localtuya.pytuya:decrypted result='{"devId":"3013761250029115dc9d","dps":{"20":true,"21":"white","22":500,"24":"000003e803e8","25":"000e0d0000000000000000c803e8","26":0}}'
AVAILABLE DPS ARE [{'20': True, '21': 'white', '22': 500, '24': '000003e803e8', '25': '000e0d0000000000000000c803e8', '26': 0}]
INFO:localtuya:COMPLETE response from device 3013761250029115dc9d [192.168.1.108].
INFO:localtuya:TIMEOUT: No response from device 3013761250029115dc9d [192.168.1.108] after 2 attempts.

Provide Home Assistant taceback/logs

See logs above

Additional information

alex-phillips commented 3 years ago

Debug logs:

2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.common] [673...ca7] Connecting to 192.168.1.108
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Started heartbeat loop
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Sending command heartbeat (device type: type_0a)
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Send payload: b'{}'
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Waiting for sequence number -100
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.common] [673...ca7] Retrieving initial state
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Sending command status (device type: type_0a)
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Send payload: b'{"gwId":"REMOVED","devId":"REMOVED"}'
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Waiting for sequence number 1
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Dispatching message TuyaMessage(seqno=0, cmd=9, retcode=0, payload=b'', crc=2958142211)
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Got heartbeat response
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Decrypted payload: {}
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Dispatching message TuyaMessage(seqno=1, cmd=10, retcode=1, payload=b'\x8c\xe1\x01\xdb\x9e|\xa5\xadu\x88\x17\xe2\xf8\xd1\xaadP_\xcfZ\r\x96\xcb\rX\x1d\xe8)\x7f\x88\xf1\x84', crc=4184553899)                                                                                                                                                                                                                                                                          
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Dispatching sequence number 1
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] switching to dev_type type_0d
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Re-send status due to device type change (type_0a -> type_0d)
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Sending command status (device type: type_0d)
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Send payload: b'{"devId":"REMOVED","uid":"REMOVED","t":"REMOVED","dps":{"20":null,"22":null,"21":null,"24":null,"25":null}}'
2021-04-14 12:20:05 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Waiting for sequence number 2
2021-04-14 12:20:07 DEBUG (MainThread) [custom_components.localtuya.pytuya] [301...c9d] Sending command heartbeat (device type: type_0a)
2021-04-14 12:20:07 DEBUG (MainThread) [custom_components.localtuya.pytuya] [301...c9d] Send payload: b'{}'
2021-04-14 12:20:07 DEBUG (MainThread) [custom_components.localtuya.pytuya] [301...c9d] Waiting for sequence number -100
2021-04-14 12:20:07 DEBUG (MainThread) [custom_components.localtuya.pytuya] [301...c9d] Dispatching message TuyaMessage(seqno=0, cmd=9, retcode=0, payload=b'', crc=2958142211)
2021-04-14 12:20:07 DEBUG (MainThread) [custom_components.localtuya.pytuya] [301...c9d] Got heartbeat response
2021-04-14 12:20:07 DEBUG (MainThread) [custom_components.localtuya.pytuya] [301...c9d] Decrypted payload: {}
2021-04-14 12:20:10 ERROR (MainThread) [custom_components.localtuya.common] [673...ca7] Connect to 192.168.1.108 failed
Traceback (most recent call last):
  File "/config/custom_components/localtuya/common.py", line 149, in _make_connection
    status = await self._interface.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 472, in status
    status = await self.exchange(STATUS)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 467, in exchange
    return await self.exchange(command, dps)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 451, in exchange
    msg = await self.dispatcher.wait_for(seqno)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 240, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 501, in wait_for
    raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError
2021-04-14 12:20:10 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Closing connection
2021-04-14 12:20:10 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Stopped heartbeat loop
2021-04-14 12:20:10 DEBUG (MainThread) [custom_components.localtuya.pytuya] [673...ca7] Connection lost: None
2021-04-14 12:20:10 DEBUG (MainThread) [custom_components.localtuya.common] [673...ca7] Disconnected - waiting for discovery broadcast

jrochate commented 3 years ago

I'm having the same problem with two SULION bulbs (white only).

I think I found out what the problem is:

when the power is off and on, the bulb tries to connect Internet. If it doesn't have access to internet, it will remain in "freeze" state until we resync again and then get a new key.

Even if we give internet access after that first try, the bulb won't come up.

This is the error from the log.

maybe localtuya module could handle this exception, avoid the error log and warns user about the need to resync.

2021-04-22 20:33:22 ERROR (MainThread) [custom_components.localtuya.common] [bf4...rcv] Connect to 192.168.150.105 failed Traceback (most recent call last): File "/config/custom_components/localtuya/common.py", line 139, in _make_connection self._interface = await pytuya.connect( File "/config/customcomponents/localtuya/pytuya/init.py", line 637, in connect , protocol = await loop.create_connection( File "/usr/local/lib/python3.8/asyncio/base_events.py", line 1025, in create_connection raise exceptions[0] File "/usr/local/lib/python3.8/asyncio/base_events.py", line 1010, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.8/asyncio/base_events.py", line 924, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 496, in sock_connect return await fut File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 528, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') OSError: [Errno 113] Connect call failed ('192.168.150.105', 6668) 2021-04-22 20:33:22 ERROR (MainThread) [custom_components.localtuya.common] [612...d2b] Connect to 192.168.150.104 failed Traceback (most recent call last): File "/config/custom_components/localtuya/common.py", line 139, in _make_connection self._interface = await pytuya.connect( File "/config/customcomponents/localtuya/pytuya/init.py", line 637, in connect , protocol = await loop.create_connection( File "/usr/local/lib/python3.8/asyncio/base_events.py", line 1025, in create_connection raise exceptions[0] File "/usr/local/lib/python3.8/asyncio/base_events.py", line 1010, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.8/asyncio/base_events.py", line 924, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 496, in sock_connect return await fut File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 528, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') OSError: [Errno 113] Connect call failed ('192.168.150.104', 6668)

alex-phillips commented 3 years ago

I was able to "fix" the issue somehow. When the bulb first powers up, it is in a state where localtuya cannot connect (the timeout in my original post). But I wrote a script using https://github.com/codetheweb/tuyapi that simply connects to the bulb, issues a command, and then disconnects. This script works fine and after the disconnect, localtuya is able to connect to the bulb successfully afterwards.

alex-phillips commented 3 years ago

Well, I wouldn't call it a 'fix', but it puts the bulb back into a state that localtuya can then work with again. Hopefully it'll be some help as to figure out how to fix the issue inside localtuya?

jrochate commented 3 years ago

can you share with me, so I can see if that exact same script solves the problem with SULION bulbs? TIA

alex-phillips commented 3 years ago

@jrochate It's just a modified version of an example script tuyapi has on their repo. I've created a repo here for ease of sharing: https://github.com/alex-phillips/tuyapi-test

Just change the IP, ID, and KEY props at the top. Also, depending on the device, you may have to change the cmd variable as your device may not support this command.

It's also possible that the .set and sending the command is not required? It may just need to connect and then disconnect.

Let me know if it works for you.

jrochate commented 3 years ago

Awesome!!! It really works and you saved me a lot of time in resync and get new Local Key.

On both lamps I get output like this:

$ node test.js Connected to device! Data from device: { devId: '612027572462ab03bd2b', dps: { '20': true, '21': 'white', '22': 467, '23': 569, '25': '000e0d0000000000000000c80000', '26': 0 } } Boolean status of default property: undefined. Error! Timeout waiting for status response from device id: 612027572462ab03bd2b Disconnected from device.

And then they appear again on HA.

@rospogrigio you could take a look at this script from @alex-phillips. It really solves an annoying problem with stalled bulbs.

Thank you all.

Elendilon commented 3 years ago

I've been setting up localtuya in an effort to "cloud proof" my home, because who knows when these random chinese servers will go down or start updating devices with malware? I just started, so all my devices were ordered within the last few weeks; and unfortunately no one company made everything I need so its a spread of manufacturers. This "can't reconnect after power loss" issue was the last thing holding me back on some devices.

A note was added recently to the localtuya readme.md "you must block DNS requests too", but blocking DNS only solved my issue with a single device manufacturer (gosung). The rest could not be controlled until internet and DNS was restored to them, even though they successfully connect to wifi. Here are my experiences for what happens on power loss and return (with no internet available):

Treatlife: Instantly controllable Gosung: Controllable after a few minutes but only if DNS is also blocked Sunco and Helloify: Uncontrollable forever, even with DNS blocked

Although running the script above did not solve my issue, adding "issueRefreshOnConnect: true" did. I did not need to set any values; just connect with that string in place and then the devices become controllable the next time localtuya polls them.

This is just a guess, but this "refresh" command is likely newer and needs sent to devices on newer firmware before they start responding. Also, how each manufacturer has implemented it (or the lack of getting it) seems to differ. This is also why (as found in another issue report) opening the Smart Life app causes these devices to start responding again.

Elendilon commented 3 years ago

Hacked together a fix that sends the REFRESH command in localtuya. I'm sure there are edge cases I didn't handle here, as every single manufacturer I have handled this situation differently/oddly. But if anyone wants to try, my branch is here:

https://github.com/Elendilon/localtuya/tree/zombie_fix

Idan37S commented 3 years ago

I'm in the same boat, after some time the device is without power, when it comes back to life LocalTuya won't detect it. Only if i open the Tuya app and send an action to the device then LocalTuya will re-detect it.

Any solution to that?

Elendilon commented 3 years ago

You can try my branch if you want (see the post directly above yours); the reason my devices could not be commanded after a power loss was due to needing the 0x12 REFRESH command sent to them. Given that yours come back if you open the tuya app then I'd say there is a good chance you are in the same state.

Idan37S commented 3 years ago

The problem is that I won't get the future updates from the official repo that way. What are the chances that your commit gets merged into the official repo?

Elendilon commented 3 years ago

So far I'm the only one that has tried it, and given that every single device from different manufacturers I have caused different edge cases I'm almost sure there are more issues yet to be found. If you or someone else tries it and it works then I'll PR it to start further review. It needs cleaned up and I'm not sure I'm going to have time to work on that, so if it gets merged will probably depend on if someone more "official" or involved wants to pick it up.

Idan37S commented 3 years ago

I have tried it in the past 4 days and so far it has been working flawlessly with my Tuya Bulb and Downlight. My use case is that I'm switching on and off the electric power (with the physical switch) from those devices (old apartment), And after a few days or so with no power the Tuya devices wouldn't be detected by LocalTuya when it came back to life, they would remain unavailable even though the Tuya app was able to control them if I tried, and only after doing that the LocalTuya would detect them again. This commit of yours as fixed it for me so far, I hope this get merged in some way or another.

Elendilon commented 3 years ago

Thanks for trying it. If it worked for you, then I will go ahead and PR it and get the discussion on it started.

shtrom commented 2 years ago

Some updates on my end on this: everything was working fine with some franken-branch of mine which was a mix of @Elendilon's branch #491, and my encoding fix for #424 https://github.com/rospogrigio/localtuya/issues/424#issuecomment-964097664.

But I wanted the latest and shiniest, so I upgraded Local Tuya to latest. #424 immediately reared its ugly head, so I re-applied my patch, but the devices weren't Zombifying, so I assumed that this issue here was fixed on master.

Zombie fix still needed

Fast forward to this morning, after a power cut, and both globe are 🧟 , so it seems the current master definitely doesn't fix all the issues.

I wanted to reach for #491 and reapply it to test, but as pointed here, it now conflicts with master. I tried to git mergetool, but the changes are sufficiently not trivial not to be sure what to do.

So, as suggested above, it does seem like a rebase of #491 on master, and a merge, is still needed.

Workaround with tuya-cli

In the meantime I ended up with a workaround using tuya-cli from https://github.com/TuyaAPI/cli, as a simple fix to revive the globes, by setting the needed DPs, which makes them appear. It seems only the ID and brightness DPs are strictly necessary, but I'm setting all those that I know exist, and this makes the globe operational again.

$ IP=192.0.2.1
$ ID=eb...
$ KEY=...
$ tuya-cli set --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3 --dps 20  --set true
Set succeeded.
$ tuya-cli set --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3 --dps 21  --set 'white'
Set succeeded.
$ tuya-cli set --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3 --dps 22  --set 500
Set succeeded.
$ tuya-cli set --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3 --dps 23  --set 1000
Set succeeded.
$ tuya-cli set --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3 --dps 25  --set '030e0d00000000000000001f403e8'
Set succeeded.
$ tuya-cli set --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3 --dps 26  --set 0
Set succeeded.
$ tuya-cli get --id ${ID} --key ${KEY} --ip ${IP} --protocol-version 3.3
{
  '20': true,
  '21': 'white',
  '22': 1000,
  '25': '030e0d00000000000000001f403e8',
  '26': 0
}

shtrom commented 2 years ago

Following up on my previous message.

Workaround with HA scripts (not sure this one works)

LocalTuya has a set_dp service that can be used to re-vive DPs instead of tuya-cli. I created two scripts:

a generic script setting the DPs

alias: Revive Tuya globe
variables:
max_brightness: 1000
brightness: 1000
scene_data: 030e0d00000000000000001f403e8
sequence:
- service: localtuya.set_dp
data:
  device_id: '{{ device_id }}'
  dp: 20
  value: true
- service: localtuya.set_dp
data:
  device_id: '{{ device_id }}'
  dp: 21
  value: white
- service: localtuya.set_dp
data:
  device_id: '{{ device_id }}'
  dp: 22
  value: '{{ brightness }}'
- service: localtuya.set_dp
data:
  device_id: '{{ device_id }}'
  dp: 23
  value: '{{ max_brightness }}'
- service: localtuya.set_dp
data:
  device_id: '{{ device_id }}'
  dp: 25
  value: '{{ scene_data }}'
- service: localtuya.set_dp
data:
  device_id: '{{ device_id }}'
  dp: 26
  value: 0
mode: single
icon: mdi:lightbulb-alert-outline

it takes the device_id as a parameter.

a specific script that sets the device_id and calls the previous one

alias: Revive lounge room lamp
sequence:
- service: script.reset_loungeroom_lamp
data:
  device_id: eb...
mode: single
icon: mdi:lightbulb-alert

The script runs without error, but I haven't been able to 100% confirm that it actually does what it needed. I suspect localtuya may not want to set_dp until, maybe, the ID DP is available. Unfortunately, now that my devices are de-zombified again, it's tricky to retest and confirm.

I'm leaving this here nonetheless in case someone else want to give it a go, as it at lease provides a fully HA-based solution to dezombify without having to patch localtuya. Please report here with info on success/failure if you do.

shtrom commented 2 years ago

The script runs without error, but I haven't been able to 100% confirm that it actually does what it needed. I suspect localtuya may not want to set_dp until, maybe, the ID DP is available. Unfortunately, now that my devices are de-zombified again, it's tricky to retest and confirm.

I can now confirm that it works.

sibowler commented 2 years ago

@shtrom - I've incorporated the set_dp behavior into PR #956 . The changes in this PR allow you to specify DPIDs that are not detected and it will initialise them on connection. So far this has worked with all my offline Tuya devices, except for a Fanco fan - but even the Tuya App isn't able to make this work without the internet.

rospogrigio / localtuya