[REQUEST] Ikea Trådfri Gateway (smart lights hub controller) plugin?

[moroen]

Thanks M for the quick response. While you were typing this I already uninstalled twisted and re-installed it for python3
The service runs again !!

But still no hardware showing

Just to make sure I've gotten this, you can't select IKEA Tradfri in the hardware list in Domoticz, or you're able to add the IKEA Tradfri plugin, but no devices being shown?

Regards,
M

[Toolman]

Just to make sure I've gotten this, you can't select IKEA Tradfri in the hardware list in Domoticz, or you're able to add the IKEA Tradfri plugin, but no devices being shown?

Regards,
M

It's the first you mention.
I can't select IKEA Tradfri in the harware list in Domoticz.

[moroen]

Just to make sure I've gotten this, you can't select IKEA Tradfri in the hardware list in Domoticz, or you're able to add the IKEA Tradfri plugin, but no devices being shown?

Regards,
M

It's the first you mention.
I can't select IKEA Tradfri in the harware list in Domoticz.

Ok, try running Domoticz from the command line. Make sure you stop the Domoticz service first, and post the startup lines...

Regards,
M

[Toolman]

Ok, try running Domoticz from the command line. Make sure you stop the Domoticz service first, and post the startup lines...

Regards,
M

Completely nothing about Tradfri:

Code: Select all

