search

MadPatrick / somfy

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

Some more issues in the log. #37

Closed MikeyMan83 closed 1 year ago

MikeyMan83 commented 1 year ago

Hi!

Had some further authorisation errors. Thought i'd do a git pull first and see what happened.

The login issues are gone (for now), but i do see some errors occuring:

2022-12-06 13:33:09.763 Status: Somfy zonneschermen: Entering work loop.
2022-12-06 13:33:09.763 Status: Somfy zonneschermen: Started.
2022-12-06 13:33:12.194 Status: Somfy zonneschermen: Initialized version 4.1.20, author 'MadPatrick'
2022-12-06 13:33:12.211 Status: Somfy zonneschermen: Location does not exist, logging to default location
2022-12-06 13:33:12.211 Status: Somfy zonneschermen: Starting Tahoma blind plugin, logging to file somfy.log
2022-12-06 13:33:13.370 Error: Somfy zonneschermen: Call to function 'onStart' failed, exception details:
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: Traceback (most recent call last):
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 557, in onStart
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: _plugin.onStart()
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 169, in onStart
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: self.tahoma.register_listener()
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/tahoma_local.py", line 254, in register_listener
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: response = self.listener.register_listener(self.base_url_local + "/events/register", headers=self.headers_with_token, verify=False)
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/listener.py", line 51, in register_listener
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: utils.handle_response(response, "get listener ID")
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/utils.py", line 60, in handle_response
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2022-12-06 13:33:13.374 Error: Somfy zonneschermen: exceptions.TahomaException: failed request during get listener ID, check credentials: 401
2022-12-06 13:34:42.109 Error: Somfy zonneschermen: Call to function 'onCommand' failed, exception details:
2022-12-06 13:34:42.110 Error: Somfy zonneschermen: Traceback (most recent call last):
2022-12-06 13:34:42.110 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 585, in onCommand
2022-12-06 13:34:42.111 Error: Somfy zonneschermen: _plugin.onCommand(DeviceId, Unit, Command, Level, Color)
2022-12-06 13:34:42.111 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 276, in onCommand
2022-12-06 13:34:42.111 Error: Somfy zonneschermen: self.update_devices_status(event_list)
2022-12-06 13:34:42.111 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 358, in update_devices_status
2022-12-06 13:34:42.111 Error: Somfy zonneschermen: states = dataset["states"]
2022-12-06 13:34:42.111 Error: Somfy zonneschermen: KeyError: 'states'
2022-12-06 13:34:52.215 Error: Somfy zonneschermen: Call to function 'onHeartbeat' failed, exception details:
2022-12-06 13:34:52.215 Error: Somfy zonneschermen: Traceback (most recent call last):
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 593, in onHeartbeat
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: _plugin.onHeartbeat()
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 315, in onHeartbeat
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: self.update_devices_status(event_list)
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 358, in update_devices_status
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: states = dataset["states"]
2022-12-06 13:34:52.216 Error: Somfy zonneschermen: KeyError: 'states'
2022-12-06 13:35:12.202 Error: Somfy zonneschermen: Call to function 'onHeartbeat' failed, exception details:
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: Traceback (most recent call last):
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 593, in onHeartbeat
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: _plugin.onHeartbeat()
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 315, in onHeartbeat
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: self.update_devices_status(event_list)
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 358, in update_devices_status
2022-12-06 13:35:12.203 Error: Somfy zonneschermen: states = dataset["states"]
2022-12-06 13:35:12.204 Error: Somfy zonneschermen: KeyError: 'states'

And the logfile: somfy.log

Hope it helps :)

MikeyMan83 commented 1 year ago

Also; i'm not seeing the devices in the MQTT output anymore... ?

JanJaapKo commented 1 year ago

Hey @MikeyMan83 this is a relatively old issue, can you check if it still occurs on the latest version?

MikeyMan83 commented 1 year ago

@JanJaapKo It's not fully clean. Just did a git pull, and a restart:

