search

MadPatrick / somfy

Tahoma/Conexoon plugin for IO blinds, this plugin require internet connexion and a Somfy account
GNU General Public License v3.0
15 stars 4 forks source link

Web version: The plugin works only few seconds then it fails with "No ListenerId has been provided" #31

Closed Chaussette23 closed 1 year ago

Chaussette23 commented 1 year ago

Hello, I used to work with older Nonolk plugin, then it seem it failed very often, so I wanted to try yours which is the most up to date. I have a Connexoon, a Somfy account, my shutters are detected and the plugin seems to works fine, but only for a very short time. I enabled debug mode and I had a look.

Here is the cleaned "somfy" log : https://pastebin.com/4hLhL1UY

Since the moment where a command fails, I get also errors in Domoticz log. I get one Python error per second (per "heartbeats" I think).

Here is one error in Domoticz log : https://pastebin.com/bSnb1buL

JanJaapKo commented 1 year ago

OK, I added something that will retry to log in when it fails at some point (it is not very clear to me why it failed at the second command while it executed the first command correctly). Can you try with version 12?

The onHeartbeat errors for the listener are a bit deceptive, as it is in fact a log in error (at least for web version).

Btw you can paste the logging in the ticket, that is a bit easier than via pastebin. Just add the logging and format it as code (with 3 times a quote around it)

Chaussette23 commented 1 year ago

Wow, thanks for the fast reply ! I got your update and played a little for 15 minutes and everything went perfectly fine on all devices...

Then, I waited for one minute and tried again and I got the same error as before and now, nothing works (unless I restart the plugin). Sorry for the log on pastebin, I copy/pasted at first but it looks like crlf weren't taken into account and so the log wasn't readable at all. I will try to do better.

2022-11-26 18:27:24,095 - DEBUG    - plugin.py          - Polling unit in 401 heartbeats.
2022-11-26 18:27:25,053 - DEBUG    - plugin.py          - Polling unit in 400 heartbeats.
2022-11-26 18:27:26,056 - DEBUG    - plugin.py          - Polling unit in 399 heartbeats.
2022-11-26 18:27:27,059 - DEBUG    - plugin.py          - Polling unit in 398 heartbeats.
2022-11-26 18:27:28,064 - DEBUG    - plugin.py          - Polling unit in 397 heartbeats.
2022-11-26 18:27:29,069 - DEBUG    - plugin.py          - Polling unit in 396 heartbeats.
2022-11-26 18:27:29,971 - DEBUG    - plugin.py          - onCommand: DeviceId: 'io://pin/device' Unit: '1', Command: 'Set Level', Level: '76', Hue: ''
2022-11-26 18:27:29,972 - DEBUG    - plugin.py          - preparing command: # commands: 2
2022-11-26 18:27:29,972 - DEBUG    - plugin.py          - preparing command: # actions_serialized: 1
2022-11-26 18:27:29,973 - DEBUG    - plugin.py          - preparing command: json data: {"actions": [{"commands": [{"name": "setClosure", "parameters": [76]}], "deviceURL": "io://pin/device"}], "label": "Domoticz device - setClosure"}
2022-11-26 18:27:29,974 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 18:13:51.924774) >= datetime.datetime.now() = True
2022-11-26 18:27:29,974 - DEBUG    - tahoma.py          - start command
2022-11-26 18:27:29,975 - INFO     - tahoma.py          - Sending command to tahoma api
2022-11-26 18:27:29,975 - DEBUG    - tahoma.py          - onCommand: headers: '{'Host': 'tahomalink.com', 'Connection': 'keep-alive', 'Accept-Encoding': 'gzip, deflate', 'Accept': '*/*', 'Content-Type': 'application/json', 'Cookie': 'JSESSIONID=...; Path=/enduser-mobile-web; Secure; HttpOnly; SameSite=None'}', data '{"actions": [{"commands": [{"name": "setClosure", "parameters": [76]}], "deviceURL": "io://pin/device"}], "label": "Domoticz device - setClosure"}'
2022-11-26 18:27:29,986 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 18:27:30,126 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/exec/apply HTTP/1.1" 401 66
2022-11-26 18:27:30,136 - DEBUG    - tahoma.py          - command response: status '401' response body: '{'errorCode': 'RESOURCE_ACCESS_DENIED', 'error': 'Not authenticated'}'
2022-11-26 18:27:30,137 - ERROR    - tahoma.py          - status code 401 authorisation failed, check credentials
2022-11-26 18:27:30,244 - DEBUG    - plugin.py          - Polling unit in 395 heartbeats.
2022-11-26 18:27:31,096 - DEBUG    - plugin.py          - Polling unit in 394 heartbeats.
2022-11-26 18:27:32,099 - DEBUG    - plugin.py          - Polling unit in 393 heartbeats.
2022-11-26 18:27:33,051 - DEBUG    - plugin.py          - Polling unit in 392 heartbeats.
2022-11-26 18:27:34,054 - DEBUG    - plugin.py          - Polling unit in 391 heartbeats.
2022-11-26 18:27:35,057 - DEBUG    - plugin.py          - Polling unit in 390 heartbeats.
2022-11-26 18:27:36,059 - DEBUG    - plugin.py          - Polling unit in 389 heartbeats.
2022-11-26 18:27:37,062 - DEBUG    - plugin.py          - Polling unit in 388 heartbeats.
2022-11-26 18:27:38,065 - DEBUG    - plugin.py          - Polling unit in 387 heartbeats.
2022-11-26 18:27:39,069 - DEBUG    - plugin.py          - Polling unit in 386 heartbeats.
2022-11-26 18:27:40,072 - DEBUG    - plugin.py          - Polling unit in 385 heartbeats.

The curious thing is, I didn't saw anything from your modification in the full logs ( "attempting to poll web version but not logged in" )

Here is the domoticz error log :

2022-11-26 18:39:26.059  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-26 18:39:26.060  Error: Somfy: Traceback (most recent call last):
2022-11-26 18:39:26.060  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 582, in onHeartbeat
2022-11-26 18:39:26.060  Error: Somfy:     _plugin.onHeartbeat()
2022-11-26 18:39:26.060  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 295, in onHeartbeat
2022-11-26 18:39:26.060  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-26 18:39:26.060  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-26 18:39:26.060  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-26 18:39:26.060  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-26 18:39:27.066  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-26 18:39:27.067  Error: Somfy: Traceback (most recent call last):
2022-11-26 18:39:27.067  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 582, in onHeartbeat
2022-11-26 18:39:27.067  Error: Somfy:     _plugin.onHeartbeat()
2022-11-26 18:39:27.067  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 295, in onHeartbeat
2022-11-26 18:39:27.067  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-26 18:39:27.067  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-26 18:39:27.067  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-26 18:39:27.067  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-26 18:39:28.074  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-26 18:39:28.075  Error: Somfy: Traceback (most recent call last):
2022-11-26 18:39:28.075  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 582, in onHeartbeat
2022-11-26 18:39:28.075  Error: Somfy:     _plugin.onHeartbeat()
2022-11-26 18:39:28.075  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 295, in onHeartbeat
2022-11-26 18:39:28.076  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-26 18:39:28.076  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-26 18:39:28.076  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-26 18:39:28.076  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-26 18:39:29.137  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-26 18:39:29.139  Error: Somfy: Traceback (most recent call last):
2022-11-26 18:39:29.139  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 582, in onHeartbeat
2022-11-26 18:39:29.139  Error: Somfy:     _plugin.onHeartbeat()
2022-11-26 18:39:29.139  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 295, in onHeartbeat
2022-11-26 18:39:29.139  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-26 18:39:29.139  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-26 18:39:29.139  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-26 18:39:29.139  Error: Somfy: exceptions.TahomaException: No listenerId has been provided

And if it can help, when I try to move a device and I get an error, the first error is a 401 return, while all next other errors are 400 errors

JanJaapKo commented 1 year ago

Hey, the "attempting to poll web version but not logged in" should come the first time the heartbeat counter is back to 0 again after the command failed (which is not in the logging so can you see if this fixed it?)

I've made a change to force the re-login on a failed command sending due to not-loggedin. Can you try this? v .13

Btw: I'm not always this prompt ;)

Chaussette23 commented 1 year ago

I searched in the full log and I found the new debug string, but it has been printed some minutes after the error. The first error with version 12 was at 18:27:29 while the first occurence of this string was at 18:34:05 :

2022-11-26 18:34:02,082 - DEBUG    - plugin.py          - Polling unit in 3 heartbeats.
2022-11-26 18:34:03,085 - DEBUG    - plugin.py          - Polling unit in 2 heartbeats.
2022-11-26 18:34:04,091 - DEBUG    - plugin.py          - Polling unit in 1 heartbeats.
2022-11-26 18:34:05,059 - DEBUG    - plugin.py          - Poll unit
2022-11-26 18:34:05,059 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = False and self.__expiry_date (2022-12-02 18:13:51.924774) >= datetime.datetime.now() = True
2022-11-26 18:34:05,060 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = False and self.__expiry_date (2022-12-02 18:13:51.924774) >= datetime.datetime.now() = True
2022-11-26 18:34:05,060 - DEBUG    - plugin.py          - attempting to poll web version but not logged in
2022-11-26 18:34:05,070 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 18:34:05,694 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/login HTTP/1.1" 200 None
2022-11-26 18:34:05,709 - DEBUG    - tahoma.py          - Login respone: status_code: '200' reponse body: '{'success': True, 'roles': [{'name': 'ENDUSER'}]}'
2022-11-26 18:34:05,709 - INFO     - tahoma.py          - Tahoma authentication succeeded, login valid until 2022-12-02 18:34:05

I will try version 13 and let you know ! In any case, thank you !

Chaussette23 commented 1 year ago

Same thing with version 13 :

After some heartbeats, it stopped working (but worked perfectly until then) :

2022-11-26 21:11:15,098 - DEBUG    - plugin.py          - Polling unit in 362 heartbeats.
2022-11-26 21:11:16,050 - DEBUG    - plugin.py          - Polling unit in 361 heartbeats.
2022-11-26 21:11:16,602 - DEBUG    - plugin.py          - onCommand: DeviceId: 'io://PIN/DEVICE' Unit: '1', Command: 'Set Level', Level: '87', Hue: ''
2022-11-26 21:11:16,606 - DEBUG    - plugin.py          - preparing command: # commands: 2
2022-11-26 21:11:16,607 - DEBUG    - plugin.py          - preparing command: # actions_serialized: 1
2022-11-26 21:11:16,609 - DEBUG    - plugin.py          - preparing command: json data: {"actions": [{"commands": [{"name": "setClosure", "parameters": [87]}], "deviceURL": "io://PIN/DEVICE"}], "label": "Domoticz - Somfy Escalier - setClosure"}
2022-11-26 21:11:16,610 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:07:18.090736) >= datetime.datetime.now() = True
2022-11-26 21:11:16,611 - DEBUG    - tahoma.py          - start command
2022-11-26 21:11:16,612 - INFO     - tahoma.py          - Sending command to tahoma api
2022-11-26 21:11:16,613 - DEBUG    - tahoma.py          - onCommand: headers: '{'Host': 'tahomalink.com', 'Connection': 'keep-alive', 'Accept-Encoding': 'gzip, deflate', 'Accept': '*/*', 'Content-Type': 'application/json', 'Cookie': 'JSESSIONID=...; Path=/enduser-mobile-web; Secure; HttpOnly; SameSite=None'}', data '{"actions": [{"commands": [{"name": "setClosure", "parameters": [87]}], "deviceURL": "io://PIN/DEVICE"}], "label": "Domoticz - setClosure"}'
2022-11-26 21:11:16,622 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:11:16,768 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/exec/apply HTTP/1.1" 401 66
2022-11-26 21:11:16,778 - DEBUG    - tahoma.py          - command response: status '401' response body: '{'errorCode': 'RESOURCE_ACCESS_DENIED', 'error': 'Not authenticated'}'
2022-11-26 21:11:16,778 - ERROR    - tahoma.py          - status code 401 authorisation failed, check credentials
2022-11-26 21:11:17,094 - DEBUG    - plugin.py          - Polling unit in 360 heartbeats.
2022-11-26 21:11:18,097 - DEBUG    - plugin.py          - Polling unit in 359 heartbeats.
2022-11-26 21:11:19,050 - DEBUG    - plugin.py          - Polling unit in 358 heartbeats.