2018-01-11 22:52:12.170 Domoticz V3.8805 (c)2012-2018 GizMoCuz
2018-01-11 22:52:12.170 Build Hash: e160f7cc, Date: 2018-01-09 15:56:44
2018-01-11 22:52:12.170 System: Raspberry Pi
2018-01-11 22:52:12.170 Startup Path: /home/pi/domoticz/
2018-01-11 22:52:12.210 Sunrise: 08:42:00 SunSet: 16:51:00
2018-01-11 22:52:12.210 Day length: 08:09:00 Sun at south: 12:46:00
2018-01-11 22:52:12.210 Civil twilight start: 08:03:00 Civil twilight end: 17:30:00
2018-01-11 22:52:12.210 Nautical twilight start: 07:20:00 Nautical twilight end: 18:13:00
2018-01-11 22:52:12.210 Astronomical twilight start: 06:39:00 Astronomical twilight end: 18:53:00
2018-01-11 22:52:12.210 EventSystem: reset all events...
2018-01-11 22:52:12.220 Active notification Subsystems: (0/14)
2018-01-11 22:52:12.221 WebServer(HTTP) started on address: :: with port 8080
2018-01-11 22:52:12.226 WebServer(SSL) started on address: :: with port 443
2018-01-11 22:52:12.227 Proxymanager started.
2018-01-11 22:52:12.228 Camera: settings (re)loaded
2018-01-11 22:52:12.229 Starting shared server on: :::6144
2018-01-11 22:52:12.229 TCPServer: shared server started...
2018-01-11 22:52:12.229 RxQueue: queue worker started...
2018-01-11 22:52:14.230 P1 Smart Meter: Using serial port: /dev/ttyUSB0
2018-01-11 22:52:14.430 RFLink: Using serial port: /dev/ttyACM0
2018-01-11 22:52:14.730 OpenZWave: using config in: /home/pi/domoticz/Config/
2018-01-11 22:52:14.732 OpenZWave: Starting...
2018-01-11 22:52:14.732 OpenZWave: Version: 1.4-2713-ge2021e46-dirty
2018-01-11 22:52:15.358 OpenZWave: Driver Ready
2018-01-11 22:52:15.373 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: SWITCH BINARY, Label: Switch, Instance: 1
2018-01-11 22:52:15.373 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: SWITCH MULTILEVEL, Label: Level, Instance: 1
2018-01-11 22:52:15.374 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: SWITCH MULTILEVEL, Label: Bright, Instance: 1
2018-01-11 22:52:15.374 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: SWITCH MULTILEVEL, Label: Dim, Instance: 1
2018-01-11 22:52:15.374 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: METER, Label: Energy, Instance: 1
2018-01-11 22:52:15.375 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: METER, Label: Power, Instance: 1
2018-01-11 22:52:15.375 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: METER, Label: Voltage, Instance: 1
2018-01-11 22:52:15.375 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: METER, Label: Current, Instance: 1
2018-01-11 22:52:15.375 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: COLOR, Label: Color, Instance: 1
2018-01-11 22:52:15.376 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: COLOR, Label: Color Index, Instance: 1
2018-01-11 22:52:15.377 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: CLOCK, Label: Day, Instance: 1
2018-01-11 22:52:15.378 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: CLOCK, Label: Hour, Instance: 1
2018-01-11 22:52:15.378 OpenZWave: Value_Added: Node: 2 (0x02), CommandClass: CLOCK, Label: Minute, Instance: 1
2018-01-11 22:52:15.378 OpenZWave: NodeID: 2 (0x02), Thermostat Clock: Friday 08:55
2018-01-11 22:52:15.379 (Z-stick) General/Thermostat Clock (Thermostat Clock)
2018-01-11 22:52:15.380 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: SENSOR BINARY, Label: Sensor, Instance: 0
2018-01-11 22:52:15.380 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: SENSOR MULTILEVEL, Label: Temperature, Instance: 1
2018-01-11 22:52:15.380 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: SENSOR MULTILEVEL, Label: Luminance, Instance: 3
2018-01-11 22:52:15.381 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: SENSOR MULTILEVEL, Label: Relative Humidity, Instance: 5
2018-01-11 22:52:15.381 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: SENSOR MULTILEVEL, Label: Ultraviolet, Instance: 27
2018-01-11 22:52:15.382 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: ALARM, Label: Alarm Type, Instance: 1
2018-01-11 22:52:15.382 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: ALARM, Label: Alarm Level, Instance: 1
2018-01-11 22:52:15.383 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: ALARM, Label: SourceNodeId, Instance: 1
2018-01-11 22:52:15.383 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: ALARM, Label: Burglar, Instance: 1
2018-01-11 22:52:15.384 OpenZWave: Value_Added: Node: 5 (0x05), CommandClass: BATTERY, Label: Battery Level, Instance: 1
2018-01-11 22:52:19.904 P1 Smart Meter: Meter reports as DSMR 4.2
2018-01-11 22:52:20.274 P1 Smart Meter: Found gas meter on M-Bus channel 1
2018-01-11 22:52:20.455 (P1 Smart Meter) P1 Smart Meter (Elektriciteitsmeter)
2018-01-11 22:52:20.456 (P1 Smart Meter) P1 Smart Meter (Gasmeter)
2018-01-11 22:52:24.973 Incoming connection from: 192.168.192.35
2018-01-11 22:52:27.056 OpenZWave: Received timeout notification from HomeID: 3536960503, NodeID: 2 (0x02)
2018-01-11 22:52:30.475 (P1 Smart Meter) P1 Smart Meter (Elektriciteitsmeter)
2018-01-11 22:52:37.229 OpenZWave: Received timeout notification from HomeID: 3536960503, NodeID: 2 (0x02)
2018-01-11 22:52:37.723 (Z-stick) General/kWh (Garage Switch kWh Meter)
2018-01-11 22:52:37.913 (Z-stick) Usage (Unknown)
2018-01-11 22:52:37.914 (Z-stick) General/kWh (Garage Switch kWh Meter)
2018-01-11 22:52:38.102 (Z-stick) General/Voltage (Garage Switch Voltage)
2018-01-11 22:52:38.202 (RFLink) Light/Switch (Unknown)
2018-01-11 22:52:38.292 (Z-stick) Current (Garage Switch Ampere)
2018-01-11 22:52:39.017 OpenZWave: NodeID: 2 (0x02), Thermostat Clock: Saturday 09:32
2018-01-11 22:52:39.019 (Z-stick) General/Thermostat Clock (Thermostat Clock)
2018-01-11 22:52:39.672 (Z-stick) Temp + Humidity (Carport Temp Hum)
2018-01-11 22:52:40.495 (P1 Smart Meter) P1 Smart Meter (Elektriciteitsmeter)
2018-01-11 22:52:42.687 (Z-stick) Lux (Carport Lux)
2018-01-11 22:52:43.328 (Z-stick) Temp + Humidity (Carport Temp Hum)
2018-01-11 22:52:46.444 (Z-stick) UV (Carport UV)
2018-01-11 22:52:47.864 OpenZWave: All Nodes queried