2023-01-10 16:45:49.725 Error: Somfy zonneschermen: Call to function 'onStart' failed, exception details:
2023-01-10 16:45:49.728 Error: Somfy zonneschermen: Traceback (most recent call last):
2023-01-10 16:45:49.728 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 561, in onStart
2023-01-10 16:45:49.728 Error: Somfy zonneschermen: _plugin.onStart()
2023-01-10 16:45:49.728 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 174, in onStart
2023-01-10 16:45:49.728 Error: Somfy zonneschermen: filtered_devices = self.tahoma.get_devices()
2023-01-10 16:45:49.729 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/tahoma_local.py", line 188, in get_devices
2023-01-10 16:45:49.729 Error: Somfy zonneschermen: utils.handle_response(response, "get devices")
2023-01-10 16:45:49.729 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/utils.py", line 84, in handle_response
2023-01-10 16:45:49.729 Error: Somfy zonneschermen: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2023-01-10 16:45:49.729 Error: Somfy zonneschermen: exceptions.TahomaException: failed request during get devices, check credentials: 401

It seems to be working though.

JanJaapKo commented 1 year ago

OK. If the error keeps coming, please make a full restart and send me also somfy.log.

MikeyMan83 commented 1 year ago

After a restart the errors regularly come back:

2023-01-11 07:19:24.818 Error: Somfy zonneschermen: Call to function 'onStart' failed, exception details:
2023-01-11 07:19:24.829 Error: Somfy zonneschermen: Traceback (most recent call last):
2023-01-11 07:19:24.829 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 561, in onStart
2023-01-11 07:19:24.829 Error: Somfy zonneschermen: _plugin.onStart()
2023-01-11 07:19:24.829 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 174, in onStart
2023-01-11 07:19:24.830 Error: Somfy zonneschermen: filtered_devices = self.tahoma.get_devices()
2023-01-11 07:19:24.830 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/tahoma_local.py", line 188, in get_devices
2023-01-11 07:19:24.830 Error: Somfy zonneschermen: utils.handle_response(response, "get devices")
2023-01-11 07:19:24.830 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/utils.py", line 84, in handle_response
2023-01-11 07:19:24.830 Error: Somfy zonneschermen: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2023-01-11 07:19:24.830 Error: Somfy zonneschermen: exceptions.TahomaException: failed request during get devices, check credentials: 401
2023-01-11 08:37:08.625 Error: SQL Query("SELECT nValue, sValue FROM Preferences WHERE (Key='SensorTimeout')") : no more rows available

Log file: somfy.log

MikeyMan83 commented 1 year ago

@JanJaapKo anything useful in the logs?

JanJaapKo commented 1 year ago

You need to enable debug logging, now there is not enough info. Seems like an error at every restart of the plugin so should be easy enough to reproduce.

MikeyMan83 commented 1 year ago

@JanJaapKo Took a while, since i had several issues after updating to bullseye... But here you are: somfy.log

Some other errors this time...

BTW; rather huge amount of logging. Today alone was 120mb :X

JanJaapKo commented 1 year ago

Well I don't see any errors in that log file?

And when you are just running normally, then you can switch off debug logging, that will save a lot of log lines.......

MikeyMan83 commented 1 year ago

That's strange... I do see errors in domoticz:

2023-01-17 07:35:02.944 Error: Somfy zonneschermen: Update to 'UnitEx' failed to update any DeviceStatus records for key 38/io://2017-8871-5701/14384853/1
2023-01-17 08:05:04.344 Error: Somfy zonneschermen: Update to 'UnitEx' failed to update any DeviceStatus records for key 38/io://2017-8871-5701/14384853/1
2023-01-17 13:45:02.629 Error: Somfy zonneschermen: Update to 'UnitEx' failed to update any DeviceStatus records for key 38/io://2017-8871-5701/14384853/1
2023-01-17 15:25:02.976 Error: Somfy zonneschermen: Update to 'UnitEx' failed to update any DeviceStatus records for key 38/io://2017-8871-5701/14384853/1
2023-01-17 16:50:02.094 Error: Somfy zonneschermen: Update to 'UnitEx' failed to update any DeviceStatus records for key 38/io://2017-8871-5701/14384853/1
JanJaapKo commented 1 year ago

Yes but that was not included in the somfy log, as the error is not generated in the plugin (all system/domoticz errors only appear in the domoticz log). Let me have a look.