I confirm that there was no trace of "attempting to poll web version but not logged in" at this moment.

Domoticz log after 2 failed attempts :

2022-11-26 21:11:16.779  Error: Somfy: Call to function 'onCommand' failed, exception details:
2022-11-26 21:11:16.785  Error: Somfy: Traceback (most recent call last):
2022-11-26 21:11:16.786  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 577, in onCommand
2022-11-26 21:11:16.787  Error: Somfy:     _plugin.onCommand(DeviceId, Unit, Command, Level, Color)
2022-11-26 21:11:16.787  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 266, in onCommand
2022-11-26 21:11:16.788  Error: Somfy:     self.tahoma.send_command(self.command_data)
2022-11-26 21:11:16.788  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 204, in send_command
2022-11-26 21:11:16.789  Error: Somfy:     self.handle_response(response, "send command")
2022-11-26 21:11:16.790  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 219, in handle_response
2022-11-26 21:11:16.790  Error: Somfy:     raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2022-11-26 21:11:16.791  Error: Somfy: exceptions.TahomaException: failed request during send command, check credentials: 401 
...
2022-11-26 21:14:52.526  Error: Somfy: Call to function 'onCommand' failed, exception details:
2022-11-26 21:14:52.527  Error: Somfy: Traceback (most recent call last):
2022-11-26 21:14:52.527  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 577, in onCommand
2022-11-26 21:14:52.527  Error: Somfy:     _plugin.onCommand(DeviceId, Unit, Command, Level, Color)
2022-11-26 21:14:52.527  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 266, in onCommand
2022-11-26 21:14:52.527  Error: Somfy:     self.tahoma.send_command(self.command_data)
2022-11-26 21:14:52.527  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 204, in send_command
2022-11-26 21:14:52.527  Error: Somfy:     self.handle_response(response, "send command")
2022-11-26 21:14:52.527  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 215, in handle_response
2022-11-26 21:14:52.527  Error: Somfy:     raise exceptions.TahomaException("failed request during "+ action + ", check url or body: " + str(response.status_code))
2022-11-26 21:14:52.527  Error: Somfy: exceptions.TahomaException: failed request during send command, check url or body: 400

