moroen / IKEA-Tradfri-plugin

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

connection / status issues #13

Closed mo8Zomo0 closed 6 years ago

mo8Zomo0 commented 6 years ago

Hello!

I do not want to rule out that its the Ikea hub as well, but I noticed since the addon of the group functionality I have some issues setting lamps and get their status.

My Ikea setup is 18 lights in 8 groups

I have not really identified the issue. I had some generic connection issues before, and now I reboot my hub every night, that fixed the issue then.

I a running the tradfri.tac in the foreground in a screen, so I can see a bit more whats going on there. I noticed that restarting this service helped as well, like I use the light switch and expect to see the status update for the two lights connected to it, but it never shows up there, after restarting the service at least messages for subscribed laps show up again.

I have the feeling that this is the main issue, in Domotics I see a lamp and that its on, I can turn it off, I can see that action in the D. log but I can not see the status itself beeing updated to off.

When using coap directly I noticed that groups seem to take more time to respond and also do not seem to like lots of commands in a quick sequence. Can this be an issue here?

An error I saw in the tac log is: (no further info after that. Unhandled error in Deferred:

domoticz log

2017-09-13 14:33:56.922 User: Admin initiated a switch command (142/IKEA - Sz2/Off) 2017-09-13 14:33:56.957 (IKEA) Calling message handler 'onCommand'. 2017-09-13 14:33:56.957 (KEA) Command: Off Level: 0 Type: 244 SubType: 73 2017-09-13 14:33:56.957 (IKEA) Sending 59 bytes of data:. 2017-09-13 14:33:56.958 (IKEA) 7b 22 61 63 74 69 6f 6e 22 3a 20 22 73 65 74 53 74 61 74 65 {"action":."setState 2017-09-13 14:33:56.958 (IKEA) 22 2c 20 22 73 74 61 74 65 22 3a 20 22 4f 66 66 22 2c 20 22 ",."state":."Off",." 2017-09-13 14:33:56.958 (IKEA) 64 65 76 69 63 65 49 44 22 3a 20 22 36 35 35 35 34 22 7d .. deviceID":."65554"} 2017-09-13 14:33:57.058 (IKEA) Received 38 bytes of data:. 2017-09-13 14:33:57.058 (IKEA) 7b 22 61 63 74 69 6f 6e 22 3a 20 22 73 65 74 53 74 61 74 65 {"action":."setState 2017-09-13 14:33:57.058 (IKEA) 22 2c 20 22 73 74 61 74 75 73 22 3a 20 22 4f 6b 22 7d .. .. ",."status":."Ok"}

moroen commented 6 years ago

I've read several posts elsewhere, that indicates that the gateway hangs, and it might have something to do with the number of requests.

I think that the issue here is the way observations are being implemented. So far I've been unable to maintain a consistent observation of state changes, the coap observe-function just stops working after a (short) while.

So at the moment observations are done by polling. As I general rule, I try to avoid polling as much as possible, but at the moment it's the way this is implemented. To further worsen the issue, polling is done on a device by device basis, the same for groups, so I imagine that polling 18 lights in 8 groups puts quite a strain on the gateway. I have an idea on how to reduce the number of polls, and until I get propper observations going, I'll try to implement a less resource demanding way of polling...

Another solution is disabling observation of state changes all together, but then Domoticz will not change it's bulb state if the bulbs are switched using the remote.

mo8Zomo0 commented 6 years ago

did you always poll or also subscribe? At least in the version from like 1-2 weeks ago it worked ok for me. I think the groups are more sensitive on any kind of requests.

When my GW hung it hung, but then also regular coaps requests, not only the observe, and also the IKEA app itself. but with the once a day reset it worked better. I also noticed that it had some arp issues here in my network, so sending out a ping before a request also improved that when I tested the coap client.

I think polling is not great. some observe / subscribe or whats possible in coap with trådfri sound better.

moroen commented 6 years ago

The adapter has always used polling. Polling is definitely not great, and I hope to change to another form of observation, but haven't been able to make it stable so far.

The way polling was done until now was really inefficient, but the commit just pushed to both master and development-branches should significantly reduce the load on the gateway, unless I have misunderstood the pytradfri-library...

Could you give it a try, and let me know how it works out? I'll move getting another way of observation working up on the priority list!

leejoow commented 6 years ago

Hi, I'm having the same problem. If I run tradfy.tac from the command line after some time I see the error:

Unhandled error in Deferred

With the latest code I see the following in the log:

Traceback (most recent call last):
  File "/usr/local/lib/python3.4/dist-packages/twisted/python/log.py", line 103, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/local/lib/python3.4/dist-packages/twisted/python/log.py", line 86, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/local/lib/python3.4/dist-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/local/lib/python3.4/dist-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
--- <exception caught here> ---
  File "/usr/local/lib/python3.4/dist-packages/twisted/internet/posixbase.py", line 597, in _doReadOrWrite
    why = selectable.doRead()
  File "/usr/local/lib/python3.4/dist-packages/twisted/internet/tcp.py", line 208, in doRead
    return self._dataReceived(data)
  File "/usr/local/lib/python3.4/dist-packages/twisted/internet/tcp.py", line 214, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "tradfri.tac", line 78, in dataReceived
    self.factory.setState(self, command["deviceID"], command["state"])
  File "tradfri.tac", line 360, in setState
    targetDevice = self.api(self.gateway.get_group(int(deviceID)))
  File "/usr/local/lib/python3.4/dist-packages/pytradfri/api/libcoap_api.py", line 78, in request
    return _execute(api_commands[0])
  File "/usr/local/lib/python3.4/dist-packages/pytradfri/api/libcoap_api.py", line 67, in _execute
    raise RequestTimeout() from None
pytradfri.error.RequestTimeout:

Disconnected

In the previous commit I had this same problem, however I could still send commands and noticed there was no result comming from the gateway back. If I switched the lights with the remote, no status updates came in. Switching in Domoticz resulted in changing the ligts, but also no status update came through.

BTW, the gateway still works with the app on my iPhone, after restarting the tradfri.tac everything works again. So I don't think the gateway itself hangs.

moroen commented 6 years ago

There appears to be some kind of timeout from the coap-client. I'm currently trying to get to grips with asyncio og aiocoap, in order to switch the adapter to aiocoap and trying to get some kind of stable observations going... I have made som progress, but the observation still times out after a while, so still struggling...

moroen commented 6 years ago

I have restored some error handling in the observation routine. It will still fail observation after a while, but it should be possible to continue switching lights etc even after failing...