[moroen]

Ok, try running Domoticz from the command line. Make sure you stop the Domoticz service first, and post the startup lines...

Regards,
M

Completely nothing about Tradfri:

Code: Select all

2018-01-11 22:52:12.170 Domoticz V3.8805 (c)2012-2018 GizMoCuz
2018-01-11 22:52:12.170 Build Hash: e160f7cc, Date: 2018-01-09 15:56:44
2018-01-11 22:52:12.170 System: Raspberry Pi
2018-01-11 22:52:12.170 Startup Path: /home/pi/domoticz/
2018-01-11 22:52:12.210 Sunrise: 08:42:00 SunSet: 16:51:00
2018-01-11 22:52:12.210 Day length: 08:09:00 Sun at south: 12:46:00
2018-01-11 22:52:12.210 Civil twilight start: 08:03:00 Civil twilight end: 17:30:00
2018-01-11 22:52:12.210 Nautical twilight start: 07:20:00 Nautical twilight end: 18:13:00
2018-01-11 22:52:12.210 Astronomical twilight start: 06:39:00 Astronomical twilight end: 18:53:00
2018-01-11 22:52:12.210 EventSystem: reset all events...
2018-01-11 22:52:12.220 Active notification Subsystems: (0/14)
2018-01-11 22:52:12.221 WebServer(HTTP) started on address: :: with port 8080
2018-01-11 22:52:12.226 WebServer(SSL) started on address: :: with port 443
2018-01-11 22:52:12.227 Proxymanager started.
2018-01-11 22:52:12.228 Camera: settings (re)loaded
2018-01-11 22:52:12.229 Starting shared server on: :::6144
2018-01-11 22:52:12.229 TCPServer: shared server started...
2018-01-11 22:52:12.229 RxQueue: queue worker started...

Actually, no mention of python at all! Is this the latest prebuilt beta or are you compiling from source?

Regards,
M

[Toolman]

Actually, no mention of python at all! Is this the latest prebuilt beta or are you compiling from source?

Regards,
M

Latest prebuilt beta

[moroen]

Actually, no mention of python at all! Is this the latest prebuilt beta or are you compiling from source?

Regards,
M

Latest prebuilt beta

This seems to suggest that the latest prebuilt beta has been compiled without python enabled... I'm running the latest beta, but compiled from source, and python is enabled and works quite well... Guess we have to watch the forums to see if anyone else has the same problem with the prebuilt binary for raspberry, and I'll see if I can find the time to dig out my raspberry to confirm...

If you're feeling adventurous, compiling from source isn't all that difficult, and the wiki has a rather good description on how to do it. It's somewhat of a drag on the raspberry because of long compile times, but quite doable!

Regards,
M

[Toolman]

This seems to suggest that the latest prebuilt beta has been compiled without python enabled... I'm running the latest beta, but compiled from source, and python is enabled and works quite well... Guess we have to watch the forums to see if anyone else has the same problem with the prebuilt binary for raspberry, and I'll see if I can find the time to dig out my raspberry to confirm...

If you're feeling adventurous, compiling from source isn't all that difficult, and the wiki has a rather good description on how to do it. It's somewhat of a drag on the raspberry because of long compile times, but quite doable!

Regards,
M

Thanks for all the support Moroen.
Maybe I'll feel adventurous next weekend and give the compile a go. I'll let you know.
Looks like I'm not the only one with this problem https://www.domoticz.com/forum/viewtopi ... on#p166044

Regards,
Michel

[rasper]

