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

Logs do not contain useful info when there are low level network issues during connection configuration #1609

Closed
robinhood-code opened this issue Feb 5, 2024 · 10 comments

Comments

@robinhood-code
Copy link

This form is for reporting bugs. If you have encountered a bug, you should
generally have some log messages or device diagnostics to show something is
going wrong. If your problem is more of a question or a request for help,
then Discussions is
probably a more suitable venue.

Describe the bug
A clear and concise description of what the bug is.

Unable to add a Tuya WIFI device while Device ID, IP address, Local Key have all been specified.

To Reproduce
Steps to reproduce the behavior including the device the issue was observed with:

  1. Click "Add Device" under Local-Tuya
  2. Enter info including Device ID, IP address and Local Key
  3. After a while the error "Unable to connect to your device with those details. It could be an intermittent issue, or they may be incorrect.

Expected behavior
Device can be added.

Additional context
Add any other context about the problem here.

If the bug involves a device, then please include device diagnostics from
Settings / Devices & Services / Tuya Local (your device) / "1 device"

Please check if there are messages from Tuya Local in the Home
Assistant log (Settings / System / Logs), and include those too.

If applicable, add screenshots to help explain your problem.

image

Device is connected to the router:

image

Device is online on Tuya IOT website:

image

Device is pingable within the network:

image

Error entry in HA:

Logger: homeassistant.util.async_
Source: util/async_.py:141
First occurred: 3:21:52 PM (5 occurrences)
Last logged: 3:54:29 PM
Detected blocking call to sleep inside the event loop by custom integration 'tuya_local' at custom_components/tuya_local/device.py, line 77: self._api = tinytuya.Device(dev_id, address, local_key), please create a bug report at https://github.com/make-all/tuya-local/issues

@robinhood-code robinhood-code added the bug Something isn't working label Feb 5, 2024
@make-all make-all removed the bug Something isn't working label Feb 5, 2024
@robinhood-code robinhood-code changed the title Cannot add device (Detected blocking call to sleep inside the event loop by custom integration 'tuya_local') Cannot add device with IP address specified (Detected blocking call to sleep inside the event loop by custom integration 'tuya_local') Feb 5, 2024
@make-all
Copy link
Owner

make-all commented Feb 5, 2024

The error message you are reporting only appears when the IP address is blank or "Auto", so this log message does not match the described scenario. The connection issue is most likely covered in #522 already, or if not, can be added there when you figure out what the problem is. Possibly you are using the uuid instead of device id, or one of the other entries is not matching what it needs to be.

@make-all make-all closed this as not planned Won't fix, can't repro, duplicate, stale Feb 5, 2024
@robinhood-code
Copy link
Author

robinhood-code commented Feb 5, 2024

Thanks for the quick feedback.

It was indeed not related to Auto IP settings.

After a few trials and errors apparently there was no log generated when the error occurred so I was blind guess at the beginning.

After a while I figured I could enable the debug logging for the integration and in the debug log I found the following entry:

2024-02-05 19:00:54.642 DEBUG (SyncWorker_0) [custom_components.tuya_local.device] Test refreshed device state: {"Error": "Check device key or version", "Err": "914", "Payload": null}

from search I was brought to this issue #1576

And this was the same issue where I needed to select v3.5 instead of using Auto.

For anyone who has connection issue in the future it is worth to enable debug logging which gives you more logs to help your troubleshooting.

@robinhood-code
Copy link
Author

Just curious, why the versioning "Auto" is not a simple for loop to loop through all the versions (or after an unsuccessful attempt of guessing) and see which one works?

@make-all
Copy link
Owner

make-all commented Feb 5, 2024

It is a simple loop, which worked reasonably reliably when the common protocols were 3.1 and 3.3, but the 3.4 and 3.5 devices seem to get into funny states where they will fail for some time after a wrong protocol was tried even when the correct protocol is used.

@robinhood-code
Copy link
Author

that makes sense thanks. hopefully the error message can be improved but I know I can't be asking too much here : )

@make-all
Copy link
Owner

make-all commented Feb 5, 2024

I'm thinking to make a special case when the Device name is "Test" to output the low level messages from the tinytuya library with higher priority. The reason the network errors are debug messages is that they happen quite frequently when the tuya device is busy, and these are handled by retries so don't need to be cluttering up the log at high level.

@robinhood-code
Copy link
Author

or only during the add device process?

@make-all make-all added bug Something isn't working awaiting confirmation Wating for confirmation the issue is solved unreleased Will be in next release labels Feb 5, 2024
@make-all make-all reopened this Feb 5, 2024
@make-all make-all changed the title Cannot add device with IP address specified (Detected blocking call to sleep inside the event loop by custom integration 'tuya_local') Logs do not contain useful info when there are low level network issues during connection configuration Feb 5, 2024
@make-all
Copy link
Owner

make-all commented Feb 5, 2024

I'll hijack this report to track the log improvements.

make-all added a commit that referenced this issue Feb 5, 2024
This is already done in the receive loop, but errors were not detected
when doing a one time refresh (as in the Test connection when a device
is added - when those messages are perhaps most valuable).

Issue #1609
@make-all
Copy link
Owner

make-all commented Feb 5, 2024

Basically the warning log was there in the main receive loop, but was missing from the one-time device poll that is used during configuration.

This was due to a behaviour change in tinytuya some time back, from throwing exceptions to just reporting the errors through the json response, and I missed updating this second location.

@robinhood-code
Copy link
Author

sent you coffee to keep you awake while you're indulged in coding : )

@make-all make-all removed bug Something isn't working awaiting confirmation Wating for confirmation the issue is solved unreleased Will be in next release labels Feb 9, 2024
@make-all make-all closed this as completed Feb 9, 2024
timlaing pushed a commit to timlaing/tuya-local that referenced this issue Aug 8, 2024
This is already done in the receive loop, but errors were not detected
when doing a one time refresh (as in the Test connection when a device
is added - when those messages are perhaps most valuable).

Issue make-all#1609
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