Zigbee (Telegesis) coordinator won't detect my devices (Trådfri bulbs)

Hydropower · February 19, 2019, 10:12pm

I have my Telegesis Zigbee coordinator binding up and running, but when trying to detect a device from Paper UI Inbox I get nothing (I tried both powering up my bulb first, then start detecting in OH, and vice versa). My logs shows me:

2019-02-19 21:56:10.956 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,B759,C94BE0E458776313
2019-02-19 21:56:10.956 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 21:56:10.956 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=46937, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-19 21:56:11.023 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update
2019-02-19 21:56:11.024 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 000D6F000AEC3BEB
2019-02-19 21:56:11.024 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: Update mesh
2019-02-19 21:56:11.024 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: scheduled [NEIGHBORS, ROUTES]
2019-02-19 21:56:11.957 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 21:56:11.957 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-19 21:56:11.958 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-02-19 21:56:12.087 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,B759,C94BE0E458776313
2019-02-19 21:56:12.088 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 21:56:12.088 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=46937, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-19 21:56:12.397 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: running
2019-02-19 21:56:12.398 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=5E, startIndex=0]
2019-02-19 21:56:12.399 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=94, payload=00 00]
2019-02-19 21:56:12.399 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]
2019-02-19 21:56:12.400 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 21:56:12.400 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]
2019-02-19 21:56:12.401 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0031


2019-02-19 21:56:12.561 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:ED
2019-02-19 21:56:12.561 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 21:56:12.561 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=237, status=SUCCESS]
2019-02-19 21:56:12.562 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8031,05:,00,FF
2019-02-19 21:56:12.562 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32817, messageData=00 00 00 00 00, rssi=0, lqi=255]
2019-02-19 21:56:12.563 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 00 00]
2019-02-19 21:56:12.563 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]
2019-02-19 21:56:12.565 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:ED
2019-02-19 21:56:12.566 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=237]
2019-02-19 21:56:12.566 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=237]
2019-02-19 21:56:12.566 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=5E, startIndex=0]
2019-02-19 21:56:12.571 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]]
2019-02-19 21:56:12.571 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementLqiRequest complete [0 neighbors]
2019-02-19 21:56:12.571 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000AEC3BEB: Neighbor table unchanged
2019-02-19 21:56:12.572 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: request NEIGHBORS successful. Advanced to ROUTES.
2019-02-19 21:56:12.572 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: running
2019-02-19 21:56:12.572 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=5F, startIndex=0]
2019-02-19 21:56:12.573 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=95, payload=00 00]
2019-02-19 21:56:12.573 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]
2019-02-19 21:56:12.574 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 21:56:12.574 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]
2019-02-19 21:56:12.575 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032

Is there anything in that log that indicates what I am doing wrong? From the best of my understanding the device doesn’t say anything to the coordinator?

Regards
Henrik

chris · February 19, 2019, 11:30pm

Are you actually starting a discovery scan? I don’t see anything in this log that shows that you enabled discovery (ie no Join messages are in the log).

Hydropower · February 20, 2019, 9:20am

Hi Chris,
Thank you! There’s a lot in that log and of course I missed the important part…
This is where the joining process seems to start, but I’m not sure what to expect as a response:

2019-02-19 22:04:22.924 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,B759,C94BE0E458776313
2019-02-19 22:04:22.925 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 22:04:22.925 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=46937, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-19 22:04:23.388 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_telegesis:0000000C
2019-02-19 22:04:23.389 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-02-19 22:04:23.390 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=6A, permitDuration=60, tcSignificance=true]
2019-02-19 22:04:23.391 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=106, payload=00 3C 01]
2019-02-19 22:04:23.392 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01]
2019-02-19 22:04:23.392 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 22:04:23.393 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01]
2019-02-19 22:04:23.395 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDMCASTB:03,1F,FFFC,00,00,0000,0036
<

2019-02-19 22:04:23.396 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=6B, permitDuration=60, tcSignificance=true]
2019-02-19 22:04:23.397 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=107, payload=00 3C 01]
2019-02-19 22:04:23.397 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=null]
2019-02-19 22:04:23.398 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 22:04:23.522 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 22:04:23.523 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, status=SUCCESS]
2019-02-19 22:04:23.523 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=null]
2019-02-19 22:04:23.524 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:03,0000,00,00,0000,0036
<

