Support for IKEA Trådfri

[stefangsbb]

Hmmm, very strange. I have the same firmware version on my GW 1.1.0015, so that is not the issue. As I said, each request is a new separate UDP message, so that it stays disconnected means that no messages get through. If you have an occasional packet loss, it should not always be disconnected.

I have now added some more detailed logging for when it fails in the communication with the gateway, so if you upgrade to the nightly build, you will get more logs.

Code: Select all

sudo nethome upgrade-nightly

Another thing that would be interesting would be to temporarily connect your Raspberry directly to your router, so we know if the "power socket network adapter" has a part in the problem or not.

[mikkot]

Hi Stefan,

Thanks for your help so far. Now I have connected my raspberry pi directly to the router with an ethernet cable. Unfortunately it did not resolve this issue. Now after upgrading to the latest nightly I got the following log

17.08.19 13:30:07 TCPCommandPort$Session Disconnected from 127.0.0.1
17.08.19 13:30:07 TCPCommandPort Connection from 127.0.0.1
17.08.19 13:28:38 HomeServer Activated 107 of 111 Items
17.08.19 13:28:30 DTLSConnector Unexpected error occurred while processing record from peer [/192.168.1.15:5684]
17.08.19 13:28:15 TrayBarIcon SystemTray is not supported on this system
17.08.19 13:28:13 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 13:28:12 DTLSConnector DTLS connector listening on [{0}] with MTU [{1}] using (inbound) datagram buffer size [{2} bytes]
17.08.19 13:28:09 CoapEndpoint Starting endpoint at 0.0.0.0/0.0.0.0:0
17.08.19 13:28:04 NetworkConfig Error while storing properties to /opt/nethome/lib/Californium.properties
17.08.19 13:28:04 NetworkConfig Storing standard properties in file Californium.properties
17.08.19 13:28:03 H2DatabaseTCPServer Started the H2 web server at: https://192.168.1.99:8082, Web Console server running at http://127.0.1.1:8082 (others can connect)
17.08.19 13:28:03 H2DatabaseTCPServer Started the H2 database server at: tcp://127.0.1.1:9092
17.08.19 13:27:59 MqttClient Connected to MQTT Server tcp://localhost
17.08.19 13:27:44 HomeItemFileLoader Loading Items from /etc/opt/nethome/config.xml
17.08.19 13:27:43 HomeManagerStarter Logging to: /var/log/nethome/HomeManager%g.log
17.08.19 13:27:43 HomeManagerStarter **Starting HomeManager 3.0-562d9**

After this I restarted nethome with "sudo nethome restart". Ikea GW stayed "disconnected" after the restart;

Source Message
17.08.19 13:45:11 HomeServer Activated 107 of 111 Items
17.08.19 13:45:10 TCPCommandPort$Session Disconnected from 127.0.0.1
17.08.19 13:45:09 TCPCommandPort Connection from 127.0.0.1
17.08.19 13:44:44 TrayBarIcon SystemTray is not supported on this system
17.08.19 13:44:41 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 13:44:40 DTLSConnector DTLS connector listening on [{0}] with MTU [{1}] using (inbound) datagram buffer size [{2} bytes]
17.08.19 13:44:40 CoapEndpoint Starting endpoint at 0.0.0.0/0.0.0.0:0
17.08.19 13:44:39 NetworkConfig Error while storing properties to /opt/nethome/lib/Californium.properties
17.08.19 13:44:39 NetworkConfig Storing standard properties in file Californium.properties
17.08.19 13:44:38 H2DatabaseTCPServer Started the H2 web server at: https://192.168.1.99:8082, Web Console server running at http://127.0.1.1:8082 (others can connect)
17.08.19 13:44:37 H2DatabaseTCPServer Started the H2 database server at: tcp://127.0.1.1:9092
17.08.19 13:44:32 MqttClient Connected to MQTT Server tcp://localhost
17.08.19 13:44:05 HomeItemFileLoader Loading Items from /etc/opt/nethome/config.xml
17.08.19 13:44:04 HomeManagerStarter Logging to: /var/log/nethome/HomeManager%g.log
17.08.19 13:44:04 HomeManagerStarter **Starting HomeManager 3.0-562d9**