JanJaapKo commented 1 year ago

OK, is it always for the luminance sensor? And at every update or just once in a while?

MikeyMan83 commented 1 year ago

Think it's always the same id.

Does get updated a lot:

2023-01-17 22:10:19.355 Status: Somfy zonneschermen: Updating device: Verlichtingssensor achterkant
2023-01-17 22:10:39.326 Status: Somfy zonneschermen: Updating device: Verlichtingssensor achterkant
2023-01-17 22:10:59.319 Status: Somfy zonneschermen: Updating device: Verlichtingssensor achterkant
2023-01-17 22:11:19.364 Status: Somfy zonneschermen: Updating device: Verlichtingssensor achterkant
JanJaapKo commented 1 year ago

Yes I know. Still trying to find a way to avoid it if the value hasn't changed but one of my Pi's broke this morning so I'm fixing that one in prarallel (but with slightly more prio ;) )

JanJaapKo commented 1 year ago

OK I pushed a version were there is a check on if the current value is not equal to the new value.

But when looking into the code, there was already something to prevent updating to the same state, so I added a new logline. So could you please be so kind to run it a while in debug mode?

MikeyMan83 commented 1 year ago

@JanJaapKo of course! Small effort 😉

MikeyMan83 commented 1 year ago

Got some different errors now:

2023-01-19 10:57:22.309 Error: Somfy zonneschermen: KeyError: 0
2023-01-19 10:57:42.294 Error: Somfy zonneschermen: Call to function 'onHeartbeat' failed, exception details:
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: Traceback (most recent call last):
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 611, in onHeartbeat
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: _plugin.onHeartbeat()
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 308, in onHeartbeat
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: self.update_devices_status(utils.filter_states(filtered_devices))
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 436, in update_devices_status
2023-01-19 10:57:42.295 Error: Somfy zonneschermen: UpdateDevice(dev, status_num, nValue,sValue)
2023-01-19 10:57:42.296 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 688, in UpdateDevice
2023-01-19 10:57:42.296 Error: Somfy zonneschermen: logging.debug("Updating device "+Devices[Device].Units[Unit].Name+ " with current sValue '"+Devices[Device].Units[Unit].sValue+"' to '" +sValue+"'")
2023-01-19 10:57:42.296 Error: Somfy zonneschermen: KeyError: 0
2023-01-19 10:58:02.440 Error: Somfy zonneschermen: Call to function 'onHeartbeat' failed, exception details:
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: Traceback (most recent call last):
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 611, in onHeartbeat
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: _plugin.onHeartbeat()
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 308, in onHeartbeat
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: self.update_devices_status(utils.filter_states(filtered_devices))
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 436, in update_devices_status
2023-01-19 10:58:02.441 Error: Somfy zonneschermen: UpdateDevice(dev, status_num, nValue,sValue)
2023-01-19 10:58:02.442 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 688, in UpdateDevice
2023-01-19 10:58:02.442 Error: Somfy zonneschermen: logging.debug("Updating device "+Devices[Device].Units[Unit].Name+ " with current sValue '"+Devices[Device].Units[Unit].sValue+"' to '" +sValue+"'")
MikeyMan83 commented 1 year ago

somfy.log

And the log

JanJaapKo commented 1 year ago

Oops, small copying error. Should be fixed now.

MikeyMan83 commented 1 year ago

Check! Git pull should do the trick?

MikeyMan83 commented 1 year ago

Now only one time error:

2023-01-20 09:48:17.730 Error: Somfy zonneschermen: Call to function 'onStart' failed, exception details:
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: Traceback (most recent call last):
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 575, in onStart
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: _plugin.onStart()
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/plugin.py", line 176, in onStart
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: filtered_devices = self.tahoma.get_devices()
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/tahoma_local.py", line 188, in get_devices
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: utils.handle_response(response, "get devices")
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: File "/home/pi/domoticz/plugins/somfy/utils.py", line 84, in handle_response
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: raise exceptions.TahomaException("failed request during "+ action + ", check credentials: " + str(response.status_code))
2023-01-20 09:48:17.738 Error: Somfy zonneschermen: exceptions.TahomaException: failed request during get devices, check credentials: 401