LED strip changes colour on its own

AJUK · May 7, 2020, 5:48pm

I’ve just put an RGBW LED strip up with a Zigbee controller. It’s kind of working but is doing strange things.

If I change the colour, just by tapping on the slider in the Paper UI rather than sliding it, I get something like this in the log and the slider moves back and forth for a few seconds before settling at a different colour to where I tapped it:

2020-05-07 18:41:52.666 [nt.ItemStatePredictedEvent] - iGardenLEDsColour predicted to become 308,54,100
2020-05-07 18:41:52.683 [vent.ItemStateChangedEvent] - iGardenLEDsColour changed from 307.55905,100.0,100 to 308,54,100
2020-05-07 18:41:55.053 [vent.ItemStateChangedEvent] - iGardenLEDsColour changed from 308,54,100 to 329,100,100
2020-05-07 18:41:55.552 [vent.ItemStateChangedEvent] - iGardenLEDsColour changed from 329,100,100 to 307.55905,95.27559,100
2020-05-07 18:41:55.995 [vent.ItemStateChangedEvent] - iGardenLEDsColour changed from 307.55905,95.27559,100 to 350,51,100
2020-05-07 18:41:56.497 [vent.ItemStateChangedEvent] - iGardenLEDsColour changed from 350,51,100 to 307.55905,53.937008,100

Is this normal?

chris · May 7, 2020, 7:45pm

Are you able to provide a debug log showing what is happening please? The binding doc explains what to do (toward the bottom there’s a section on debugging).

AJUK · May 7, 2020, 8:28pm

Just checked that. It’s a bit over my knowledge level, I’m afraid. I tried to follow an instruction to open a karaf shell but that didn’t work.

Could you give me a pointer, please?

The LED strip has 3 channels: Colour, Saturation and Brightness. They all do weird things where you click at one end of the slider. It goes where you click then it’ll whizz down to one end and back. At the same time, the saturation will do the same even though I haven’t touched it. I wonder if it’s a limitation of either the driver or the strip.

The driver is:
https://www.amazon.co.uk/gp/product/B07XCWSZCS/ref=ppx_yo_dt_b_search_asin_title?ie=UTF8&psc=1

The LED strip is:
https://www.amazon.co.uk/gp/product/B07DDCQFM5/ref=ppx_yo_dt_b_search_asin_title?ie=UTF8&psc=1

AJUK · May 7, 2020, 9:38pm

Correction. The Thing only has one channel - color.

I’m also questioning if it’s something I’m doing wrong. It detects the thing. I add an item with the type “color” and link it to the color channel for the thing. This automatically creates sliders for the colour, saturation and brightness.

AJUK · May 8, 2020, 6:48am

Ok, moved on a bit. I’ve worked out how to enter Karaf commands and done what it says on the binding page. The only issue at the moment is that it’s not doing its weird autonomous sliding thing. However, it did just go from on to off without me doing anything.

I’ve looked at the logs. Even if I filter by the address of that devices it’s still shoving through anything up to 10 entries a second. If I change the colour using my phone and watch the log, how much do you need after the command is sent?

chris · May 8, 2020, 9:39am

Cool - sounds like you’re making progress.

If you can provide me all the log associated with the event we’re trying to debug. So if it’s a short event (eg a single button press as we have here) then a few seconds or so is fine. This allows me to focus on the issue.

If it’s a more general issue such as startup, initialisation etc, then I like to get a much longer log to get better context about what’s going on.

rossko57 · May 8, 2020, 9:43am

This has the feel of two devices being linked somehow to one channel.

AJUK · May 8, 2020, 12:34pm

I wondered about this. There is only one channel - for color - so initially I added a colour change item and a switch. I’ve now removed all the items and links and created a new one, leaving it with the suggestions.

In the Paper UI interface I still get Colour, Brightness and Saturation sliders. I get this in the log if I change the colour. I’ve left the brightness and saturation at maximum:

2020-05-08 13:26:28.437 [ome.event.ItemCommandEvent] - Item ‘GardenLEDs’ received command 357,100,100
2020-05-08 13:26:28.463 [nt.ItemStatePredictedEvent] - GardenLEDs predicted to become 357,100,100
2020-05-08 13:26:28.480 [vent.ItemStateChangedEvent] - GardenLEDs changed from 236,100,100 to 357,100,100

So, in there, it says that it’s done it but it takes about 30 seconds for the light to respond.

It does seem like it doesn’t like certain colours and will default to a soft green. I’ve checked my wiring just in case there was a dodgy connection and that seems fine.

AJUK · May 8, 2020, 12:41pm

This is what I get when I just tap a point on the colour slider on the Paper UI interface. This is about 5 seconds worth. Apologies for the length. I haven’t been playing with this long enough to know what’s relevant and what’s not. I figured it’s better looking at it than for it!

2020-05-08 13:35:45.929 [ome.event.ItemCommandEvent] - Item 'GardenLEDs' received command 117,0,0

2020-05-08 13:35:45.964 [nt.ItemStatePredictedEvent] - GardenLEDs predicted to become 117,0,0

2020-05-08 13:35:45.982 [vent.ItemStateChangedEvent] - GardenLEDs changed from 240,0,0 to 117,0,0

==> /var/log/openhab2/openhab.log <==

2020-05-08 13:35:45.988 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000476832A: Command for channel zigbee:device:cb7365dd:00158d000476832a:00158D000476832A_1_color --> 117,0,0 [HSBType]

2020-05-08 13:35:45.992 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=0, state=WAITING, sendCnt=0, command=OffCommand [On/Off: 0000/0 -> 4397/1, cluster=0006, TID=--]]

2020-05-08 13:35:45.995 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 13 A1 00 0B 57 FF FE 98 8F 53 75 8B 00 03 F7 71 24 3A 55 33 34

2020-05-08 13:35:45.995 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: Added transaction to queue, len=3, transaction=ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=0, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4397/1, cluster=0300, TID=--, hue=83, saturation=0, transitionTime=10]]

2020-05-08 13:35:45.997 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeRouteRecordEvent [ieeeAddress=000B57FFFE988F53, networkAddress=30091, receiveOptions=UNKNOWN, addressList=F771 243A 5533]

2020-05-08 13:35:45.999 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - Unhandled XBee Frame: XBeeRouteRecordEvent [ieeeAddress=000B57FFFE988F53, networkAddress=30091, receiveOptions=UNKNOWN, addressList=F771 243A 5533]

2020-05-08 13:35:46.040 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 19 91 00 0B 57 FF FE 98 8F 53 75 8B 01 01 00 08 01 04 01 08 51 0A 00 00 20 7F 83

2020-05-08 13:35:46.041 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=000B57FFFE988F53, networkAddress=30091, sourceEndpoint=1, destinationEndpoint=1, clusterId=8, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=08 51 0A 00 00 20 7F]

2020-05-08 13:35:46.043 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=758B/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=08 51 0A 00 00 20 7F]

2020-05-08 13:35:46.044 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=81, commandId=10]

2020-05-08 13:35:46.045 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Level Control: 758B/1 -> 0000/1, cluster=0008, TID=51, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]]

2020-05-08 13:35:46.046 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 758B/1 -> 0000/1, cluster=0008, TID=51, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]] 

2020-05-08 13:35:46.047 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 758B/1 -> 0000/1, cluster=0008, TID=51, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]] ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=33586, state=DISPATCHED, sendCnt=2, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 4397/1, cluster=0019, TID=CC, status=NO_IMAGE_AVAILABLE, manufacturerCode=4478, imageType=269, fileVersion=1, imageSize=0]]

2020-05-08 13:35:46.048 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 758B/1 -> 0000/1, cluster=0008, TID=51, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]] ZigBeeTransaction [ieeeAddress=286D9700010C9D86 queueTime=703233, state=DISPATCHED, sendCnt=1, command=DefaultResponse [IAS Zone: 0000/0 -> 11B9/1, cluster=0500, TID=66, commandIdentifier=0, statusCode=SUCCESS]]

