Lightify Connector died

Hi Folks,

since some weeks I started do work with the Osram Sylvania Lightify binding. Sporadic I get an error, “Connector died”. Then I have to restart Openhab 2.1 to get it to work again.
Does anybody has an idea?

Here the relevant part of the logs:

2017-11-27 20:25:02.774 [DEBUG] [org.openhab.binding.osramlightify   ] - BundleEvent STARTING - org.openhab.binding.osramlightify
2017-11-27 20:25:02.784 [DEBUG] [org.openhab.binding.osramlightify   ] - BundleEvent STARTED - org.openhab.binding.osramlightify
2017-11-27 20:25:02.993 [DEBUG] [org.openhab.binding.osramlightify   ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=423, service.bundleid=10, service.scope=singleton} - org.openhab.binding.osramlightify
2017-11-27 20:25:03.038 [DEBUG] [mlightify.internal.LightifyConnector] - Lightify connector started
2017-11-27 20:25:03.056 [DEBUG] [mlightify.internal.LightifyConnector] - Connecting to Lightify gateway...
2017-11-27 20:25:03.064 [DEBUG] [mlightify.internal.LightifyConnector] - Connecting to Lightify gateway using mDNS address 192.168.10.141:4000
2017-11-27 20:25:03.071 [DEBUG] [mlightify.internal.LightifyConnector] - Connected
2017-11-27 20:25:03.075 [DEBUG] [mlightify.internal.LightifyConnector] - TX: Packet type = GROUPCAST, Command = GET_GATEWAY_FIRMWARE_VERSION, Seq number = 0
2017-11-27 20:25:03.079 [TRACE] [mlightify.internal.LightifyConnector] - TX: 0600026F00000000
2017-11-27 20:25:03.103 [TRACE] [mlightify.internal.LightifyConnector] - RX: 0B00036F000000000001010335
2017-11-27 20:25:03.112 [INFO ] [sages.LightifyGatewayFirmwareMessage] - osramlightify:gateway:017b998c: firmware version = 1.1.3.53
2017-11-27 20:25:03.134 [TRACE] [overy.LightifyDeviceDiscoveryService] - Start scanning for paired devices
2017-11-27 20:25:03.135 [TRACE] [mlightify.internal.LightifyConnector] - TX: Packet type = GROUPCAST, Command = LIST_GROUPS, Seq number = 1
2017-11-27 20:25:03.137 [TRACE] [mlightify.internal.LightifyConnector] - TX: 0700021E0100000001
2017-11-27 20:25:03.166 [TRACE] [mlightify.internal.LightifyConnector] - RX: 1B00031E010000000001000200537465686C616D706500000000000000
2017-11-27 20:25:03.169 [TRACE] [l.messages.LightifyListGroupsMessage] - 0: reachable=0 power=false luminance=0 temperature=0 white mode=true r=0 g=0 b=0 a=0 time since seen=0mins joining=0
2017-11-27 20:25:03.172 [ERROR] [mlightify.internal.LightifyConnector] - Connector died:
java.lang.NullPointerException
        at org.openhab.binding.osramlightify.internal.messages.LightifyListGroupsMessage.handleResponse(LightifyListGroupsMessage.java:100)[10:org.openhab.binding.osramlightify:2.2.0.201710152309]
        at org.openhab.binding.osramlightify.internal.LightifyConnector.run(LightifyConnector.java:318)[10:org.openhab.binding.osramlightify:2.2.0.201710152309]

That’s strange. It looks like you have a thing for a group defined on the gateway but the thing doesn’t have a handler set. The thing’s UID would be osramlightify:gateway:017b998c:2 and the gateway calls it “Stehlampe”. Is that defined in a thing file somewhere or was it added via paperUI? You could try making sure it isn’t in any thing files then deleting it and re-adding it from the inbox.

Perhaps a Problem between OH 2.1.0 and Binding 2.2.0?

If you have an DEV System , try OH 2.2.0 with the Snapshot Binding?

I have checked, it is not defined any thing in a File.
What I did: I have deleted “Stehlampe” via Paper UI, did a stop and start bundle and then I did a rescan. Stehlampe was found again (as expected). In the logs (without DEBUG) I see following:

2017-11-28 08:43:18.697 [WARN ] [mlightify.internal.LightifyConnector] - Error
org.openhab.binding.osramlightify.internal.exceptions.LightifyException: status = RESET_REQUIRED response to Packet type = GROUPCAST, Command = GET_GATEWAY_FIRMWARE_VERSION, Seq number = 0, Status = RESET_REQUIRED
        at org.openhab.binding.osramlightify.internal.messages.LightifyBaseMessage.handleResponse(LightifyBaseMessage.java:235)[10:org.openhab.binding.osramlightify:2.2.0.201710152309]
        at org.openhab.binding.osramlightify.internal.messages.LightifyGatewayFirmwareMessage.handleResponse(LightifyGatewayFirmwareMessage.java:66)[10:org.openhab.binding.osramlightify:2.2.0.201710152309]
        at org.openhab.binding.osramlightify.internal.LightifyConnector.run(LightifyConnector.java:299)[10:org.openhab.binding.osramlightify:2.2.0.201710152309]
2017-11-28 08:43:18.716 [WARN ] [mlightify.internal.LightifyConnector] - Sequence number mismatch. Please report this! Got:
2017-11-28 08:43:19.061 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'osramlightify:group:017b998c:2' to inbox.