Edit : I waited for the heartbeats to come to zero, and then I got a weird thing : it looks like it tries to log in each heartbeats with success (status 200), but I still get an error when trying to move a shutter :

...
2022-11-26 21:17:15,091 - DEBUG    - plugin.py          - Polling unit in 2 heartbeats.
2022-11-26 21:17:16,095 - DEBUG    - plugin.py          - Polling unit in 1 heartbeats.
2022-11-26 21:17:17,051 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:17,052 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = False and self.__expiry_date (2022-12-02 21:14:52.221488) >= datetime.datetime.now() = True
2022-11-26 21:17:17,053 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = False and self.__expiry_date (2022-12-02 21:14:52.221488) >= datetime.datetime.now() = True
2022-11-26 21:17:17,053 - DEBUG    - plugin.py          - attempting to poll web version but not logged in
2022-11-26 21:17:17,063 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:17,863 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/login HTTP/1.1" 200 None
2022-11-26 21:17:17,875 - DEBUG    - tahoma.py          - Login respone: status_code: '200' reponse body: '{'success': True, 'roles': [{'name': 'ENDUSER'}]}'
2022-11-26 21:17:17,875 - INFO     - tahoma.py          - Tahoma authentication succeeded, login valid until 2022-12-02 21:17:17
2022-11-26 21:17:17,876 - DEBUG    - tahoma.py          - login: cookies: '<RequestsCookieJar[<Cookie JSESSIONID=6FAD67E67BA914E97391549B58E699DE for tahomalink.com/enduser-mobile-web>]>', headers: '{'Date': 'Sat, 26 Nov 2022 20:17:17 GMT', 'Server': 'overkiz', 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains, max-age=31536000 ; includeSubDomains', 'Cache-Control': 'no-cache, no-store, max-age=0, must-revalidate', 'Pragma': 'no-cache', 'Expires': '0', 'X-XSS-Protection': '1; mode=block', 'X-Frame-Options': 'DENY', 'X-Content-Type-Options': 'nosniff', 'Content-Type': 'application/json;charset=UTF-8', 'Set-Cookie': 'JSESSIONID=6FAD67E67BA914E97391549B58E699DE; Path=/enduser-mobile-web; Secure; HttpOnly; SameSite=None', 'Keep-Alive': 'timeout=5, max=50', 'Connection': 'Keep-Alive', 'Transfer-Encoding': 'chunked'}'
2022-11-26 21:17:17,877 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:17,877 - DEBUG    - tahoma.py          - start register
2022-11-26 21:17:17,878 - DEBUG    - listener.py        - start register listener
2022-11-26 21:17:17,880 - DEBUG    - listener.py        - register request: self.headers_with_token: '{"Host": "tahomalink.com", "Connection": "keep-alive", "Accept-Encoding": "gzip, deflate", "Accept": "*/*", "Content-Type": "application/json", "Cookie": "JSESSIONID=6FAD67E67BA914E97391549B58E699DE; Path=/enduser-mobile-web; Secure; HttpOnly; SameSite=None"}'
2022-11-26 21:17:17,886 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:18,012 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/register HTTP/1.1" 200 None
2022-11-26 21:17:18,020 - DEBUG    - listener.py        - register response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:18,022 - DEBUG    - listener.py        - succeeded to get listener ID: {'id': 'b59650b3-ac10-3e01-11e7-b11a4e92fc4f'}
2022-11-26 21:17:18,123 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:18,124 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:18,124 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:18,125 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:18,125 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:18,131 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:18,264 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:18,271 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:18,273 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:19,085 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:19,091 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:19,091 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:19,092 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:19,092 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:19,109 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:19,245 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:19,252 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:19,254 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:20,057 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:20,057 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:20,058 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:20,058 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:20,058 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:20,064 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:20,189 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:20,196 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:20,198 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:21,051 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:21,054 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:21,055 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:21,056 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:21,056 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:21,068 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:21,263 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:21,279 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:21,282 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:22,089 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:22,091 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:22,092 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:22,092 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:22,093 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:22,102 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:22,260 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:22,268 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:22,270 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:23,072 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:23,073 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:23,075 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:23,075 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:23,076 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:23,082 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:23,218 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:23,226 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:23,228 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:24,081 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:24,081 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:24,082 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:24,082 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:24,083 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:24,088 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:24,260 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:24,269 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:24,271 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:25,073 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:25,074 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:25,074 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:25,075 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:25,075 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:25,081 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:25,208 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:25,216 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:25,218 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:26,070 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:26,071 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:26,072 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:26,072 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:26,072 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:26,079 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:26,214 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:26,221 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:26,223 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:27,076 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:27,077 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:27,077 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:27,078 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:27,078 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:27,084 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:27,219 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:27,229 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:27,231 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:28,085 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:28,088 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:28,088 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:28,089 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:28,089 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:28,095 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:28,224 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:28,232 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:28,234 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:29,086 - DEBUG    - plugin.py          - Poll unit
2022-11-26 21:17:29,087 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:29,087 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-02 21:17:17.875688) >= datetime.datetime.now() = True
2022-11-26 21:17:29,088 - DEBUG    - tahoma.py          - start get events
2022-11-26 21:17:29,088 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-26 21:22:18 self.__valid = True
2022-11-26 21:17:29,100 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-26 21:17:29,239 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b59650b3-ac10-3e01-11e7-b11a4e92fc4f/fetch HTTP/1.1" 200 None
2022-11-26 21:17:29,246 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-26 21:17:29,248 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-26 21:17:30,051 - DEBUG    - plugin.py          - Poll unit
...
MadPatrick commented 1 year ago

What is the refresh interval? For the web connection you can set the refresh interval too short. If you set it to 1 sec the somfy portal can block you for a period.

Chaussette23 commented 1 year ago

Yes, I saw your recommendations on this subject and so it's set to "10m".

MadPatrick commented 1 year ago

You can set in to 1 min or 20 sec when you are testing. The Somfy portal is a bit buggy and often the conntection is refused of not working

Chaussette23 commented 1 year ago

Yes, I understand this but as everything works as expected at the beginning : connection if set, shutters are working properly, etc. I thought it would be OK. I will lower this value and see what's happening.

As I saw that Tahoma box can now be used with a local API and stop depending on Somfy's server, I'm thinking on upgrading... However, I saw that there is the "normal" Tahoma box and there is a "Tahoma switch" box. Both are working fine in "local network mode" ?

MadPatrick commented 1 year ago

I have the "Normal" Tahoma box myself and this working very good in local mode. No experience with the new "Tahoma switch" box. Maybe there are users with this box and using the plugin

Chaussette23 commented 1 year ago

Ok thank you for the information.

I'm currently checking the Python code (as I'm a C/C++ programmer, I still understand things, more or less). I have the feeling that there is a problem in the refresh loop. I changed the refresh interval to one minute, to check. I cleaned all logs and restarted. However, I didn't sent any commands. I just started the Somfy plugin and nothing else. After one minute, the polling unit starts a new connection to "tahomalink.com:443", the reply is 200, and... while I was expecting to see again :

In fact, I see that the plugin starts a new connection each seconds (heartbeat) :