2020-05-08 13:35:46.049 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 758B/1 -> 0000/1, cluster=0008, TID=51, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]] ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=4404, state=DISPATCHED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> 4397/1, cluster=0300, TID=5E, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-08 13:35:46.050 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 758B/1 -> 0000/1, cluster=0008, TID=51, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=127]]] ZigBeeTransaction [ieeeAddress=286D9700010C9A8F queueTime=1755959, state=DISPATCHED, sendCnt=2, command=DefaultResponse [IAS Zone: 0000/0 -> B234/1, cluster=0500, TID=43, commandIdentifier=0, statusCode=SUCCESS]]

2020-05-08 13:35:46.052 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000B57FFFE988F53: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000B57FFFE988F53 queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Level Control: 0000/0 -> 758B/1, cluster=0008, TID=51, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-08 13:35:46.052 [DEBUG] [converter.ZigBeeConverterSwitchLevel] - 000B57FFFE988F53: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=127, lastReportTime=Fri May 08 13:35:46 BST 2020, implemented=true]

2020-05-08 13:35:46.053 [DEBUG] [transaction.ZigBeeTransactionManager] - 758B/1: Sending ZigBeeTransaction [ieeeAddress=000B57FFFE988F53 queueTime=1, state=WAITING, sendCnt=0, command=DefaultResponse [Level Control: 0000/0 -> 758B/1, cluster=0008, TID=51, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-08 13:35:46.054 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 5 outstanding

2020-05-08 13:35:46.055 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Level Control: 0000/0 -> 758B/1, cluster=0008, TID=51, commandIdentifier=10, statusCode=SUCCESS]

2020-05-08 13:35:46.056 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=81, commandId=11]

2020-05-08 13:35:46.057 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=758B/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=8D, rssi=--, lqi=--, payload=10 51 0B 0A 00]

2020-05-08 13:35:46.058 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=000B57FFFE988F53, networkAddress=30091, sourceEndpoint=1, destinationEndpoint=1, cluster=8, profileId=260, broadcastRadius=0, options=[], data=10 51 0B 0A 00]

2020-05-08 13:35:46.059 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 3: XBeeTransmitRequestExplicitCommand [frameId=240, ieeeAddress=000B57FFFE988F53, networkAddress=30091, sourceEndpoint=1, destinationEndpoint=1, cluster=8, profileId=260, broadcastRadius=0, options=[], data=10 51 0B 0A 00]

2020-05-08 13:35:46.516 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B ED B2 34 00 00 00 A1

2020-05-08 13:35:46.517 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=237, networkAddress=45620, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-08 13:35:46.518 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=238, ieeeAddress=00158D000476832A, networkAddress=17303, sourceEndpoint=1, destinationEndpoint=1, cluster=25, profileId=260, broadcastRadius=0, options=[], data=19 CC 02 98]

2020-05-08 13:35:46.520 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 18 11 EE 00 15 8D 00 04 76 83 2A 43 97 01 01 00 19 01 04 00 00 19 CC 02 98 BE

2020-05-08 13:35:46.605 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B EE 43 97 00 00 00 AC

2020-05-08 13:35:46.606 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=238, networkAddress=17303, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-08 13:35:46.607 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=239, ieeeAddress=00158D000476832A, networkAddress=17303, sourceEndpoint=1, destinationEndpoint=1, cluster=768, profileId=260, broadcastRadius=0, options=[], data=10 5E 0B 0A 00]

2020-05-08 13:35:46.609 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 EF 00 15 8D 00 04 76 83 2A 43 97 01 01 03 00 01 04 00 00 10 5E 0B 0A 00 CF

2020-05-08 13:35:46.709 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B EF 43 97 00 00 00 AB

2020-05-08 13:35:46.710 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=239, networkAddress=17303, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

2020-05-08 13:35:46.714 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=240, ieeeAddress=000B57FFFE988F53, networkAddress=30091, sourceEndpoint=1, destinationEndpoint=1, cluster=8, profileId=260, broadcastRadius=0, options=[], data=10 51 0B 0A 00]

