Lots of errors

[rge]

I'm doing a trial of this plugin but I get far too many errors in my log.

For example, frequent occurrences of:

AK Ikea ERROR [585]: Request failed() : /15001/65537
AK Ikea ERROR [xxx]: Device doesn't exist in the system

There's no problem controlling the gateway through the Ikea app, and no other issues from HS or plugins.

This morning the whole plugin seemed to lock up - trying to access the device page of any Ikea device crashed HS. This was resolved by rebooting, disabling the plugin and then re-enabling it.

System - HS 4.1.7.0 Linux Standard on Pi4, AK Ikea 3.0.0.40

[alexbk66]

I'm doing a trial of this plugin but I get far too many errors in my log.

For example, frequent occurrences of:

AK Ikea ERROR [585]: Request failed() : /15001/65537
AK Ikea ERROR [xxx]: Device doesn't exist in the system

There's no problem controlling the gateway through the Ikea app, and no other issues from HS or plugins.

This morning the whole plugin seemed to lock up - trying to access the device page of any Ikea device crashed HS. This was resolved by rebooting, disabling the plugin and then re-enabling it.

System - HS 4.1.7.0 Linux Standard on Pi4, AK Ikea 3.0.0.40

"Device doesn't exist in the system" - is a separate question, it's not a problem and can be ignored. All my plugins monitor deleting HS devices in case the device controlled by the plugin gets deleted. But because the device (even from different plugin) was deleted - I can't really tell what plugin it belonged to. In the new version (funny, I'm doing right now) - I change it to a warning.

Regarding "Request failed" - I saw it also today, it looks like it lost authorization token. Probably because the IKEA gateway IP address changed.
Please check that the plugin has the correct IP address and does have App key.
I had to delete the Ikea.Bridge device and restart the plugin.

[rge]

Thanks, but it's not completely broken as if the IP or key were wrong.

I re-enabled the plugin, it found all it's devices (green ticks on the config page), but still gave these errors:

10/25/2020 13:46:42 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15005
10/25/2020 13:46:36 Legacy-Plugin AK Ikea Warning [585]: Retry: /15005
10/25/2020 13:46:36 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15005
10/25/2020 13:46:23 Legacy-Plugin AK Ikea ERROR[585]: Request failed() : /15005/131075/196615
10/25/2020 13:46:18 Legacy-Plugin AK Ikea Warning [585]: Retry: /15005/131075/196615
10/25/2020 13:46:18 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15005/131075/196615
10/25/2020 13:45:26 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15005/131073/196618
10/25/2020 13:45:20 Legacy-Plugin AK Ikea Warning [585]: Retry: /15005/131073/196618
10/25/2020 13:45:20 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15005/131073/196618
10/25/2020 13:44:43 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15001
10/25/2020 13:44:38 Legacy-Plugin AK Ikea Warning [585]: Retry: /15001
10/25/2020 13:44:38 Legacy-Plugin AK Ikea ERROR [585]: Request failed() : /15001
10/25/2020 13:44:33 Legacy-Plugin AK Ikea Warning [585]: Unable to get resources from Gateway

[alexbk66]

Thanks, but it's not completely broken as if the IP or key were wrong.

I re-enabled the plugin, it found all it's devices (green ticks on the config page), but still gave these errors:

Can you delete all IKEA devices and start clean?

I confirmed that when IP address changes - it doesn't recover properly. Setting static IP address is always recommended.

But I'm trying to find out how to reset the plugin internally without restarting - it's not trivial because the comms protocol needs to keep connection constantly.
The easiest workaround would be to crash the plugin and let HomeSeer restart it, unfortunately HS doesn't provide programmatic way to restart the plugin.
I'll continue tomorrow, it's a bit late in AU.

[rge]

Thanks for the support. The IP address hasn't changed, I have it locked in my DHCP specifically for this reason.

I can delete the devices - will they recreate automatically or are there some specific steps to follow?

Another couple of points - I have the refresh time set to 15 seconds for everything, and also the errors don't seem to happen when I turn of full logging (of course ) but maybe this points to some level of network overload which logging slows down enough to remove. Unfortunately can't leave the logging on for too long because of the volume.

[alexbk66]

Thanks for the support. The IP address hasn't changed, I have it locked in my DHCP specifically for this reason.

I can delete the devices - will they recreate automatically or are there some specific steps to follow?

Another couple of points - I have the refresh time set to 15 seconds for everything, and also the errors don't seem to happen when I turn of full logging (of course ) but maybe this points to some level of network overload which logging slows down enough to remove. Unfortunately can't leave the logging on for too long because of the volume.

All devices will be re-created - first it will create the Bridge (Root) device - then you need to enter the key (found on the bottom of the bridge), then it will find all other devices.

But still, you better wait for the new version - hopefully tomorrow.

I always recommend setting static IP, but at the same time I prefer to use mDNS (Zeroconf) - just to eliminate one extra setup step.
Most devices these days support it. So when IP changes - mDNS discovers it and the plugin should handle it internally.

Most my plugins work this way. But IKEA is different because it's using device observation - so in theory you don't need polling at all. But observation keeps connection constantly open which is obviously a problem when IP changes.

[alexbk66]

Ver 3.0.0.41 (in BETA section of the updater) - Improve re-connect reliability

[rge]

Ver 3.0.0.41 (in BETA section of the updater) - Improve re-connect reliability

Sorry didn't see this earlier, now installed and will report back how it goes.

[rge]

I still get hundreds of log entries like this:

10/27/2020 23:00:04 Legacy-Plugin AK Ikea Warning [585]: ~ ReconnectAll ~
10/27/2020 23:00:02 Legacy-Plugin AK Ikea Warning [585]: 23:00:02 [DTLSClientChannel] Warn - Sessions are different
10/27/2020 22:59:59 Legacy-Plugin AK Ikea Warning [585]: 22:59:59 [DTLSClientChannel] Warn - Sessions are different
10/27/2020 22:59:59 Legacy-Plugin AK Ikea Warning [585]: Retry: /15005/131073/196619
10/27/2020 22:59:59 Legacy-Plugin AK Ikea Warning [585]: Request failed() : /15005/131073/196619
10/27/2020 22:58:47 Legacy-Plugin AK Ikea Warning [585]: 22:58:47 [DTLSClientChannel] Warn - Sessions are different
10/27/2020 22:58:47 Legacy-Plugin AK Ikea Warning [585]: Retry: /15001/65538
10/27/2020 22:58:47 Legacy-Plugin AK Ikea Warning [585]: Request failed() : /15001/65538
10/27/2020 22:58:30 Legacy-Plugin AK Ikea Warning [585]: 22:58:30 [DTLSClientChannel] Warn - Sessions are different
10/27/2020 22:58:27 Legacy-Plugin AK Ikea Warning [585]: 22:58:27 [DTLSClientChannel] Warn - Setup a new session -
10/27/2020 22:58:23 Legacy-Plugin AK Ikea Warning [585]: Retry: /15001/65544
10/27/2020 22:58:23 Legacy-Plugin AK Ikea Warning [585]: Request failed() : /15001/65544

and also errors like this:

10/27/2020 19:27:47 Legacy-Plugin AK Ikea ERROR [618]: GetGroup: System.NullReferenceException: Object reference not set to an instance of an object. at HSPI_AKIkea.DeviceIkeaDevice.get_GroupController () [0x00010] in :0 at HSPI_AKIkea.DeviceIkeaGroup.GetGroup () [0x00014] in :0
10/27/2020 18:28:23 Legacy-Plugin AK Ikea ERROR [660]: GetTradfriDevice(65547): System.NullReferenceException: Object reference not set to an instance of an object. at HSPI_AKIkea.DeviceIkeaDevice.get_DeviceController () [0x00010] in :0 at HSPI_AKIkea.DeviceIkeaDevice.TimerCallback () [0x00042] in :0
10/27/2020 18:22:31 Legacy-Plugin AK Ikea ERROR [615]: GetGroup: System.NullReferenceException: Object reference not set to an instance of an object. at HSPI_AKIkea.DeviceIkeaDevice.get_GroupController () [0x00010] in :0 at HSPI_AKIkea.DeviceIkeaGroup.GetGroup () [0x00014] in :0

[alexbk66]

In .41 I added more error handling and logging - Before [DTLSClientChannel] warnings were hidden.

Can you please now delete all IKEA HS devices and start clean.

[EDIT]

I'll also check and fix the errors above, will post new version soon.

[rge]

I started clean and still get a huge number of warnings like this:

[723]: Request failed() : /15004/131075
[723]: Retry: /15004/131075
[723]: 12:19:50 [DTLSClientChannel] Warn - Sessions are different

If I disable all polling everything seems to work OK, I don't know if this is the best option?

As I enable polling on devices, the number of warnings increases. Given the message, I wonder if the code opens multiple sessions for the polling and then mixes up the results?

[alexbk66]

I started clean and still get a huge number of warnings like this:

[723]: Request failed() : /15004/131075
[723]: Retry: /15004/131075
[723]: 12:19:50 [DTLSClientChannel] Warn - Sessions are different

If I disable all polling everything seems to work OK, I don't know if this is the best option?

As I enable polling on devices, the number of warnings increases. Given the message, I wonder if the code opens multiple sessions for the polling and then mixes up the results?

Normally polling is not necessary - because the protocol also uses device observation and should be notified of any changes.
I still use polling because it's most reliable - it it doesn't work (i.e. connection lost) - you see the problem straight away.

Regarding the sessions - IKEA use complicated comms protocol CoAP, internally it keeps secure session with the device. When communication timeouts for any reason (I think it's 3 seconds) - it starts a new session. But it doesn't look like it works properly. It's not in my code, its in CoAP library, but because of these issues I have to download CoAP source code to debug it.

I've seen this issue myself, but usually re-entering the Gateway code fixes the problem. I'll keep investigating...

In the mean time if you are sure that observation does work - you can disable polling. But personally I never trust these technologies.

And another question - before upgrading to HS4 it was working?

[alexbk66]

BTW, I published ver. 3.0.0.42 (in BETA).

And I'm looking into porting to HS4 - too much work

[EDIT]

Ver 3.0.0.43 (in BETA) seems to work. I also tested with HS4 (where I did get issues before) and it's all good.

[rge]

In the mean time if you are sure that observation does work - you can disable polling. But personally I never trust these technologies.

And another question - before upgrading to HS4 it was working?

Thanks Alex - for me it isn't super critical that everything is up-to-date, so I think I'll leave polling off for now and try it again as you do updates.

It didn't use your plugin prior to HS4 so I can't say if there's any difference.

Will install 3.0.0.42 asap, and thanks again for the support.

[alexbk66]

Thanks Alex - for me it isn't super critical that everything is up-to-date, so I think I'll leave polling off for now and try it again as you do updates.

It didn't use your plugin prior to HS4 so I can't say if there's any difference.

Will install 3.0.0.42 asap, and thanks again for the support.

As I said, ver 3.0.0.43 now, polling works as well.
Not sure why HS4 caused issues - I updated all dependencies to latest versions - seems to work now.