Hello, I am running Openhab2, version 2.2.0 build 994, on a Raspberry Pi. I am having lots of trouble with the LIFX binding recently. Earlier this year, it was working perfectly - I had rules controlling several LIFX bulbs throughout the house - but something seems to have changed. I cannot get the binding to reliably control lights at all any more. Most of the time, it ignores commands altogether, but sometimes one or two commands will slip through after 1-3 minutes. The LIFX iOS app and Alexa are able to control the lights without any issue, every time.
As for my network, I am running a Netgear AC1900 router with Merlin firmware. IPv6 is disabled on my network. In an effort to reduce variables, I changed my 2.4g wifi to a fixed channel (11) and removed the second wifi access point from my network. I also disabled IPv6 on the Pi.
I have tried this with both auto-discovered things, and a things file. Here is my things file, this is a simplified version that I am using for testing that contains only one light:
Thing lifx:colorlight:D073D521BE82 "Media Room Lamp" [ deviceId="D073D521BE82", fadetime=3000 ] {
Channels:
Type color : color [ powerOnBrightness=100 ]
}
Items file:
Color media_room_lamp "Media Room Lamp" { channel="lifx:colorlight:D073D521BE82:color" }
Switch media_room_lamp_power "Media Room Lamp Power" { channel="lifx:colorlight:D073D521BE82:color" }
Dimmer media_room_lamp_temperature "Media Room Lamp Temperature" { channel="lifx:colorlight:D073D521BE82:temperature" }
Here are the LIFX-related lines in my log, this contains startup and a failed attempt to control a bulb:
2017-08-02 19:03:47.386 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lifx.items'
2017-08-02 19:05:14.151 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'lifx.things'
2017-08-02 19:05:40.358 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate command 'OFF' for item 'media_room_lamp' to handler for channel 'lifx:colorlight:D073D521BE82:color', because no thing with the UID 'lifx:colorlight:D073D521BE82' could be found.
2017-08-02 19:05:40.360 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update 'OFF' for item 'media_room_lamp' to handler for channel 'lifx:colorlight:D073D521BE82:color', because no thing with the UID 'lifx:colorlight:D073D521BE82' could be found.
2017-08-02 19:06:51.808 [DEBUG] [org.eclipse.smarthome.binding.lifx ] - BundleEvent STARTING - org.eclipse.smarthome.binding.lifx
2017-08-02 19:06:51.881 [DEBUG] [org.eclipse.smarthome.binding.lifx ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.binding.lifx.internal.LifxChannelFactory}={component.name=org.eclipse.smarthome.binding.lifx.internal.LifxChannelFactory, component.id=220, service.id=1025, service.bundleid=220, service.scope=bundle} - org.eclipse.smarthome.binding.lifx
2017-08-02 19:07:45.713 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate command '260,100,50' for item 'media_room_lamp' to handler for channel 'lifx:colorlight:D073D521BE82:color', because no thing with the UID lifx:colorlight:D073D521BE82' could be found.
2017-08-02 19:07:45.947 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate update '260,100,50' for item 'media_room_lamp' to handler for channel 'lifx:colorlight:D073D521BE82:color', because no thing with the UID 'lifx:colorlight:D073D521BE82' could be found.
2017-08-02 19:07:53.780 [DEBUG] [org.eclipse.smarthome.binding.lifx ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.eclipse.smarthome.binding.lifx.internal.LifxHandlerFactory, component.id=221, service.id=1027, service.bundleid=220, service.scope=bundle} - org.eclipse.smarthome.binding.lifx
2017-08-02 19:07:53.851 [DEBUG] [inding.lifx.handler.LifxLightHandler] - Initializing the LIFX handler for light 'D0:73:D5:21:DA:8A'.
2017-08-02 19:07:53.917 [DEBUG] [ternal.LifxLightCommunicationHandler] - Starting LIFX communication handler for light 'D0:73:D5:21:DA:8A'.
2017-08-02 19:07:53.919 [DEBUG] [ternal.LifxLightCommunicationHandler] - The LIFX handler will use '97ee7716' as source identifier
2017-08-02 19:07:53.923 [DEBUG] [ternal.LifxLightCommunicationHandler] - Adding '/10.42.0.116' as interface address with MTU 1500
2017-08-02 19:07:53.925 [DEBUG] [ternal.LifxLightCommunicationHandler] - Adding '/10.42.0.255' as broadcast address
2017-08-02 19:07:53.933 [DEBUG] [ternal.LifxLightCommunicationHandler] - Binding the broadcast channel on port 56701
2017-08-02 19:07:54.024 [DEBUG] [inding.lifx.handler.LifxLightHandler] - Initializing the LIFX handler for light 'D0:73:D5:21:BE:82'.
2017-08-02 19:07:54.026 [DEBUG] [ternal.LifxLightCommunicationHandler] - Starting LIFX communication handler for light 'D0:73:D5:21:BE:82'.
2017-08-02 19:07:54.027 [DEBUG] [ternal.LifxLightCommunicationHandler] - The LIFX handler will use '9020d987' as source identifier
2017-08-02 19:07:54.028 [DEBUG] [ternal.LifxLightCommunicationHandler] - Adding '/10.42.0.116' as interface address with MTU 1500
2017-08-02 19:07:54.029 [DEBUG] [ternal.LifxLightCommunicationHandler] - Adding '/10.42.0.255' as broadcast address
2017-08-02 19:07:54.030 [DEBUG] [ternal.LifxLightCommunicationHandler] - Binding the broadcast channel on port 56702
2017-08-02 19:07:54.061 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - Starting the LIFX device background discovery
2017-08-02 19:07:54.064 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - Adding '/10.42.0.116' as interface address with MTU 1500
2017-08-02 19:07:54.065 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - Adding '/10.42.0.255' as broadcast address
2017-08-02 19:07:54.068 [DEBUG] [org.eclipse.smarthome.binding.lifx ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={component.name=org.eclipse.smarthome.binding.lifx.internal.LifxLightDiscovery, component.id=222, service.id=1028, service.bundleid=220, service.scope=bundle} - org.eclipse.smarthome.binding.lifx
2017-08-02 19:07:54.078 [DEBUG] [org.eclipse.smarthome.binding.lifx ] - BundleEvent STARTED - org.eclipse.smarthome.binding.lifx
2017-08-02 19:07:54.102 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - The LIFX discovery service will use '27a99505' as source identifier
2017-08-02 19:08:54.141 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - The LIFX discovery service will use '59a24c8b' as source identifier
2017-08-02 19:08:58.569 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:DA:8A : Updating light properties
2017-08-02 19:08:58.771 [DEBUG] [.lifx.internal.LifxLightStateChanger] - D0:73:D5:21:BE:82 : Sending SetLightPowerRequest packet
2017-08-02 19:09:54.171 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - The LIFX discovery service will use '9e6ad234' as source identifier
2017-08-02 19:10:08.908 [DEBUG] [.lifx.internal.LifxLightStateChanger] - D0:73:D5:21:BE:82 : Sending SetColorRequest packet
2017-08-02 19:10:09.042 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:DA:8A : Resending requests for missing response packets
2017-08-02 19:10:09.145 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:BE:82 : Updating light properties
2017-08-02 19:10:54.189 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - The LIFX discovery service will use 'ad9e2b41' as source identifier
2017-08-02 19:11:18.901 [DEBUG] [.lifx.internal.LifxLightStateChanger] - D0:73:D5:21:BE:82 : Sending SetLightPowerRequest packet
2017-08-02 19:11:19.085 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:DA:8A : Resending requests for missing response packets
2017-08-02 19:11:19.190 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:BE:82 : Resending requests for missing response packets
2017-08-02 19:11:54.210 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - The LIFX discovery service will use 'e0c37bd6' as source identifier
2017-08-02 19:12:29.995 [DEBUG] [.lifx.internal.LifxLightStateChanger] - D0:73:D5:21:BE:82 : No pending packet found for ack with sequence number: 3
2017-08-02 19:12:30.001 [DEBUG] [.lifx.internal.LifxLightStateChanger] - D0:73:D5:21:BE:82 : Sending SetLightPowerRequest packet
2017-08-02 19:12:30.112 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:DA:8A : Resending requests for missing response packets
2017-08-02 19:12:30.214 [DEBUG] [.internal.LifxLightPropertiesUpdater] - D0:73:D5:21:BE:82 : Resending requests for missing response packets
2017-08-02 19:12:54.224 [DEBUG] [ing.lifx.internal.LifxLightDiscovery] - The LIFX discovery service will use '25dcd6c9' as source identifier
The things show up in the OSGI console as ONLINE, eventually. In the events log, when the system starts the bundle is not able to bring the devices ONLINE immediately, they start OFFLINE and then come up some time later (note the time gap):
2017-08-02 19:07:54.026 [hingStatusInfoChangedEvent] - 'lifx:colorlight:D073D521BE82' changed from UNINITIALIZED to INITIALIZING
2017-08-02 19:07:54.038 [hingStatusInfoChangedEvent] - 'lifx:colorlight:D073D521BE82' changed from INITIALIZING to OFFLINE
2017-08-02 19:10:08.908 [hingStatusInfoChangedEvent] - 'lifx:colorlight:D073D521BE82' changed from OFFLINE to ONLINE
Is there any possible way this could be my router or my network configuration? The router is a few months old, I can’t remember if it coincided with the problems starting. Since the iOS app and Alexa both work though, that makes me doubt there is a network issue. However, the log mentions missing packets…
I’m not sure how to debug this further, so I’m coming here for help! Let me know what else I can provide. Would TRACE logging help? Are there any wifi or network settings I can try?