One more question for my information: How did you find out from the data that I have a thing called Stehlampe. I assume it is not clear text?..

Kevin, I use OH 2.1 and because of the mentioned error, I used the actual snapshot from lightify. So, I don’t think it is an issue from OH…

Any more ideas?

0x53 = S
0x74 = t
0x65 = e
0x68 = h
0x6C = l
0x61 = a
0x6D = m
0x70 = p
0x65 = e

The RESET_REQUIRED is fixed in the latest jar so you need to update it. Then see if the group thing works when added back. I’ve no idea how you could have had a thing without a handler on the bridge with only paperUI config. The handler should be set by the core when the thing is added and then never change.

I develop against release not dev so there’s no problem running on openHAB 2.1. And, yeah, I read hex and, yeah, it’s clear text on the LAN and relies solely on WiFi encryption and access controls. The cloud protocol is at least partly clear as well. Wireshark says it’s QUIC but that’s because it’s UDP on port 443. Disable QUIC decoding and it’s immediately obvious packets start with a length and contain a sequence number. Maybe the payload is encrypted but given the setup on the gateway it isn’t going to be strongly encrypted. Anyway, at least OSRAM, Arrayent (who run the cloud bit for them) and Amazon AWS compute (who provide the cloud service for them) have the data anyway so I’d just assume it’s public. At some point I’ll test whether you can just block the cloud access and I’ll add a security document. To be fair though, all wireless stuff has risks. But it would be nice if vendors would try and minimize them and document what people need to aware of!

Thank you for explanation.
Now I’ve installed the binding from Monday. I’ll come back to here, if the taken actions (update binding and delete the Group Thing) hasn’t fixed my problems

Hi @mjagdis!

First of all thanks for your continuous support on the Osram/Lightify binding - I appreciate it a lot!
I have changed from manual to PaperUI config, since the binding.

I face similar issues like mentioned here since a while, where I will get this error, once in a while. It results in all things turning to UNKNOWN.

2019-03-10 12:35:59.915 [ERROR] [mlightify.internal.LightifyConnector] - Connector died: 

java.lang.NullPointerException: null

	at org.openhab.binding.osramlightify.internal.messages.LightifyListPairedDevicesMessage.handleResponse(LightifyListPairedDevicesMessage.java:183) ~[?:?]

	at org.openhab.binding.osramlightify.internal.LightifyConnector.run(LightifyConnector.java:330) ~[?:?]

The Gateway changes to UNKNOWN as well - entering the Gateways IP in PaperUI doesn’t change the status.
Restarting the binding via

bundle:restart

results in the below:

2019-03-10 12:41:29.503 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-05-FD-FD' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.508 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-05-FD-FD' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.521 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-00-E5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.527 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-00-E5' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.546 [hingStatusInfoChangedEvent] - 'osramlightify:rgbw:7C-B0-3E-AA-00-A2-5D-C8' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.549 [hingStatusInfoChangedEvent] - 'osramlightify:rgbw:7C-B0-3E-AA-00-A2-5D-C8' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.563 [hingStatusInfoChangedEvent] - 'osramlightify:power:7C-B0-3E-AA-00-A3-3B-3F' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.567 [hingStatusInfoChangedEvent] - 'osramlightify:power:7C-B0-3E-AA-00-A3-3B-3F' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.582 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-24-74' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.586 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-24-74' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.594 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-3D-2C' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.599 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-3D-2C' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.614 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-00-F7' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.618 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-00-F7' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.631 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-2B-C1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.636 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-2B-C1' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.653 [hingStatusInfoChangedEvent] - 'osramlightify:tunable:84-18-26-00-00-00-52-B7' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.660 [hingStatusInfoChangedEvent] - 'osramlightify:tunable:84-18-26-00-00-00-52-B7' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.671 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-70-A1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.680 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-70-A1' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.702 [hingStatusInfoChangedEvent] - 'osramlightify:tunable:84-18-26-00-00-00-6C-FB' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.708 [hingStatusInfoChangedEvent] - 'osramlightify:tunable:84-18-26-00-00-00-6C-FB' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.715 [hingStatusInfoChangedEvent] - 'osramlightify:power:7C-B0-3E-AA-00-A3-B1-17' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.719 [hingStatusInfoChangedEvent] - 'osramlightify:power:7C-B0-3E-AA-00-A3-B1-17' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.748 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-05-FD-D4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.753 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-05-FD-D4' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.758 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-72-3D' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.763 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-06-72-3D' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.780 [hingStatusInfoChangedEvent] - 'osramlightify:allpaired:017c0419' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.784 [hingStatusInfoChangedEvent] - 'osramlightify:allpaired:017c0419' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.787 [hingStatusInfoChangedEvent] - 'osramlightify:allpaired:017c0419' changed from UNKNOWN to ONLINE

2019-03-10 12:41:29.798 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-26-57' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.807 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-26-57' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.820 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-38-1F' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.826 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-38-1F' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.843 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-05-FE-23' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.849 [hingStatusInfoChangedEvent] - 'osramlightify:dimmable:84-18-26-00-00-05-FE-23' changed from INITIALIZING to UNKNOWN

2019-03-10 12:41:29.857 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-37-54' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2019-03-10 12:41:29.864 [hingStatusInfoChangedEvent] - 'osramlightify:power:84-18-26-00-00-0C-37-54' changed from INITIALIZING to UNKNOWN

I’d appreciate your help!

Kurt