2019-02-19 22:04:23.682 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:06
2019-02-19 22:04:23.683 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 22:04:23.684 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=6, status=SUCCESS]
2019-02-19 22:04:23.684 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8036,02:,00,FF
2019-02-19 22:04:23.685 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32822, messageData=00 00, rssi=0, lqi=255]
2019-02-19 22:04:23.685 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00]
2019-02-19 22:04:23.686 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]
2019-02-19 22:04:23.687 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:06
2019-02-19 22:04:23.687 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=6]
2019-02-19 22:04:23.688 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=6]
2019-02-19 22:04:24.689 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 22:04:24.689 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-19 22:04:24.690 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-02-19 22:04:24.819 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,B759,C94BE0E458776313
2019-02-19 22:04:24.819 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 22:04:24.819 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=46937, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-19 22:04:25.820 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 22:04:25.820 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-19 22:04:25.820 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-02-19 22:04:25.949 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,B759,C94BE0E458776313
2019-02-19 22:04:25.950 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-19 22:04:25.950 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=46937, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-19 22:04:26.950 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-19 22:04:26.951 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-19 22:04:26.951 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

Wiese · February 20, 2019, 9:34am

As I have the same setting here, I´ll try to explain my findings.

Tradfri bulb needs to be resetted. You could do it with switching the power or a lot easier: with a philipps dimmer switch (press and hold +/- 10 seconds very near to the bulb)
Turn on the bulb
Start the scan in OH
From my experiences it was more successful if the bulb was very near the usb-device (few cm).
If you pair the bulb with an ikea switch/dimmer, the connection to OH could be removed and you need to start with 1.

Hope this help
Chris

Hydropower · February 20, 2019, 9:49am

Thank you Wiese, doing it in the correct order is the first step. I just did as you describe (bulb is just a few cm from the USB-device. I blinked six time and got a confirmation blink, turned off the bulb for a few seconds, turned it back on and started a search for devices on the zigbee binding under inbox) but unfortunately nothing was found!

The sequence showed up in the logg as:


2019-02-20 09:39:39.372 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,B759,C94BE0E458776313
2019-02-20 09:39:39.373 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:39.373 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=46937, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-20 09:39:39.941 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update
2019-02-20 09:39:39.942 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 000D6F000AEC3BEB
2019-02-20 09:39:39.942 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: Update mesh
2019-02-20 09:39:39.943 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: scheduled [ROUTES, NEIGHBORS]
2019-02-20 09:39:39.937 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_telegesis:0000000C
2019-02-20 09:39:39.946 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-02-20 09:39:39.948 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=2B, permitDuration=60, tcSignificance=true]
2019-02-20 09:39:39.949 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=43, payload=00 3C 01]
2019-02-20 09:39:39.950 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01]
2019-02-20 09:39:39.951 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:39.951 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01]
2019-02-20 09:39:39.953 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDMCASTB:03,1F,FFFC,00,00,0000,0036
<

2019-02-20 09:39:39.954 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=2C, permitDuration=60, tcSignificance=true]
2019-02-20 09:39:39.954 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=44, payload=00 3C 01]
2019-02-20 09:39:39.955 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=null]
2019-02-20 09:39:39.956 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:40.080 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:40.081 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, status=SUCCESS]
2019-02-20 09:39:40.081 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=null]
2019-02-20 09:39:40.082 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:03,0000,00,00,0000,0036
<

2019-02-20 09:39:40.241 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:36
2019-02-20 09:39:40.242 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:40.242 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=54, status=SUCCESS]
2019-02-20 09:39:40.243 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8036,02:,00,FF
2019-02-20 09:39:40.243 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32822, messageData=00 00, rssi=0, lqi=255]
2019-02-20 09:39:40.244 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00]
2019-02-20 09:39:40.245 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]
2019-02-20 09:39:40.246 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:36
2019-02-20 09:39:40.247 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=54]
2019-02-20 09:39:40.247 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=54]
2019-02-20 09:39:40.724 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: running
2019-02-20 09:39:40.725 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=2D, startIndex=0]
2019-02-20 09:39:40.727 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=45, payload=00 00]
2019-02-20 09:39:40.727 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]
2019-02-20 09:39:40.727 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:40.728 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]
2019-02-20 09:39:40.729 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032