2020-05-08 13:35:46.717 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 F0 00 0B 57 FF FE 98 8F 53 75 8B 01 01 00 08 01 04 00 00 10 51 0B 0A 00 A0

2020-05-08 13:35:46.859 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 13 A1 00 0B 57 FF FE 98 8F 53 75 8B 00 03 F7 71 24 3A 55 33 34

2020-05-08 13:35:46.860 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeRouteRecordEvent [ieeeAddress=000B57FFFE988F53, networkAddress=30091, receiveOptions=UNKNOWN, addressList=F771 243A 5533]

2020-05-08 13:35:46.863 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - Unhandled XBee Frame: XBeeRouteRecordEvent [ieeeAddress=000B57FFFE988F53, networkAddress=30091, receiveOptions=UNKNOWN, addressList=F771 243A 5533]

2020-05-08 13:35:46.882 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B F0 75 8B 00 00 00 84

2020-05-08 13:35:46.884 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=240, networkAddress=30091, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]

==> /var/log/openhab2/events.log <==

2020-05-08 13:35:47.106 [vent.ItemStateChangedEvent] - MoonDistance changed from 364589.46725608414 km to 364592.23084613937 km

2020-05-08 13:35:47.163 [vent.ItemStateChangedEvent] - Azimuth changed from 193.49328180239195 ° to 193.9088762921083 °

2020-05-08 13:35:47.189 [vent.ItemStateChangedEvent] - Elevation changed from 55.414102468270364 ° to 55.377177902174246 °

2020-05-08 13:35:47.191 [vent.ItemStateChangedEvent] - Diffuse_Radiation changed from 125.7883052833381 W/m² to 125.78056352097921 W/m²

2020-05-08 13:35:47.193 [vent.ItemStateChangedEvent] - Total_Radiation changed from 714.580792459189 W/m² to 714.1474306743162 W/m²

==> /var/log/openhab2/openhab.log <==

2020-05-08 13:35:49.043 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=286D9700010C9D86 queueTime=706227, state=FAILED, sendCnt=1, command=DefaultResponse [IAS Zone: 0000/0 -> 11B9/1, cluster=0500, TID=66, commandIdentifier=0, statusCode=SUCCESS]]

2020-05-08 13:35:49.044 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 4 outstanding

2020-05-08 13:35:49.046 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 286D9700010C9D86: transactionComplete FAILED 0

2020-05-08 13:35:49.048 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 286D9700010C9D86: Added transaction to queue, len=11, transaction=ZigBeeTransaction [ieeeAddress=286D9700010C9D86 queueTime=706233, state=WAITING, sendCnt=1, command=DefaultResponse [IAS Zone: 0000/0 -> 11B9/1, cluster=0500, TID=66, commandIdentifier=0, statusCode=SUCCESS]]

2020-05-08 13:35:49.051 [DEBUG] [transaction.ZigBeeTransactionManager] - 11B9/1: Sending ZigBeeTransaction [ieeeAddress=286D9700010C9D86 queueTime=706235, state=WAITING, sendCnt=1, command=DefaultResponse [IAS Zone: 0000/0 -> 11B9/1, cluster=0500, TID=66, commandIdentifier=0, statusCode=SUCCESS]]

2020-05-08 13:35:49.052 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 5 outstanding

2020-05-08 13:35:49.055 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [IAS Zone: 0000/0 -> 11B9/1, cluster=0500, TID=66, commandIdentifier=0, statusCode=SUCCESS]

2020-05-08 13:35:49.056 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=102, commandId=11]

2020-05-08 13:35:49.058 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=11B9/1, profile=0104, cluster=0500, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=8E, rssi=--, lqi=--, payload=10 66 0B 00 00]

2020-05-08 13:35:49.062 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=286D9700010C9D86, networkAddress=4537, sourceEndpoint=1, destinationEndpoint=1, cluster=1280, profileId=260, broadcastRadius=0, options=[], data=10 66 0B 00 00]