Then I deleted the GW item and created a new one;

17.08.19 13:48:39 CoapEndpoint Destroying endpoint at address 0.0.0.0/0.0.0.0:0
17.08.19 13:48:39 DTLSConnector DTLS connector listening on [{0}] with MTU [{1}] using (inbound) datagram buffer size [{2} bytes]
17.08.19 13:48:39 CoapEndpoint Starting endpoint at 0.0.0.0/0.0.0.0:0
17.08.19 13:48:20 CoapEndpoint Destroying endpoint at address 0.0.0.0/0.0.0.0:0
17.08.19 13:48:20 DTLSConnector Stopping DTLS connector on [{0}]
17.08.19 13:48:20 CoapEndpoint Stopping endpoint at address 0.0.0.0/0.0.0.0:36822

And then, after few minutes, this happened. The gateway is "Not Connected". I did not do anything with the ONH nor with Ikea phone app.

17.08.19 13:55:07 IkeaGatewayClient Failed request for IKEA GW, error: 4.04
(no other new lines in log)

I hope you you can figure out what's going on.

BR,
Mikko

[mikkot]

Btw where does the text "IKEA GW" come from in the log? Just asking because I'm quite sure this was the nethome item name I gave for the very first time to the GW. Since the first failure and recreation I have been using other names ("New Item nn").

BR,
Mikko

[stefangsbb]

Ahaaa, now we are getting somewhere - you receive a 404 from the GW! It could be that you have created a HomeItem for a lamp, that does no longer exist - but that IKEA Lamp Item keeps polling for its current state, and the GW keep getting 404 since the lamp no longer exist.

My guess in that case is that everything still works fine, even if the gateway says it is offline. Try creating a fresh Lamp-Item and check if that still works even after the GW is offline.

I also see a strange error when trying to set up the encrypted DTLS-connection but I cannot see why.

The text "IKEA GW" is what I entered in the log message to identify the Item type. Is the fixed IP you entered 192.168.1.15?

[mikkot]

Okey, I did the following;
1. IKEA GW reset & reinstall the remote and 2 lamps
2.I deleted ALL the IKEA items in ONH i.e. the GW and two the lamps I have connected.
3. Then I created the GW and the lamp items again.

They were working for couple of minutes perfectly, then - as before - no commands went thru anymore, but IKEA GW status was still "Connected". After couple of more minutes also the GW status went back to "Not Connected".

The log:
17.08.19 19:58:22 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65537
17.08.19 19:51:56 CoapEndpoint Destroying endpoint at address 0.0.0.0/0.0.0.0:0
17.08.19 19:51:56 DTLSConnector DTLS connector listening on [{0}] with MTU [{1}] using (inbound) datagram buffer size [{2} bytes]
17.08.19 19:51:56 CoapEndpoint Starting endpoint at 0.0.0.0/0.0.0.0:0
17.08.19 19:51:39 ReliabilityLayer Endpoint is being destroyed: skipping retransmission
17.08.19 19:51:37 ReliabilityLayer Endpoint is being destroyed: skipping retransmission
17.08.19 19:51:31 CoapEndpoint Destroying endpoint at address 0.0.0.0/0.0.0.0:0
17.08.19 19:51:31 DTLSConnector Stopping DTLS connector on [{0}]
17.08.19 19:51:31 CoapEndpoint Stopping endpoint at address 0.0.0.0/0.0.0.0:60046
17.08.19 19:51:21 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 19:51:20 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 19:50:21 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 19:50:19 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 19:48:09 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65538
17.08.19 19:45:16 TCPCommandPort$Session Disconnected from 127.0.0.1
17.08.19 19:45:12 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001
17.08.19 19:45:09 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65537
17.08.19 19:45:08 TCPCommandPort Connection from 127.0.0.1
17.08.19 19:38:09 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65538
17.08.19 19:35:08 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65537
17.08.19 19:30:17 TCPCommandPort$Session Disconnected from 127.0.0.1
17.08.19 19:30:09 TCPCommandPort Connection from 127.0.0.1
17.08.19 19:28:09 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65538
17.08.19 19:25:08 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65537
17.08.19 19:19:12 TCPCommandPort$Session Disconnected from 127.0.0.1
17.08.19 19:19:12 TCPCommandPort Connection from 127.0.0.1
17.08.19 19:18:09 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65538
17.08.19 19:15:16 TCPCommandPort$Session Disconnected from 127.0.0.1
17.08.19 19:15:08 TCPCommandPort Connection from 127.0.0.1
17.08.19 19:15:08 IkeaGatewayClient Timeout waiting for response from IKEA GW coaps://192.168.1.15/15001/65537