2019-02-20 09:39:40.928 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:38
2019-02-20 09:39:40.929 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:40.929 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=56, status=SUCCESS]
2019-02-20 09:39:40.930 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8032,50:@9,00,FF
2019-02-20 09:39:40.931 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 00 0F 00 00 39 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
2019-02-20 09:39:40.932 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 40 00 0F 00 00 39 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-02-20 09:39:40.933 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=0, routingTableList=[RoutingTable [destinationAddress=0, status=DISCOVERY_UNDERWAY, memoryConstrained=true, manyToOne=true, routeRecordRequired=true, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-02-20 09:39:40.934 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:38
2019-02-20 09:39:40.935 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=56]
2019-02-20 09:39:40.935 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=56]
2019-02-20 09:39:40.938 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=2D, startIndex=0]
2019-02-20 09:39:40.954 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=0, routingTableList=[RoutingTable [destinationAddress=0, status=DISCOVERY_UNDERWAY, memoryConstrained=true, manyToOne=true, routeRecordRequired=true, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-02-20 09:39:40.955 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=2E, startIndex=15]
2019-02-20 09:39:40.958 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=46, payload=00 0F]
2019-02-20 09:39:40.958 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 0F, messageId=null]
2019-02-20 09:39:40.959 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:40.960 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 0F, messageId=null]
2019-02-20 09:39:40.962 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032


2019-02-20 09:39:41.238 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:3A
2019-02-20 09:39:41.239 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:41.239 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 0F, messageId=58, status=SUCCESS]
2019-02-20 09:39:41.240 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8032,50:@,00,FF
2019-02-20 09:39:41.241 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 0F 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
2019-02-20 09:39:41.242 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 40 0F 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-02-20 09:39:41.242 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-02-20 09:39:41.244 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=2E, startIndex=15]
2019-02-20 09:39:41.245 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=15, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-02-20 09:39:41.246 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=2F, startIndex=30]
2019-02-20 09:39:41.246 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=47, payload=00 1E]
2019-02-20 09:39:41.246 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 1E, messageId=null]
2019-02-20 09:39:41.246 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:41.247 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 1E, messageId=null]
2019-02-20 09:39:41.249 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032


2019-02-20 09:39:41.249 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:3A
2019-02-20 09:39:41.249 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=58]
2019-02-20 09:39:41.250 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=58]
2019-02-20 09:39:41.447 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:3C
2019-02-20 09:39:41.448 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:41.448 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 1E, messageId=60, status=SUCCESS]
2019-02-20 09:39:41.450 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8032,50:@,00,FF
2019-02-20 09:39:41.451 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 1E 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
2019-02-20 09:39:41.452 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 40 1E 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-02-20 09:39:41.452 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=30, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-02-20 09:39:41.453 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:3C
2019-02-20 09:39:41.454 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=60]
2019-02-20 09:39:41.454 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=60]
2019-02-20 09:39:41.456 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=2F, startIndex=30]
2019-02-20 09:39:41.457 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=30, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-02-20 09:39:41.458 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=30, startIndex=45]
2019-02-20 09:39:41.458 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=48, payload=00 2D]
2019-02-20 09:39:41.458 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 2D, messageId=null]
2019-02-20 09:39:41.459 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:41.459 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 2D, messageId=null]
2019-02-20 09:39:41.460 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032
-

2019-02-20 09:39:41.659 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:3E
2019-02-20 09:39:41.660 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:41.660 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 2D, messageId=62, status=SUCCESS]
2019-02-20 09:39:41.661 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8032,50:@-,00,FF
2019-02-20 09:39:41.662 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 2D 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
2019-02-20 09:39:41.663 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 40 2D 0F 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-02-20 09:39:41.663 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=45, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-02-20 09:39:41.665 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:3E
2019-02-20 09:39:41.665 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=30, startIndex=45]
2019-02-20 09:39:41.666 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=62]
2019-02-20 09:39:41.666 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=45, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-02-20 09:39:41.667 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=31, startIndex=60]
2019-02-20 09:39:41.668 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=49, payload=00 3C]
2019-02-20 09:39:41.668 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 3C, messageId=null]
2019-02-20 09:39:41.669 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:41.669 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=62]
2019-02-20 09:39:41.669 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 3C, messageId=null]
2019-02-20 09:39:41.671 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032
<