2022-11-27 10:21:11,140 - INFO     - plugin.py          - starting plugin version 4.1.11
2022-11-27 10:21:11,141 - INFO     - plugin.py          - Starting version: 4.1.11
2022-11-27 10:21:11,142 - DEBUG    - plugin.py          - checking versions: current '4.1.11', config '4.1.11'
2022-11-27 10:21:11,143 - DEBUG    - plugin.py          - starting to log in with mode Web
2022-11-27 10:21:11,143 - DEBUG    - listener.py        - listener created
2022-11-27 10:21:11,158 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-27 10:21:11,876 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/login HTTP/1.1" 200 None
2022-11-27 10:21:11,887 - DEBUG    - tahoma.py          - Login respone: status_code: '200' reponse body: '{'success': True, 'roles': [{'name': 'ENDUSER'}]}'
2022-11-27 10:21:11,888 - INFO     - tahoma.py          - Tahoma authentication succeeded, login valid until 2022-12-03 10:21:11
[... starting of the script, devices found on Tahoma accoung and in Domoticz... ]
2022-11-27 10:21:12,285 - DEBUG    - tahoma.py          - start get events
2022-11-27 10:21:12,286 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-27 10:26:12 self.__valid = True
2022-11-27 10:21:12,292 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-27 10:21:12,418 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b863ff56-ac10-3e01-11e7-b11a685785a7/fetch HTTP/1.1" 200 None
2022-11-27 10:21:12,425 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-27 10:21:12,429 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-27 10:21:12,530 - DEBUG    - plugin.py          - Polling unit in 59 heartbeats.
2022-11-27 10:21:13,086 - DEBUG    - plugin.py          - Polling unit in 58 heartbeats.
2022-11-27 10:21:14,094 - DEBUG    - plugin.py          - Polling unit in 57 heartbeats.
...
2022-11-27 10:22:07,083 - DEBUG    - plugin.py          - Polling unit in 4 heartbeats.
2022-11-27 10:22:08,087 - DEBUG    - plugin.py          - Polling unit in 3 heartbeats.
2022-11-27 10:22:09,090 - DEBUG    - plugin.py          - Polling unit in 2 heartbeats.
2022-11-27 10:22:10,094 - DEBUG    - plugin.py          - Polling unit in 1 heartbeats.
2022-11-27 10:22:11,097 - DEBUG    - plugin.py          - Poll unit
2022-11-27 10:22:11,101 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:11,102 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:11,103 - DEBUG    - tahoma.py          - start get events
2022-11-27 10:22:11,104 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-27 10:26:12 self.__valid = True
2022-11-27 10:22:11,114 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-27 10:22:11,246 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b863ff56-ac10-3e01-11e7-b11a685785a7/fetch HTTP/1.1" 200 None
2022-11-27 10:22:11,256 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-27 10:22:11,259 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-27 10:22:12,061 - DEBUG    - plugin.py          - Poll unit
2022-11-27 10:22:12,063 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:12,065 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:12,065 - DEBUG    - tahoma.py          - start get events
2022-11-27 10:22:12,066 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-27 10:26:12 self.__valid = True
2022-11-27 10:22:12,072 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-27 10:22:12,200 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b863ff56-ac10-3e01-11e7-b11a685785a7/fetch HTTP/1.1" 200 None
2022-11-27 10:22:12,208 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-27 10:22:12,210 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-27 10:22:13,062 - DEBUG    - plugin.py          - Poll unit
2022-11-27 10:22:13,063 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:13,064 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:13,065 - DEBUG    - tahoma.py          - start get events
2022-11-27 10:22:13,066 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-27 10:26:12 self.__valid = True
2022-11-27 10:22:13,073 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-27 10:22:13,209 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b863ff56-ac10-3e01-11e7-b11a685785a7/fetch HTTP/1.1" 200 None
2022-11-27 10:22:13,217 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-27 10:22:13,220 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-27 10:22:14,085 - DEBUG    - plugin.py          - Poll unit
2022-11-27 10:22:14,087 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:14,088 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-03 10:21:11.887827) >= datetime.datetime.now() = True
2022-11-27 10:22:14,090 - DEBUG    - tahoma.py          - start get events
2022-11-27 10:22:14,091 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-27 10:26:12 self.__valid = True
2022-11-27 10:22:14,101 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-27 10:22:14,252 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/b863ff56-ac10-3e01-11e7-b11a685785a7/fetch HTTP/1.1" 200 None
2022-11-27 10:22:14,262 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-27 10:22:14,264 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
[... it continues like this indefinitely ...]

I have the feeling that a variable is not reset or something like that. However, I also have the feeling that it may not be relevant to my problem... In Domoticz, I get corresponding errors each seconds also :


2022-11-27 10:17:27.080  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-27 10:17:27.081  Error: Somfy: Traceback (most recent call last):
2022-11-27 10:17:27.081  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-27 10:17:27.081  Error: Somfy:     _plugin.onHeartbeat()
2022-11-27 10:17:27.081  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-27 10:17:27.081  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-27 10:17:27.081  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-27 10:17:27.081  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-27 10:17:27.081  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-27 10:17:28.086  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-27 10:17:28.089  Error: Somfy: Traceback (most recent call last):
2022-11-27 10:17:28.089  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-27 10:17:28.090  Error: Somfy:     _plugin.onHeartbeat()
2022-11-27 10:17:28.091  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-27 10:17:28.091  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-27 10:17:28.092  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-27 10:17:28.093  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-27 10:17:28.093  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-27 10:17:29.102  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-27 10:17:29.105  Error: Somfy: Traceback (most recent call last):
2022-11-27 10:17:29.105  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-27 10:17:29.105  Error: Somfy:     _plugin.onHeartbeat()
2022-11-27 10:17:29.106  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-27 10:17:29.106  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-27 10:17:29.106  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-27 10:17:29.106  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-27 10:17:29.106  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-27 10:17:30.060  Error: Somfy: Call to function 'onHeartbeat' failed, exception details:
2022-11-27 10:17:30.061  Error: Somfy: Traceback (most recent call last):
2022-11-27 10:17:30.061  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-27 10:17:30.061  Error: Somfy:     _plugin.onHeartbeat()
2022-11-27 10:17:30.061  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-27 10:17:30.061  Error: Somfy:     event_list = self.tahoma.get_events()
2022-11-27 10:17:30.061  Error: Somfy:   File "/home/domoticz/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-27 10:17:30.061  Error: Somfy:     raise exceptions.TahomaException("No listenerId has been provided")
2022-11-27 10:17:30.061  Error: Somfy: exceptions.TahomaException: No listenerId has been provided
2022-11-27 10:17:30.373  Status: Somfy: Stop directive received.
2022-11-27 10:17:30.635  Status: Somfy: Exiting work loop.
2022-11-27 10:17:30.673  Status: Somfy: Stopping threads.
2022-11-27 10:17:30.674  Status: Somfy: Stopped.
Abidos14 commented 1 year ago

Hi,

Same behaviour for me and mixed with issue #29 about Connexoon not udpdating (hope I should not have created a new issue). Once the plugin is started, everything seems to be OK for a while. Even if blind status does not udpdate in domoticz.

Then the following errors appear in domoticz's logs :