A lot of timeouts for IKEA GW response. Something is still wrong. All the time the iPhone app was working normally.

Could it be a faulty GW hardware? On the other hand, the app is working ok... I guess it's using the same API/protocol than ONH. I'm actually visiting IKEA tomorrow. I could change the unit just to be safe.

Any more ideas left?

BR,
Mikko

[stefangsbb]

Ok, that was a really thorough investigation - good work. Unfortunately we are still a bit stuck... I see three possible causes:
1) The COAP client library I use, get stuck somehow
2) Your router stops distributing the UDP-messages correctly between the endpoints
3) The IKEA GW stops listening for messages specifically from OpenNetHome

It is strange that it starts working again when you recreate the Item. One thing that happens at creation is that MDNS is used to discover the GW on the network, maybe that has a part in this? Could you try to do a MDNS-scan when the GW loses connection? You find the MDNS_Scanner in "Ports" under "All Items". Just press "scan" and see if that has any effect on how the IKEA GW behaves.

[stefangsbb]

There is another possibility - that the GW changes port is uses. I have now implemented an updated version where the GW-Item also reads the port from the mDNS reply, and also updates the port (and IP) if it changes in later mDNS entries. It is in the nightly build.

[mikkot]

Thanks again Stefan!

I got back home from IKEA, now with a brand new GW, remote and lamp. Just recreated everything from the scratch once more. While unplugging the old GW this morning I realised a potential power issue; The GW was connected to the routers usb socket (meant for an external HDD). It may not output enough power. The IKEA GW says 1A in the back. The new GW is now connected with the usb power dongle that came with the unit.

I think this might have been the reason for strange behaviour (although still don't get why it worked for couple of minutes every time I recreated the item and also the phone app worked all the time...).

I have not yet upgraded to your latest nightly build. Let's see how the new GW works first (with a proper power).

Edit: It has been up 'n running for 45 minutes now and everything seems to work still (that never happened before). Pity, that I cannot verify the problem 100% as I no longer have the original GW, but I'd bet my money on the power issue! (Well, thinking again, I could try the usb socket on the router again, maybe another day )

Br,
Mikko

[stefangsbb]

Ok, I am really glad that the problem seems to be solved!
I am still very surprised about the cause though... I find it hard to understand how either of those two causes could have had the effect that it worked for a while and then stopped (but not for the app). Well, hardware related issues can be really tricky...
Hope the system will work well for you now!

[mikkot]

Yes, HW/power issues can cause really strange symptoms. I have personally experienced these with several ESP8266/arduino projects at home.

Forget to properly thank you for your excellent support! So thank you very much!

And back to my original feature requests: Do you know if the IKEA remote signals could be received by ONH without effecting any lamps directly (no pairing between the lamp and remote at all)? Would be nice to use the remote as a generic switch/command interface for ONH. I read somewhere that at least this is not possible for HUE remotes as Philips has not opened the API for the remote signals.

BR,
Mikko