2019-02-20 09:39:41.841 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:40
2019-02-20 09:39:41.842 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:41.842 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 3C, messageId=64, status=SUCCESS]
2019-02-20 09:39:41.843 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8032,19:@<,00,FF
2019-02-20 09:39:41.844 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32818, messageData=00 00 40 3C 04 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00, rssi=0, lqi=255]
2019-02-20 09:39:41.844 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32818, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 40 3C 04 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00 00 00 03 00 00]
2019-02-20 09:39:41.845 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=60, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]
2019-02-20 09:39:41.846 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=31, startIndex=60]
2019-02-20 09:39:41.847 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:40
2019-02-20 09:39:41.848 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=64]
2019-02-20 09:39:41.848 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=64]
2019-02-20 09:39:41.848 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [SUCCESS, ManagementRoutingResponse [0/0 -> 0/0, cluster=8032, TID=NULL, status=SUCCESS, routingTableEntries=64, startIndex=60, routingTableList=[RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]]]
2019-02-20 09:39:41.849 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementLqiRequest complete [2 routes]
2019-02-20 09:39:41.850 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000AEC3BEB: Routing table NEW: [RoutingTable [destinationAddress=0, status=DISCOVERY_UNDERWAY, memoryConstrained=true, manyToOne=true, routeRecordRequired=true, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
2019-02-20 09:39:41.850 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000AEC3BEB: Routing table OLD: [RoutingTable [destinationAddress=0, status=DISCOVERY_UNDERWAY, memoryConstrained=true, manyToOne=true, routeRecordRequired=true, nextHopAddress=0], RoutingTable [destinationAddress=0, status=INACTIVE, memoryConstrained=false, manyToOne=false, routeRecordRequired=false, nextHopAddress=0]]
2019-02-20 09:39:41.851 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000AEC3BEB: Routing table unchanged
2019-02-20 09:39:41.851 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: request ROUTES successful. Advanced to NEIGHBORS.
2019-02-20 09:39:41.852 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: running
2019-02-20 09:39:41.853 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=32, startIndex=0]
2019-02-20 09:39:41.853 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=50, payload=00 00]
2019-02-20 09:39:41.854 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]
2019-02-20 09:39:41.854 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:41.855 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]
2019-02-20 09:39:41.857 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0031


2019-02-20 09:39:42.017 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:42
2019-02-20 09:39:42.017 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-20 09:39:42.018 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=66, status=SUCCESS]
2019-02-20 09:39:42.019 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8031,05:,00,FF
2019-02-20 09:39:42.019 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32817, messageData=00 00 00 00 00, rssi=0, lqi=255]
2019-02-20 09:39:42.020 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 00 00]
2019-02-20 09:39:42.020 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]
2019-02-20 09:39:42.022 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=32, startIndex=0]
2019-02-20 09:39:42.022 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:42
2019-02-20 09:39:42.022 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]]
2019-02-20 09:39:42.023 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=66]
2019-02-20 09:39:42.023 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=66]
2019-02-20 09:39:42.023 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: ManagementLqiRequest complete [0 neighbors]
2019-02-20 09:39:42.024 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - 000D6F000AEC3BEB: Neighbor table unchanged
2019-02-20 09:39:42.024 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: request NEIGHBORS successful. Advanced to null.
2019-02-20 09:39:42.025 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: running
2019-02-20 09:39:42.025 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: complete
2019-02-20 09:39:42.026 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000AEC3BEB: Node 0 update
2019-02-20 09:39:42.034 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-02-20 09:39:42.040 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-02-20 09:39:43.023 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-20 09:39:43.024 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-20 09:39:43.024 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

Any thoughts?

Henrik

Hydropower · February 21, 2019, 11:05am

