Zigbee binding

chris · December 21, 2017, 12:34am

These sticks should work (it’s the same as the other Ember devices people are using). It should work with all firmware up to 5.8 - after than Silabs have made some changes and I’m not fully implemented the new protocol yet.

Sometimes with these sticks the device doesn’t initialise - this is what we saw with your stick in the past. Normally it will sort its self out - I spent some time working with Silabs to try and resolve this, but as it’s intermittent, it’s not easy to find and Silabs were not able to provide much insight. It’s something I need to look at again in the new year.

TheNetStriker · December 21, 2017, 1:45pm

Thanks, I will try again if it works better than with the last version. The reason why I would want to try this again is that I have some annoying problems with the Hue binding since the OH 2.2 update which I described here: Hue bridge and lamps offline after OH 2.2 update

Maybe you could also take a look at this thread or tell me which person I could ask regarding the Hue binding.

AFromD · December 22, 2017, 12:48pm

I am having problems with my Ember dongle. After some time it just stops working, although OH acts like everything is OK. So one minute, all devices work as expected, the next minute everything stops reacting. When I command something through Alexa, it responds “ok” and commands are being executed in the paper UI. However, nothing is effected on the Zigbee devices. All my things show as “online”.

I have tried restarting OH, and rebooting the Windows 10 PC. Sometimes this restores it to working order, but it will always drop out again over time.

I have activated debug logging, here is a piece. Last part shows my trying to change color on Hue lamps. But also my motion sensor and Osram socket is not reacting or updating.

[type=EMBER_OUTGOING_DIRECT, indexOrDestination=29299, apsFrame=EmberApsFrame [profileId=0, clusterId=50, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=146], messageTag=59, status=EMBER_SUCCESS, messageContents=]
2017-12-22 13:41:07.171 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4]
2017-12-22 13:41:07.176 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - Sent queue larger than window [1 > 1].
2017-12-22 13:41:07.182 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=6, reTx=false, data=3B 90 45 00 00 00 32 80 00 00 40 01 00 00 D4 FF B3 73 72 FF FF 0F 00 00 02 00 02 00 00 00 00 00 AB 6C 00 AB 6C]
2017-12-22 13:41:07.184 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=212], lastHopLqi=255, lastHopRssi=-77, sender=29299, bindingIndex=255, addressIndex=255, messageContents=00 00 02 00 02 00 00 00 00 00 AB 6C 00 AB 6C]
2017-12-22 13:41:07.186 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0, clusterId=32818, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=212], lastHopLqi=255, lastHopRssi=-77, sender=29299, bindingIndex=255, addressIndex=255, messageContents=00 00 02 00 02 00 00 00 00 00 AB 6C 00 AB 6C]
2017-12-22 13:41:07.188 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=29299/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, sequence=59, payload=00 00 02 00 02 00 00 00 00 00 AB 6C 00 AB 6C]
2017-12-22 13:41:07.190 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [29299/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=2, startIndex=0, routingTableListCount=2, routingTableList=[RoutingTable [destinationAddress=0, status=ACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=27819, status=ACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=27819]]]
2017-12-22 13:41:07.192 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5]
2017-12-22 13:41:07.193 [DEBUG] [tems.zigbee.ZigBeeNetworkMeshMonitor] - 29299: Ending mesh update
2017-12-22 13:41:07.196 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - Sent queue larger than window [1 > 1].
2017-12-22 13:41:07.198 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameNak [ackNum=6]
2017-12-22 13:41:07.200 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=6, ackNum=5, reTx=true, data=3C 00 34 00 92 B0 00 00 01 00 00 00 40 11 00 00 3C 3C 05 00 92 B0 01 00]
2017-12-22 13:41:07.210 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - Sent queue larger than window [1 > 1].
2017-12-22 13:41:07.322 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameAck [ackNum=7]
2017-12-22 13:41:07.324 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=7, reTx=false, data=3C 80 34 00 93]
2017-12-22 13:41:07.326 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=147]
2017-12-22 13:41:07.327 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=147]
2017-12-22 13:41:07.328 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=147]
2017-12-22 13:41:07.329 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6]
2017-12-22 13:41:12.130 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=7, reTx=false, data=3C 90 3F 00 92 B0 00 00 01 00 00 00 40 11 00 00 93 3C 66 00]
2017-12-22 13:41:12.132 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=147], messageTag=60, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:12.134 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=147], messageTag=60, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:12.135 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=147], messageTag=60, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:12.136 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7]
2017-12-22 13:41:16.271 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 45202: Discovery request IEEE_ADDRESS failed. Wait before retry.
2017-12-22 13:41:17.773 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 45202/0, cluster=0001, TID=3D, nwkAddrOfInterest=45202, requestType=1, startIndex=0]
2017-12-22 13:41:17.776 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=45202/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, sequence=61, payload=00 92 B0 01 00]
2017-12-22 13:41:17.778 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=61], messageTag=61, messageContents=00 92 B0 01 00]
2017-12-22 13:41:17.780 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP queue: 12
2017-12-22 13:41:17.782 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=61], messageTag=61, messageContents=00 92 B0 01 00]
2017-12-22 13:41:17.785 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=7, ackNum=7, reTx=false, data=3D 00 34 00 92 B0 00 00 01 00 00 00 40 11 00 00 3D 3D 05 00 92 B0 01 00]
2017-12-22 13:41:17.913 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=0, reTx=false, data=3D 80 34 00 94]
2017-12-22 13:41:17.916 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=148]
2017-12-22 13:41:17.918 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=148]
2017-12-22 13:41:17.919 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=148]
2017-12-22 13:41:17.920 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0]
2017-12-22 13:41:19.570 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=0, reTx=false, data=3D 90 45 00 04 01 06 00 03 01 00 00 00 00 C2 FF A9 7E 04 FF FF 07 18 83 0A 00 00 10 00]
2017-12-22 13:41:19.573 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=194], lastHopLqi=255, lastHopRssi=-87, sender=1150, bindingIndex=255, addressIndex=255, messageContents=18 83 0A 00 00 10 00]
2017-12-22 13:41:19.574 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=194], lastHopLqi=255, lastHopRssi=-87, sender=1150, bindingIndex=255, addressIndex=255, messageContents=18 83 0A 00 00 10 00]
2017-12-22 13:41:19.576 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=1150/3, destinationAddress=0/1, profile=0104, cluster=6, addressMode=null, radius=0, sequence=61, payload=18 83 0A 00 00 10 00]
2017-12-22 13:41:19.578 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=131, commandId=10]
2017-12-22 13:41:19.581 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: 1150/3 -> 0/1, cluster=0006, TID=83, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=false]]
2017-12-22 13:41:19.591 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1]
2017-12-22 13:41:22.618 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=0, reTx=false, data=3D 90 3F 00 92 B0 00 00 01 00 00 00 40 11 00 00 94 3D 66 00]
2017-12-22 13:41:22.620 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=148], messageTag=61, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:22.622 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=148], messageTag=61, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:22.623 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=148], messageTag=61, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:22.624 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2]
2017-12-22 13:41:22.854 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=0, reTx=false, data=3D 90 45 04 00 00 06 00 00 00 08 00 00 00 A9 FF A9 E3 EF FF FF 09 DF FD FF 04 01 01 19 00 00]
2017-12-22 13:41:22.856 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0, clusterId=6, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=169], lastHopLqi=255, lastHopRssi=-87, sender=61411, bindingIndex=255, addressIndex=255, messageContents=DF FD FF 04 01 01 19 00 00]
2017-12-22 13:41:22.858 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0, clusterId=6, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=169], lastHopLqi=255, lastHopRssi=-87, sender=61411, bindingIndex=255, addressIndex=255, messageContents=DF FD FF 04 01 01 19 00 00]
2017-12-22 13:41:22.861 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=61411/0, destinationAddress=0/0, profile=0000, cluster=6, addressMode=null, radius=0, sequence=61, payload=DF FD FF 04 01 01 19 00 00]
2017-12-22 13:41:22.864 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [61411/0 -> 0/0, cluster=0006, TID=NULL, nwkAddrOfInterest=65533, profileId=260, inClusterCount=1, inClusterList=[25], outClusterCount=0, outClusterList=[]]
2017-12-22 13:41:22.866 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3]
2017-12-22 13:41:27.805 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 45202: Discovery request IEEE_ADDRESS failed. Wait before retry.
2017-12-22 13:41:29.307 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 45202/0, cluster=0001, TID=3E, nwkAddrOfInterest=45202, requestType=1, startIndex=0]
2017-12-22 13:41:29.310 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=45202/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, sequence=62, payload=00 92 B0 01 00]
2017-12-22 13:41:29.315 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=62], messageTag=62, messageContents=00 92 B0 01 00]
2017-12-22 13:41:29.316 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP queue: 12
2017-12-22 13:41:29.319 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=62], messageTag=62, messageContents=00 92 B0 01 00]
2017-12-22 13:41:29.322 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=3, reTx=false, data=3E 00 34 00 92 B0 00 00 01 00 00 00 40 11 00 00 3E 3E 05 00 92 B0 01 00]
2017-12-22 13:41:29.446 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=1, reTx=false, data=3E 80 34 00 95]
2017-12-22 13:41:29.447 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=149]
2017-12-22 13:41:29.450 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=149]
2017-12-22 13:41:29.451 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=149]
2017-12-22 13:41:29.452 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4]
2017-12-22 13:41:34.255 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=1, reTx=false, data=3E 90 3F 00 92 B0 00 00 01 00 00 00 40 11 00 00 95 3E 66 00]
2017-12-22 13:41:34.260 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=149], messageTag=62, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:34.263 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=149], messageTag=62, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:34.265 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=149], messageTag=62, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:34.266 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5]
2017-12-22 13:41:39.339 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 45202: Discovery request IEEE_ADDRESS failed. Wait before retry.
2017-12-22 13:41:40.844 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 45202/0, cluster=0001, TID=3F, nwkAddrOfInterest=45202, requestType=1, startIndex=0]
2017-12-22 13:41:40.847 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=45202/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, sequence=63, payload=00 92 B0 01 00]
2017-12-22 13:41:40.850 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=63], messageTag=63, messageContents=00 92 B0 01 00]
2017-12-22 13:41:40.890 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP queue: 12
2017-12-22 13:41:40.891 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=63], messageTag=63, messageContents=00 92 B0 01 00]
2017-12-22 13:41:40.892 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=5, reTx=false, data=3F 00 34 00 92 B0 00 00 01 00 00 00 40 11 00 00 3F 3F 05 00 92 B0 01 00]
2017-12-22 13:41:41.008 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=2, reTx=false, data=3F 80 34 00 96]
2017-12-22 13:41:41.010 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=150]
2017-12-22 13:41:41.012 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=150]
2017-12-22 13:41:41.013 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=150]
2017-12-22 13:41:41.015 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6]
2017-12-22 13:41:45.817 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=2, reTx=false, data=3F 90 3F 00 92 B0 00 00 01 00 00 00 40 11 00 00 96 3F 66 00]
2017-12-22 13:41:45.820 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=150], messageTag=63, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:45.822 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=150], messageTag=63, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:45.823 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=45202, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=150], messageTag=63, status=EMBER_DELIVERY_FAILED, messageContents=]
2017-12-22 13:41:45.825 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7]
2017-12-22 13:41:50.898 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 45202: Discovery request IEEE_ADDRESS failed. Wait before retry.
2017-12-22 13:41:52.401 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 45202: Ending node discovery
2017-12-22 13:42:03.368 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=2, reTx=false, data=3F 90 45 00 04 01 02 04 02 01 00 01 00 00 AA FF AF E3 EF FF FF 08 08 30 0A 00 00 29 58 07]
2017-12-22 13:42:03.373 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=170], lastHopLqi=255, lastHopRssi=-81, sender=61411, bindingIndex=255, addressIndex=255, messageContents=08 30 0A 00 00 29 58 07]
2017-12-22 13:42:03.375 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=1026, sourceEndpoint=2, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=170], lastHopLqi=255, lastHopRssi=-81, sender=61411, bindingIndex=255, addressIndex=255, messageContents=08 30 0A 00 00 29 58 07]
2017-12-22 13:42:03.378 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=61411/2, destinationAddress=0/1, profile=0104, cluster=1026, addressMode=null, radius=0, sequence=63, payload=08 30 0A 00 00 29 58 07]
2017-12-22 13:42:03.379 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=48, commandId=10]
2017-12-22 13:42:03.382 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Temperature measurement: 61411/2 -> 0/1, cluster=0402, TID=30, reports=[Attribute Report: attributeDataType=SIGNED_16_BIT_INTEGER, attributeIdentifier=0, attributeValue=1880]]
2017-12-22 13:42:03.384 [DEBUG] [bee.dongle.ember.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0]
2017-12-22 13:42:13.515 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102F1AE8C: Command for channel zigbee:device:3e5f29cf:0017880102f1ae8c:0017880102F1AE8C_11_color_color --> 0
2017-12-22 13:42:13.517 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - No handler found for zigbee:device:3e5f29cf:0017880102f1ae8c:0017880102F1AE8C_11_color_color
2017-12-22 13:42:13.518 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00178801021DC6C4: Command for channel zigbee:device:3e5f29cf:00178801021dc6c4:00178801021DC6C4_11_color_color --> 0
2017-12-22 13:42:13.519 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - No handler found for zigbee:device:3e5f29cf:00178801021dc6c4:00178801021DC6C4_11_color_color
2017-12-22 13:42:14.362 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 0017880102F1AE8C: Command for channel zigbee:device:3e5f29cf:0017880102f1ae8c:0017880102F1AE8C_11_color_color --> OFF
2017-12-22 13:42:14.363 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - No handler found for zigbee:device:3e5f29cf:0017880102f1ae8c:0017880102F1AE8C_11_color_color
2017-12-22 13:42:14.368 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00178801021DC6C4: Command for channel zigbee:device:3e5f29cf:00178801021dc6c4:00178801021DC6C4_11_color_color --> OFF
2017-12-22 13:42:14.369 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - No handler found for zigbee:device:3e5f29cf:00178801021dc6c4:00178801021DC6C4_11_color_color

weakfl · December 22, 2017, 2:41pm

@AFromD this is a known issue.

I’ve currently set a cron rule that restarts the binding every hour as a workaround until this gets fixed.

jj_hh · December 22, 2017, 4:07pm

hi,I am a newcomer in openhab. Now, I have the same trouble as yours，And It has troubled me for three days.I can’t find any good ways to solve.Can I ask you how to solve it? thank you very much.

TheNetStriker · December 24, 2017, 12:51pm

Hi jj, do you mean the problems with the Phillips Hue binding or with the ZigBee binding?

@chris: I did get the Ember stick with firmware 5.8 working with the 2.2 release of the Zigbee binding, but there are still some issues. These are the ones I encountered:

The channels inside a lamp do no update each other. (e.g. if I update the switch channel it does not automatically update the color and dimmer channel to zero or the actual color)
It takes a long time until all lamps are online. (there are 32 lamps in my setup)
The delay when switching a light is still still much bigger than with the hue binding. (about 1 second with the Hue binding and about 3 to 4 seconds with the Zigbee binding)
As you said the Ember stick does not always initialize on the first try. I had to restart the binding a few times.
I also found several errors in the log regarding discovery:

java.lang.NullPointerException: null
	at com.zsmartsystems.zigbee.internal.ZigBeeNetworkDiscoverer.updateEndpoint(ZigBeeNetworkDiscoverer.java:598) [254:org.openhab.binding.zigbee:2.2.0]
	at com.zsmartsystems.zigbee.internal.ZigBeeNetworkDiscoverer.getSimpleDescriptor(ZigBeeNetworkDiscoverer.java:565) [254:org.openhab.binding.zigbee:2.2.0]
	at com.zsmartsystems.zigbee.internal.ZigBeeNetworkDiscoverer.access$800(ZigBeeNetworkDiscoverer.java:61) [254:org.openhab.binding.zigbee:2.2.0]
	at com.zsmartsystems.zigbee.internal.ZigBeeNetworkDiscoverer$3.run(ZigBeeNetworkDiscoverer.java:340) [254:org.openhab.binding.zigbee:2.2.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]

Are some of these errors maybe already fixed in the latest snapshot of the binding?

chris · December 24, 2017, 1:48pm

Hi
Thee should not be any long delays in the binding unless there are timeouts. Please check the logs.

If lamps support reporting then they should update the binding if they are changed. However please remember there is a lot of development going on at the moment so for sure there will still be some issues. Maybe some devices are not responding well and this is causing both of these - it’s hard to say without seeing what is happening.

The NpE I’ve probably fixed but it’s not in the latest binding yet - I will resolve this when I get home from holiday in a few days.

TheNetStriker · December 24, 2017, 1:56pm

Hi Chris, I did not find any timeouts in the log. (with ERROR log level) Also I remember that I read somewhere that the official Hue lamps do not support reporting the status. I don’t know how exactly that works on the Hue binding.

chris · December 24, 2017, 2:19pm

Timeouts won’t be logged at error level - errors are meant for major system problems which I don’t thing a timeout like this is. So you will need to use debug I think.

I’ve not yet added polling - so if the device doesnt report then it probably won’t update. I’ll look at this when I get back from holiday in a few days.

jj_hh · December 25, 2017, 3:56pm

hi,David，Thanks for your reply，I’m mean the problem with the Zigbee binding ;
The log is same with yours

And the Zigbee always offline.

TheNetStriker · December 25, 2017, 4:28pm

No I ha da different error with the Ember stick and it was solved simply by restarting the binding a few times.

chris · December 25, 2017, 8:13pm

Is it possible for your to send me (maybe via email) a debug log during the binding initialisation so I can see what the Hue responds to for some of the messages. If it is rejecting the reporting command then I can use this to trigger polling automatically (I’ve added polling yesterday, although I need to test it when I get home before releasing this).

TheNetStriker · December 26, 2017, 1:11pm

Hi Chris, I just sent you an email containing the log from the initialization. I only commented out my network key, network id etc. Sadly I wasn’t able to create a log while toggle a light because for some reason the lights didn’t want to change to online this time. I hope you can figure out whats going on.

chris · December 26, 2017, 11:07pm

Got it - thanks.

chris · December 26, 2017, 11:26pm

Can you confirm that node 26 is one of the Hue devices?

TheNetStriker · December 27, 2017, 12:11am

I only have hue devices in my setup. Some are older ones, but most of them are newer ones that also support color temperature.

chris · December 27, 2017, 12:41am

Ok, then I think the changes I’ve made ought to work for polling. I’ll give it a closer look in the next day or so and get it merged.

puzzle-star · December 27, 2017, 10:30am

Hi @chris,

It has taken a bit longer than expected, as migration to OH 2.2 has not been straight-forward for me.

After upgrading, no Zigbee devices were discovered (all of them were seen, but all attribute requests timed out). The issue is that I could not find anything else wrong in the logs, and I do not know exactly what I did to make it work (including reflashing my CC2531, and reverting to OH 2.1 and then back to 2.2). It just decided to start working again for some reason after two days of experiments. If I am able to reproduce it I will let you know.

I have submitted the PR for color XY changes. To make it simpler:

I just kept the changes to the color channel (not to the CT one)
I kept the ColorHelper class, but removed everything that is already in the ESH HSBType. When I have time I will open an issue and request for these to be merged directly into ESH, but I understand it would take longer, so I would prefer making XY color support by now independent on this change.
I made the need for the onoff cluster optional as discussed (I applied the same also to the need for level control cluster)

On the CT channel, as discussed I had a look at the hue binding implementation. It is also traeated as a dimmer there, but it breaks group status aggregation and other things. I would rather treat it as other kind of color channel, and add conversion from the Kelvion temperature to the HSBType (as per XY), which would also add the capacity to chose color temperature through the color picker. Would this make sense ?

chris · December 27, 2017, 11:40pm

Thanks. I’d hoped to look at this tonight, and I’ve started the review, but not finished (tomorrow!).

Good move - thanks.

Ok, that’s fine. I think I’d really like to see if this is something that ESH would benefit from - I think so as I guess other bindings are probably also doing the same conversions… For now though a small separate class is fine and we can refactor it out if it changes…

Two suggestions with this - firstly, a CT to HSB conversion does make sense to me. I had a look at this a few weeks back but there were no good sources I could find - I think it would be good though, and I think this could also be added to the HSBType in ESH… (Maybe the ESH maintainers disagree, but worth discussing I think).

Regarding the actual type for CT, I would for now leave it as a dimmer to be compatible with Hue. I think a discussion about this in ESH would be good as really it would be good to see a slider that allows to select CT (ie not 0 to 100%, but defined in Kelvin).

chris · December 28, 2017, 11:26am

I’ve finished my review - a few comments, but nothing too major I think. Let me know what you think - I’ve got a bunch of changes pending which will break your PR (ie it will cause merge errors) - if possible it’s probably best to get your PR merged first so I can resolve the changes, but if you think it will be a few days before you can look at it, then I might look to merge my changes first…

Let me know what you think .