2022-11-28 10:56:17.229 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception  details:
2022-11-28 10:56:17.232 Error: Volets roulants: Traceback (most recent call last):
2022-11-28 10:56:17.232 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-28 10:56:17.232 Error: Volets roulants: event_list = self.tahoma.get_events()
2022-11-28 10:56:17.232 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 130, in get_events
2022-11-28 10:56:17.232 Error: Volets roulants: raise exceptions.NoListenerFailure()
2022-11-28 10:56:17.232 Error: Volets roulants: exceptions.NoListenerFailure: Trying to fetch events without listener registered
2022-11-28 10:56:17.232 Error: Volets roulants:
2022-11-28 10:56:17.232 Error: Volets roulants: During handling of the above exception, another exception occurred:
2022-11-28 10:56:17.232 Error: Volets roulants:
2022-11-28 10:56:17.232 Error: Volets roulants: Traceback (most recent call last):
2022-11-28 10:56:17.232 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-28 10:56:17.232 Error: Volets roulants: _plugin.onHeartbeat()
2022-11-28 10:56:17.232 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 304, in onHeartbeat
2022-11-28 10:56:17.232 Error: Volets roulants: self.tahoma.register_listener() #register a new listener
2022-11-28 10:56:17.232 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 165, in register_listener
2022-11-28 10:56:17.232 Error: Volets roulants: raise exceptions.TahomaException("Not logged in")
2022-11-28 10:56:17.232 Error: Volets roulants: exceptions.TahomaException: Not logged in```

Then things still seem to be OK. Later on, I get :

2022-11-28 11:23:23.067 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception details:
2022-11-28 11:23:23.068 Error: Volets roulants: Traceback (most recent call last):
2022-11-28 11:23:23.068 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-28 11:23:23.068 Error: Volets roulants: _plugin.onHeartbeat()
2022-11-28 11:23:23.068 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-28 11:23:23.068 Error: Volets roulants: event_list = self.tahoma.get_events()
2022-11-28 11:23:23.068 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-28 11:23:23.068 Error: Volets roulants: raise exceptions.TahomaException("No listenerId has been provided")
2022-11-28 11:23:23.068 Error: Volets roulants: exceptions.TahomaException: No listenerId has been provided
2022-11-28 11:23:24.070 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception details:
2022-11-28 11:23:24.071 Error: Volets roulants: Traceback (most recent call last):
2022-11-28 11:23:24.071 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-28 11:23:24.071 Error: Volets roulants: _plugin.onHeartbeat()
2022-11-28 11:23:24.071 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-28 11:23:24.071 Error: Volets roulants: event_list = self.tahoma.get_events()
2022-11-28 11:23:24.071 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-28 11:23:24.071 Error: Volets roulants: raise exceptions.TahomaException("No listenerId has been provided")
2022-11-28 11:23:24.071 Error: Volets roulants: exceptions.TahomaException: No listenerId has been provided
2022-11-28 11:23:25.074 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception details:
2022-11-28 11:23:25.074 Error: Volets roulants: Traceback (most recent call last):
2022-11-28 11:23:25.074 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat
2022-11-28 11:23:25.074 Error: Volets roulants: _plugin.onHeartbeat()
2022-11-28 11:23:25.074 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 298, in onHeartbeat
2022-11-28 11:23:25.074 Error: Volets roulants: event_list = self.tahoma.get_events()
2022-11-28 11:23:25.074 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 114, in get_events
2022-11-28 11:23:25.074 Error: Volets roulants: raise exceptions.TahomaException("No listenerId has been provided")

From then on , any action (either from scripts or manually in domoticz) is useless : the plugin needs to be restarted to work.

Plugin logs somfy.log

Device : rpi OS : Buster Dz version : 2022.2.

JanJaapKo commented 1 year ago

I have the feeling that a variable is not reset or something like that. However, I also have the feeling that it may not be relevant to my problem....

Well spotted, I forgot to reset the heartbeat forcing... Is in per v 14.

Using that one, can you check what's going on? Hopefully that clears up a lot of the logging mess.

Btw: if you have some experience in C++, Python is quite a nice language to dive into. They've taken OO to the max: everything is an object. Quite nice and clean. And debugging is fantastic as you do not need to compile.

Chaussette23 commented 1 year ago

Hello,

Yeah, I will have a look at Python, I just need to take the time to do it... not so simple...

I updated, I'm on version 15. Things seems to improve : I can now move all my shutters and it seems that it still works after the first poll unit count down ! However, I still get a connection for each heartbeat after the first count down :

[...]
2022-11-28 21:11:55,100 - DEBUG    - plugin.py          - Polling unit in 4 heartbeats.
2022-11-28 21:11:56,053 - DEBUG    - plugin.py          - Polling unit in 3 heartbeats.
2022-11-28 21:11:57,056 - DEBUG    - plugin.py          - Polling unit in 2 heartbeats.
2022-11-28 21:11:58,059 - DEBUG    - plugin.py          - Polling unit in 1 heartbeats.
2022-11-28 21:11:59,062 - DEBUG    - plugin.py          - Poll unit
2022-11-28 21:11:59,063 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:11:59,063 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:11:59,064 - DEBUG    - tahoma.py          - start get events
2022-11-28 21:11:59,065 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-28 21:16:50 self.__valid = True
2022-11-28 21:11:59,074 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-28 21:11:59,248 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/bfd99c87-ac10-3e01-11e7-b11ac84030fe/fetch HTTP/1.1" 200 None
2022-11-28 21:11:59,260 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-28 21:11:59,262 - DEBUG    - tahoma.py          - get_events: add event: URL: 'io://...' num states: '2'
2022-11-28 21:11:59,263 - DEBUG    - tahoma.py          - get_events: add event: URL: 'io://...' num states: '2'
2022-11-28 21:11:59,263 - DEBUG    - tahoma.py          - get_events: add event: URL: 'io://...' num states: '2'
2022-11-28 21:11:59,264 - DEBUG    - plugin.py          - updating device status self.tahoma.startup = False on num datasets: 3
2022-11-28 21:11:59,265 - DEBUG    - plugin.py          - updating device status on data: [{'timestamp': 1669666311191, 'setupOID': [...]
2022-11-28 21:11:59,265 - DEBUG    - plugin.py          - checking device updates for 3 filtered events
2022-11-28 21:11:59,266 - DEBUG    - plugin.py          - checking dataset: {'timestamp': 1669666311191, 'setupOID': [...]
2022-11-28 21:11:59,266 - DEBUG    - plugin.py          - checking dataset: {'timestamp': 1669666312569, 'setupOID': [...]
2022-11-28 21:11:59,269 - INFO     - plugin.py          - Updating device:Somfy
2022-11-28 21:11:59,290 - DEBUG    - plugin.py          - checking dataset: {'timestamp': 1669666313738, 'setupOID': [...]
2022-11-28 21:11:59,291 - INFO     - plugin.py          - Updating device:Somfy
2022-11-28 21:12:00,072 - DEBUG    - plugin.py          - Poll unit
2022-11-28 21:12:00,081 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:00,082 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:00,083 - DEBUG    - tahoma.py          - start get events
2022-11-28 21:12:00,084 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-28 21:16:59 self.__valid = True
2022-11-28 21:12:00,127 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-28 21:12:00,290 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/bfd99c87-ac10-3e01-11e7-b11ac84030fe/fetch HTTP/1.1" 200 None
2022-11-28 21:12:00,300 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-28 21:12:00,303 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-28 21:12:01,056 - DEBUG    - plugin.py          - Poll unit
2022-11-28 21:12:01,057 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:01,057 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:01,058 - DEBUG    - tahoma.py          - start get events
2022-11-28 21:12:01,059 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-28 21:16:59 self.__valid = True
2022-11-28 21:12:01,065 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-28 21:12:01,195 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/bfd99c87-ac10-3e01-11e7-b11ac84030fe/fetch HTTP/1.1" 200 None
2022-11-28 21:12:01,203 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-28 21:12:01,206 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-28 21:12:02,058 - DEBUG    - plugin.py          - Poll unit
2022-11-28 21:12:02,059 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:02,060 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:02,060 - DEBUG    - tahoma.py          - start get events
2022-11-28 21:12:02,061 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-28 21:16:59 self.__valid = True
2022-11-28 21:12:02,067 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-28 21:12:02,219 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/bfd99c87-ac10-3e01-11e7-b11ac84030fe/fetch HTTP/1.1" 200 None
2022-11-28 21:12:02,227 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-28 21:12:02,230 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-28 21:12:03,082 - DEBUG    - plugin.py          - Poll unit
2022-11-28 21:12:03,083 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:03,084 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-04 21:07:00.356803) >= datetime.datetime.now() = True
2022-11-28 21:12:03,084 - DEBUG    - tahoma.py          - start get events
[... etc. ...]
Tatroxitum commented 1 year ago

Same here after a git pull : On startup ok, then one command ok, then on heartbeat ko : status: 401, {"errorCode":"RESOURCE_ACCESS_DENIED","error":"Not authenticated"} somfy.log

Update : despite heartbeat is ko, all commands sent after works.

Abidos14 commented 1 year ago

Hello,

I pulled version 15. Plugin started with reset of token, then stopped, set reset token on false and started again.

Things seem to improve a little : plugin works longer. However, I finally get the following errors in domoticz :

022-11-29 09:45:26.638 Status: EventSystem: reset all device statuses... 
2022-11-29 09:46:17.054 Status: User: Admin (IP: 192.XX.XXX.XXX) initiated a switch command (812/Volets roulants - Chambre 1/Set Level) 
2022-11-29 09:46:17.220 Error: Volets roulants: Call to function 'onCommand' failed, exception details: 
2022-11-29 09:46:17.221 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 09:46:17.221 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 577, in onCommand 
2022-11-29 09:46:17.221 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color) 
2022-11-29 09:46:17.221 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand 
2022-11-29 09:46:17.221 Error: Volets roulants: self.tahoma.send_command(self.command_data) 
2022-11-29 09:46:17.221 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command 
2022-11-29 09:46:17.221 Error: Volets roulants: self.handle_response(response, "send command") 
2022-11-29 09:46:17.221 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 219, in handle_response 
2022-11-29 09:46:17.221 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code)) 
2022-11-29 09:46:17.221 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check credentials: 401 
2022-11-29 09:46:50.879 Status: User: Admin (IP: 192.XX.XXX.XXX) initiated a switch command (812/Volets roulants - Chambre 1/Set Level) 
2022-11-29 09:46:51.972 Error: Volets roulants: Call to function 'onCommand' failed, exception details: 
2022-11-29 09:46:51.973 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 09:46:51.973 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 577, in onCommand 
2022-11-29 09:46:51.973 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color) 
2022-11-29 09:46:51.973 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand 
2022-11-29 09:46:51.973 Error: Volets roulants: self.tahoma.send_command(self.command_data) 
2022-11-29 09:46:51.973 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command 
2022-11-29 09:46:51.973 Error: Volets roulants: self.handle_response(response, "send command") 
2022-11-29 09:46:51.973 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 215, in handle_response 
2022-11-29 09:46:51.973 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check url or body: " + str(response.status_code)) 
2022-11-29 09:46:51.973 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check url or body: 400 
2022-11-29 09:46:52.530 Status: User: Admin (IP: 192.XX.XXX.XXX) initiated a switch command (812/Volets roulants - Chambre 1/Set Level) 
2022-11-29 09:46:53.194 Status: User: Admin (IP: 192.XX.XXX.XXX) initiated a switch command (812/Volets roulants - Chambre 1/Set Level) 
2022-11-29 09:46:53.365 Error: Volets roulants: Call to function 'onCommand' failed, exception details: 
2022-11-29 09:46:53.366 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 09:46:53.366 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 577, in onCommand 
2022-11-29 09:46:53.366 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color) 
2022-11-29 09:46:53.366 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand 
2022-11-29 09:46:53.366 Error: Volets roulants: self.tahoma.send_command(self.command_data) 
2022-11-29 09:46:53.366 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command 
2022-11-29 09:46:53.366 Error: Volets roulants: self.handle_response(response, "send command") 
2022-11-29 09:46:53.366 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 215, in handle_response 
2022-11-29 09:46:53.366 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check url or body: " + str(response.status_code)) 
2022-11-29 09:46:53.366 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check url or body: 400 
2022-11-29 09:46:54.165 Error: Volets roulants: Call to function 'onCommand' failed, exception details: 
2022-11-29 09:46:54.166 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 09:46:54.166 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 577, in onCommand 
2022-11-29 09:46:54.166 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color) 
2022-11-29 09:46:54.166 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand 
2022-11-29 09:46:54.166 Error: Volets roulants: self.tahoma.send_command(self.command_data) 
2022-11-29 09:46:54.166 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command 
2022-11-29 09:46:54.166 Error: Volets roulants: self.handle_response(response, "send command") 
2022-11-29 09:46:54.166 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 215, in handle_response 
2022-11-29 09:46:54.166 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check url or body: " + str(response.status_code)) 
2022-11-29 09:46:54.166 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check url or body: 400 

2022-11-29 10:00:57.094 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception details: 
2022-11-29 10:00:57.095 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 10:00:57.095 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 585, in onHeartbeat 
2022-11-29 10:00:57.095 Error: Volets roulants: _plugin.onHeartbeat() 
2022-11-29 10:00:57.096 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 299, in onHeartbeat 
2022-11-29 10:00:57.096 Error: Volets roulants: event_list = self.tahoma.get_events() 
2022-11-29 10:00:57.096 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 114, in get_events 
2022-11-29 10:00:57.096 Error: Volets roulants: raise exceptions.TahomaException("No listenerId has been provided") 
2022-11-29 10:00:57.096 Error: Volets roulants: exceptions.TahomaException: No listenerId has been provided 

2022-11-29 10:10:26.919 Status: User: Admin (IP: 192.XX.XXX.XXX) initiated a switch command (815/Volets roulants - Chambre 3/Set Level) 
2022-11-29 10:10:27.127 Error: Volets roulants: Call to function 'onCommand' failed, exception details: 
2022-11-29 10:10:27.127 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 10:10:27.127 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 577, in onCommand 
2022-11-29 10:10:27.127 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color) 
2022-11-29 10:10:27.127 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand 
2022-11-29 10:10:27.127 Error: Volets roulants: self.tahoma.send_command(self.command_data) 
2022-11-29 10:10:27.127 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command 
2022-11-29 10:10:27.127 Error: Volets roulants: self.handle_response(response, "send command") 
2022-11-29 10:10:27.127 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 219, in handle_response 
2022-11-29 10:10:27.127 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code)) 
2022-11-29 10:10:27.127 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check credentials: 401 
2022-11-29 10:10:57.605 Status: User: Admin (IP: 192.XX.XXX.XXX) initiated a switch command (812/Volets roulants - Chambre 1/Set Level) 
2022-11-29 10:10:57.944 Error: Volets roulants: Call to function 'onCommand' failed, exception details: 
2022-11-29 10:10:57.945 Error: Volets roulants: Traceback (most recent call last): 
2022-11-29 10:10:57.945 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 577, in onCommand 
2022-11-29 10:10:57.945 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color) 
2022-11-29 10:10:57.945 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand 
2022-11-29 10:10:57.945 Error: Volets roulants: self.tahoma.send_command(self.command_data) 
2022-11-29 10:10:57.945 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command 
2022-11-29 10:10:57.945 Error: Volets roulants: self.handle_response(response, "send command") 
2022-11-29 10:10:57.945 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 215, in handle_response 
2022-11-29 10:10:57.945 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check url or body: " + str(response.status_code)) 
2022-11-29 10:10:57.945 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check url or body: 400

Plugin logs somfy.log

Concerning blind position update with Connexoon in domoticz, it still does'nt work properly : when it does update, it most often indicates not the last blind position but the previous one. eg. : blind is fully open. I set it to 70% in dz. Blind moves to 70%. But position is still 100% in dz. If I set position to 60%, the blinds moves to 60% and position in dz is updated to 70%.

JanJaapKo commented 1 year ago

OK, I'll first try to solve the issue with the errors, that is more urgent I think. Can someone retry with v16?

Chaussette23 commented 1 year ago

Hello,

I tried with version 16 but the behavior is the same as previously. The connection is OK, the first heartbeats countdown goes fine, commands are sent and executed correctly, but after the first countdown, the plugin connects on each heartbeat :

2022-11-29 21:47:35,094 - DEBUG    - tahoma.py          - start get events
2022-11-29 21:47:35,094 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-29 21:51:34 self.__valid = True
2022-11-29 21:47:35,101 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-29 21:47:35,233 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/c52434e6-ac10-3e01-11e7-b11aa607f8c6/fetch HTTP/1.1" 200 None
2022-11-29 21:47:35,241 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-29 21:47:35,243 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-29 21:47:36,096 - DEBUG    - plugin.py          - Poll unit
2022-11-29 21:47:36,097 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-05 21:46:35.110337) >= datetime.datetime.now() = True
2022-11-29 21:47:36,098 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-29 21:51:34 self.__valid = True
2022-11-29 21:47:36,099 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-05 21:46:35.110337) >= datetime.datetime.now() = True
2022-11-29 21:47:36,100 - DEBUG    - tahoma.py          - start get events
2022-11-29 21:47:36,101 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-29 21:51:34 self.__valid = True
2022-11-29 21:47:36,110 - DEBUG    - connectionpool.py  - Starting new HTTPS connection (1): tahomalink.com:443
2022-11-29 21:47:36,242 - DEBUG    - connectionpool.py  - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/c52434e6-ac10-3e01-11e7-b11aa607f8c6/fetch HTTP/1.1" 200 None
2022-11-29 21:47:36,250 - DEBUG    - tahoma.py          - get events response: status '200' response body: '<Response [200]>'
2022-11-29 21:47:36,252 - DEBUG    - tahoma.py          - get_events: no DeviceStateChangedEvent found in response: []
2022-11-29 21:47:37,054 - DEBUG    - plugin.py          - Poll unit
2022-11-29 21:47:37,055 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-05 21:46:35.110337) >= datetime.datetime.now() = True
2022-11-29 21:47:37,055 - DEBUG    - listener.py        - listener vald: self.__listener_expiry = 2022-11-29 21:51:34 self.__valid = True
2022-11-29 21:47:37,056 - DEBUG    - tahoma.py          - checking logged in status: self.__logged_in = True and self.__expiry_date (2022-12-05 21:46:35.110337) >= datetime.datetime.now() = True
2022-11-29 21:47:37,056 - DEBUG    - tahoma.py          - start get events

While this happen, command are still working.

Tatroxitum commented 1 year ago

I've got this same only on launch 2022-11-29 21:46:20,475 - DEBUG - plugin.py - create_devices: finished create devices 2022-11-29 21:46:20,476 - DEBUG - tahoma.py - start get events 2022-11-29 21:46:20,476 - DEBUG - listener.py - listener vald: self.__listener_expiry = 2022-11-29 21:50:20 self.__valid = True 2022-11-29 21:46:20,481 - DEBUG - connectionpool.py - Starting new HTTPS connection (1): tahomalink.com:443 2022-11-29 21:46:20,572 - DEBUG - connectionpool.py - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/XxxxX/fetch HTTP/1.1" 200 None 2022-11-29 21:46:20,579 - DEBUG - tahoma.py - get events response: status '200' response body: '<Response [200]>' 2022-11-29 21:46:20,582 - DEBUG - tahoma.py - get_events: no DeviceStateChangedEvent found in response: [] 2022-11-29 21:46:20,683 - DEBUG - plugin.py - Polling unit in 299 heartbeats. 2022-11-29 21:46:21,084 - DEBUG - plugin.py - Polling unit in 298 heartbeats.

Then on first polling (5min) : 2022-11-29 21:51:18,068 - DEBUG - plugin.py - Polling unit in 1 heartbeats. 2022-11-29 21:51:19,073 - DEBUG - plugin.py - Poll unit 2022-11-29 21:51:19,079 - DEBUG - tahoma.py - checking logged in status: self.logged_in = True and self.__expiry_date (2022-12-05 21:46:20.186694) >= datetime.datetime.now() = True 2022-11-29 21:51:19,080 - DEBUG - listener.py - listener vald: self.listener_expiry = 2022-11-29 21:50:20 self.__valid = False 2022-11-29 21:51:19,081 - DEBUG - tahoma.py - start register 2022-11-29 21:51:19,081 - DEBUG - listener.py - start register listener 2022-11-29 21:51:19,083 - DEBUG - listener.py - register request: self.headers_with_token: '{"Host": "tahomalink.com", "Connection": "keep-alive", "Accept-Encoding": "gzip, deflate", "Accept": "/", "Content-Type": "application/json", "Cookie": "JSESSIONID=XxxxX; Path=/enduser-mobile-web; Secure; HttpOnly; SameSite=None"}' 2022-11-29 21:51:19,094 - DEBUG - connectionpool.py - Starting new HTTPS connection (1): tahomalink.com:443 2022-11-29 21:51:19,243 - DEBUG - connectionpool.py - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/register HTTP/1.1" 401 66 2022-11-29 21:51:19,250 - DEBUG - listener.py - register response: status '401' response body: '<Response [401]>' 2022-11-29 21:51:19,252 - ERROR - utils.py - status code 401 authorisation failed, check credentials 2022-11-29 21:51:20,061 - DEBUG - plugin.py - Polling unit in 299 heartbeats.

I'v restarted domoticz before testing this version, maybe this explains why I do not have the same behaviour

Chaussette23 commented 1 year ago

I may have found something and I need your Python and plugin experience on this. Can you check "plugin.py" line 313 ? I think a tab is missing. Without this tab, the "heartbeat" is always set to 1 and so discard the polling countdown afterward. I think this "heartbeat force" is only necessary when a device has events to be updated. Can you confirm ?

                if event_list is not None and len(event_list) > 0:
                    self.update_devices_status(event_list)
                self.heartbeat = True

Should become :

                if event_list is not None and len(event_list) > 0:
                    self.update_devices_status(event_list)
                    self.heartbeat = True

?

Edit : seems to work as expected with this change.

Tatroxitum commented 1 year ago

I'm not sure about this change, without it I do not have the problem you mentionned.

JanJaapKo commented 1 year ago

Looking at it, I wonder if that line could also just be removed. Let's first see how it goes now....

Tatroxitum commented 1 year ago

Same behavior : on polling : 2022-11-29 22:49:15,087 - DEBUG - plugin.py - Poll unit 2022-11-29 22:49:15,088 - DEBUG - tahoma.py - checking logged in status: self.logged_in = True and self.__expiry_date (2022-12-05 22:44:16.405107) >= datetime.datetime.now() = True 2022-11-29 22:49:15,089 - DEBUG - listener.py - listener vald: self.listener_expiry = 2022-11-29 22:48:16 self.__valid = False 2022-11-29 22:49:15,091 - DEBUG - tahoma.py - start register 2022-11-29 22:49:15,092 - DEBUG - listener.py - start register listener 2022-11-29 22:49:15,093 - DEBUG - listener.py - register request: self.headers_with_token: '{"Host": "tahomalink.com", "Connection": "keep-alive", "Accept-Encoding": "gzip, deflate", "Accept": "/", "Content-Type": "application/json", "Cookie": "JSESSIONID=XxxxX; Path=/enduser-mobile-web; Secure; HttpOnly; SameSite=None"}' 2022-11-29 22:49:15,104 - DEBUG - connectionpool.py - Starting new HTTPS connection (1): tahomalink.com:443 2022-11-29 22:49:15,280 - DEBUG - connectionpool.py - https://tahomalink.com:443 "POST /enduser-mobile-web/enduserAPI/events/register HTTP/1.1" 401 66 2022-11-29 22:49:15,288 - DEBUG - listener.py - register response: status '401' response body: '<Response [401]>' 2022-11-29 22:49:15,290 - ERROR - utils.py - status code 401 authorisation failed, check credentials 2022-11-29 22:49:16,051 - DEBUG - plugin.py - Polling unit in 299 heartbeats.

Abidos14 commented 1 year ago

Hello,

I pulled version 17.

Things improved. Indeed, scripts and manual commands in domoticz have been working for me for more than 30 mn !!

I only get the following message every 5 minutes, id for each polling :


2022-11-30` 10:03:32.224 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception details:
2022-11-30 10:03:32.225 Error: Volets roulants: Traceback (most recent call last):
2022-11-30 10:03:32.225 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 301, in onHeartbeat
2022-11-30 10:03:32.225 Error: Volets roulants: event_list = self.tahoma.get_events()
2022-11-30 10:03:32.225 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 130, in get_events
2022-11-30 10:03:32.225 Error: Volets roulants: raise exceptions.NoListenerFailure()
2022-11-30 10:03:32.225 Error: Volets roulants: exceptions.NoListenerFailure: Trying to fetch events without listener registered
2022-11-30 10:03:32.225 Error: Volets roulants:
2022-11-30 10:03:32.225 Error: Volets roulants: During handling of the above exception, another exception occurred:
2022-11-30 10:03:32.225 Error: Volets roulants:
2022-11-30 10:03:32.225 Error: Volets roulants: Traceback (most recent call last):
2022-11-30 10:03:32.225 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 590, in onHeartbeat
2022-11-30 10:03:32.225 Error: Volets roulants: _plugin.onHeartbeat()
2022-11-30 10:03:32.225 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 307, in onHeartbeat
2022-11-30 10:03:32.225 Error: Volets roulants: self.tahoma.register_listener() #register a new listener
2022-11-30 10:03:32.225 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 165, in register_listener
2022-11-30 10:03:32.225 Error: Volets roulants: raise exceptions.TahomaException("Not logged in")
2022-11-30 10:03:32.225 Error: Volets roulants: exceptions.TahomaException: Not logged in
Abidos14 commented 1 year ago