Hi Moroen,
Using your plugin now for a while with latest domoticz beta 8805 and ikea firmware 1.3.14. It works great, but i have two questions I hope you could answer:
- I have a group called X with three lights. If i push on for group X in the domoticz gui then it works fine, lights are turned on and the group is switched to on state. If i however set a timer to turn the group X on, or do so in a script through JSON then the lights turn on fine, but the group remains in off state. I would expect the group to switch to on state? is this known behavior?
- If I schedule a sunset timer on group X then domoticz fires the timer ok, but the lights do not turn on, and also the group remains in off state. I suspect this is a domoticz issue, or do you have an idea?

Tx in advance for help!

[moroen]

Hi Moroen,
Using your plugin now for a while with latest domoticz beta 8805 and ikea firmware 1.3.14. It works great, but i have two questions I hope you could answer:
- I have a group called X with three lights. If i push on for group X in the domoticz gui then it works fine, lights are turned on and the group is switched to on state. If i however set a timer to turn the group X on, or do so in a script through JSON then the lights turn on fine, but the group remains in off state. I would expect the group to switch to on state? is this known behavior?
- If I schedule a sunset timer on group X then domoticz fires the timer ok, but the lights do not turn on, and also the group remains in off state. I suspect this is a domoticz issue, or do you have an idea?

Tx in advance for help!

Thank you for bringing this to my attention!

I'm not able to fully reproduce issue 1, switching groups or setting the level for a group using JSON on my system gives the expected result.

The other part of issue 1 and issue 2 is linked, problems switching or setting levels using timers. One one hand I'm a bit embarrassed that I've missed this, on the other I can't shake the feeling that something has changed somewhere outside the plugin, as I imagine this used to work on my system, but during testing now, I'm seeing the same thing as you...

Anyway, I have pushed an update that should fix these issues to the development branch. Would you be so kind as to test it, and let me know if it now works as expected?

Regards,
M

[rasper]

Hi Moroen,

Yes of course will help testing and will keep you updated.

I have to admit that once every while my Ikea hub seems to hang, ie not responsive, also not through the Ikea app on my phone, so no issue with the plugin. It happened again last night, and while looking at syslog/logging it seems there is something strange going on with handling timeout in domoticz/plugin. Especially a reference to a plugin print that mentioned there is no attribute message is suspicious. The timeout itself is caused by the hub I assume, but handling the timeout in the plugin gives:

Code: Select all

