Unable to pair any device

[triller-telekom]

Using commit 9dc77ee (Add option to set profile id as console command line argument (#910)) I cannot pair any device.

Last working commit that I used was 4cea309 (Document EMBER_MAC_COMMAND_TRANSMIT_FAILURE in active scan (#886)).

I have tested it with a telegesis dongle and an ember stick. According to the zigbee sniffer, both die right after the DeviceAnnounce.

This is what I see in the logs while trying to pair a Centralite 3200 smart plug:

2019-12-19T15:42:08.136+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - Permit join to FFFC/0 for 60 seconds.
2019-12-19T15:42:08.137+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=1, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.138+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - FFFC/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=1, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.138+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2019-12-19T15:42:08.139+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]
2019-12-19T15:42:08.140+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFC/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=04, payload=04 3C 01]
2019-12-19T15:42:08.141+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - 000D6F000F24146C: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.142+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - 0000/0: Sending ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=2, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.142+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
2019-12-19T15:42:08.143+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]
2019-12-19T15:42:08.144+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=05, payload=05 3C 01]
2019-12-19T15:42:08.149+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP queue: 1
2019-12-19T15:42:08.151+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP: EzspSendBroadcastRequest [destination=FFFC, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=04], radius=31, messageTag=04, messageContents=04 3C 01]
2019-12-19T15:42:08.152+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - --> TX SPI frame: FE 18 04 00 FF 00 36 FC FF 00 00 36 00 00 00 40 11 00 00 04 1F 04 03 04 3C 01 
2019-12-19T15:42:08.159+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 07 04 80 FF 00 36 00 36 
2019-12-19T15:42:08.160+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=36]
2019-12-19T15:42:08.162+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP queue: 1
2019-12-19T15:42:08.162+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=36]
2019-12-19T15:42:08.190+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1B 04 88 FF 00 45 05 00 00 36 00 00 00 00 01 00 00 36 FF 00 00 00 FF FF 03 04 3C 01 
2019-12-19T15:42:08.192+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=36], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=04 3C 01]
2019-12-19T15:42:08.193+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=36], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=04 3C 01]
2019-12-19T15:42:08.193+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=36, payload=04 3C 01]
2019-12-19T15:42:08.194+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]
2019-12-19T15:42:08.195+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true] 
2019-12-19T15:42:08.195+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=null queueTime=59, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.197+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=57, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.199+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0000, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=05], messageTag=05, messageContents=05 3C 01]
2019-12-19T15:42:08.200+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - --> TX SPI frame: FE 18 05 00 FF 00 34 00 00 00 00 00 36 00 00 00 40 11 00 00 05 05 03 05 3C 01 
2019-12-19T15:42:08.219+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 07 05 80 FF 00 34 00 37 
2019-12-19T15:42:08.220+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=37]
2019-12-19T15:42:08.222+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=37]
2019-12-19T15:42:08.336+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1B 05 8C FF 00 45 00 00 00 36 00 00 00 40 01 00 00 37 FF 00 00 00 FF FF 03 05 3C 01 
2019-12-19T15:42:08.337+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=37], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=05 3C 01]
2019-12-19T15:42:08.338+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=37], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=05 3C 01]
2019-12-19T15:42:08.339+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=37, payload=05 3C 01]
2019-12-19T15:42:08.340+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]
2019-12-19T15:42:08.340+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true] 
2019-12-19T15:42:08.341+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=null queueTime=205, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.343+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=202, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.367+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1A 05 8C FF 00 45 00 00 00 36 80 00 00 40 01 00 00 38 FF 00 00 00 FF FF 02 05 00 
2019-12-19T15:42:08.368+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=38], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=05 00]
2019-12-19T15:42:08.368+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=38], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=05 00]
2019-12-19T15:42:08.369+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=8036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=38, payload=05 00]
2019-12-19T15:42:08.370+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=05, status=SUCCESS]
2019-12-19T15:42:08.371+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=05, status=SUCCESS] 
2019-12-19T15:42:08.372+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=05, status=SUCCESS] ZigBeeTransaction [ieeeAddress=null queueTime=236, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.373+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=05, status=SUCCESS] ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=233, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.397+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 16 05 88 FF 00 3F 00 00 00 00 00 36 00 00 00 40 11 00 00 37 05 00 00 
2019-12-19T15:42:08.398+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=37], messageTag=05, status=EMBER_SUCCESS, messageContents=]
2019-12-19T15:42:08.398+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=37], messageTag=05, status=EMBER_SUCCESS, messageContents=]
2019-12-19T15:42:08.399+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=05 state=RX_ACK
2019-12-19T15:42:08.400+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=05, state=RX_ACK, outstanding=2
2019-12-19T15:42:08.401+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=260, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=05, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:08.401+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
2019-12-19T15:42:08.401+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - 000D6F000F24146C: transactionComplete COMPLETE 0
2019-12-19T15:42:08.402+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 05 -> RX_ACK == COMPLETE
2019-12-19T15:42:09.192+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 16 DD 88 FF 00 3F 06 FC FF 00 00 36 00 00 00 00 01 00 00 36 04 00 00 
2019-12-19T15:42:09.193+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=36], messageTag=04, status=EMBER_SUCCESS, messageContents=]
2019-12-19T15:42:09.194+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=36], messageTag=04, status=EMBER_SUCCESS, messageContents=]
2019-12-19T15:42:09.194+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=04 state=RX_ACK
2019-12-19T15:42:09.194+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=04, state=RX_ACK, outstanding=1
2019-12-19T15:42:09.202+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=1066, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=04, permitDuration=60, tcSignificance=true]]
2019-12-19T15:42:09.203+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2019-12-19T15:42:09.203+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete COMPLETE 0
2019-12-19T15:42:09.203+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 04 -> RX_ACK == COMPLETE
2019-12-19T15:42:13.089+0100   170  DEBUG          [symbolicName=org.eclipse.smarthome.config.discovery, className=org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl] - Finished 1 of 2 discovery services.
2019-12-19T15:42:15.658+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 13 18 88 FF 00 24 5A 89 5B 2B BD 0B 00 6F 0D 00 02 03 FF FF 
2019-12-19T15:42:15.660+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=FFFF]
2019-12-19T15:42:15.660+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=FFFF]
2019-12-19T15:42:15.661+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 000D6F000BBD2B5B: nodeStatusUpdate - node status is DEVICE_LEFT, network address is 35162.
2019-12-19T15:42:15.661+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 35162: Node has left, but wasn't found in the network.
2019-12-19T15:42:16.116+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 13 1C 88 FF 00 24 5A 89 5B 2B BD 0B 00 6F 0D 00 02 03 FF FF 
2019-12-19T15:42:16.117+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=FFFF]
2019-12-19T15:42:16.117+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=FFFF]
2019-12-19T15:42:16.118+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 000D6F000BBD2B5B: nodeStatusUpdate - node status is DEVICE_LEFT, network address is 35162.
2019-12-19T15:42:16.118+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 35162: Node has left, but wasn't found in the network.
2019-12-19T15:42:16.572+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 13 20 88 FF 00 24 5A 89 5B 2B BD 0B 00 6F 0D 00 02 03 FF FF 
2019-12-19T15:42:16.573+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=FFFF]
2019-12-19T15:42:16.574+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_DEVICE_LEFT, policyDecision=EMBER_NO_ACTION, parentOfNewNodeId=FFFF]
2019-12-19T15:42:16.575+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 000D6F000BBD2B5B: nodeStatusUpdate - node status is DEVICE_LEFT, network address is 35162.
2019-12-19T15:42:16.575+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 35162: Node has left, but wasn't found in the network.
2019-12-19T15:42:17.822+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 13 2B 8C FF 00 24 5A 89 5B 2B BD 0B 00 6F 0D 00 01 00 00 00 
2019-12-19T15:42:17.823+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000]
2019-12-19T15:42:17.823+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=895A, newNodeEui64=000D6F000BBD2B5B, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000]
2019-12-19T15:42:17.824+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 000D6F000BBD2B5B: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 35162.
2019-12-19T15:42:17.852+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1B 2B 8C FF 00 45 04 00 00 36 00 00 00 00 01 00 00 5B FF CC 5A 89 FF FF 03 01 B4 00 
2019-12-19T15:42:17.853+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=5B], lastHopLqi=255, lastHopRssi=-52, sender=895A, bindingIndex=255, addressIndex=255, messageContents=01 B4 00]
2019-12-19T15:42:17.854+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=5B], lastHopLqi=255, lastHopRssi=-52, sender=895A, bindingIndex=255, addressIndex=255, messageContents=01 B4 00]
2019-12-19T15:42:17.855+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=895A/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=5B, payload=01 B4 00]
2019-12-19T15:42:17.856+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [895A/0 -> 0000/0, cluster=0036, TID=01, permitDuration=180, tcSignificance=false]
2019-12-19T15:42:17.856+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [895A/0 -> 0000/0, cluster=0036, TID=01, permitDuration=180, tcSignificance=false] 
2019-12-19T15:42:17.882+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 0D 2B 8C FF 00 62 5B 2B BD 0B 00 6F 0D 00 
2019-12-19T15:42:17.883+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingSenderEui64Handler [senderEui64=000D6F000BBD2B5B]
2019-12-19T15:42:17.884+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingSenderEui64Handler [senderEui64=000D6F000BBD2B5B]
2019-12-19T15:42:17.914+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 24 2B 88 FF 00 45 04 00 00 13 00 00 00 00 04 00 00 5C FF CC 5A 89 FF FF 0C 81 5A 89 5B 2B BD 0B 00 6F 0D 00 8E 
2019-12-19T15:42:17.915+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0013, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_SOURCE_EUI64], groupId=0, sequence=5C], lastHopLqi=255, lastHopRssi=-52, sender=895A, bindingIndex=255, addressIndex=255, messageContents=81 5A 89 5B 2B BD 0B 00 6F 0D 00 8E]
2019-12-19T15:42:17.916+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0013, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_SOURCE_EUI64], groupId=0, sequence=5C], lastHopLqi=255, lastHopRssi=-52, sender=895A, bindingIndex=255, addressIndex=255, messageContents=81 5A 89 5B 2B BD 0B 00 6F 0D 00 8E]
2019-12-19T15:42:17.917+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=895A/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=5C, payload=81 5A 89 5B 2B BD 0B 00 6F 0D 00 8E]
2019-12-19T15:42:17.918+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [895A/0 -> 0000/0, cluster=0013, TID=81, nwkAddrOfInterest=895A, ieeeAddr=000D6F000BBD2B5B, capability=8E]
2019-12-19T15:42:17.920+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [895A/0 -> 0000/0, cluster=0013, TID=81, nwkAddrOfInterest=895A, ieeeAddr=000D6F000BBD2B5B, capability=8E]
2019-12-19T15:42:48.801+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 40 88 FF 00 45 04 00 00 06 00 00 00 00 01 00 00 5D FF CF 5A 89 FF FF 09 02 FD FF 04 01 01 19 00 00 
2019-12-19T15:42:48.802+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=5D], lastHopLqi=255, lastHopRssi=-49, sender=895A, bindingIndex=255, addressIndex=255, messageContents=02 FD FF 04 01 01 19 00 00]
2019-12-19T15:42:48.803+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=5D], lastHopLqi=255, lastHopRssi=-49, sender=895A, bindingIndex=255, addressIndex=255, messageContents=02 FD FF 04 01 01 19 00 00]
2019-12-19T15:42:48.805+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=895A/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=5D, payload=02 FD FF 04 01 01 19 00 00]
2019-12-19T15:42:48.807+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [895A/0 -> 0000/0, cluster=0006, TID=02, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T15:42:48.808+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [895A/0 -> 0000/0, cluster=0006, TID=02, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]

And if i try to pair a Bitron video 902010/25 smart plug it looks like ZSS is not responding to the MatchDescriptorRequest anymore:

2019-12-19T17:31:22.106+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - Permit join to FFFC/0 for 60 seconds.
2019-12-19T17:31:22.107+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - Broadcast: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.108+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - FFFC/0: Sending ZigBeeTransaction [ieeeAddress=null queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.108+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2019-12-19T17:31:22.109+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]
2019-12-19T17:31:22.110+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=FFFC/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=07, payload=07 3C 01]
2019-12-19T17:31:22.113+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - 000D6F000F24146C: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=0, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=--, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.114+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - 0000/0: Sending ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=2, state=WAITING, sendCnt=0, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.115+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 2 outstanding
2019-12-19T17:31:22.117+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]
2019-12-19T17:31:22.119+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=08, payload=08 3C 01]
2019-12-19T17:31:22.119+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP queue: 1
2019-12-19T17:31:22.120+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP: EzspSendBroadcastRequest [destination=FFFC, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=07], radius=31, messageTag=07, messageContents=07 3C 01]
2019-12-19T17:31:22.121+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - --> TX SPI frame: FE 18 07 00 FF 00 36 FC FF 00 00 36 00 00 00 40 11 00 00 07 1F 07 03 07 3C 01 
2019-12-19T17:31:22.132+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 07 07 80 FF 00 36 00 3C 
2019-12-19T17:31:22.134+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=3C]
2019-12-19T17:31:22.135+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendBroadcastResponse [status=EMBER_SUCCESS, sequence=3C]
2019-12-19T17:31:22.138+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP queue: 1
2019-12-19T17:31:22.164+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1B 07 88 FF 00 45 05 00 00 36 00 00 00 00 01 00 00 3C FF 00 00 00 FF FF 03 07 3C 01 
2019-12-19T17:31:22.165+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=3C], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=07 3C 01]
2019-12-19T17:31:22.165+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST_LOOPBACK, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=3C], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=07 3C 01]
2019-12-19T17:31:22.166+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=3C, payload=07 3C 01]
2019-12-19T17:31:22.167+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]
2019-12-19T17:31:22.167+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true] 
2019-12-19T17:31:22.168+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=null queueTime=61, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.171+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=58, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.172+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - TX EZSP: EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0000, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=08], messageTag=08, messageContents=08 3C 01]
2019-12-19T17:31:22.174+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - --> TX SPI frame: FE 18 08 00 FF 00 34 00 00 00 00 00 36 00 00 00 40 11 00 00 08 08 03 08 3C 01 
2019-12-19T17:31:22.193+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 07 08 80 FF 00 34 00 3D 
2019-12-19T17:31:22.194+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=3D]
2019-12-19T17:31:22.195+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=3D]
2019-12-19T17:31:22.310+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1B 08 8C FF 00 45 00 00 00 36 00 00 00 40 01 00 00 3D FF 00 00 00 FF FF 03 08 3C 01 
2019-12-19T17:31:22.312+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=3D], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=08 3C 01]
2019-12-19T17:31:22.313+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=3D], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=08 3C 01]
2019-12-19T17:31:22.314+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=0036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=3D, payload=08 3C 01]
2019-12-19T17:31:22.315+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]
2019-12-19T17:31:22.316+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true] 
2019-12-19T17:31:22.318+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=null queueTime=210, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.319+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true] ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=207, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.341+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 1A 08 8C FF 00 45 00 00 00 36 80 00 00 40 01 00 00 3E FF 00 00 00 FF FF 02 08 00 
2019-12-19T17:31:22.342+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=3E], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=08 00]
2019-12-19T17:31:22.343+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=8036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=3E], lastHopLqi=255, lastHopRssi=0, sender=0000, bindingIndex=255, addressIndex=255, messageContents=08 00]
2019-12-19T17:31:22.344+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0000/0, destinationAddress=0000/0, profile=0000, cluster=8036, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=3E, payload=08 00]
2019-12-19T17:31:22.346+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=08, status=SUCCESS]
2019-12-19T17:31:22.347+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=08, status=SUCCESS] 
2019-12-19T17:31:22.348+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=08, status=SUCCESS] ZigBeeTransaction [ieeeAddress=null queueTime=241, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.350+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ManagementPermitJoiningResponse [0000/0 -> 0000/0, cluster=8036, TID=08, status=SUCCESS] ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=237, state=DISPATCHED, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.381+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 16 08 88 FF 00 3F 00 00 00 00 00 36 00 00 00 40 11 00 00 3D 08 00 00 
2019-12-19T17:31:22.382+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=3D], messageTag=08, status=EMBER_SUCCESS, messageContents=]
2019-12-19T17:31:22.384+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY], groupId=0, sequence=3D], messageTag=08, status=EMBER_SUCCESS, messageContents=]
2019-12-19T17:31:22.384+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=08 state=RX_ACK
2019-12-19T17:31:22.385+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=08, state=RX_ACK, outstanding=2
2019-12-19T17:31:22.387+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=000D6F000F24146C queueTime=274, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> 0000/0, cluster=0036, TID=08, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:22.387+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 1 outstanding
2019-12-19T17:31:22.387+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - 000D6F000F24146C: transactionComplete COMPLETE 0
2019-12-19T17:31:22.388+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 08 -> RX_ACK == COMPLETE
2019-12-19T17:31:23.180+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 16 BA 88 FF 00 3F 06 FC FF 00 00 36 00 00 00 00 01 00 00 3C 07 00 00 
2019-12-19T17:31:23.181+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=3C], messageTag=07, status=EMBER_SUCCESS, messageContents=]
2019-12-19T17:31:23.182+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_BROADCAST, indexOrDestination=65532, apsFrame=EmberApsFrame [profileId=0000, clusterId=0036, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=3C], messageTag=07, status=EMBER_SUCCESS, messageContents=]
2019-12-19T17:31:23.184+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=07 state=RX_ACK
2019-12-19T17:31:23.184+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=07, state=RX_ACK, outstanding=1
2019-12-19T17:31:23.191+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=null queueTime=1084, state=COMPLETE, sendCnt=1, command=ManagementPermitJoiningRequest [0000/0 -> FFFC/0, cluster=0036, TID=07, permitDuration=60, tcSignificance=true]]
2019-12-19T17:31:23.192+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2019-12-19T17:31:23.192+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionQueue] - Broadcast: transactionComplete COMPLETE 0
2019-12-19T17:31:23.192+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 07 -> RX_ACK == COMPLETE
2019-12-19T17:31:27.052+0100   170  DEBUG          [symbolicName=org.eclipse.smarthome.config.discovery, className=org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl] - Finished 1 of 2 discovery services.
2019-12-19T17:32:11.245+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 13 66 88 FF 00 24 14 22 80 28 EA 0E 00 4B 12 00 01 00 00 00 
2019-12-19T17:32:11.246+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=2214, newNodeEui64=00124B000EEA2880, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000]
2019-12-19T17:32:11.246+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspTrustCenterJoinHandler [newNodeId=2214, newNodeEui64=00124B000EEA2880, status=EMBER_STANDARD_SECURITY_UNSECURED_JOIN, policyDecision=EMBER_USE_PRECONFIGURED_KEY, parentOfNewNodeId=0000]
2019-12-19T17:32:11.247+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - 00124B000EEA2880: nodeStatusUpdate - node status is UNSECURED_JOIN, network address is 8724.
2019-12-19T17:32:11.475+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 24 68 88 FF 00 45 04 00 00 13 00 00 00 00 00 00 00 01 FE DA 14 22 FF FF 0C 00 14 22 80 28 EA 0E 00 4B 12 00 8E 
2019-12-19T17:32:11.477+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0013, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=01], lastHopLqi=254, lastHopRssi=-38, sender=2214, bindingIndex=255, addressIndex=255, messageContents=00 14 22 80 28 EA 0E 00 4B 12 00 8E]
2019-12-19T17:32:11.478+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0013, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=01], lastHopLqi=254, lastHopRssi=-38, sender=2214, bindingIndex=255, addressIndex=255, messageContents=00 14 22 80 28 EA 0E 00 4B 12 00 8E]
2019-12-19T17:32:11.479+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=01, payload=00 14 22 80 28 EA 0E 00 4B 12 00 8E]
2019-12-19T17:32:11.480+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [2214/0 -> 0000/0, cluster=0013, TID=00, nwkAddrOfInterest=2214, ieeeAddr=00124B000EEA2880, capability=8E]
2019-12-19T17:32:11.481+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [2214/0 -> 0000/0, cluster=0013, TID=00, nwkAddrOfInterest=2214, ieeeAddr=00124B000EEA2880, capability=8E] 
2019-12-19T17:32:11.596+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 24 69 88 FF 00 45 04 00 00 13 00 00 00 00 00 00 00 02 F9 DA 14 22 FF FF 0C 01 14 22 80 28 EA 0E 00 4B 12 00 8E 
2019-12-19T17:32:11.598+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0013, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=02], lastHopLqi=249, lastHopRssi=-38, sender=2214, bindingIndex=255, addressIndex=255, messageContents=01 14 22 80 28 EA 0E 00 4B 12 00 8E]
2019-12-19T17:32:11.598+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0013, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=02], lastHopLqi=249, lastHopRssi=-38, sender=2214, bindingIndex=255, addressIndex=255, messageContents=01 14 22 80 28 EA 0E 00 4B 12 00 8E]
2019-12-19T17:32:11.600+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0013, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=02, payload=01 14 22 80 28 EA 0E 00 4B 12 00 8E]
2019-12-19T17:32:11.601+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [2214/0 -> 0000/0, cluster=0013, TID=01, nwkAddrOfInterest=2214, ieeeAddr=00124B000EEA2880, capability=8E]
2019-12-19T17:32:11.602+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DeviceAnnounce [2214/0 -> 0000/0, cluster=0013, TID=01, nwkAddrOfInterest=2214, ieeeAddr=00124B000EEA2880, capability=8E] 
2019-12-19T17:32:12.511+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 71 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 04 FB DA 14 22 FF FF 09 02 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:12.512+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=04], lastHopLqi=251, lastHopRssi=-38, sender=2214, bindingIndex=255, addressIndex=255, messageContents=02 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:12.513+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=04], lastHopLqi=251, lastHopRssi=-38, sender=2214, bindingIndex=255, addressIndex=255, messageContents=02 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:12.514+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=04, payload=02 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:12.516+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=02, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:12.516+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=02, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:17.652+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 9F 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 05 F5 D5 14 22 FF FF 09 03 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:17.653+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=05], lastHopLqi=245, lastHopRssi=-43, sender=2214, bindingIndex=255, addressIndex=255, messageContents=03 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:17.654+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=05], lastHopLqi=245, lastHopRssi=-43, sender=2214, bindingIndex=255, addressIndex=255, messageContents=03 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:17.655+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=05, payload=03 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:17.656+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=03, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:17.656+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=03, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:22.112+0100   170  DEBUG          [symbolicName=org.eclipse.smarthome.config.discovery, className=org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl] - Finished 2 of 2 discovery services.
2019-12-19T17:32:22.112+0100   376  DEBUG          [symbolicName=org.eclipse.smarthome.io.rest.core, className=org.eclipse.smarthome.io.rest.core.internal.discovery.DiscoveryResource] - Scan for binding 'zigbee' successfully finished.
2019-12-19T17:32:22.725+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 CC 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 07 FD D3 14 22 FF FF 09 04 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:22.726+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=07], lastHopLqi=253, lastHopRssi=-45, sender=2214, bindingIndex=255, addressIndex=255, messageContents=04 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:22.727+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=07], lastHopLqi=253, lastHopRssi=-45, sender=2214, bindingIndex=255, addressIndex=255, messageContents=04 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:22.728+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=07, payload=04 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:22.729+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=04, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:22.730+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=04, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:27.707+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 F8 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 08 FD D1 14 22 FF FF 09 05 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:27.708+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=08], lastHopLqi=253, lastHopRssi=-47, sender=2214, bindingIndex=255, addressIndex=255, messageContents=05 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:27.709+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=08], lastHopLqi=253, lastHopRssi=-47, sender=2214, bindingIndex=255, addressIndex=255, messageContents=05 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:27.710+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=08, payload=05 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:27.711+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:27.712+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=05, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:32.698+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 26 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 0A F6 D4 14 22 FF FF 09 06 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:32.699+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0A], lastHopLqi=246, lastHopRssi=-44, sender=2214, bindingIndex=255, addressIndex=255, messageContents=06 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:32.700+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0A], lastHopLqi=246, lastHopRssi=-44, sender=2214, bindingIndex=255, addressIndex=255, messageContents=06 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:32.702+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=0A, payload=06 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:32.703+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=06, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:32.703+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=06, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:37.690+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 52 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 0B F9 D6 14 22 FF FF 09 07 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:37.691+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0B], lastHopLqi=249, lastHopRssi=-42, sender=2214, bindingIndex=255, addressIndex=255, messageContents=07 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:37.692+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0B], lastHopLqi=249, lastHopRssi=-42, sender=2214, bindingIndex=255, addressIndex=255, messageContents=07 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:37.693+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=0B, payload=07 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:37.694+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=07, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:37.695+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=07, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:42.650+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 7E 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 0C FA D5 14 22 FF FF 09 08 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:42.651+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0C], lastHopLqi=250, lastHopRssi=-43, sender=2214, bindingIndex=255, addressIndex=255, messageContents=08 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:42.652+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0C], lastHopLqi=250, lastHopRssi=-43, sender=2214, bindingIndex=255, addressIndex=255, messageContents=08 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:42.653+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=0C, payload=08 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:42.654+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=08, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:42.654+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=08, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]] 
2019-12-19T17:32:47.754+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - <-- RX SPI frame: FE 21 AB 88 FF 00 45 04 00 00 06 00 00 00 00 00 00 00 0E FE D3 14 22 FF FF 09 09 FD FF 04 01 01 19 00 00 
2019-12-19T17:32:47.755+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.internal.spi.SpiFrameHandler] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0E], lastHopLqi=254, lastHopRssi=-45, sender=2214, bindingIndex=255, addressIndex=255, messageContents=09 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:47.756+0100   445  DEBUG          [symbolicName=com.zsmartsystems.zigbee.dongle.ember, className=com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0006, sourceEndpoint=0, destinationEndpoint=0, options=[], groupId=0, sequence=0E], lastHopLqi=254, lastHopRssi=-45, sender=2214, bindingIndex=255, addressIndex=255, messageContents=09 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:47.757+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=2214/0, destinationAddress=0000/0, profile=0000, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, apsCounter=0E, payload=09 FD FF 04 01 01 19 00 00]
2019-12-19T17:32:47.758+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.ZigBeeNetworkManager] - RX CMD: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=09, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]
2019-12-19T17:32:47.759+0100   432  DEBUG          [symbolicName=com.zsmartsystems.zigbee, className=com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: MatchDescriptorRequest [2214/0 -> 0000/0, cluster=0006, TID=09, nwkAddrOfInterest=FFFD, profileId=0104, inClusterList=[25], outClusterList=[]]

[cdjackson]

Just so I'm clear what you are doing -:

What software are you using the libraries with? Is this still openHAB? What version of OH? Have you refactored for the latest changes?

I probably won't have time to look at this until late next week, but please answer the above...

[triller-telekom]

I am using the openHAB binding, but it is adjusted to work with the latest ZSS master. However I have documented the solution of my problem here: openhab/org.openhab.binding.zigbee#531

If everything would only be that easy :)

@cdjackson: So fortunately no real big issue with the latest master. Have a nice christmas and a good start into 2020!