search

leeyuentuen / localtuya

local handling for Tuya devices
GNU General Public License v3.0
71 stars 17 forks source link

Unknown error when adding Bluetooth Gateway via config flow #29

Open chris24walsh opened 1 year ago

chris24walsh commented 1 year ago

The problem

When attempting to add a Tuya Bluetooth Gateway via the config flow, it gives me an error: An unknown error occurred. See log for details.

Checking the logs gives this more detailed error message:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/config_flow.py", line 428, in async_step_basic_sub_device_info
    self.dps_strings = await validate_input(self.hass, user_input)
  File "/config/custom_components/localtuya/config_flow.py", line 260, in validate_input
    detected_dps = await interface.detect_available_dps(data[CONF_DEVICE_ID])
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 684, in detect_available_dps
    status = await self.status(cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 598, in status
    status = await self.exchange(ACTION_STATUS, cid=cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 563, in exchange
    msg = await self.dispatcher.wait_for(seqno)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 325, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

Environment

Steps to reproduce

  1. Add Integration -> LocalTuya
  2. Select gateway from list of devices.
  3. Fill in details, checking the 'Is gateway' box.
  4. Click 'SUBMIT'
  5. Error appears in the top of the dialog box, An unknown error occurred. See log for details.

Configuration configuration.yaml or config_flow

Name: Bluetooth Gateway
Local key: <redacted>
Host: 192.168.2.134
Device ID: bf12b9e35267857daeyjrf
Protocol version: 3.3 (Also tried 3.1)
Is Gateway: (checked box)

DP dump

INFO:localtuya:Detecting list of available DPS of device bf12b9e35267857daeyjrf [192.168.2.134], protocol 3.3. DEBUG:localtuya.pytuya:[bf1...jrf] Sending command 10 (device type: type_0a) DEBUG:localtuya.pytuya:[bf1...jrf] Sending payload: b'{"gwId":"bf12b9e35267857daeyjrf","devId":"bf12b9e35267857daeyjrf","uid":"bf12b9e35267857daeyjrf","t":"1673454033"}' DEBUG:localtuya.pytuya:[bf1...jrf] Command 10 waiting for sequence number 1 DEBUG:localtuya.pytuya:[bf1...jrf] Connection lost: [Errno 54] Connection reset by peer ERROR:localtuya.pytuya:[bf1...jrf] Failed to get status: Traceback (most recent call last): File "/Users/chris/.pyenv/versions/3.9.6/lib/python3.9/asyncio/locks.py", line 413, in acquire await fut asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/Users/chris/.pyenv/versions/3.9.6/lib/python3.9/asyncio/tasks.py", line 492, in wait_for fut.result() asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/Users/chris/dev/personal/hass/local-tuya/tuyadebug/localtuya/pytuya/init.py", line 849, in detect_available_dps data = await self.status() File "/Users/chris/dev/personal/hass/local-tuya/tuyadebug/localtuya/pytuya/init.py", line 781, in status status = await self.exchange(DP_QUERY) File "/Users/chris/dev/personal/hass/local-tuya/tuyadebug/localtuya/pytuya/init.py", line 755, in exchange msg = await self.dispatcher.wait_for(seqno, payload.cmd) File "/Users/chris/dev/personal/hass/local-tuya/tuyadebug/localtuya/pytuya/init.py", line 446, in wait_for await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout) File "/Users/chris/.pyenv/versions/3.9.6/lib/python3.9/asyncio/tasks.py", line 494, in wait_for raise exceptions.TimeoutError() from exc asyncio.exceptions.TimeoutError

Provide Home Assistant taceback/logs

This error originated from a custom integration.

Logger: custom_components.localtuya.pytuya
Source: custom_components/localtuya/pytuya/__init__.py:325
Integration: LocalTuya (documentation, issues)
First occurred: 4:24:14 PM (1 occurrences)
Last logged: 4:24:14 PM

[bf1...jrf] Failed to get status:
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 702, in detect_available_dps
    status = await self.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 602, in status
    status = await self.exchange(ACTION_STATUS)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 563, in exchange
    msg = await self.dispatcher.wait_for(seqno)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 325, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
This error originated from a custom integration.

Logger: custom_components.localtuya.config_flow
Source: custom_components/localtuya/pytuya/__init__.py:325
Integration: LocalTuya (documentation, issues)
First occurred: 4:24:14 PM (1 occurrences)
Last logged: 4:24:14 PM

Unexpected exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/config_flow.py", line 364, in async_step_basic_info
    self.dps_strings = await validate_input(self.hass, user_input)
  File "/config/custom_components/localtuya/config_flow.py", line 270, in validate_input
    detected_dps = await interface.detect_available_dps()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 702, in detect_available_dps
    status = await self.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 602, in status
    status = await self.exchange(ACTION_STATUS)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 563, in exchange
    msg = await self.dispatcher.wait_for(seqno)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 325, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

Additional information

Adding this device via the configuration.yaml 'works', but the adding the subdevices doesn't seem to work. I believe this issue may be due to the only sub-devices being bluetooth smart locks, as I understand that a lock entity is not yet defined for localtuya. Can you confirm this, or explain what else I can do here?

leeyuentuen commented 1 year ago

should be the same issue as this? https://github.com/leeyuentuen/localtuya/issues/29

chris24walsh commented 1 year ago

hmm? you linked this same issue

leeyuentuen commented 1 year ago

hmm? you linked this same issue

my bad.. phone issue. Will be checked soon.

leeyuentuen commented 1 year ago

have you try the beta version 3.7.0. maybe your device is using 3.4 protocol. is also one of my zigbee gateway

issue can be here discuss https://github.com/leeyuentuen/localtuya/issues/35

mariustt commented 1 year ago

Same problem here:

2023-02-11 19:57:03.846 ERROR (MainThread) [custom_components.localtuya.pytuya] [bff...jmq] Failed to get status: 
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 976, in detect_available_dps
    status = await self.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 875, in status
    status = await self.exchange(DP_QUERY)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 824, in exchange
    msg = await self.dispatcher.wait_for(seqno, payload.cmd)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 504, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
2023-02-11 19:57:13.860 ERROR (MainThread) [custom_components.localtuya.pytuya] [bff...jmq] Failed to get status: 'NoneType' object has no attribute 'write'
Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 976, in detect_available_dps
    status = await self.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 875, in status
    status = await self.exchange(DP_QUERY)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 823, in exchange
    self.transport.write(enc_payload)
AttributeError: 'NoneType' object has no attribute 'write'
2023-02-11 19:57:13.863 ERROR (MainThread) [custom_components.localtuya.pytuya] [bff...jmq] Failed to get status: 'NoneType' object has no attribute 'write'
Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 976, in detect_available_dps
    status = await self.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 875, in status
    status = await self.exchange(DP_QUERY)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 823, in exchange
    self.transport.write(enc_payload)
AttributeError: 'NoneType' object has no attribute 'write'
2023-02-11 19:57:13.864 ERROR (MainThread) [custom_components.localtuya.pytuya] [bff...jmq] Failed to get status: 'NoneType' object has no attribute 'write'
Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 976, in detect_available_dps
    status = await self.status()
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 875, in status
    status = await self.exchange(DP_QUERY)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 823, in exchange
    self.transport.write(enc_payload)
AttributeError: 'NoneType' object has no attribute 'write'

In my case I use bluetooth gateway - https://moeshouse.com/products/moes-gateway-bhub-w-ms?_pos=1&_sid=660586feb&_ss=r

When I select protocol 3.3. or lower, the gateway device does not add. When I select 3.4., the device is added, however I get the error which you can see in the comment above. This issue is present in all latest versions:

teixeluis commented 1 year ago

Same error here, using 3.7.0 beta 2, and hassio 2023.2.5.

image

And in the logs, the two errors:

` Logger: custom_components.localtuya.config_flow Source: custom_components/localtuya/config_flow.py:306 Integration: LocalTuya integration (documentation, issues) First occurred: 17:15:00 (1 occurrences) Last logged: 17:15:00

Unexpected exception Traceback (most recent call last): File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire await fut asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for return fut.result() asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/config/custom_components/localtuya/config_flow.py", line 289, in validate_input detected_dps = await interface.detect_available_dps(data[CONF_DEVICE_ID]) File "/config/custom_components/localtuya/pytuya/init.py", line 958, in detect_available_dps status = await self.status(cid) File "/config/custom_components/localtuya/pytuya/init.py", line 871, in status status = await self.exchange(DP_QUERY_NEW, cid=cid) File "/config/custom_components/localtuya/pytuya/init.py", line 824, in exchange msg = await self.dispatcher.wait_for(seqno, payload.cmd) File "/config/custom_components/localtuya/pytuya/init.py", line 504, in wait_for await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout) File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for raise exceptions.TimeoutError() from exc asyncio.exceptions.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/config/custom_components/localtuya/config_flow.py", line 457, in async_step_basic_sub_device_info self.dps_strings = await validate_input(self.hass, user_input) File "/config/custom_components/localtuya/config_flow.py", line 306, in validate_input await interface.close() KeyError: (-100, <asyncio.locks.Semaphore object at 0x672638b0 [locked]>)

Logger: custom_components.localtuya.pytuya Source: custom_components/localtuya/pytuya/init.py:504 Integration: LocalTuya integration (documentation, issues) First occurred: 17:15:00 (1 occurrences) Last logged: 17:15:00

[bfd...gyz] Failed to get status for cid xxxxxxx: Traceback (most recent call last): File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire await fut asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for return fut.result() asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/config/custom_components/localtuya/pytuya/init.py", line 958, in detect_available_dps status = await self.status(cid) File "/config/custom_components/localtuya/pytuya/init.py", line 871, in status status = await self.exchange(DP_QUERY_NEW, cid=cid) File "/config/custom_components/localtuya/pytuya/init.py", line 824, in exchange msg = await self.dispatcher.wait_for(seqno, payload.cmd) File "/config/custom_components/localtuya/pytuya/init.py", line 504, in wait_for await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout) File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for raise exceptions.TimeoutError() from exc asyncio.exceptions.TimeoutError `

It only occurs when adding the sub-device though.

thanks

suddy commented 1 year ago

the same error when add tuya both zigbee&bluetooth Gateway.

using 3.7.0 beta 2, and hassio 2023.2.5. both YAML or config flow has the same error(Gateway add successful, but after that, add sub_device is error)

Error log:

[code] 2023-02-21 22:49:13.328 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration localtuya which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2023-02-21 22:49:13.329 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2023-02-21 22:49:40.732 ERROR (MainThread) [homeassistant.util.logging] Exception in _handle_sub_device_request when dispatching 'localtuya_gateway_6cdxxxxxxxxxxxlt': ({'request': 'request_add', 'cid': '086xxxxxxxx05e', 'content': {'dps': {1: None}}},) Traceback (most recent call last): File "/usr/local/lib/python3.10/locks.py", line 390, in acquire await fut asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for return fut.result() asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/config/custom_components/localtuya/common.py", line 403, in _handle_sub_device_request await self._get_sub_device_status(cid) File "/config/custom_components/localtuya/common.py", line 440, in _get_sub_device_status status = await self._interface.status(cid) File "/config/custom_components/localtuya/pytuya/init.py", line 871, in status status = await self.exchange(DP_QUERY_NEW, cid=cid) File "/config/custom_components/localtuya/pytuya/init.py", line 824, in exchange msg = await self.dispatcher.wait_for(seqno, payload.cmd) File "/config/custom_components/localtuya/pytuya/init.py", line 504, in wait_for await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout) File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for raise exceptions.TimeoutError() from exc asyncio.exceptions.TimeoutError

2023-02-21 22:51:24.445 WARNING (SyncWorker_6) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 22:52:30.577 WARNING (SyncWorker_7) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 22:54:42.770 WARNING (SyncWorker_6) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 22:56:54.965 WARNING (SyncWorker_2) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 23:00:13.305 WARNING (SyncWorker_4) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 23:01:19.392 WARNING (SyncWorker_8) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 23:04:37.701 WARNING (SyncWorker_1) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 2023-02-21 23:06:49.983 WARNING (SyncWorker_6) [custom_components.localtuya.climate] [086...05e] Entity climate.tuya_zigbee_climate_entity_1 is requesting unknown DPS index 1 [/code]

alexualbu commented 1 year ago

can the folks who have 3.4 gateways try the latest 3.7.0 beta out and provide some logs with the, hopefully new, errors?

alexualbu commented 1 year ago

re-pinging @chris24walsh , @suddy, @teixeluis

teixeluis commented 1 year ago

Hi @alexualbu,

I currently am unable to test with the sub-device (Lockbox L1) as it is currently out of range of the bluetooth gateway, and is on another house I am only able to go to in the next weekend.

But trying to add it in the current conditions, using v3.7.0 beta 5, I am getting the following error when trying to add the sub-device:

Logger: custom_components.localtuya.config_flow
Source: custom_components/localtuya/pytuya/__init__.py:516
Integration: LocalTuya integration ([documentation](https://github.com/leeyuentuen/localtuya/), [issues](https://github.com/leeyuentuen/localtuya/issues))
First occurred: 19:30:09 (2 occurrences)
Last logged: 19:32:15

Unexpected exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/config_flow.py", line 457, in async_step_basic_sub_device_info
    self.dps_strings = await validate_input(self.hass, user_input)
  File "/config/custom_components/localtuya/config_flow.py", line 289, in validate_input
    detected_dps = await interface.detect_available_dps(data[CONF_DEVICE_ID])
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 971, in detect_available_dps
    status = await self.status(cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 884, in status
    status = await self.exchange(DP_QUERY_NEW, cid=cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 837, in exchange
    msg = await self.dispatcher.wait_for(seqno, payload.cmd)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 516, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

Maybe in this case it is a justifiable error, as the subdevice is out of bluetooth range. The bluetooth gateway is online though.

Not sure if it is any useful but is what I can provide for now.

Cheers

alexualbu commented 1 year ago

thanks, @teixeluis - this looks like it's caused by the device not being connected. In any event, right now sub-devices under v3.4 gateways are not working (see #39 ) so this is going to take a while.

teixeluis commented 1 year ago

Ok thanks for the feedback @alexualbu. Nevertheless regarding the gateway itself are there any sensors or other types of entities that should get created after having added the gateway? Thanks

alexualbu commented 1 year ago

@teixeluis, most GWs do not have DPs (i have 1 without and one with a few) - normally if DPs are detected you would get the UI for defining entities in the config flow

teixeluis commented 1 year ago

Maybe not very relevant, as @alexualbu confirmed that sub-devices currently are not supported with these v3.4 bluetooth gateways, but when trying to add the subdevice, now that I have it within range, I get the errors:

Logger: custom_components.localtuya.pytuya
Source: custom_components/localtuya/pytuya/__init__.py:516
Integration: LocalTuya integration ([documentation](https://github.com/leeyuentuen/localtuya/), [issues](https://github.com/leeyuentuen/localtuya/issues))
First occurred: 12:00:55 (1 occurrences)
Last logged: 12:00:55

[bfd...gyz] Failed to get status for cid xxxxxxx:
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 971, in detect_available_dps
    status = await self.status(cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 884, in status
    status = await self.exchange(DP_QUERY_NEW, cid=cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 837, in exchange
    msg = await self.dispatcher.wait_for(seqno, payload.cmd)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 516, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
Logger: custom_components.localtuya.config_flow
Source: custom_components/localtuya/pytuya/__init__.py:516
Integration: LocalTuya integration ([documentation](https://github.com/leeyuentuen/localtuya/), [issues](https://github.com/leeyuentuen/localtuya/issues))
First occurred: 12:00:55 (1 occurrences)
Last logged: 12:00:55

Unexpected exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/config_flow.py", line 457, in async_step_basic_sub_device_info
    self.dps_strings = await validate_input(self.hass, user_input)
  File "/config/custom_components/localtuya/config_flow.py", line 289, in validate_input
    detected_dps = await interface.detect_available_dps(data[CONF_DEVICE_ID])
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 971, in detect_available_dps
    status = await self.status(cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 884, in status
    status = await self.exchange(DP_QUERY_NEW, cid=cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 837, in exchange
    msg = await self.dispatcher.wait_for(seqno, payload.cmd)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 516, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError
alexualbu commented 1 year ago

@teixeluis, which version are you on?

teixeluis commented 1 year ago

@teixeluis, which version are you on?

@alexualbu I am on Home Assistant 2023.3.6, and using Local Tuya 3.7.0-beta.5. I haven't yet tested with beta 8.

alexualbu commented 1 year ago

@teixeluis, beta8 seems to do the trick. Let us know once you manage to test.

teixeluis commented 1 year ago

Updated to beta 8. Error is very similar:

Logger: custom_components.localtuya.pytuya
Source: custom_components/localtuya/pytuya/__init__.py:525
Integration: LocalTuya integration ([documentation](https://github.com/leeyuentuen/localtuya/), [issues](https://github.com/leeyuentuen/localtuya/issues))
First occurred: 22:30:49 (1 occurrences)
Last logged: 22:30:49

[bfd...gyz] Failed to get status for cid xxxxx:
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/locks.py", line 390, in acquire
    await fut
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 986, in detect_available_dps
    status = await self.status(cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 899, in status
    status = await self.exchange(DP_QUERY_NEW, cid=cid)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 853, in exchange
    msg = await self.dispatcher.wait_for(seqno, payload.cmd)
  File "/config/custom_components/localtuya/pytuya/__init__.py", line 525, in wait_for
    await asyncio.wait_for(self.listeners[seqno].acquire(), timeout=timeout)
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

Should I remove and re-add the bluetooth gateway integration or is it irrelevant?

Thanks

alexualbu commented 1 year ago

@teixeluis - yes, please. Also, make sure you restart HA and provide a full debug log. As per #39 BT gateways seem to work now.

teixeluis commented 1 year ago

Re-adding the gateway, it waits a long time, and then throws an error:

Logger: asyncio
Source: custom_components/localtuya/pytuya/__init__.py:852
Integration: LocalTuya integration ([documentation](https://github.com/leeyuentuen/localtuya/), [issues](https://github.com/leeyuentuen/localtuya/issues))
First occurred: 22:42:12 (4 occurrences)
Last logged: 22:43:56

socket.send() raised exception.

Both gateway and device are online

alexualbu commented 1 year ago

So they are working? I ll still need the full log (debug enabled) to see what s happening, not just the error.

teixeluis commented 1 year ago

So they are working?

They show up as online in the Tuya cloud

Here is the debug log for the localtuya custom component:

home-assistant_2023-04-16T21-56-11.594Z_localtuya.log

alexualbu commented 1 year ago

For some reason it seems that the conection to the GW is not working. This seems specific to your setup.

Connection lost: [Errno 104] Connection reset by peer

You could try closing the Smartlife app to make sure. And presumably you have already tried v3.3 for the protocol and it s not that :)

alexualbu commented 1 year ago

@chris24walsh, @suddy can you try out 3.7.0 beta8?

teixeluis commented 1 year ago

Tested again after a while, while making sure I did not have the Tuya app running, and also not logged into the tuya developer site. The gateway is added successfully. When trying to add the sub-device, I obtain the same or similar error again. Attaching debug logs:

home_assistant_localtuya_teixeluis_18042023.log

teixeluis commented 1 year ago

Also tried with v3.3 protocol and obtain the same error.

alexualbu commented 1 year ago

@teixeluis , can you provide the logs for the 3.3 attempt too? it would be interesting to see logs from @suddy & @chris24walsh to confirm whether or not it's the same issue. @leeyuentuen, do you have any other thoughts on the Connection reset ?

leeyuentuen commented 1 year ago

@alexualbu just thinking loud, but could the connection be reset if there are too many simultaneous connections? like Tuya app, home assistant, and dev environment.

could it also be that the ZigBee gateway can't reach them?

It could also be that the config is not correctly connected to the sub-device, so we don't get an answer. It will time out and we get a connection lost/reset

alexualbu commented 1 year ago

that was my line of thinking too - but it seems that it's the same issue with SmartLife closed. @teixeluis , just for the record - presumably you don't have multiple instances of HA started or other scripts/apps connected to the GW directly. @leeyuentuen , not sure it has anything to do with sub-devices here - the connection is reset right before starting the heart beat and after the initial TCP connection is made (without any sub-devices connected). one thing you could try @teixeluis is to try tuya-cli or tinytuya just so we can exclude the fact that this has anything to do with HA & localtuya (which is my suspicion at the moment)

teixeluis commented 1 year ago

Here is also the log after setting up as API v3.3. I will later test with tuya-cli / tinytuya.

home_assistant_localtuya_teixeluis_19042023_trunc.log

alexualbu commented 1 year ago

@teixeluis, thanks - looks identical. let us know what the additional tools testing turns out.

teixeluis commented 1 year ago

@alexualbu sorry for the long delay. Finally took the time to check it out. I tried tinytuya, and sure enough it appears to successfully collect some data from both the gateway and the subdevice:

>> Saving list to devices.json
    2 registered devices saved

>> Saving raw TuyaPlatform response to tuya-raw.json

Poll local devices? (Y/n): y

Scanning local network for Tuya devices...
    1 local devices discovered

Polling local devices...
    [Bluetooth Gateway        ] 192.168.1.96       - DPS: {'38': 'off'}
    [Lockbox L1               ] Error: No IP found

>> Saving device snapshot data to snapshot.json

>> Saving IP addresses to devices.json
    1 device IP addresses found

Done.

.....

 cat tuya-raw.json
{
    "result": [
        {
            "active_time": 1680379037,
            "biz_type": 0,
            "category": "cz",
            "create_time": 1676465837,
            "icon": "smart/icon/ay1552546478455PA09B/16536201369942f47a15b.png",
            "id": "xxxxx",
            "ip": "89.214.134.133",
            "lat": "xxxxx",
            "local_key": "xxxxx",
            "lon": "xxxxx",
            "model": "CR3L\u84dd\u7259\u7f51\u5173\uff0c\u652f\u6301128\u5b50\u8bbe\u5907 ",
            "name": "Bluetooth Gateway",
            "online": true,
            "owner_id": "xxxxx",
            "product_id": "xxxxx",
            "product_name": "Bluetooth Gateway",
            "status": [],
            "sub": true,
            "time_zone": "+01:00",
            "uid": "xxxxx",
            "update_time": 1684097602,
            "uuid": "xxxxx"
        },
        {
            "active_time": 1676198914,
            "biz_type": 0,
            "category": "ms",
            "create_time": 1676198914,
            "icon": "smart/icon/bay1608116745067lxPX/c7a2317e890764c2a35ff1dd0454dbc0.jpg",
            "id": "xxxxx",
            "ip": "",
            "lat": "",
            "local_key": "xxxxx",
            "lon": "",
            "model": "",
            "name": "Lockbox L1",
            "node_id": "xxxxx",
            "online": true,
            "owner_id": "xxxxx",
            "product_id": "yxo1lldk",
            "product_name": "Lockbox L1",
            "status": [
                {
                    "code": "bluetooth_unlock",
                    "value": "xxxxx"
                },
                {
                    "code": "residual_electricity",
                    "value": 100
                },
                {
                    "code": "unlock_password",
                    "value": 0
                },
                {
                    "code": "unlock_dynamic",
                    "value": 0
                },
                {
                    "code": "unlock_ble",
                    "value": 1
                },
                {
                    "code": "alarm_lock",
                    "value": "wrong_finger"
                },
                {
                    "code": "key_tone",
                    "value": "mute"
                },
                {
                    "code": "lock_motor_state",
                    "value": false
                },
                {
                    "code": "unlock_temporary",
                    "value": 0
                }
            ],
            "sub": true,
            "time_zone": "+00:00",
            "uid": "eu16761989024734kfN3",
            "update_time": 1680379037,
            "uuid": "xxxxx"
        }
    ],
    "success": true,
    "t": 1684277598339,
    "tid": "xxxx",
    "file": {
        "name": "tuya-raw.json",
        "description": "Full raw list of Tuya devices.",
        "account": "xxxxx",
        "date": "2023-05-16T23:53:18.791962",
        "tinytuya": "1.12.7"
    }
}

Cheers

teixeluis commented 1 year ago

For example it would be very useful to capture the residual_electricity parameter as a sensor. Just learned that this lock box when it reports that the battery is at 94% it actually means it is nearly depleted :(

alexualbu commented 1 year ago

@teixeluis, the one thing I can think of right now is that maybe there is network problem between your HA host and the gateway. Did you run tinytuya from the same machine?

teixeluis commented 1 year ago

Hello @alexualbu, correct I have installed tinytuya in the same home assistant machine, and tested from there.

teixeluis commented 1 year ago

Btw the gateway I am able to successfully add in localtuya. Only the subdevice will fail to get added.

teixeluis commented 1 year ago

@alexualbu I tried again re-installing the integration (beta 10 version), and now it succeeded in installing the subdevice. It was unable to detect the DPs (as expected I guess, from your previous comment), but it allowed to manually define the following 6 DPs:

image

I have set these as sensor entities. These don't seem to work or change state however.

Anything I should be doing differently for adding these DPs?

Thanks

teixeluis commented 1 year ago

Regarding the above, I have since recreated the entities providing as DPs the ones I have found via the method of looking up the codes sent in the tuya iot platform when performing queries to the device logs.

This is what I came up with regarding the Lockin Lockbox L1:

dp_id,name
1,add unlock method
2,delete unlock method
3,modify unlock method
6,ble unlock
8,remaining battery
13,code unlock
14,dynamic unlock
19,ble unlock record
21,alarm
30,keypad volume
44,lock rtc
46,manual lock
47,lock motor state
51,add temporary code
52,delete temporary code
53,modify temporary code
54,synchronized unlock method
55,temporary code unlock
64,set t0 time of offline code
65,clear one offline code
66,delete all offline codes
67,offline code unlock

However, even after for example changing the keypad volume in the app and confirming that the event appears in the Tuya portal device logs, still nothing changes in the sensor in home assistant.

Cheers

teixeluis commented 1 year ago

@alexualbu if a subdevice is set for protocol version 3.3, does the gateway also need to be set to the same version? I currently have the gateway on version 3.4 and the subdevice on 3.3. I don't see any error logs showing up regarding this integration, and yet the entities keep showing up as unavailable.

Thanks

alexualbu commented 1 year ago

@teixeluis , the sub-device protocol really shouldn't matter (probably a slip that it's still in there)because localtuya communicate with the gateway over Tuya protocol, the gateway communicates via zigbee or BT with the sub-devices.

in your case it's unlikely that the sub-devices will work no matter how you add them - the connection with the GW gets interrupted so there is no way to get updates or control them.

teixeluis commented 1 year ago

ok, thanks for the feedback @alexualbu.

in your case it's unlikely that the sub-devices will work no matter how you add them - the connection with the GW gets interrupted so there is no way to get updates or control them.

That timeout error I have reported initially does not seem to happen as much (happened once, then I repeated the entire process and it added successfully).

Does tinytuya also communicate locally in order to obtain info from the subdevice? (it successfully obtains status info).

alexualbu commented 1 year ago

@teixeluis, if the connection does not get cut off then the status should be received. You can grab some more logs to confirm.

teixeluis commented 1 year ago

@alexualbu, yes, I get a lot of these repeatedly:

2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.common] [gateway] Connected to gateway 192.168.1.96 successfully
2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.common] [gateway] Attempting to reconnect 1 subdevices
2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.common] [gateway] Parsing subdevice ('<subdevice>', {'dps': {8: None, 1: None, 2: None, 3: None, 6: None, 13: None, 14: None, 19: None, 21: None, 30: None, 44: None, 46: None, 47: None, 51: None, 52: None, 53: None, 54: None, 55: None, 64: None, 65: None, 66: None, 67: None}, 'retry_status': False})
2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.common] [gateway] Dispatching event event_connected to sub-device <subdevice> with data None
2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.common] [gateway] Dispatch Event GW_EVT_CONNECTED <subdevice>
2023-05-21 18:01:28.445 INFO (MainThread) [custom_components.localtuya.common] [gateway] Getting status for <subdevice>
2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] 3.4 device: negotiating a new session key
2023-05-21 18:01:28.445 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] final payload for cmd 3: b'0123456789abcdef'
2023-05-21 18:01:28.446 DEBUG (SyncWorker_5) [custom_components.localtuya.common] [subdevice] Received event event_connected from gateway with data None
2023-05-21 18:01:28.448 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Command 3 waiting for sequence number -102
2023-05-21 18:01:28.454 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Dispatching message CMD 4 TuyaMessage(seqno=15143, cmd=4, retcode=0, payload=b'\xb4\xdc/\xb4\xbf!\xd2)\x0b\xcb\xce\xbc\x07\xb29+\x9d[\xcc<\xc4VKR\xf3\xb6<Q0f.\x7f\xa4V\n\xd7\xd2K\xe3\xbbw\x99J\x9d\x1fi"\xc0\xf1\xfc\xe3\x0f\xd0\x15\x1c\xa6\x02\x93\x94\x11\x90\xb7\x99\xfc', crc=b'\xc7=y>"[a|6\xedV\x11\x05\x19EZ\xc6L@E\x1bS`\xd1\x1d4\xa6\x96\x170K\xb4', crc_good=True)
2023-05-21 18:01:28.454 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Got key negotiation response
2023-05-21 18:01:28.454 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] decrypted session key negotiation step 2: payload=b'3ef69cb5d0d753a5\x14I\x11\xb7_\x87/?\xd0\xfe=\xd2\x8e8+\x8c\xc6\xf7\x8em\xef\xd0\x90&"\\\x03\xdc0\x95l\xf3'
2023-05-21 18:01:28.455 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] final payload for cmd 5: b'e\xec\xa1/n\xca\xdf\xdb\xc57Y!4R\xef\x11}\xa23\x82P\xa2\x0c\x03|\t\xb3V\x1d#?\xee'
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Session key negotiate success! session key: b'\x00\x07.=\x90}\x82_\xb6\xd2\xdaN4z\xdea'
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Sending command 16 (device type: v3.4)
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] final payload_dict for '<gateway>' ('v3.4'/'v3.4'): {1: {'command': {'gwId': '', 'devId': '', 'uid': '', 't': ''}}, 7: {'command': {'protocol': 5, 't': 'int', 'data': {}}, 'command_override': 13}, 8: {'command': {'gwId': '', 'devId': ''}}, 9: {'command': {'gwId': '', 'devId': ''}}, 10: {'command': {}, 'command_override': 16}, 13: {'command': {'protocol': 5, 't': 'int', 'data': {}}}, 16: {'command': {}}, 18: {'command': {'dpId': [18, 19, 20]}}, 64: {'command': {'reqType': '', 'data': {}}}}
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Sending payload: b'{"cid":"<subdevice>"}'
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] final payload for cmd 16: b'{"cid":"<subdevice>"}'
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Dispatching sequence number 15144
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] payload b'\x00\x00U\xaa\x00\x00;(\x00\x00\x00\x10\x00\x00\x00D\xef\xae\xe5\x8b\x15_;j\xc9\xbb\xda\x0fW\x7f\xb0][\x13iG=\xdf\x97\x91\x15,\x06\xcc\x07\xef\x1b\x91\xda"\xac\x88l\xc8(u\xb3>\xd3K\xaa\x187D5t\xb6\x02\n\x80\xcc\x0f\x01MW\xd2\\\xef+\xc7\x00\x00\xaaU' - MessagePayload(cmd=16, payload=b'{"cid":"<subdevice>"}')
2023-05-21 18:01:28.456 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Command 16 waiting for sequence number 15144
2023-05-21 18:01:28.473 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Dispatching message CMD 16 TuyaMessage(seqno=15144, cmd=16, retcode=1, payload=b'\xe2R\xd9\xda\xdd\xe2\x01\xe2a\\U"qg\xfa\x93', crc=b'\xb19\r\xfd\x9f\xd1C\xd3\xff\xbc\xb2\xd4\xd5!\xb4y\x0f\xbe\xa4p\x9f\x04\xfa\x91P\x93\x00,\xb2vY@', crc_good=True)
2023-05-21 18:01:28.474 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Dispatching sequence number 15144
2023-05-21 18:01:28.475 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] Deciphered data = 'devid not found'
2023-05-21 18:01:28.475 DEBUG (MainThread) [custom_components.localtuya.pytuya] [gateway] ERROR Invalid JSON Response from Device - 900 - payload: "devid not found"
alexualbu commented 1 year ago

@teixeluis, excellent - this is a new error.

can you confirm whether you put in the right cid/node_id in the config / UI? or did you replace the actual id in the logs?

payload=b'{"cid":"<subdevice>"}')

teixeluis commented 1 year ago

@alexualbu yes, I just obfuscated here for sharing publicly. Instead the actual id obtained is used. The same for the gateway.

alexualbu commented 1 year ago

@teixeluis, just so we completely exclude this - for the sub-device you are not using the device id, but rather the node_id?

teixeluis commented 1 year ago

Hi @alexualbu, no, I am using the sub-device ID, as can be found in the tuya developer portal, or in the "id" field in the tinytuya dump:

        {
            "active_time": 1676198914,
            "biz_type": 0,
            "category": "ms",
            "create_time": 1676198914,
            "icon": "smart/icon/bay1608116745067lxPX/c7a2317e890764c2a35ff1dd0454dbc0.jpg",
            "id": "bf3xxxxxxxxxmqj",
            "ip": "",
            "lat": "",
...

The configuration:

image

That value in the logs is consistent with the sub-device id above:

2023-05-22 23:04:35.505 DEBUG (MainThread) [custom_components.localtuya.pytuya] [bfd...gyz] payload b'\x00\x00U\xaa\x00\x00\xde\x80\x00\x00\x00\x10\x00\x00\x00Dp\xdaq/a\xf2\x05w\xbf\xcb\xd7\xe2!\xa8\xce\x92\xb2_\xe7F\n\xef<\xddj6\xc0\xcc\xb2w\xa1"\xb6\x18\x12Q\x88\x8d\xc8\xa1\xbfN#\xafW\x7f\xe9\xc7\xc6 \xf6\xd6\xc8\x0f\xdd\xd6\xc2R\xb2B\xfa\x17]\xa4\x00\x00\xaaU' - MessagePayload(cmd=16, payload=b'{"cid":"bf3xxxxxxxxxmqj"}')
alexualbu commented 1 year ago

@teixeluis , so then that's the issue - you should be using node_id for subdevices

teixeluis commented 1 year ago

oh ok, I will give that a try..

teixeluis commented 1 year ago

@alexualbu yes, now it was able to detect the dp_id 8 (battery state):

image

It doesn't seem to detect the other DP ids though (if I uncheck the box to keep adding more, it only keeps showing dp id 8 again).

But battery state is consistent with current value, which is good.