After roughly 1 hour, I finally get the following error :

2022-11-30 10:31:26.898 Error: Volets roulants: Call to function 'onCommand' failed, exception details:
2022-11-30 10:31:26.899 Error: Volets roulants: Traceback (most recent call last):
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 582, in onCommand
2022-11-30 10:31:26.899 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color)
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand
2022-11-30 10:31:26.899 Error: Volets roulants: self.tahoma.send_command(self.command_data)
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command
2022-11-30 10:31:26.899 Error: Volets roulants: self.handle_response(response, "send command")
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 219, in handle_response
2022-11-30 10:31:26.899 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2022-11-30 10:31:26.899 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check credentials: 401

Plugin logs somfy.log

Abidos14 commented 1 year ago

After roughly 1 hour, I finally get the following error with manual command :

2022-11-30 10:31:26.898 Error: Volets roulants: Call to function 'onCommand' failed, exception details:
2022-11-30 10:31:26.899 Error: Volets roulants: Traceback (most recent call last):
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 582, in onCommand
2022-11-30 10:31:26.899 Error: Volets roulants: _plugin.onCommand(DeviceId, Unit, Command, Level, Color)
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 266, in onCommand
2022-11-30 10:31:26.899 Error: Volets roulants: self.tahoma.send_command(self.command_data)
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 204, in send_command
2022-11-30 10:31:26.899 Error: Volets roulants: self.handle_response(response, "send command")
2022-11-30 10:31:26.899 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 219, in handle_response
2022-11-30 10:31:26.899 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2022-11-30 10:31:26.899 Error: Volets roulants: exceptions.TahomaException: failed request during send command, check credentials: 401