Jan 16 21:39:59 domoticzpi3 twistd[368]: 2018-01-16T21:39:59+0100 [twisted.internet.defer#critical] Unhandled error in Deferred:
Jan 16 21:39:59 domoticzpi3 twistd[368]: 2018-01-16T21:39:59+0100 [twisted.internet.defer#critical]
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011Traceback (most recent call last):
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/base.py", line 1243, in run
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011    self.mainLoop()
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/base.py", line 1252, in mainLoop
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011    self.runUntilCurrent()
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/base.py", line 878, in runUntilCurrent
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011    call.func(*call.args, **call.kw)
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/task.py", line 239, in __call__
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011    d = defer.maybeDeferred(self.f, *self.a, **self.kw)
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011--- <exception caught here> ---
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/defer.py", line 150, in maybeDeferred
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011    result = f(*args, **kw)
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011  File "/home/pi/domoticz/plugins/IKEA-Tradfri/tradfri.tac", line 250, in announce
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011    print("Error in annouce: {0}:{1}".format(e, e.message))
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011builtins.AttributeError: 'RequestTimeout' object has no attribute 'message'
Jan 16 21:39:59 domoticzpi3 twistd[368]: #011

Afterwards I keep getting timeouts like:

Code: Select all

Jan 16 21:45:14 domoticzpi3 twistd[368]: 2018-01-16T21:45:14+0100 [CoapAdapter,0,127.0.0.1] Unhandled Error
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011Traceback (most recent call last):
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/python/log.py", line 103, in callWithLogger
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    return callWithContext({"system": lp}, func, *args, **kw)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/python/log.py", line 86, in callWithContext
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    return context.call({ILogContext: newCtx}, func, *args, **kw)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/python/context.py", line 122, in callWithContext
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    return self.currentContext().callWithContext(ctx, func, *args, **kw)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/python/context.py", line 85, in callWithContext
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    return func(*args,**kw)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011--- <exception caught here> ---
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    why = selectable.doRead()
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/tcp.py", line 205, in doRead
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    return self._dataReceived(data)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/twisted/internet/tcp.py", line 211, in _dataReceived
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    rval = self.protocol.dataReceived(data)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/domoticz/plugins/IKEA-Tradfri/tradfri.tac", line 89, in dataReceived
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    self.factory.setState(self, command["deviceID"], command["state"])
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/domoticz/plugins/IKEA-Tradfri/tradfri.tac", line 401, in setState
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    targetDevice = self.api(self.gateway.get_group(int(deviceID)))
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/pytradfri/api/libcoap_api.py", line 92, in request
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    return self._execute(api_commands)
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011  File "/home/pi/.local/lib/python3.5/site-packages/pytradfri/api/libcoap_api.py", line 81, in _execute
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011    raise RequestTimeout() from None
Jan 16 21:45:14 domoticzpi3 twistd[368]: #011pytradfri.error.RequestTimeout:

Between 21:39 and this morning the timeouts kept coming and the whole raspberry pi seemd to have restarted twice (not sure if there is a relation, and I can't find out what happened exactly). When unplugging the hub and plugging it back in this morning, the system restored itself to ok operation, without rebooting/restarting Domoticz. This is what I see just before the reboot:

Code: Select all

Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 5 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 4 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 6: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 6 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 3: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 3 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 5 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 4 was not an MTP device
Jan 17 02:20:24 domoticzpi3 liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="347" x-info="http://www.rsyslog.com"] start
Jan 17 02:20:24 domoticzpi3 kernel: [    0.000000] Booting Linux on physical CPU 0x0
Jan 17 02:20:24 domoticzpi3 kernel: [    0.000000] Linux version 4.9.59-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1047 SMP Sun Oct 29 12:19:23 GMT 2017

[moroen]

Hi Moroen,

Yes of course will help testing and will keep you updated.

I have to admit that once every while my Ikea hub seems to hang, ie not responsive, also not through the Ikea app on my phone, so no issue with the plugin. It happened again last night, and while looking at syslog/logging it seems there is something strange going on with handling timeout in domoticz/plugin. Especially a reference to a plugin print that mentioned there is no attribute message is suspicious. The timeout itself is caused by the hub I assume, but handling the timeout in the plugin gives:

Code: Select all

Jan 16 21:39:59 domoticzpi3 twistd[368]: 2018-01-16T21:39:59+0100 [twisted.internet.defer#critical] Unhandled error in Deferred:
...

Afterwards I keep getting timeouts like:

Code: Select all

Jan 16 21:45:14 domoticzpi3 twistd[368]: 2018-01-16T21:45:14+0100 [CoapAdapter,0,127.0.0.1] Unhandled Error
...

Between 21:39 and this morning the timeouts kept coming and the whole raspberry pi seemd to have restarted twice (not sure if there is a relation, and I can't find out what happened exactly). When unplugging the hub and plugging it back in this morning, the system restored itself to ok operation, without rebooting/restarting Domoticz. This is what I see just before the reboot:

Code: Select all

Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 5 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 4 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 6: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 6 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 3: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 3 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 5 was not an MTP device
Jan 17 02:20:24 domoticzpi3 mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2"
Jan 17 02:20:24 domoticzpi3 mtp-probe: bus: 1, device: 4 was not an MTP device
Jan 17 02:20:24 domoticzpi3 liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="347" x-info="http://www.rsyslog.com"] start
Jan 17 02:20:24 domoticzpi3 kernel: [    0.000000] Booting Linux on physical CPU 0x0
Jan 17 02:20:24 domoticzpi3 kernel: [    0.000000] Linux version 4.9.59-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1047 SMP Sun Oct 29 12:19:23 GMT 2017

Handling timeouts when the gateway doesn't respond is somewhat of an achilles heel in the plugin. Timeout-handling with twisted is a nightmare (at least to me), and I just haven't had the motivation and time to make a real effort for fixing it, especially in the version using libcoap and coap-client (i.e. the current development/master branch).

I have done some experiments using aiocoap (python native coap-library, check the aiocoap-branch if you're interested), but robustness and general usability just isn't there, it works, but fails more often than the coap-client version, spews a lot error messages and completely fails to monitor state changes with some consistency.

My main motivation has been and continue to be trying to get a propper observation of state changes when usin the IKEA-remotes and better handling of communcation errors, but at the moment I have more or less given up using python for this...

I'm not giving up on the plugin, as more and more IKEA Tradfri bulbs somehow finds their way into our household... I'm currently experimenting with go, the golang coap library (canopus) appears much more mature than aiocoap, I have prototypes for command line tools, tradfri coap-adaptor and consistent observations working, just not ready for allround testing...

As to why your Pi restarts, I have no idea...

Regards,
M

[rasper]

Hi Moroen,

Thanks for swift reply! I have tested your new development branch and my sunset timer just fired, the lights were switched on and also the group now nicely switches on. Thanks a lot for the fix, so far so good!

As for the timeouts, what I think would be good if at least the attributes printed in case of errors do exist. I guess it is the plugin trying to print some attribute that does not exist? I guess that printing unknown attributes could cause some issues. For sure IKEA needs to make sure the hub is more stable , because also my phone app hung on trying to reach the hub.

I looked a little more at syslog kind of logging and at the time of the reboot I see twistd getting a SIGTERM at some point, just before the reboot. Who is issuing/causing the SIGTERM is not clear to me.

Do you also have some instabilities in your IKEA hub every now and then? Is there maybe a way to reset the hub through a command/script, such that we can build some watchdog script or so?

[moroen]

Hi Moroen,

Thanks for swift reply! I have tested your new development branch and my sunset timer just fired, the lights were switched on and also the group now nicely switches on. Thanks a lot for the fix, so far so good!

As for the timeouts, what I think would be good if at least the attributes printed in case of errors do exist. I guess it is the plugin trying to print some attribute that does not exist? I guess that printing unknown attributes could cause some issues. For sure IKEA needs to make sure the hub is more stable , because also my phone app hung on trying to reach the hub.

I looked a little more at syslog kind of logging and at the time of the reboot I see twistd getting a SIGTERM at some point, just before the reboot. Who is issuing/causing the SIGTERM is not clear to me.

Do you also have some instabilities in your IKEA hub every now and then? Is there maybe a way to reset the hub through a command/script, such that we can build some watchdog script or so?

Glad it worked out so far!

The unknown attribute part is an error message from an unhandled error in twisted (timeout), I don't think this actually causes any problem, it's just an error message from twisted. The real problem is that the adapter doesn't recover from an timeout because the normal python error handling just doesn't work with twisted. I tried to understand twisted error handling, but my eyes glazed over and my brain went into shutdown...

Yes, the gateway hangs from time to time, but not as often when disabling observe changes. The way it does it now, is by polling, and it the frequency of gateway freezes appears to be related to the number of requests being sent, indicating a possible memory leak. And yes, there is a way to reset the hub via coap, but then the hub need to respond to be able to process the request... I've pondered reseting the gateway for example once every day, in order to minimize any memory leaks, but haven't gotten around to it.

Regards,
M

[rasper]

Yes, the gateway hangs from time to time, but not as often when disabling observe changes. The way it does it now, is by polling, and it the frequency of gateway freezes appears to be related to the number of requests being sent, indicating a possible memory leak. And yes, there is a way to reset the hub via coap, but then the hub need to respond to be able to process the request... I've pondered reseting the gateway for example once every day, in order to minimize any memory leaks, but haven't gotten around to it.

Regards,
M

Maybe just put a smart powerplug between the hub and the power and then have Domoticz reset it daily

[moroen]

Yes, the gateway hangs from time to time, but not as often when disabling observe changes. The way it does it now, is by polling, and it the frequency of gateway freezes appears to be related to the number of requests being sent, indicating a possible memory leak. And yes, there is a way to reset the hub via coap, but then the hub need to respond to be able to process the request... I've pondered reseting the gateway for example once every day, in order to minimize any memory leaks, but haven't gotten around to it.

Regards,
M

Maybe just put a smart powerplug between the hub and the power and then have Domoticz reset it daily

Good one, it's called home automation for a reason!

Regards,
M

[Toolman]

Thanks for all the support Moroen.
Maybe I'll feel adventurous next weekend and give the compile a go. I'll let you know.
Looks like I'm not the only one with this problem viewtopic.php?f=65&t=21379&p=166044&hil ... on#p166044

Regards,
Michel

Hi M,
I promised to keep you updated. It took I while, but here's the update:
Finally I did a complete re-install of Raspbian (I decided to do that on an external HDD instead of on a SD-card, this took some time and I had to overcome some problems, hence the long time to respond but it's up and running). A fresh install of Domoticz and your Tradfri solution.
It's working now. I've to see how stable it will turn out, because I just got it running a couple of minutes ago.
Thanks for all the support.
Regards,
Michel

[rasper]

Yes, the gateway hangs from time to time, but not as often when disabling observe changes. The way it does it now, is by polling, and it the frequency of gateway freezes appears to be related to the number of requests being sent, indicating a possible memory leak. And yes, there is a way to reset the hub via coap, but then the hub need to respond to be able to process the request... I've pondered reseting the gateway for example once every day, in order to minimize any memory leaks, but haven't gotten around to it.

Regards,
M

Maybe just put a smart powerplug between the hub and the power and then have Domoticz reset it daily

Good one, it's called home automation for a reason!

Regards,
M

I have been experimenting a bit, and it rebooting the Ikea hub through a smartplug seems to work quite stable. I however had to create a new psk for domoticz to connect properly to the hub after the first reboot. I did experiment a bit since the last hub boot with generating psks in scripts, but I did not expect that the reboot of the hub would invalidate the psk I configured for the plugin. When using the latest psk I generated it worked fine.

Do you have any idea about the persistency of the psks? Would they somehow rotate/timeout?

[moroen]

Maybe just put a smart powerplug between the hub and the power and then have Domoticz reset it daily

Good one, it's called home automation for a reason!

Regards,
M

I have been experimenting a bit, and it rebooting the Ikea hub through a smartplug seems to work quite stable. I however had to create a new psk for domoticz to connect properly to the hub after the first reboot. I did experiment a bit since the last hub boot with generating psks in scripts, but I did not expect that the reboot of the hub would invalidate the psk I configured for the plugin. When using the latest psk I generated it worked fine.

Do you have any idea about the persistency of the psks? Would they somehow rotate/timeout?

I read somewhere that the number of idents/psk in the gateway is limited, so if you create a lot of them, the oldest pair would be overwritten. Unfortunately I'm unable to remember where I read it, but probably in connection with pytradfri...

I've also noticed, while testing the create ident/psk functionality of my golang tradfri command line utility, that previously generated pairs suddenly stopped working, but then there was just a matter of recreating it and everything was fine...

Regards,
M

[moffe]

Stupid question...but I haven't been able to find out how I use the development branch?
I have the latest beta build 3.8834 and I get these messages:

2018-01-23 16:45:51.540 (Ikea Tradfri) Connected successfully to: 192.168.0.72
2018-01-23 16:45:51.541 Error: (Ikea Tradfri) 'onMessage' failed 'TypeError':'onMessage() missing 2 required positional arguments: 'Status' and 'Extra''.
2018-01-23 16:46:02.111 PluginSystem: Restarting I/O service thread.
2018-01-23 16:46:02.112 (Ikea Tradfri) Device has disconnected