Open jasonacox opened 5 months ago
I believe we actually want to pass the entire context to the recursion:
return self._tuyaplatform(uri, action, post, ver, True, query, content_type)
Thank you for confirming the bug and opening an issue. I did some further experimenting with changed code (passing the query to the recursion) and here's what happens:
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): openapi.tuyaeu.com:443
DEBUG:urllib3.connectionpool:https://openapi.tuyaeu.com:443 "GET /v1.0/devices/xxx/logs?end_time=1706594703065&query_type=1&size=100&start_row_key=NjFmMDhiMDRia3ppYmFhYjFlY2EzNjJmOTE4OWZiXzkyMjMzNzAzMzAyNjAyMTIyMDlfN18xMDI%3D&start_time=1706594093089&type=7 HTTP/1.1" 200 110
DEBUG:tinytuya.core:GET: URL=https://openapi.tuyaeu.com/v1.0/devices/xxx/logs?end_time=1706594703065&query_type=1&size=100&start_row_key=NjFmMDhiMDRia3ppYmFhYjFlY2EzNjJmOTE4OWZiXzkyMjMzNzAzMzAyNjAyMTIyMDlfN18xMDI%3D&start_time=1706594093089&type=7 HEADERS={'client_id': 'xxx', 'sign': 'F698D11A8DD38D20B8ED2E76517EB79E48F533B3B462611FC99C3B299CC500BD', 't': '1706594703861', 'sign_method': 'HMAC-SHA256', 'mode': 'cors', 'access_token': '09713a250341a6ae236a81017d4ec096'} response code=200 text={"code":1010,"msg":"token invalid","success":false,"t":1706594704137,"tid":"82a8bc84bf3511eea28be2dee5a60296"} token=09713a250341a6ae236a81017d4ec096
DEBUG:tinytuya.core:Token Expired - Try to renew
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): openapi.tuyaeu.com:443
DEBUG:urllib3.connectionpool:https://openapi.tuyaeu.com:443 "GET /v1.0/token?grant_type=1 HTTP/1.1" 200 235
DEBUG:tinytuya.core:GET: URL=https://openapi.tuyaeu.com/v1.0/token?grant_type=1 HEADERS={'secret': 'xxx', 'client_id': 'xxx', 'sign': '0EF6317217EE3BA5B47DA7D463405A95B3C225CCCD55CE45249D5CC6BA8FF49B', 't': '1706594704180', 'sign_method': 'HMAC-SHA256', 'mode': 'cors'} response code=200 text={"result":{"access_token":"3eac7c4bfd85de6e42825b10db346e38","expire_time":7200,"refresh_token":"ab8aecdf89cdbe5af1bba4b5afd4abf3","uid":"xxx"},"success":true,"t":1706594704467,"tid":"82d8eeebbf3511eea28be2dee5a60296"} token=None
DEBUG:tinytuya.core:server_time_offset: 0
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): openapi.tuyaeu.com:443
DEBUG:urllib3.connectionpool:https://openapi.tuyaeu.com:443 "GET /v1.0/devices/xxx/logs?end_time=1706594703065&query_type=1&size=100&start_row_key=NjFmMDhiMDRia3ppYmFhYjFlY2EzNjJmOTE4OWZiXzkyMjMzNzAzMzAyNjAyMTIyMDlfN18xMDI%3D&start_time=1706594093089&type=7 HTTP/1.1" 200 109
DEBUG:tinytuya.core:GET: URL=https://openapi.tuyaeu.com/v1.0/devices/xxx/logs?end_time=1706594703065&query_type=1&size=100&start_row_key=NjFmMDhiMDRia3ppYmFhYjFlY2EzNjJmOTE4OWZiXzkyMjMzNzAzMzAyNjAyMTIyMDlfN18xMDI%3D&start_time=1706594093089&type=7 HEADERS={'client_id': 'xxx', 'sign': 'A8621F491CB9743BAAA096439D459117DB0AC4E8F2CBFE38564E1B3D246B7650', 't': '1706594704512', 'sign_method': 'HMAC-SHA256', 'mode': 'cors', 'access_token': '3eac7c4bfd85de6e42825b10db346e38'} response code=200 text={"code":1004,"msg":"sign invalid","success":false,"t":1706594704792,"tid":"830cd60abf3511ee8eb5fe6a6f85d0cd"} token=3eac7c4bfd85de6e42825b10db346e38
I see that the retry request is now formed properly with all the query params (at first sight) but still it returns a new error now: 1004 sign invalid. If debugging the first error was kind of obvious (the URL clearly wrong), here I must admit that I'm out of my depth with all this tokens and signing stuff, so I'm afraid someone more knowledgeable will have to look at this. In my log excerpt I have replaced any potentially confidential stuff with xxx, but if I replaced anything that you need to debug please let me know.
Thanks @ndlarge - Does it ever start working again? If so, do you see anything different in the logs when it starts working?
Oh yes, on the next cron run it works as if nothing's happened, gets a new token, most of the time it succeeds to get all the fetches intact but every few hours it gets this 'token invalid' error on a random fetch, then 'sign invalid' on retry and then, as it only specifically checks for 'token invalid' to retry it just stops and returns the current response with the error. And as getdevicelog() does not do any error checking at all and just checks for has_next to loop further, it stops and returns whatever part of the full log it has. Now if only the tuya api call could be forced to return log entries in ascending time order then on the next run my script would start from the last timestamp available and cover the gap but unfortunately it returns them in descending order starting from the very last, so the first fetch contains chronologically last entries creating the gap that cannot be covered by my simple algorithm.
Hum... It may be good to change the failure logic to raise an exception then have the script start over. If that fixes it, it isn't some odd Tuya API rate limit issue, but something wrong with the token renewal logic. I haven't been able to replicate it but I'm likely not running it long enough.
if not self.token:
log.debug("Failed to renew token")
raise ValueError("Failed to renew token")
I may have time to look at it this weekend.
It happens randomly to me and so far I have not been able to find any system to it. I thought it might be because I was requesting too many fetches in too little time. Added time.sleep(1) between fetches, the errors did not go away. Then I thought it might be because I was requesting token renewals too often (every 10 minutes). I started storing the token in a file and passing the old token to Cloud(). Now the script doesn't request a token on every run but still have the errors now and then. The key question of course is why Tuya cloud would reject a perfectly good brand new token as "expired". But for the moment I guess the only thing we could realistically do on this side is improve error handling and just retry properly when it happens. I'm afraid my python skills are not quite up to the task (a week ago I did not know what it is :)
Originally posted by @ndlarge in https://github.com/jasonacox/tinytuya/discussions/452