I have been struggling a bit further and moved the USB stick to my computer and installed Telegesis terminal. Using the instructions under chapter 3 of the quick start guide I found that If I stopped the current PAN and created a new one I could actually find the bulb. So I moved the USB stick back to my NAS and retried the detection. Now I can find the bulb but it shows up as " Unknown ZigBee Device D0CF5EFFFEC0C9B4", a generic zigbee device that cannot do anything…
Looking in the log it seems the request for device info times out:


2019-02-21 10:52:33.831 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,7B5E,C94BE0E458776313
2019-02-21 10:52:33.832 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-21 10:52:33.832 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=31582, epanId=C94BE0E458776313, status=SUCCESS]
2019-02-21 10:52:34.242 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NodeDescriptorRequest [0/0 -> 59882/0, cluster=0002, TID=FC, nwkAddrOfInterest=59882]
2019-02-21 10:52:34.244 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - D0CF5EFFFEC0C9B4: Node SVC Discovery: NodeDescriptorResponse returned null
2019-02-21 10:52:34.244 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - D0CF5EFFFEC0C9B4: Node SVC Discovery: request NODE_DESCRIPTOR failed. Retry 4, wait 11615ms before retry.
2019-02-21 10:52:34.749 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NodeDescriptorRequest [0/0 -> 37500/0, cluster=0002, TID=FD, nwkAddrOfInterest=37500]
2019-02-21 10:52:34.751 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - D0CF5EFFFEC0C9B4: Node SVC Discovery: NodeDescriptorResponse returned null
2019-02-21 10:52:34.751 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - D0CF5EFFFEC0C9B4: Node SVC Discovery: request NODE_DESCRIPTOR failed. Retry 3, wait 4516ms before retry.
2019-02-21 10:52:34.833 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-21 10:52:34.833 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-21 10:52:34.834 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

Any thoughts?
Henrik

Hydropower · February 21, 2019, 11:25am

This part of the log seems interesting:


2019-02-21 11:14:34.407 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:7F
2019-02-21 11:14:34.408 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-02-21 11:14:34.408 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01, messageId=127, status=SUCCESS]
2019-02-21 11:14:34.410 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8036,02:,00,FF
2019-02-21 11:14:34.411 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=0, profileId=0, destinationEp=0, sourceEp=0, clusterId=32822, messageData=00 00, rssi=0, lqi=255]
2019-02-21 11:14:34.412 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00]
2019-02-21 11:14:34.413 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS]
2019-02-21 11:14:34.414 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:7F
2019-02-21 11:14:34.415 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=127]
2019-02-21 11:14:34.416 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=127]
2019-02-21 11:14:35.373 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:D0CF5EFFFEC0C9B4,7E39,0000,00,00,0013,0C:9~´ÉÀþÿ^ÏÐ,-19,FF
2019-02-21 11:14:35.374 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=D0CF5EFFFEC0C9B4, networkAddress=32313, profileId=0, destinationEp=0, sourceEp=0, clusterId=19, messageData=81 39 7E B4 C9 C0 FE FF 5E CF D0 8E, rssi=-25, lqi=255]
2019-02-21 11:14:35.375 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=32313/0, destinationAddress=0/0, profile=0000, cluster=19, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=81 39 7E B4 C9 C0 FE FF 5E CF D0 8E]
2019-02-21 11:14:35.376 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [32313/0 -> 0/0, cluster=0013, TID=NULL, nwkAddrOfInterest=32313, ieeeAddr=D0CF5EFFFEC0C9B4, capability=142]
2019-02-21 11:14:35.377 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Mesh related command received. Triggering mesh update.
2019-02-21 11:14:35.377 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - D0CF5EFFFEC0C9B4: Device announce received. NWK=32313
2019-02-21 11:14:35.378 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Start mesh update task with interval of 300 seconds
2019-02-21 11:14:35.379 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - D0CF5EFFFEC0C9B4: Node 32313 added to the network
2019-02-21 11:14:35.389 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update
2019-02-21 11:14:35.390 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update for 000D6F000AEC3BEB
2019-02-21 11:14:35.391 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: Update mesh
2019-02-21 11:14:35.391 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for D0CF5EFFFEC0C9B4
2019-02-21 11:14:35.392 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - D0CF5EFFFEC0C9B4: Node SVC Discovery: start discovery
2019-02-21 11:14:35.393 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - D0CF5EFFFEC0C9B4: Node SVC Discovery: scheduled [ACTIVE_ENDPOINTS, NWK_ADDRESS, POWER_DESCRIPTOR, NEIGHBORS, NODE_DESCRIPTOR]
2019-02-21 11:14:35.392 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: scheduled [ROUTES, NEIGHBORS]
2019-02-21 11:14:35.397 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2019-02-21 11:14:35.405 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2019-02-21 11:14:35.412 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFEC0C9B4: Starting ZigBee device discovery
2019-02-21 11:14:35.414 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFEC0C9B4: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_telegesis:0000000C
2019-02-21 11:14:35.419 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:0000000C:d0cf5efffec0c9b4' to inbox.
2019-02-21 11:14:35.421 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - D0CF5EFFFEC0C9B4: Node discovery not complete
2019-02-21 11:14:36.379 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-02-21 11:14:36.379 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]
2019-02-21 11:14:36.434 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