And if command launched from script :

2022-11-30 10:38:36.197 Error: Volets roulants: Call to function 'onHeartbeat' failed, exception details:
2022-11-30 10:38:36.198 Error: Volets roulants: Traceback (most recent call last):
2022-11-30 10:38:36.198 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 590, in onHeartbeat
2022-11-30 10:38:36.198 Error: Volets roulants: _plugin.onHeartbeat()
2022-11-30 10:38:36.198 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 293, in onHeartbeat
2022-11-30 10:38:36.198 Error: Volets roulants: self.tahoma.register_listener()
2022-11-30 10:38:36.198 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/tahoma.py", line 167, in register_listener
2022-11-30 10:38:36.198 Error: Volets roulants: response = self.listener.register_listener(self.base_url + '/enduser-mobile-web/enduserAPI/events/register', headers=Headers, verify = True, timeout=self.timeout)
2022-11-30 10:38:36.198 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/listener.py", line 51, in register_listener
2022-11-30 10:38:36.198 Error: Volets roulants: utils.handle_response(response, "get listener ID")
2022-11-30 10:38:36.198 Error: Volets roulants: File "/home/pi/domoticz/plugins/somfy/utils.py", line 60, in handle_response
2022-11-30 10:38:36.198 Error: Volets roulants: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2022-11-30 10:38:36.198 Error: Volets roulants: exceptions.TahomaException: failed request during get listener ID, check credentials: 401

Plugin logs somfy.log

Chaussette23 commented 1 year ago

Hello,

I let the plugin ran for the entire night and had a look this morning (with a polling rate set to 25 minutes). To my point of view, this ticket is closed. Regarding the modification of the indentation of hearbeat, The error "No ListenerId has been provided" is now gone.

That being said... my shutters weren't working this morning, so I had a look and I can see three remaining problems :

So I will close this ticket if everyone agree.

And I will open a new ticket for the 401 error that occur in a manner I didn't understood yet.