moroen / IKEA-Tradfri-plugin

A Python plugin for Domoticz to controll IKEA Gateway
68 stars 23 forks source link

Time-out to Tradfri hub causes update to Domoticz to stop #56

Closed basrieter closed 5 years ago

basrieter commented 5 years ago

Apparently there is a timeout somewhere the try-except generates a new exception because the RequestTimeout does not have an attribute message:

,2018-10-31T08:12:15.474642160Z Unhandled error in Deferred:
,2018-10-31T08:12:15.487248324Z 
,2018-10-31T08:12:15.487415875Z Traceback (most recent call last):
,2018-10-31T08:12:15.487486395Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/base.py", line 1267, in run
,2018-10-31T08:12:15.487557384Z     self.mainLoop()
,2018-10-31T08:12:15.487622853Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/base.py", line 1276, in mainLoop
,2018-10-31T08:12:15.487693008Z     self.runUntilCurrent()
,2018-10-31T08:12:15.487757904Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/base.py", line 902, in runUntilCurrent
,2018-10-31T08:12:15.487827955Z     call.func(*call.args, **call.kw)
,2018-10-31T08:12:15.487894257Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/task.py", line 239, in __call__
,2018-10-31T08:12:15.487962538Z     d = defer.maybeDeferred(self.f, *self.a, **self.kw)
,2018-10-31T08:12:15.488028266Z --- <exception caught here> ---
,2018-10-31T08:12:15.488095506Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/defer.py", line 151, in maybeDeferred
,2018-10-31T08:12:15.488165036Z     result = f(*args, **kw)
,2018-10-31T08:12:15.488229359Z   File "tradfri.tac", line 337, in announce
,2018-10-31T08:12:15.488356389Z     print("Error in annouce: {0}:{1}".format(e, e.message))
,2018-10-31T08:12:15.488424670Z builtins.AttributeError: 'RequestTimeout' object has no attribute 'message'

This basically stops the tradfri.tac from sending updates to Domoticz. I can still switch devices from Domoticz, but switching them with the Ikea remotes, is not show in Domoticz

moroen commented 5 years ago

This is due to how twisted handles errors in deferred routines.

Stable observations without the need for polling are a priority, but since that's still difficult, I'll try to make the polling a bit more stable. Thanks for reminding me of this issue, I'll move it up on my "priority list"... :)

Regards, M

basrieter commented 5 years ago

Sure, np. But the AttributeError in the except, is that something we can fix? Perhaps with a more specific exception:

except RequestTimeout, e:
    print("Error in annouce: {0}:{1}".format(e, e.<someattributethatworks>))
    pass

except Exception as e: 
    print("Error in annouce: {0}:{1}".format(e, e.message))
moroen commented 5 years ago

Probably, but handling exceptions in twisted deferred functions are (at least I found it to be) a nightmare.

I have pushed a simpler solution to the development branch. This is a solution more in line with future planed changes (which is to get rid of coap-client and twisted and replace them with aiocoap).

If you would be as kind as to try the development-branch?

Regards, M

basrieter commented 5 years ago

Updated both the plugin as the connector to development. Got some errors every now and then:

2018-11-04 19:48:00.303 Error: (Tradfri) No transport, write directive to 'Main' ignored.

And if I use Domoticz to switch off/on, the actual switch does not change on the screen. It is only updated after the polling interval, which I have set it to 10 seconds.

From the Tradfri controller output I then read:


2018-11-04T18:51:28.375414492Z Unhandled Error
2018-11-04T18:51:28.375646835Z Traceback (most recent call last):
2018-11-04T18:51:28.375942406Z   File "/usr/local/lib/python3.5/dist-packages/twisted/python/log.py", line 103, in callWithLogger
2018-11-04T18:51:28.376236049Z     return callWithContext({"system": lp}, func, *args, **kw)
2018-11-04T18:51:28.376497818Z   File "/usr/local/lib/python3.5/dist-packages/twisted/python/log.py", line 86, in callWithContext
2018-11-04T18:51:28.376809952Z     return context.call({ILogContext: newCtx}, func, *args, **kw)
2018-11-04T18:51:28.377025054Z   File "/usr/local/lib/python3.5/dist-packages/twisted/python/context.py", line 122, in callWithContext
2018-11-04T18:51:28.377313594Z     return self.currentContext().callWithContext(ctx, func, *args, **kw)
2018-11-04T18:51:28.377542759Z   File "/usr/local/lib/python3.5/dist-packages/twisted/python/context.py", line 85, in callWithContext
2018-11-04T18:51:28.377829841Z     return func(*args,**kw)
2018-11-04T18:51:28.378109735Z --- <exception caught here> ---
2018-11-04T18:51:28.378339785Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
2018-11-04T18:51:28.378630408Z     why = selectable.doRead()
2018-11-04T18:51:28.378871865Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/tcp.py", line 243, in doRead
2018-11-04T18:51:28.379162123Z     return self._dataReceived(data)
2018-11-04T18:51:28.379401497Z   File "/usr/local/lib/python3.5/dist-packages/twisted/internet/tcp.py", line 249, in _dataReceived
2018-11-04T18:51:28.379687953Z     rval = self.protocol.dataReceived(data)
2018-11-04T18:51:28.379967899Z   File "tradfri.tac", line 100, in dataReceived
2018-11-04T18:51:28.380199512Z     self.factory.setState(self, command["deviceID"], command["state"])
2018-11-04T18:51:28.380481333Z   File "tradfri.tac", line 523, in setState
2018-11-04T18:51:28.380764977Z     self.announce()
2018-11-04T18:51:28.380998934Z builtins.AttributeError: 'AdaptorFactory' object has no attribute 'announce'```
moroen commented 5 years ago

The error with status not being updated right away should be fixed in the lasted commit just pushed to development.

The No-transport error needs further investigation.

basrieter commented 5 years ago

Using the development version for 2 days now. So far so good. The problem usually surfaced after a longer periode, so let's keep our fingers crossed.

moroen commented 5 years ago

Thank you for the feedback. I'll keep this issue open for a couple of more days, and if no reports of any errors, merge into the master branch!

moroen commented 5 years ago

No further errors reported. Merged into master

basrieter commented 5 years ago

You beat me to it. No problems so far. Thanks for the fix.

moroen commented 5 years ago

:)

basrieter commented 5 years ago

After some weeks I still encounter connection losses to the hub. I need to restart it to make it all work again.

It seems like after some time the it just won't accept any more connections. I have the idea that it comes back faster if I set the polling interval to lower values (faster polling)

moroen commented 5 years ago

This is in line with other repports and my own observations, that polling somehow after a while makes the HUB freeze and need a restart.

On the system controlling the lights etc. in our house, I don't use polling at all, and I have never needed to restart the gateway because of it freezing.

Hopefully propper observations will remedy this, I'm currently working with converting the adapter to aiocoap, which according to some reportst, provide more stable polling. Until this, as a stopgap messure, I would recommend no polling or alt least using as long a poll intervall as possible.

We should perhaps open a separate issue for this...

martialman commented 5 years ago

Hello, I'm sorry, i have the same problem than basrieter, with the same Tradfri controller output and the same error in domoticz, what advise me to help me? I am french, I could misunderstand because of the translations, the devellopement is the beta version of domoticz ?? My domoticz version : 4.10256 beta on raspberry.

I thank you in advance

moroen commented 5 years ago

You should use the master version regardless of domoticz stable or beta, the plugin is unified for both versions. Could you please post the log describing the error?

martialman commented 5 years ago

Tank you for your help, I'm sorry, but now i have new problem, i think it's the upgrade? my log : /usr/local/lib/python3.4/dist-packages/cryptography/hazmat/bindings/openssl/binding.py:163: CryptographyDeprecationWarning: OpenSSL version 1.0.1 is no longer supported by the OpenSSL project, please upgrade. A future version of cryptography will drop support for it. utils.CryptographyDeprecationWarning IKEA-tradfri COAP-adaptor version 0.8.3 started (command line)!

In first time my error log is similar to basrieter.

Tank you

moroen commented 5 years ago

Your python version is too old, you need to use at least version 3.5, but 3.6 is recommended!

martialman commented 5 years ago

I'm sorry but wanting to upgrade libtool my raspberry planted by asking me for a login at startup after hours of testing for the repaired I ended up all reinstall and everything works now very very well thank you very much for your quick answers soon thank you