It ends with “Node discovery not complete”, what is causing it to fail?

Henrik

chris · February 22, 2019, 4:24am

This just means that the service discovery is not complete, so the binding can’t complete the addition of the device. It’s not really abnormal.

The log is really a bit short to see what is happening.

Hydropower · February 24, 2019, 9:11pm

Ok, sorry. I’m trying to get the exact same sequence but with a clean log file that is small enough to upload, but right now I can’t even get it to detect it as an unknown device? This is the log I get anyway:
openhab (2).log (384.9 KB)

Thanks!

Hydropower · March 12, 2019, 9:52pm

This is slowly driving me nuts! I can’t for my life get the Zigbee binding to find any trådfri bulbs, no matter what I do! I have tried removing the PAN and create a new one on the Telegesis (using the Telegesis terminal. While doing so I could see the bulb and get it’s 64 bit adress, but due to my lack of knowledge of the Zigbee protocol I was not able to understand if I got the complete descriptor from the bulb), I have tried resetting the bulb etc. etc.

Is there anything in the attached log that could indicate what the problem is? I see two Error:02 in there, could they indicate something? (in this sequence I started with a clean PAN, then connected a bulb, but it did not show up in OH, so I resetted the bulb during the search time, so two possible joins where performed)

openhab.log (208.3 KB)

Also, is there any tests that I could perform from Telegesis terminal on the PC that could indicate if the HW is working?

Thanks!
Henrik

chris · March 12, 2019, 11:23pm

The log is pretty short so there’s not really a lot to comment on, but the join command is being sent, but nothing is joining. The join itself is not something the binding has any involvement with, so there are simply no messages until something joins. Without a sniffer log it’s not really possible to tell why it’s not joining.

Hydropower · March 13, 2019, 9:18pm

What should be entered in the settings of the Telegesis thing? I have set the Trust Centre Join Mode to allow all joins, is there anything else I must do?

I know for sure that the bulb is sending out some sort of message with its ID when connected.
I can see it in the terminal window when using the Telegesis plug in my PC. The first time after resetting the bulb I get a

NEWNODE: <NWK addr>,<EUI64>,
<Parent NWK addr>

message, after that I get

RX:<EUI64>,<NWK addr>,<profileID>,
<destinationEndpoint>,<SourceEndpoint>,
<clusterID>,<length>:<payload>
[,<RSSI>,<LQI>]

every time the bulb is powered up.

And what about all those Error 02 I see every now and then? From the Silicon Labs datasheet it should be “Unknown Command”. Who is sending unknown commands? Is it the binding having bugs or what can that be?

Do you have any ideas of further investigations or tests that can be performed in order to find the root cause of these issues? I don’t have any zigbee sniffer equipment at the moment, but I suppose I could get it if nothing else works (I’m an embedded HW engineer as a profession, so it could turn up handy in the future anyway…).

Thanks!

chris · March 13, 2019, 9:30pm

Really - they why does it not do this when you run it with the binding? It seems very strange that there is nothing showing at all.

The Telegesis dongle is very heavily used, so I don’t think there is likely to be a bug, but if you can provide a log showing the issue I’ll have a look.

Hydropower · March 13, 2019, 9:39pm