2020-05-08 13:35:49.064 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=241, ieeeAddress=286D9700010C9D86, networkAddress=4537, sourceEndpoint=1, destinationEndpoint=1, cluster=1280, profileId=260, broadcastRadius=0, options=[], data=10 66 0B 00 00]

2020-05-08 13:35:49.066 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=241, ieeeAddress=286D9700010C9D86, networkAddress=4537, sourceEndpoint=1, destinationEndpoint=1, cluster=1280, profileId=260, broadcastRadius=0, options=[], data=10 66 0B 00 00]

2020-05-08 13:35:49.069 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 19 11 F1 28 6D 97 00 01 0C 9D 86 11 B9 01 01 05 00 01 04 00 00 10 66 0B 00 00 4A

rossko57 · May 8, 2020, 12:44pm

Hmm, but these things can linger. Some bindings are better than others at inflight reconfiguring.

Nah, that’s autoupdate at work. It predicts an expected Item state from a command, and applies an update, unless the binding objects. It’ll work even there is no end device at all.

AJUK · May 8, 2020, 12:44pm

And this is a shorter clip where I’ve just filtered by the device id ending in 832A:

2020-05-08 13:42:29.617 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D000476832A: Command for channel zigbee:device:cb7365dd:00158d000476832a:00158D000476832A_1_color --> 252,0,0 [HSBType]

2020-05-08 13:42:29.618 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=0, state=WAITING, sendCnt=0, command=OffCommand [On/Off: 0000/0 -> 4397/1, cluster=0006, TID=--]]

2020-05-08 13:42:29.620 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=0, state=WAITING, sendCnt=0, command=MoveToHueAndSaturationCommand [Color Control: 0000/0 -> 4397/1, cluster=0300, TID=--, hue=178, saturation=0, transitionTime=10]]

2020-05-08 13:42:37.750 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=29265, state=FAILED, sendCnt=2, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 4397/1, cluster=0019, TID=D7, status=NO_IMAGE_AVAILABLE, manufacturerCode=4478, imageType=269, fileVersion=1, imageSize=0]]

2020-05-08 13:42:37.753 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: transactionComplete FAILED 1

2020-05-08 13:42:37.754 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: transactionComplete exceeded retries 2

2020-05-08 13:42:37.756 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction terminated: ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=29272, state=FAILED, sendCnt=2, command=QueryNextImageResponse [Ota Upgrade: 0000/0 -> 4397/1, cluster=0019, TID=D7, status=NO_IMAGE_AVAILABLE, manufacturerCode=4478, imageType=269, fileVersion=1, imageSize=0]]

2020-05-08 13:42:37.758 [DEBUG] [transaction.ZigBeeTransactionManager] - 4397/1: Sending ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=8140, state=WAITING, sendCnt=0, command=OffCommand [On/Off: 0000/0 -> 4397/1, cluster=0006, TID=B7]]

2020-05-08 13:42:37.767 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=null, ieeeAddress=00158D000476832A, networkAddress=17303, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 B7 00]

2020-05-08 13:42:37.769 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=180, ieeeAddress=00158D000476832A, networkAddress=17303, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 B7 00]

2020-05-08 13:42:38.699 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=25039, state=FAILED, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> 4397/1, cluster=0300, TID=F1, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-08 13:42:38.702 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: transactionComplete FAILED 1

2020-05-08 13:42:38.704 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 00158D000476832A: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=25044, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> 4397/1, cluster=0300, TID=F1, commandIdentifier=10, statusCode=SUCCESS]]

2020-05-08 13:42:38.707 [DEBUG] [transaction.ZigBeeTransactionManager] - 4397/1: Sending ZigBeeTransaction [ieeeAddress=00158D000476832A queueTime=25047, state=WAITING, sendCnt=1, command=DefaultResponse [Color Control: 0000/0 -> 4397/1, cluster=0300, TID=F1, commandIdentifier=10, statusCode=SUCCESS]]