That’s what I’m currently trying to figure out. My problem is that the log doesn’t show all data sent to and from the Telegesis (the pure AT-commands), so I don’t know where to look in the log files. What should I expect to see when everything is working correctly?

It does sound comforting thought that it is heavily used, that means it should be possible to solve!

Could it be related to me running on a Synology NAS inside a Docker Container? It does seem to me that the binding can communicate with the Telegesis dongle, since I can see the same JPAN in the OH log as in the PC terminal when sending an AT+N, but maybe there is some limitation that I’m not aware of?

Thanks

chris · March 13, 2019, 9:49pm

Really? I can’t see how this is possible? Are you suggesting that it’s selectively not displaying some messages that are really being received, and then also selectively not processing them? Seems pretty unlikely?

I’m not sure what you are suggesting is the problem. Are you suggesting that the data is being received, but the log is not logging everything that is sent and received, or, are you suggesting that some data is being lost due to serial port issues?

I think both seem unlikely, but maybe the serial port could drop data - it just seems strange that the log you provide above seems to show no errors, and yet every time you try to join a device, it never passes that data?

Hydropower · March 13, 2019, 10:01pm

I’m probably just drowning in all the extra information that is inserted in between! In this section for example:

2019-03-13 21:41:23.764 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,4445,88B437C3BC13DF89
2019-03-13 21:41:23.764 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-03-13 21:41:23.765 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=17477, epanId=88B437C3BC13DF89, status=SUCCESS]
2019-03-13 21:41:24.309 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_telegesis:0000000C
2019-03-13 21:41:24.310 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.
2019-03-13 21:41:24.312 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=3D, permitDuration=60, tcSignificance=true]
2019-03-13 21:41:24.313 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=61, payload=00 3C 01]
2019-03-13 21:41:24.314 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01]
2019-03-13 21:41:24.315 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-03-13 21:41:24.316 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65532, sourceEp=0, destEp=0, profileId=0, clusterId=54, messageData=00 3C 01]
2019-03-13 21:41:24.318 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDMCASTB:03,1F,FFFC,00,00,0000,0036

Is the only thing done in this whole sequence to send the AT+SENDMCASTB:03,1F,FFFC,00,00,0000,0036 at the end? If so, then no, I’m just missing the forest for all the trees…

I’m grasping at straws, but I was more into the thought of serial port issues or something. If you find it unlikely I will drop that thought.

chris · March 13, 2019, 10:05pm

I find it unlikely that it would drop whole packets and have no errors in other packets. I could believe that there could be errors in the serial port and that bytes get lost, but this would cause random packet errors which I think causes exceptions (due to the fact that the Telegesis protocol has no error checking). This isn’t what we’re seeing…

Hydropower · March 13, 2019, 10:14pm

How should it look in the log when a bulb is joining?
Also, there seem to be a lot of data sent to address 0000, does that mean it is sending data to itself?

chris · March 13, 2019, 10:17pm

There will be a lot of transactions - I don’t have another log here to view, but there are notifications from the trust centre, announce messages…

It’s hard for me to comment without know what you are looking at. Can you provide the logs?

Hydropower · March 13, 2019, 10:34pm

You can see some unicast messages to 0000 and the reception of the same shortly after:openhab_4.log (572.6 KB)

2019-03-13 22:02:59.099 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,-07,4445,88B437C3BC13DF89
2019-03-13 22:02:59.100 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-03-13 22:02:59.101 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=-7, panId=17477, epanId=88B437C3BC13DF89, status=SUCCESS]
2019-03-13 22:02:59.490 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000AEC3BEB: Node SVC Discovery: running
2019-03-13 22:02:59.491 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 0/0, cluster=0032, TID=57, startIndex=0]
2019-03-13 22:02:59.492 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=87, payload=00 00]
2019-03-13 22:02:59.492 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]
2019-03-13 22:02:59.492 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1
2019-03-13 22:02:59.493 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]
2019-03-13 22:02:59.494 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,0000,00,00,0000,0032

2019-03-13 22:02:59.694 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:02
2019-03-13 22:02:59.694 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK
2019-03-13 22:02:59.695 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=2, status=SUCCESS]
2019-03-13 22:02:59.696 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:0000,0000,00,00,8032,50: