Zigbee device discovery

puzzle-star · July 8, 2018, 8:56am

Would it then make sense that you implement conditionally not checking for address changes of the coordinator (which I understand cannot happen), as per the post above? (the addition of the if)

Otherwise, discovery of the CC2531 is never working (at least that I have seen in my logs) as it gets stuck at the NWK_ADDR discovery stage

chris · July 8, 2018, 9:34am

We just need to ensure that this doesn’t have unwanted side effects. This call is/was the only way for the binding to know the EUI of the coordinator. In some coordinators, it might still be this way (I forget now).

True - the coordinator is always address 0.

This is quite strange, as I have tested the CC2531 a lot - not in real detail in recent times, but enough to ensure it starts, and I can join devices

puzzle-star · July 8, 2018, 11:32am

I have seen the error in the logs of several people having issues (i.e. in this same thread):

I will check with my new firmware in case this was something happening on the stock one due to / only when having memory issues.

chris · July 8, 2018, 6:51pm

Possibly, however if what you’re saying is correct, it would never be possible to use the TI coordinator, and clearly that isn’t the case? Maybe it’s related to different firmware - I’m not sure, but I do know that it CAN work and if we remove this, we need to ensure it doesn’t have adverse impacts on other coordinators.

puzzle-star · July 10, 2018, 6:58pm

Hi @Cris,

Please see below the related log entries:

2018-07-10 20:18:13.561 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896B01: Node SVC Discovery running
2018-07-10 20:18:13.562 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=02, ieeeAddr=00124B000E896B01, requestType=0, startIndex=0]2018-07-10 20:18:13.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=2, payload=00 01 6B 89 0E 00 4B 12 00 00 00]
2018-07-10 20:18:23.697 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null
2018-07-10 20:18:23.700 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896B01: Node SVC Discovery request NWK_ADDRESS failed. Retry 26, wait 57075ms before retry.

The NetworkAddressRequest is timing out 10 seconds after the command is sent (no response from the dongle). The following discovery tasks on the coordinator are then never completed:

NodeDiscoveryTask.NWK_ADDRESS // <-- this one fails and is retried forever
NodeDiscoveryTask.NODE_DESCRIPTOR
NodeDiscoveryTask.POWER_DESCRIPTOR
NodeDiscoveryTask.ACTIVE_ENDPOINTS
NodeDiscoveryTask.NEIGHBORS

But even if the discovery of the coordinator node is failing, everything else seems to be working for me.

So I am wondering: what is the binding using the discovered routing tables, neighbour tables, etc, for? The dongle is managing all this at z-stack level, so is it loaded only informationally, or are these used somehow by the binding to discover new nodes?

Also, is it possible that everything works without the coordinator completing discovery?

If not, I would assume that where it works it is because the coordinator was added before some change in the code. The specific line calling the discovery was added 5 months ago (Discovery refactoring), but I cannot tell if there was something similar before, and anyway it would be strange that no new cc2531’s could be added since that code went on the stable release and no one noticed…

I will check with a spare new cc2531, but that means leaving my home without lightning while I test…

Pedro

puzzle-star · July 10, 2018, 8:20pm

Hi @cris,

Tested adding a new dongle. It fails to complete discovery, but it shows up as ONLINE in openhab, so I would assume it is not a big deal? Or I am missing something?

2018-07-10 22:09:51.715 [INFO ] [.cc2531.network.ZigBeeNetworkManager] - Initialized ZigBee network with new or reset network state.
2018-07-10 22:09:54.243 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00124B000E896CE9: Discovery notification
2018-07-10 22:09:54.248 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start.
2018-07-10 22:09:54.304 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.
2018-07-10 22:09:54.385 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialise done....... 11  -4233  A6AFD0F64EFD6221
2018-07-10 22:10:05.635 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null
2018-07-10 22:10:05.637 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery request NWK_ADDRESS failed. Retry 1, wait 2104ms before retry.
2018-07-10 22:10:07.743 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery running
2018-07-10 22:10:07.749 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=05, ieeeAddr=00124B000E896CE9, requestType=0, startIndex=0]
2018-07-10 22:10:07.754 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=5, payload=00 E9 6C 89 0E 00 4B 12 00 00 00]
2018-07-10 22:10:17.883 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null
2018-07-10 22:10:17.891 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery request NWK_ADDRESS failed. Retry 2, wait 2104ms before retry.
2018-07-10 22:10:20.001 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery running
2018-07-10 22:10:20.006 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=06, ieeeAddr=00124B000E896CE9, requestType=0, startIndex=0]
2018-07-10 22:10:20.010 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=6, payload=00 E9 6C 89 0E 00 4B 12 00 00 00]
2018-07-10 22:10:30.142 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null
2018-07-10 22:10:30.165 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery request NWK_ADDRESS failed. Retry 3, wait 2104ms before retry.
2018-07-10 22:10:32.272 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery running
2018-07-10 22:10:32.278 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=07, ieeeAddr=00124B000E896CE9, requestType=0, startIndex=0]
2018-07-10 22:10:32.283 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=7, payload=00 E9 6C 89 0E 00 4B 12 00 00 00]
2018-07-10 22:10:42.415 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null
2018-07-10 22:10:42.417 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery request NWK_ADDRESS failed. Retry 4, wait 6312ms before retry.
2018-07-10 22:10:48.733 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery running
2018-07-10 22:10:48.737 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=08, ieeeAddr=00124B000E896CE9, requestType=0, startIndex=0]
2018-07-10 22:10:48.741 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=8, payload=00 E9 6C 89 0E 00 4B 12 00 00 00]
2018-07-10 22:10:58.873 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null
2018-07-10 22:10:58.877 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896CE9: Node SVC Discovery request NWK_ADDRESS failed. Retry 5, wait 8416ms before retry.

Pedro

chris · July 10, 2018, 9:01pm

Nothing - they are just used for display purposes. Some customers had a need for this information.

Yes - it should be fine so long as it knows the IEEE addresses - the NWK Address is not needed in this mode.

This call could be inhibited for the coordinator. There is some major refactoring ongoing at the moment to allow the system to work as a router so we need to be careful about how this change is made.

WeRo · August 11, 2019, 9:43am

Hi all,

since yesterday about 1 p.m. I am facing the same issue.
Most of my Zigbee Items do not work anymore. In PaperUI they are all still online, but the debug messages are the same as shown above.

I did not make any updates!
I deleted cache by openhab-cli and made a reboot.
Nothing helps.

How can I solve the problem?

chris · August 11, 2019, 9:56am

This is a very old thread and it’s hard to comment on your issue without a logfile. Please provide a full debug log so I can see what is going on.

WeRo · August 11, 2019, 12:01pm

Hi Chris,

this is a part of the debug log:

2019-08-11 12:42:54.371 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=6]

2019-08-11 12:42:54.506 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,08,4877,C3A5104CC5526D0C

2019-08-11 12:42:54.509 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:42:54.511 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=8, panId=18551, epanId=C3A5104CC5526D0C, status=SUCCESS]

2019-08-11 12:42:54.760 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A01C6C8: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]

2019-08-11 12:42:54.763 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A01C6C8: Node SVC Discovery: request NEIGHBORS failed. Retry 2, wait 4350ms before retry.

2019-08-11 12:42:54.767 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A013BF3: Node SVC Discovery: running

2019-08-11 12:42:54.771 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 22359/0, cluster=0031, TID=44, startIndex=0]

2019-08-11 12:42:54.775 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=22359/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=68, payload=00 00]

2019-08-11 12:42:54.778 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=22359, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:42:54.781 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:42:54.783 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=22359, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:42:54.786 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,5757,00,00,0000,0031^M^@^@

2019-08-11 12:42:55.015 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:0B

2019-08-11 12:42:55.016 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:42:55.017 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=22359, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=11, status=SUCCESS]

2019-08-11 12:42:55.019 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:07

2019-08-11 12:42:55.020 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=7]

2019-08-11 12:42:55.021 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=7]

2019-08-11 12:42:55.674 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:08

2019-08-11 12:42:55.676 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=8]

2019-08-11 12:42:55.678 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=8]

2019-08-11 12:42:55.909 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:09

2019-08-11 12:42:55.911 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=9]

2019-08-11 12:42:55.913 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=9]

2019-08-11 12:42:56.070 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:0A

2019-08-11 12:42:56.071 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=10]

2019-08-11 12:42:56.072 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=10]

2019-08-11 12:42:56.430 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F7BAE: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]

2019-08-11 12:42:56.431 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F7BAE: Node SVC Discovery: request NEIGHBORS failed after 13 attempts.

2019-08-11 12:42:56.432 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 65089/0, cluster=0031, TID=39, startIndex=0]

2019-08-11 12:42:56.439 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00ACED53: Node SVC Discovery: running

2019-08-11 12:42:56.441 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 17611/0, cluster=0032, TID=45, startIndex=0]

2019-08-11 12:42:56.442 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=17611/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=69, payload=00 00]

2019-08-11 12:42:56.444 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=17611, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]

2019-08-11 12:42:56.445 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:42:56.446 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=17611, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]

2019-08-11 12:42:56.449 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,44CB,00,00,0000,0032^M^@^@
2019-08-11 12:42:56.581 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:0C

2019-08-11 12:42:56.582 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:42:56.583 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=17611, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=12, status=SUCCESS]

2019-08-11 12:42:57.408 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F88EE: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [TIMEOUT]

2019-08-11 12:42:57.410 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F88EE: Node SVC Discovery: request ROUTES failed after 13 attempts.

2019-08-11 12:42:57.413 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 43986/0, cluster=0031, TID=3A, startIndex=0]

2019-08-11 12:42:57.425 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementRoutingRequest [0/0 -> 36393/0, cluster=0032, TID=3B, startIndex=0]

2019-08-11 12:42:57.428 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00AD4F4A: Node SVC Discovery: running

2019-08-11 12:42:57.430 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 32511/0, cluster=0031, TID=46, startIndex=0]

2019-08-11 12:42:57.433 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=32511/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=70, payload=00 00]

2019-08-11 12:42:57.435 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=32511, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:42:57.437 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:42:57.440 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=32511, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:42:57.445 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,7EFF,00,00,0000,0031^M^@^@

2019-08-11 12:42:57.577 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:0D

2019-08-11 12:42:57.578 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:42:57.579 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=32511, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=13, status=SUCCESS]

2019-08-11 12:42:58.017 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=false, lastReportTime=Sat Aug 10 12:04:31 CEST 2019]

2019-08-11 12:42:58.018 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 47633/3, cluster=0006, TID=47, identifiers=[0]]

2019-08-11 12:42:58.020 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=71, commandId=0]

2019-08-11 12:42:58.021 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=47633/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=71, payload=00 47 00 00 00]

2019-08-11 12:42:58.022 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=47633, sourceEp=0, destEp=3, profileId=260, clusterId=6, messageData=00 47 00 00 00, messageId=null]

2019-08-11 12:42:58.024 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1021

2019-08-11 12:42:58.581 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:42:58.583 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]

2019-08-11 12:42:58.586 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-08-11 12:42:58.718 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,08,4877,C3A5104CC5526D0C

2019-08-11 12:42:58.719 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:42:58.721 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=8, panId=18551, epanId=C3A5104CC5526D0C, status=SUCCESS]

2019-08-11 12:42:59.548 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F9F2F: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [TIMEOUT]

2019-08-11 12:42:59.551 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F9F2F: Node SVC Discovery: request ROUTES failed. Retry 12, wait 23200ms before retry.

2019-08-11 12:42:59.554 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F7BAE: Node SVC Discovery: running

2019-08-11 12:42:59.557 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementRoutingRequest [0/0 -> 43986/0, cluster=0032, TID=48, startIndex=0]

2019-08-11 12:42:59.560 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=43986/0, profile=0000, cluster=50, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=72, payload=00 00]

2019-08-11 12:42:59.562 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=43986, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]

2019-08-11 12:42:59.564 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:42:59.567 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=43986, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=null]

2019-08-11 12:42:59.577 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,ABD2,00,00,0000,0032^M^@^@
2019-08-11 12:42:59.648 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=TEMPERATURE_MEASUREMENT, id=0, name=MeasuredValue, dataType=SIGNED_16_BIT_INTEGER, lastValue=2220, lastReportTime=Sat Aug 10 11:40:18 CEST 2019]

2019-08-11 12:42:59.652 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Temperature measurement: 0/0 -> 36916/1, cluster=0402, TID=49, identifiers=[0]]

2019-08-11 12:42:59.655 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=73, commandId=0]

2019-08-11 12:42:59.658 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=36916/1, profile=0104, cluster=1026, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=73, payload=00 49 00 00 00]

2019-08-11 12:42:59.661 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=36916, sourceEp=0, destEp=1, profileId=260, clusterId=1026, messageData=00 49 00 00 00, messageId=null]

2019-08-11 12:42:59.665 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1022

2019-08-11 12:42:59.705 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:0B

2019-08-11 12:42:59.708 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=11]

2019-08-11 12:42:59.710 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=11]

2019-08-11 12:42:59.714 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:0E

2019-08-11 12:42:59.718 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:42:59.721 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=43986, sourceEp=0, destEp=0, profileId=0, clusterId=50, messageData=00 00, messageId=14, status=SUCCESS]

2019-08-11 12:43:00.275 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ON_OFF, id=0, name=OnOff, dataType=BOOLEAN, lastValue=false, lastReportTime=Sat Aug 10 12:04:12 CEST 2019]

2019-08-11 12:43:00.278 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [On/Off: 0/0 -> 32511/3, cluster=0006, TID=4A, identifiers=[0]]

2019-08-11 12:43:00.280 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=74, commandId=0]

2019-08-11 12:43:00.281 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=32511/3, profile=0104, cluster=6, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=74, payload=00 4A 00 00 00]

2019-08-11 12:43:00.283 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=32511, sourceEp=0, destEp=3, profileId=260, clusterId=6, messageData=00 4A 00 00 00, messageId=null]

2019-08-11 12:43:00.285 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:00.287 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=32511, sourceEp=0, destEp=3, profileId=260, clusterId=6, messageData=00 4A 00 00 00, messageId=null]

2019-08-11 12:43:00.290 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,7EFF,00,03,0104,0006^M^@J^@^@^@

2019-08-11 12:43:00.424 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:0F

2019-08-11 12:43:00.425 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:43:00.427 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=32511, sourceEp=0, destEp=3, profileId=260, clusterId=6, messageData=00 4A 00 00 00, messageId=15, status=SUCCESS]

2019-08-11 12:43:00.857 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A02E0A3: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [TIMEOUT]

2019-08-11 12:43:00.861 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A02E0A3: Node SVC Discovery: request ROUTES failed. Retry 9, wait 25278ms before retry.

2019-08-11 12:43:00.864 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00061C1959: Node SVC Discovery: running

2019-08-11 12:43:00.867 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 45154/0, cluster=0031, TID=4B, startIndex=0]

2019-08-11 12:43:00.870 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=45154/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=75, payload=00 00]

2019-08-11 12:43:00.874 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:00.877 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:00.880 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:00.887 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,B062,00,00,0000,0031^M^@^@

2019-08-11 12:43:01.019 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:10

2019-08-11 12:43:01.022 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:43:01.024 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=16, status=SUCCESS]

2019-08-11 12:43:01.091 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=LEVEL_CONTROL, id=0, name=CurrentLevel, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=254, lastReportTime=Sat Aug 10 12:04:42 CEST 2019]

2019-08-11 12:43:01.094 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Level Control: 0/0 -> 36393/3, cluster=0008, TID=4C, identifiers=[0]]

2019-08-11 12:43:01.096 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=76, commandId=0]

2019-08-11 12:43:01.099 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=36393/3, profile=0104, cluster=8, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=76, payload=00 4C 00 00 00]

2019-08-11 12:43:01.101 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=3, profileId=260, clusterId=8, messageData=00 4C 00 00 00, messageId=null]

2019-08-11 12:43:01.103 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:01.106 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=3, profileId=260, clusterId=8, messageData=00 4C 00 00 00, messageId=null]

2019-08-11 12:43:01.111 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,8E29,00,03,0104,0008^M^@L^@^@^@

2019-08-11 12:43:01.262 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00AD0AC2: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [TIMEOUT]

2019-08-11 12:43:01.263 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00AD0AC2: Node SVC Discovery: request ROUTES failed after 13 attempts.

2019-08-11 12:43:01.265 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F88EE: Node SVC Discovery: running

2019-08-11 12:43:01.267 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 36393/0, cluster=0031, TID=4D, startIndex=0]

2019-08-11 12:43:01.268 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:11

2019-08-11 12:43:01.269 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:43:01.270 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=36393/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=77, payload=00 00]

2019-08-11 12:43:01.271 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=3, profileId=260, clusterId=8, messageData=00 4C 00 00 00, messageId=17, status=SUCCESS]

2019-08-11 12:43:01.273 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:0C

2019-08-11 12:43:01.273 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:01.274 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=12]

2019-08-11 12:43:01.276 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=12]

2019-08-11 12:43:01.277 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:01.280 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:01.284 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,8E29,00,00,0000,0031^M^@^@

2019-08-11 12:43:01.416 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:12

2019-08-11 12:43:01.417 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:43:01.418 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=18, status=SUCCESS]

2019-08-11 12:43:02.263 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:0D

2019-08-11 12:43:02.266 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=13]

2019-08-11 12:43:02.268 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=13]

2019-08-11 12:43:03.270 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:03.271 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]

2019-08-11 12:43:03.273 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-08-11 12:43:03.404 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,08,4877,C3A5104CC5526D0C

2019-08-11 12:43:03.405 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:43:03.407 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=8, panId=18551, epanId=C3A5104CC5526D0C, status=SUCCESS]

2019-08-11 12:43:04.388 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:0E

2019-08-11 12:43:04.390 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=14]

2019-08-11 12:43:04.391 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=14]

2019-08-11 12:43:04.789 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A013BF3: Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT]

2019-08-11 12:43:04.792 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A013BF3: Node SVC Discovery: request NEIGHBORS failed. Retry 8, wait 21033ms before retry.

2019-08-11 12:43:04.796 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementRoutingRequest [0/0 -> 5944/0, cluster=0032, TID=3D, startIndex=0]

2019-08-11 12:43:04.806 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 60164/3, cluster=0006, TID=3F, identifiers=[0]]

2019-08-11 12:43:04.818 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00AFA81B: Node SVC Discovery: running

2019-08-11 12:43:04.822 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 47633/0, cluster=0031, TID=4E, startIndex=0]

2019-08-11 12:43:04.825 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=47633/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=78, payload=00 00]

2019-08-11 12:43:04.829 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=47633, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:04.832 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:04.836 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=47633, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:04.842 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,BA11,00,00,0000,0031^M^@^@

2019-08-11 12:43:04.975 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:13

2019-08-11 12:43:04.978 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 12:43:04.980 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=47633, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=19, status=SUCCESS]

2019-08-11 12:43:05.112 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:0F

2019-08-11 12:43:05.118 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=15]

2019-08-11 12:43:05.120 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=15]

2019-08-11 12:43:05.703 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:10

2019-08-11 12:43:05.704 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=16]

2019-08-11 12:43:05.705 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=16]

2019-08-11 12:43:05.929 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:11

2019-08-11 12:43:05.930 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=17]

2019-08-11 12:43:05.931 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=17]

2019-08-11 12:43:06.100 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:12

2019-08-11 12:43:06.101 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=18]

2019-08-11 12:43:06.103 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=18]

2019-08-11 12:43:06.451 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00ACED53: Node SVC Discovery: ManagementRoutingRequest returned CommandResult [TIMEOUT]

2019-08-11 12:43:06.453 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00ACED53: Node SVC Discovery: request ROUTES failed. Retry 10, wait 16233ms before retry.

2019-08-11 12:43:06.455 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementRoutingRequest [0/0 -> 56546/0, cluster=0032, TID=41, startIndex=0]

2019-08-11 12:43:06.469 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ReadAttributesCommand [On/Off: 0/0 -> 36393/3, cluster=0006, TID=42, identifiers=[0]]

2019-08-11 12:43:06.479 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A01C6C8: Node SVC Discovery: running

2019-08-11 12:43:06.482 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 65089/0, cluster=0031, TID=4F, startIndex=0]

2019-08-11 12:43:06.485 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65089/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=79, payload=00 00]

2019-08-11 12:43:06.488 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=65089, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:06.490 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 12:43:06.492 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=65089, sourceEp=0, destEp=0, profileId=0, clusterId=49, messageData=00 00, messageId=null]

2019-08-11 12:43:06.500 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:02,FE41,00,00,0000,0031^M^@^@

chris · August 11, 2019, 12:15pm

This is a pretty short log, but from what I can see the stick is NAKing all messages sent. This would indicate that the devices are not found on the network. Maybe the stick was inadvertently reset - I’m not really sure but from this short snippet there is no communications with any device.

WeRo · August 11, 2019, 12:38pm

just found this in openhab.log after restart:
2019-08-11 14:21:43.132 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee-2.5.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee [192]
Unresolved requirement: Import-Package: gnu.io
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee
-> Export-Package: com.zsmartsystems.zigbee; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:="com.zsmartsystems.zigbee.app,com.zsmartsystems.zigbee.dao,com.zsmartsystems.zigbee.security,com.zsmartsystems.zigbee.trans$
com.zsmartsystems.zigbee [197]
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.security
-> Export-Package: com.zsmartsystems.zigbee.security; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.app.otaserver
-> Export-Package: com.zsmartsystems.zigbee.app.otaserver; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:="com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.app,com.zsmartsystems.zigbee.zcl,com.zsmartsystems.zigbee.$
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl.protocol
-> Export-Package: com.zsmartsystems.zigbee.zcl.protocol; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.zcl”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.serialization
-> Export-Package: com.zsmartsystems.zigbee.serialization; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee.zcl.protocol”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl
-> Export-Package: com.zsmartsystems.zigbee.zcl; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:="com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.dao,com.zsmartsystems.zigbee.serialization,com.zsmartsystems.zigbee.$
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.app
-> Export-Package: com.zsmartsystems.zigbee.app; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.zcl”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.dao
-> Export-Package: com.zsmartsystems.zigbee.dao; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee.zcl,com.zsmartsystems.zigbee.zdo.field”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zdo.field
-> Export-Package: com.zsmartsystems.zigbee.zdo.field; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.serialization,com.zsmartsystems.zigbee.zcl”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl.field
-> Export-Package: com.zsmartsystems.zigbee.zcl.field; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee.serialization,com.zsmartsystems.zigbee.zcl,com.zsmartsystems.zigbee.zcl.protocol”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.app.iasclient
-> Export-Package: com.zsmartsystems.zigbee.app.iasclient; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:="com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.app,com.zsmartsystems.zigbee.zcl,com.zsmartsystems.zigbee.$
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl.clusters
-> Export-Package: com.zsmartsystems.zigbee.zcl.clusters; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.zcl,com.zsmartsystems.zigbee.zcl.field”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.transport
-> Export-Package: com.zsmartsystems.zigbee.transport; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.security”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl.clusters.onoff
-> Export-Package: com.zsmartsystems.zigbee.zcl.clusters.onoff; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee.zcl”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.app.discovery
-> Export-Package: com.zsmartsystems.zigbee.app.discovery; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee,com.zsmartsystems.zigbee.app” Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl.clusters.colorcontrol
-> Export-Package: com.zsmartsystems.zigbee.zcl.clusters.colorcontrol; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee.zcl”
Unresolved requirement: Import-Package: com.zsmartsystems.zigbee.zcl.clusters.iaszone
-> Export-Package: com.zsmartsystems.zigbee.zcl.clusters.iaszone; bundle-symbolic-name=“com.zsmartsystems.zigbee”; bundle-version=“1.1.7”; version=“1.1.7”; uses:=“com.zsmartsystems.zigbee.zcl”

            at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
    2019-08-11 14:21:43.164 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee-2.5.0-SNAPSHOT.jar
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee [192]
      Unresolved requirement: Import-Package: gnu.io

            at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
    2019-08-11 14:21:43.200 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee.telegesis-2.5.0-SNAPSHOT.jar
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee.telegesis [201]
      Unresolved requirement: Import-Package: gnu.io

            at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
    2019-08-11 14:21:43.203 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee.telegesis-2.5.0-SNAPSHOT.jar
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee.telegesis [201]
      Unresolved requirement: Import-Package: gnu.io

            at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
    2019-08-11 14:21:43.223 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee-2.5.0-SNAPSHOT.jar
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee [192]
      Unresolved requirement: Import-Package: gnu.io

            at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
    2019-08-11 14:21:43.239 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee-2.5.0-SNAPSHOT.jar
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee [192]
      Unresolved requirement: Import-Package: gnu.io        at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
    2019-08-11 14:21:43.246 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee.telegesis-2.5.0-SNAPSHOT.jar
    org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee.telegesis [201]
      Unresolved requirement: Import-Package: gnu.io

            at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
            at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
            at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]
2019-08-11 14:21:43.251 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zigbee.telegesis-2.5.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zigbee.telegesis [201]
  Unresolved requirement: Import-Package: gnu.io

        at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
        at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:520) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [10:org.apache.felix.fileinstall:3.6.4]
        at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [10:org.apache.felix.fileinstall:3.6.4]

chris · August 11, 2019, 12:40pm

What changed? The previous log was clearly working (in that it can communicate with the dongle), and now it is unable to load the serial driver so something must have changed between these two logs?

WeRo · August 11, 2019, 12:41pm

I deleted cache and tmp and made a restart.

chris · August 11, 2019, 1:09pm

Ok, it seems you have removed the serial driver that was presumably cached and you now need to add it back.

Since you have to reinstall some elements now, it may be worth considering updating to a more recent binding as what you’re running is quite old.

I don’t expect that deleting the cache etc will make any difference - the binding was communicating fine with the dongle, the network was up and working, but no devices were responding.

WeRo · August 11, 2019, 1:30pm

debug log after restart (limited to 48000 characters
Serial Binding is installed (binding-serial1-1.13.0)

2019-08-11 14:56:32.936 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STOPPING - com.zsmartsystems.zigbee.dongle.telegesis
2019-08-11 14:56:32.938 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STOPPED - com.zsmartsystems.zigbee.dongle.telegesis
2019-08-11 14:56:32.940 [DEBUG] [com.zsmartsystems.zigbee            ] - BundleEvent STOPPING - com.zsmartsystems.zigbee
2019-08-11 14:56:32.943 [DEBUG] [com.zsmartsystems.zigbee            ] - BundleEvent STOPPED - com.zsmartsystems.zigbee
2019-08-11 14:57:00.944 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2019-08-11 14:57:01.248 [ERROR] [org.apache.felix.scr                ] - bundle org.apache.felix.scr:2.1.2 (39)Circular reference detected trying to get service {org.eclipse.smarthome.io.net.http.TrustManagerProvider}={service.id=124, service.bundleid=200, service.sco$
 stack of references: ServiceReference: {org.eclipse.smarthome.io.net.http.TrustManagerProvider}={service.id=124, service.bundleid=200, service.scope=bundle, component.name=org.openhab.binding.icloud.internal.to_be_moved.TrustManagerProviderImpl, component.id=15}
ServiceReference: {org.eclipse.smarthome.io.net.http.HttpClientFactory, org.eclipse.smarthome.io.net.http.WebSocketFactory}={service.id=162, service.bundleid=118, service.scope=bundle, component.name=org.eclipse.smarthome.io.net.http.internal.WebClientFactoryImpl, com$
java.lang.Exception: stack trace
        at org.apache.felix.scr.impl.ComponentRegistry.enterCreate(ComponentRegistry.java:481) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.BundleComponentActivator.enterCreate(BundleComponentActivator.java:735) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:845) [39:org.apache.felix.scr:2.1.2]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
        at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleDynamicCustomizer.prebind(DependencyManager.java:962) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
        at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) [?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1053) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1007) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) [39:org.apache.felix.scr:2.1.2]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
 at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [39:org.apache.felix.scr:2.1.2]
        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [39:org.apache.felix.scr:2.1.2]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [?:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [?:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
        at org.eclipse.osgi.container.Module.start(Module.java:467) [?:?]
2019-08-11 14:57:29.390 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280

2019-08-11 14:57:29.396 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting

2019-08-11 14:57:29.769 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE

2019-08-11 14:57:29.779 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25

2019-08-11 14:57:29.781 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster OTA_UPGRADE
2019-08-11 14:57:39.808 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000B2FEDC5: Node 0 added to the network

2019-08-11 14:57:40.062 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA00AFA81B: Node 47633 added to the network

2019-08-11 14:57:40.070 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA00AD0AC2: Node 60164 added to the network

2019-08-11 14:57:40.073 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A03D042: Node 14013 added to the network

2019-08-11 14:57:40.094 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B0004A89AAD: Node 59696 added to the network

2019-08-11 14:57:40.105 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA00ACED53: Node 17611 added to the network

2019-08-11 14:57:40.109 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A02E0A3: Node 56546 added to the network

2019-08-11 14:57:40.121 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00061C1959: Node 45154 added to the network

2019-08-11 14:57:40.124 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B0008DAC9FC: Node 59165 added to the network

2019-08-11 14:57:40.182 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000F8427C3: Node 10688 added to the network

2019-08-11 14:57:40.200 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00077EC86F: Node 16103 added to the network

2019-08-11 14:57:40.207 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A01C6C8: Node 65089 added to the network

2019-08-11 14:57:40.210 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 84182600000F9F2F: Node 5944 added to the network

2019-08-11 14:57:40.214 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A013BF3: Node 22359 added to the network

2019-08-11 14:57:40.239 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 84182600000F7BAE: Node 43986 added to the network

2019-08-11 14:57:40.243 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 84182600000F88EE: Node 36393 added to the network
2019-08-11 14:57:40.247 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 84182600000EE4C8: Node 1549 added to the network

2019-08-11 14:57:40.250 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B00077F1C92: Node 9719 added to the network

2019-08-11 14:57:40.253 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00124B0008B2C211: Node 8545 added to the network

2019-08-11 14:57:40.263 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000F8426F3: Node 36916 added to the network

2019-08-11 14:57:40.267 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA00AD4F4A: Node 32511 added to the network

2019-08-11 14:57:40.269 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to UNINITIALISED

2019-08-11 14:57:40.273 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis dongle initialize.

2019-08-11 14:57:40.606 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TelegesisFrameHandler thread started

2019-08-11 14:57:40.679 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:40.686 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=18, bit=4, state=true, password=null]

2019-08-11 14:57:40.716 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS124=1

2019-08-11 14:57:40.831 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:40.892 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=18, bit=4, state=true, password=null, status=SUCCESS]

2019-08-11 14:57:40.896 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:40.897 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=1, state=false, password=null]

2019-08-11 14:57:40.900 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0E1=0

2019-08-11 14:57:41.026 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:41.027 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=1, state=false, password=null, status=SUCCESS]

2019-08-11 14:57:41.037 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:41.045 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=0, state=false, password=null]

2019-08-11 14:57:41.048 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0E0=0

2019-08-11 14:57:41.189 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:41.191 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=0, state=false, password=null, status=SUCCESS]

2019-08-11 14:57:41.194 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:41.197 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSoftwareResetCommand []

2019-08-11 14:57:41.199 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATZ

2019-08-11 14:57:41.597 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:^B^C

2019-08-11 14:57:41.601 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:JPAN:11,4877,C3A5104CC5526D0C

2019-08-11 14:57:41.606 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNetworkJoinedEvent [channel=11, panId=18551, epanId=C3A5104CC5526D0C]

2019-08-11 14:57:41.628 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:41.631 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSoftwareResetCommand [status=SUCCESS]

2019-08-11 14:57:41.634 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:41.635 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=18, bit=4, state=true, password=null]

2019-08-11 14:57:41.637 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS124=1

2019-08-11 14:57:41.752 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:41.755 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=18, bit=4, state=true, password=null, status=SUCCESS]

2019-08-11 14:57:41.757 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:41.758 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=1, state=false, password=null]

2019-08-11 14:57:41.833 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0E1=0

2019-08-11 14:57:41.944 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:41.947 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=1, state=false, password=null, status=SUCCESS]

2019-08-11 14:57:41.949 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:41.950 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=0, state=false, password=null]

2019-08-11 14:57:41.953 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0E0=0

2019-08-11 14:57:42.067 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.069 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=14, bit=0, state=false, password=null, status=SUCCESS]

2019-08-11 14:57:42.075 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.077 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetPromptEnable1Command [configuration=8804]

2019-08-11 14:57:42.080 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0E=8804

2019-08-11 14:57:42.192 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.194 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetPromptEnable1Command [configuration=8804, status=SUCCESS]

2019-08-11 14:57:42.200 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.202 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetMainFunctionCommand [configuration=350, password=password]

2019-08-11 14:57:42.205 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0A=015E:password

2019-08-11 14:57:42.322 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.325 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetMainFunctionCommand [configuration=350, password=password, status=SUCCESS]

2019-08-11 14:57:42.331 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.333 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetExtendedFunctionCommand [configuration=56A9]

2019-08-11 14:57:42.336 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS10=56A9

2019-08-11 14:57:42.450 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.453 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetExtendedFunctionCommand [configuration=56A9, status=SUCCESS]

2019-08-11 14:57:42.457 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.460 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetPromptEnable2Command [configuration=6B3C]

2019-08-11 14:57:42.471 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0F=6B3C

2019-08-11 14:57:42.578 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.582 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetPromptEnable2Command [configuration=6B3C, status=SUCCESS]

2019-08-11 14:57:42.587 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.588 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayProductIdentificationCommand [deviceName=null, firmwareRevision=null, ieeeAddress=null]

2019-08-11 14:57:42.590 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATI

2019-08-11 14:57:42.732 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:Telegesis ETRX357

2019-08-11 14:57:42.736 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:R309C-DTAG build12S

2019-08-11 14:57:42.741 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:000D6F000B2FEDC5

2019-08-11 14:57:42.813 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.818 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayProductIdentificationCommand [deviceName=ETRX357, firmwareRevision=309C-DTAG build12S, ieeeAddress=000D6F000B2FEDC5, status=SUCCESS]

2019-08-11 14:57:42.827 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING

2019-08-11 14:57:42.827 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Setting Telegesis trust centre link mode: TC_JOIN_INSECURE

2019-08-11 14:57:42.833 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.835 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisallowTcJoinCommand [disallowJoin=false, password=password]

2019-08-11 14:57:42.838 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0A5=0:password

2019-08-11 14:57:42.954 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:42.957 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisallowTcJoinCommand [disallowJoin=false, password=password, status=SUCCESS]

2019-08-11 14:57:42.963 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:42.964 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisallowUnsecuredRejoinCommand [disallowRejoin=false, password=password]

2019-08-11 14:57:42.967 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS0A3=0:password

2019-08-11 14:57:43.083 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:43.085 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisallowUnsecuredRejoinCommand [disallowRejoin=false, password=password, status=SUCCESS]

2019-08-11 14:57:43.098 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:43.100 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetOutputClustersCommand [clusterList=[1280]]

2019-08-11 14:57:43.102 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS4C=0500

2019-08-11 14:57:43.216 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:43.219 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetOutputClustersCommand [clusterList=[1280], status=SUCCESS]

2019-08-11 14:57:43.222 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis dongle startup.

2019-08-11 14:57:43.223 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:43.225 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetRegisterBitCommand [register=17, bit=14, state=true, password=null]

2019-08-11 14:57:43.227 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS11E=1

2019-08-11 14:57:43.341 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:43.343 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetRegisterBitCommand [register=17, bit=14, state=true, password=null, status=SUCCESS]

2019-08-11 14:57:43.347 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:43.349 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSetOutputPowerCommand [powerLevel=8]

2019-08-11 14:57:43.351 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS01=8

2019-08-11 14:57:43.465 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:43.467 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSetOutputPowerCommand [powerLevel=8, status=SUCCESS]

2019-08-11 14:57:43.473 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:43.475 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]

2019-08-11 14:57:43.477 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-08-11 14:57:43.610 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,08,4877,C3A5104CC5526D0C

2019-08-11 14:57:43.615 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:43.616 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=8, panId=18551, epanId=C3A5104CC5526D0C, status=SUCCESS]

2019-08-11 14:57:43.626 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:43.628 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisGetChannelMaskCommand [channelMask=NULL]

2019-08-11 14:57:43.630 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:ATS00?

2019-08-11 14:57:43.744 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:0001

2019-08-11 14:57:43.746 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:43.750 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisGetChannelMaskCommand [channelMask=0001, status=SUCCESS]

2019-08-11 14:57:43.755 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis current channel mask: TelegesisGetChannelMaskCommand [channelMask=0001, status=SUCCESS]

2019-08-11 14:57:43.759 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to ONLINE

2019-08-11 14:57:43.762 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Startup

2019-08-11 14:57:43.786 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - Network discovery task: starting

2019-08-11 14:57:43.791 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery scheduling node discovery

2019-08-11 14:57:43.805 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery starting node discovery

2019-08-11 14:57:43.814 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update

2019-08-11 14:57:43.837 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 00124B0008B2C211

2019-08-11 14:57:43.857 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B0008B2C211: Starting ZigBee device discovery

2019-08-11 14:57:43.872 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 84182600000EE4C8

2019-08-11 14:57:43.883 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 84182600000EE4C8: Starting ZigBee device discovery

2019-08-11 14:57:43.906 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000EE4C8: Node SVC Discovery: start discovery

2019-08-11 14:57:43.912 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000EE4C8: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:43.909 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0008B2C211: Node SVC Discovery: start discovery

2019-08-11 14:57:43.916 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0008B2C211: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:43.920 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 00124B00061C1959

2019-08-11 14:57:43.922 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B00061C1959: Starting ZigBee device discovery

2019-08-11 14:57:43.926 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00061C1959: Node SVC Discovery: start discovery

2019-08-11 14:57:43.931 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00061C1959: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:43.940 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 000D6F000F8426F3: Starting ZigBee device discovery

2019-08-11 14:57:43.940 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 000D6F000F8426F3

2019-08-11 14:57:43.949 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000F8426F3: Node SVC Discovery: start discovery

2019-08-11 14:57:43.957 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 000D6F000F8427C3

2019-08-11 14:57:43.959 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 000D6F000F8427C3: Starting ZigBee device discovery

2019-08-11 14:57:43.960 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000F8427C3: Node SVC Discovery: start discovery

2019-08-11 14:57:43.965 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 000D6F000B2FEDC5

2019-08-11 14:57:43.951 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000F8426F3: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:43.968 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000F8427C3: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:43.970 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 84182600000F9F2F

2019-08-11 14:57:44.051 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=0, name=ZoneState, dataType=ENUMERATION_8_BIT, lastValue=0, lastReportTime=Sat Aug 10 09:04:15 CEST 2019]

2019-08-11 14:57:44.051 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=0, name=ZoneState, dataType=ENUMERATION_8_BIT, lastValue=0, lastReportTime=Sat Aug 10 03:06:41 CEST 2019]

2019-08-11 14:57:44.057 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F9F2F: Node SVC Discovery: start discovery

2019-08-11 14:57:44.060 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F9F2F: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.065 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 7CB03EAA0A03D042

2019-08-11 14:57:44.064 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0]

2019-08-11 14:57:44.076 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:44.080 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 8545/1, cluster=0000, TID=02, identifiers=[2]]

2019-08-11 14:57:44.097 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 8545/1, cluster=0500, TID=03, identifiers=[0]]

2019-08-11 14:57:44.115 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=2, commandId=0]

2019-08-11 14:57:44.066 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 45154/1, cluster=0500, TID=01, identifiers=[0]]

2019-08-11 14:57:44.124 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 00124B0004A89AAD

2019-08-11 14:57:44.126 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0004A89AAD: Node SVC Discovery: start discovery

2019-08-11 14:57:44.128 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0004A89AAD: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.130 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 7CB03EAA00ACED53

2019-08-11 14:57:44.124 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=1, commandId=0]

2019-08-11 14:57:44.133 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=45154/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=3, payload=00 01 00 00 00]

2019-08-11 14:57:44.133 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=0, name=ZoneState, dataType=ENUMERATION_8_BIT, lastValue=0, lastReportTime=Sat Aug 10 03:05:05 CEST 2019]

2019-08-11 14:57:44.120 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A03D042: Node SVC Discovery: start discovery

2019-08-11 14:57:44.120 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=0, name=ZoneState, dataType=ENUMERATION_8_BIT, lastValue=1, lastReportTime=Sun Aug 11 14:50:21 CEST 2019]

2019-08-11 14:57:44.139 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A03D042: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 10688/1, cluster=0500, TID=05, identifiers=[0]]

2019-08-11 14:57:44.135 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 9719/1, cluster=0500, TID=04, identifiers=[0]]

2019-08-11 14:57:44.142 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=4, commandId=0]

2019-08-11 14:57:44.142 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=5, commandId=0]

2019-08-11 14:57:44.145 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=9719/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=5, payload=00 04 00 00 00]

2019-08-11 14:57:44.114 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=3, commandId=0]

2019-08-11 14:57:44.117 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=0, name=ZoneState, dataType=ENUMERATION_8_BIT, lastValue=1, lastReportTime=Sat Aug 10 09:03:45 CEST 2019]

2019-08-11 14:57:44.116 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=0, payload=00 00 00 01 00]

2019-08-11 14:57:44.086 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000B2FEDC5: Node SVC Discovery: start discovery

2019-08-11 14:57:44.092 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:44.149 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 36916/1, cluster=0500, TID=06, identifiers=[0]]

2019-08-11 14:57:44.122 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=0, name=ZoneState, dataType=ENUMERATION_8_BIT, lastValue=1, lastReportTime=Sat Aug 10 03:05:02 CEST 2019]

2019-08-11 14:57:44.123 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 00124B00077F1C92

2019-08-11 14:57:44.123 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 7CB03EAA0A013BF3

2019-08-11 14:57:44.125 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=8545/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=2, payload=00 02 00 02 00]

2019-08-11 14:57:44.137 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00ACED53: Node SVC Discovery: start discovery

2019-08-11 14:57:44.193 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00077F1C92: Node SVC Discovery: start discovery

2019-08-11 14:57:44.194 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A013BF3: Node SVC Discovery: start discovery

2019-08-11 14:57:44.196 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A013BF3: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.196 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 04 00 00 00, messageId=null]

2019-08-11 14:57:44.197 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=1, messageData=00 00 00 01 00, messageId=null]

2019-08-11 14:57:44.197 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 01 00 00 00, messageId=null]

2019-08-11 14:57:44.193 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 84182600000F88EE

2019-08-11 14:57:44.199 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:44.199 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=8545, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 02 00 02 00, messageId=null]

2019-08-11 14:57:44.201 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F88EE: Node SVC Discovery: start discovery

2019-08-11 14:57:44.200 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=0, sourceEp=0, destEp=0, profileId=0, clusterId=1, messageData=00 00 00 01 00, messageId=null]

2019-08-11 14:57:44.201 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 59696/1, cluster=0500, TID=07, identifiers=[0]]

2019-08-11 14:57:44.201 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:44.203 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=7, commandId=0]

2019-08-11 14:57:44.203 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 84182600000F88EE: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.206 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 2

2019-08-11 14:57:44.200 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B00077F1C92: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.204 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=6, commandId=0]

2019-08-11 14:57:44.208 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 45154/1, cluster=0000, TID=08, identifiers=[2]]

2019-08-11 14:57:44.209 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=36916/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=6, payload=00 06 00 00 00]

2019-08-11 14:57:44.210 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=59696/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=7, payload=00 07 00 00 00]

2019-08-11 14:57:44.211 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=36916, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 06 00 00 00, messageId=null]

2019-08-11 14:57:44.210 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=8, commandId=0]

2019-08-11 14:57:44.211 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=59696, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 07 00 00 00, messageId=null]

2019-08-11 14:57:44.213 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 3

2019-08-11 14:57:44.208 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00ACED53: Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS]

2019-08-11 14:57:44.216 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 7CB03EAA0A01C6C8

2019-08-11 14:57:44.221 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 00124B0008DAC9FC

chris · August 11, 2019, 1:35pm

The log is too short to show any of the network traffic - it only shows the coordinator initialisation.

I’m not really expecting any change from the previous log though, and I’m probably not going to be able to provide a lot of help. All I can tell from the previous log is that the dongle was unable to communicate with the devices even though it was online and has a valid network.

WeRo · August 11, 2019, 1:44pm

seems like the problem starts here:

2019-08-11 14:57:47.497 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ERROR:72

2019-08-11 14:57:47.499 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=8545, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 10 00 02 00, messageId=null, status=TOO_MANY_UNICAST]

2019-08-11 14:57:47.871 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 10688: NWK Discovery scheduling node discovery

2019-08-11 14:57:47.873 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery ending node discovery

2019-08-11 14:57:47.876 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00ACED53: Node SVC Discovery: running

2019-08-11 14:57:47.892 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=11, ieeeAddr=7CB03EAA00ACED53, requestType=0, startIndex=0]

2019-08-11 14:57:47.895 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=17, payload=00 53 ED AC 00 AA 3E B0 $

2019-08-11 14:57:47.898 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65535, sourceEp=0, destEp=0, profileId=0, clusterId=0, messageData=00 53 ED AC 00 AA 3E B0 7C 00 00]

2019-08-11 14:57:47.900 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:47.902 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65535, sourceEp=0, destEp=0, profileId=0, clusterId=0, messageData=00 53 ED AC 00 AA 3E B0 7C 00 00]

2019-08-11 14:57:47.906 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDMCASTB:0B,1F,FFFF,00,00,0000,0000^M^@Sí¬^@ª>°|^@^@

2019-08-11 14:57:48.038 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:48.040 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendMulticastCommand [radius=31, address=65535, sourceEp=0, destEp=0, profileId=0, clusterId=0, messageData=00 53 ED AC 00 AA 3E B0 7C 00 00, status=SUCCESS]

2019-08-11 14:57:48.153 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:48.156 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 9719/1, cluster=0000, TID=12, identifiers=[2]]

2019-08-11 14:57:48.159 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=18, commandId=0]

2019-08-11 14:57:48.161 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=9719/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=18, payload=00 12 00 02 00]

2019-08-11 14:57:48.163 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 12 00 02 00, messageId=null]

2019-08-11 14:57:48.165 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:48.167 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 12 00 02 00, messageId=null]

2019-08-11 14:57:48.171 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,25F7,00,01,0104,0000^M^@^R^@^B^@

2019-08-11 14:57:48.303 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ERROR:72

2019-08-11 14:57:48.305 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 12 00 02 00, messageId=null, status=TOO_MANY_UNICAST]

2019-08-11 14:57:48.669 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:48.677 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 45154/1, cluster=0000, TID=13, identifiers=[2]]

2019-08-11 14:57:48.679 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=19, commandId=0]

2019-08-11 14:57:48.682 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=45154/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=19, payload=00 13 00 02 00]

2019-08-11 14:57:48.686 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 13 00 02 00, messageId=null]

2019-08-11 14:57:48.689 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:48.691 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 13 00 02 00, messageId=null]

2019-08-11 14:57:48.695 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,B062,00,01,0104,0000^M^@^S^@^B^@

2019-08-11 14:57:48.775 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 84182600000F9F2F: Starting ZigBee device discovery

2019-08-11 14:57:48.831 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:RX:29C0,0104,00,01,0500,08:^H^E^A^@^@^@0^A,-67,FF

2019-08-11 14:57:48.834 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisReceiveMessageEvent [ieeeAddress=null, networkAddress=10688, profileId=260, destinationEp=0, sourceEp=1, clusterId=1280, messageData=08 05 01 00 00 00 30 01, rssi=-103, l$

2019-08-11 14:57:48.836 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=10688/1, destinationAddress=0/0, profile=0104, cluster=1280, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=08 05 01 00 00 00 30 01]

2019-08-11 14:57:48.838 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=5, commandId=1]

2019-08-11 14:57:48.951 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=ELECTRICAL_MEASUREMENT, id=1285, name=RMSVoltage, dataType=UNSIGNED_16_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:48.954 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Electrical Measurement: 0/0 -> 56546/3, cluster=0B04, TID=14, identifiers=[1285]]

2019-08-11 14:57:48.957 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=20, commandId=0]

2019-08-11 14:57:48.968 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=56546/3, profile=0104, cluster=2820, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=20, payload=00 14 00 05 05]

2019-08-11 14:57:48.970 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=56546, sourceEp=0, destEp=3, profileId=260, clusterId=2820, messageData=00 14 00 05 05, messageId=null]

2019-08-11 14:57:48.973 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:49.053 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReadAttributesResponse [IAS Zone: 10688/1 -> 0/0, cluster=0500, TID=05, records=[ReadAttributeStatusRecord [attributeDataType=ENUMERATION_8_BIT, attributeIdentifier=0, status=SUCCESS, a$

2019-08-11 14:57:49.060 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ReadAttributesCommand [IAS Zone: 0/0 -> 10688/1, cluster=0500, TID=05, identifiers=[0]]

2019-08-11 14:57:49.094 [DEBUG] [igbee.app.iasclient.ZclIasZoneClient] - 10688/1: IAS CIE state is currently ENROLLED[1]

2019-08-11 14:57:49.097 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sun Aug 11 14:50:22 CEST 2019]

2019-08-11 14:57:49.107 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ACK:9E

2019-08-11 14:57:49.109 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisAckMessageEvent [messageId=158]

2019-08-11 14:57:49.110 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisAckMessageEvent [messageId=158]

2019-08-11 14:57:49.113 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:A8

2019-08-11 14:57:49.115 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:49.116 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 13 00 02 00, messageId=168, status=SUCCESS]

2019-08-11 14:57:49.111 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 10688/1, cluster=0500, TID=15, identifiers=[16]]

2019-08-11 14:57:49.118 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=21, commandId=0]

2019-08-11 14:57:49.130 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=56546, sourceEp=0, destEp=3, profileId=260, clusterId=2820, messageData=00 14 00 05 05, messageId=null]

2019-08-11 14:57:49.133 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=10688/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=21, payload=00 15 00 10 00]

2019-08-11 14:57:49.135 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=10688, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 15 00 10 00, messageId=null]

2019-08-11 14:57:49.137 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:49.140 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,DCE2,00,03,0104,0B04^M^@^T^@^E^E

2019-08-11 14:57:49.271 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:95

2019-08-11 14:57:49.274 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=149]

2019-08-11 14:57:49.275 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=149]

2019-08-11 14:57:49.278 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:A9

2019-08-11 14:57:49.280 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:49.282 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=56546, sourceEp=0, destEp=3, profileId=260, clusterId=2820, messageData=00 14 00 05 05, messageId=169, status=SUCCESS]

2019-08-11 14:57:49.284 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=10688, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 15 00 10 00, messageId=null]

2019-08-11 14:57:49.287 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,29C0,00,01,0104,0500^M^@^U^@^P^@

2019-08-11 14:57:49.307 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: BindRequest [0/0 -> 36393/3, cluster=0021, TID=16, srcAddress=84182600000F88EE, srcEndpoint=3, bindCluster=8, dstAddrMode=3, dstAddress=000D6F000B2FEDC5, dstEndpoint=1]

2019-08-11 14:57:49.310 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=36393/0, profile=0000, cluster=33, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=22, payload=00 EE 88 0F 00 00 26 18$

2019-08-11 14:57:49.313 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=0, profileId=0, clusterId=33, messageData=00 EE 88 0F 00 00 26 18 84 03 08 00 03 C5 ED 2F 0B 00 6F 0D 00 01, messa$

2019-08-11 14:57:49.315 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:49.419 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ERROR:72

2019-08-11 14:57:49.421 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=10688, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 15 00 10 00, messageId=null, status=TOO_MANY_UNICAST]

2019-08-11 14:57:49.423 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=0, profileId=0, clusterId=33, messageData=00 EE 88 0F 00 00 26 18 84 03 08 00 03 C5 ED 2F 0B 00 6F 0D 00 01, message$

2019-08-11 14:57:49.427 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:16,8E29,00,00,0000,0021^M^@î^h^O^@^@&^X^d^C^H^@^CÅí/^K^@o^M^@^A

2019-08-11 14:57:49.560 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B0004A89AAD: Starting ZigBee device discovery

2019-08-11 14:57:49.563 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:49.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 59696/1, cluster=0000, TID=17, identifiers=[2]]

2019-08-11 14:57:49.566 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=23, commandId=0]

2019-08-11 14:57:49.567 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:ERROR:72

2019-08-11 14:57:49.568 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=59696/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=23, payload=00 17 00 02 00]

2019-08-11 14:57:49.570 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=36393, sourceEp=0, destEp=0, profileId=0, clusterId=33, messageData=00 EE 88 0F 00 00 26 18 84 03 08 00 03 C5 ED 2F 0B 00 6F 0D 00 01, message$

2019-08-11 14:57:49.570 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=59696, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 17 00 02 00, messageId=null]

2019-08-11 14:57:49.571 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:49.572 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=59696, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 17 00 02 00, messageId=null]

2019-08-11 14:57:49.576 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,E930,00,01,0104,0000^M^@^W^@^B^@

2019-08-11 14:57:49.709 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:96

2019-08-11 14:57:49.711 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=150]

2019-08-11 14:57:49.712 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=150]

2019-08-11 14:57:49.714 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:AC

2019-08-11 14:57:49.716 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:49.718 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=59696, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 17 00 02 00, messageId=172, status=SUCCESS]

2019-08-11 14:57:49.859 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:97

2019-08-11 14:57:49.861 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=151]

2019-08-11 14:57:49.862 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=151]

2019-08-11 14:57:50.111 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:98

2019-08-11 14:57:50.113 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=152]

2019-08-11 14:57:50.114 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=152]

2019-08-11 14:57:50.253 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:99

2019-08-11 14:57:50.255 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=153]

2019-08-11 14:57:50.256 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=153]

2019-08-11 14:57:50.303 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B00077F1C92: Starting ZigBee device discovery

2019-08-11 14:57:50.306 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:50.308 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 9719/1, cluster=0000, TID=18, identifiers=[2]]

2019-08-11 14:57:50.310 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=24, commandId=0]

2019-08-11 14:57:50.311 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=9719/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=24, payload=00 18 00 02 00]

2019-08-11 14:57:50.313 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 18 00 02 00, messageId=null]

2019-08-11 14:57:50.314 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:50.316 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 18 00 02 00, messageId=null]

2019-08-11 14:57:50.320 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,25F7,00,01,0104,0000^M^@^X^@^B^@

2019-08-11 14:57:50.542 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:9A

2019-08-11 14:57:50.544 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=154]

2019-08-11 14:57:50.546 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=154]

2019-08-11 14:57:50.548 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:AD

2019-08-11 14:57:50.550 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:50.551 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 18 00 02 00, messageId=173, status=SUCCESS]

2019-08-11 14:57:50.554 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:9B

2019-08-11 14:57:50.556 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=155]

2019-08-11 14:57:50.558 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=155]

2019-08-11 14:57:50.698 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:9C

2019-08-11 14:57:50.699 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=156]

2019-08-11 14:57:50.701 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=156]

2019-08-11 14:57:50.844 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:9D

2019-08-11 14:57:50.846 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=157]

2019-08-11 14:57:50.847 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=157]

2019-08-11 14:57:50.905 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA00ACED53: Starting ZigBee device discovery

2019-08-11 14:57:51.504 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA0A013BF3: Starting ZigBee device discovery

2019-08-11 14:57:51.849 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:51.851 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisDisplayNetworkInformationCommand [device=null, channel=null, power=null, panId=null, epanId=null]

2019-08-11 14:57:51.853 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+N?

2019-08-11 14:57:51.987 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:+N=COO,11,08,4877,C3A5104CC5526D0C

2019-08-11 14:57:51.990 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:51.991 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisDisplayNetworkInformationCommand [device=COO, channel=11, power=8, panId=18551, epanId=C3A5104CC5526D0C, status=SUCCESS]

2019-08-11 14:57:52.078 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 7CB03EAA00AFA81B: Starting ZigBee device discovery

2019-08-11 14:57:52.707 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00124B0008DAC9FC: Starting ZigBee device discovery

2019-08-11 14:57:52.710 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=BASIC, id=2, name=StackVersion, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=null]

2019-08-11 14:57:52.712 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [Basic: 0/0 -> 59165/1, cluster=0000, TID=19, identifiers=[2]]

2019-08-11 14:57:52.713 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=25, commandId=0]

2019-08-11 14:57:52.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=59165/1, profile=0104, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=25, payload=00 19 00 02 00]

2019-08-11 14:57:52.717 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=59165, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 19 00 02 00, messageId=null]

2019-08-11 14:57:52.719 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:52.720 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=59165, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 19 00 02 00, messageId=null]

2019-08-11 14:57:52.725 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,E71D,00,01,0104,0000^M^@^Y^@^B^@

2019-08-11 14:57:52.858 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:AE

2019-08-11 14:57:52.861 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:52.862 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=59165, sourceEp=0, destEp=1, profileId=260, clusterId=0, messageData=00 19 00 02 00, messageId=174, status=SUCCESS]

2019-08-11 14:57:53.515 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:A8

2019-08-11 14:57:53.517 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=168]

2019-08-11 14:57:53.518 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=168]

2019-08-11 14:57:53.956 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:A9

2019-08-11 14:57:53.958 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=169]

2019-08-11 14:57:53.959 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=169]

2019-08-11 14:57:54.254 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Aug 10 09:02:14 CEST 2019]

2019-08-11 14:57:54.254 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Aug 10 03:05:01 CEST 2019]

2019-08-11 14:57:54.254 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Aug 10 03:05:08 CEST 2019]

2019-08-11 14:57:54.256 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 45154/1, cluster=0500, TID=1A, identifiers=[16]]

2019-08-11 14:57:54.257 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 36916/1, cluster=0500, TID=1B, identifiers=[16]]

2019-08-11 14:57:54.258 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=27, commandId=0]

2019-08-11 14:57:54.258 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=26, commandId=0]

2019-08-11 14:57:54.259 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 9719/1, cluster=0500, TID=1C, identifiers=[16]]

2019-08-11 14:57:54.261 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=28, commandId=0]

2019-08-11 14:57:54.261 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=36916/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=27, payload=00 1B 00 10 00]

2019-08-11 14:57:54.258 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Aug 10 03:06:42 CEST 2019]

2019-08-11 14:57:54.265 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=36916, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1B 00 10 00, messageId=null]

2019-08-11 14:57:54.265 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 8545/1, cluster=0500, TID=1D, identifiers=[16]]

2019-08-11 14:57:54.266 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=45154/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=26, payload=00 1A 00 10 00]

2019-08-11 14:57:54.267 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=29, commandId=0]

2019-08-11 14:57:54.268 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1A 00 10 00, messageId=null]

2019-08-11 14:57:54.268 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=8545/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=29, payload=00 1D 00 10 00]

2019-08-11 14:57:54.269 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 2

2019-08-11 14:57:54.270 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=8545, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1D 00 10 00, messageId=null]

2019-08-11 14:57:54.270 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=36916, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1B 00 10 00, messageId=null]

2019-08-11 14:57:54.271 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 2

2019-08-11 14:57:54.262 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=9719/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=28, payload=00 1C 00 10 00]

2019-08-11 14:57:54.267 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 1

2019-08-11 14:57:54.273 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=9719, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1C 00 10 00, messageId=null]

2019-08-11 14:57:54.276 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 3

2019-08-11 14:57:54.273 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,9034,00,01,0104,0500^M^@^[^@^P^@

2019-08-11 14:57:54.284 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Jul 20 03:42:09 CEST 2019]

2019-08-11 14:57:54.286 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 59165/1, cluster=0500, TID=1E, identifiers=[16]]

2019-08-11 14:57:54.287 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=30, commandId=0]

2019-08-11 14:57:54.288 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=59165/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=30, payload=00 1E 00 10 00]

2019-08-11 14:57:54.290 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=59165, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1E 00 10 00, messageId=null]

2019-08-11 14:57:54.291 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 4

2019-08-11 14:57:54.298 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Aug 10 09:02:09 CEST 2019]

2019-08-11 14:57:54.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 16103/1, cluster=0500, TID=1F, identifiers=[16]]

2019-08-11 14:57:54.300 [DEBUG] [.zsmartsystems.zigbee.zcl.ZclCluster] - readSync request: ZclAttribute [cluster=IAS_ZONE, id=16, name=IASCIEAddress, dataType=IEEE_ADDRESS, lastValue=000D6F000B2FEDC5, lastReportTime=Sat Aug 10 09:02:18 CEST 2019]

2019-08-11 14:57:54.301 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=31, commandId=0]

2019-08-11 14:57:54.301 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ReadAttributesCommand [IAS Zone: 0/0 -> 59696/1, cluster=0500, TID=20, identifiers=[16]]

2019-08-11 14:57:54.302 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=16103/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=31, payload=00 1F 00 10 00]

2019-08-11 14:57:54.304 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=16103, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1F 00 10 00, messageId=null]

2019-08-11 14:57:54.303 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=32, commandId=0]

2019-08-11 14:57:54.305 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 5

2019-08-11 14:57:54.307 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=59696/1, profile=0104, cluster=1280, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=32, payload=00 20 00 10 00]

2019-08-11 14:57:54.309 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendUnicastCommand [address=59696, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 20 00 10 00, messageId=null]

2019-08-11 14:57:54.312 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 6

2019-08-11 14:57:54.390 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 36916: Node SVC Discovery: NetworkAddressRequest returned null

2019-08-11 14:57:54.392 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000F8426F3: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2281ms before retry.

2019-08-11 14:57:54.393 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B00077EC86F: NWK Discovery starting node rediscovery

2019-08-11 14:57:54.396 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=21, ieeeAddr=00124B00077EC86F, requestType=0, startIndex=0]

2019-08-11 14:57:54.399 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 59696: Node SVC Discovery: NetworkAddressRequest returned null

2019-08-11 14:57:54.400 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0004A89AAD: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2111ms before retry.

2019-08-11 14:57:54.402 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 7CB03EAA0A03D042: NWK Discovery starting node rediscovery

2019-08-11 14:57:54.403 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=22, ieeeAddr=7CB03EAA0A03D042, requestType=0, startIndex=0]

2019-08-11 14:57:54.405 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=34, payload=00 42 D0 03 0A AA 3E B0 $

2019-08-11 14:57:54.407 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65533, sourceEp=0, destEp=0, profileId=0, clusterId=0, messageData=00 42 D0 03 0A AA 3E B0 7C 00 00]

2019-08-11 14:57:54.407 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:NACK:AC

2019-08-11 14:57:54.398 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=33, payload=00 6F C8 7E 07 00 4B 12 $

2019-08-11 14:57:54.409 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisNackMessageEvent [messageId=172]

2019-08-11 14:57:54.409 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65533, sourceEp=0, destEp=0, profileId=0, clusterId=0, messageData=00 6F C8 7E 07 00 4B 12 00 00 00]

2019-08-11 14:57:54.410 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Unhandled Telegesis Frame: TelegesisNackMessageEvent [messageId=172]

2019-08-11 14:57:54.408 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 7

2019-08-11 14:57:54.412 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:AF

2019-08-11 14:57:54.411 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 8

2019-08-11 14:57:54.413 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:54.414 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=36916, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1B 00 10 00, messageId=175, status=SUCCESS]

2019-08-11 14:57:54.416 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1A 00 10 00, messageId=null]

2019-08-11 14:57:54.419 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis Data:AT+SENDUCASTB:05,B062,00,01,0104,0500^M^@^Z^@^P^@

2019-08-11 14:57:54.517 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 59165: Node SVC Discovery: NetworkAddressRequest returned null

2019-08-11 14:57:54.518 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 00124B0008DAC9FC: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2318ms before retry.

2019-08-11 14:57:54.519 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 7CB03EAA0A013BF3: NWK Discovery starting node rediscovery

2019-08-11 14:57:54.521 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=23, ieeeAddr=7CB03EAA0A013BF3, requestType=0, startIndex=0]

2019-08-11 14:57:54.522 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=35, payload=00 F3 3B 01 0A AA 3E B0 $

2019-08-11 14:57:54.524 [DEBUG] [ngle.telegesis.ZigBeeDongleTelegesis] - Telegesis send: TelegesisSendMulticastCommand [radius=31, address=65533, sourceEp=0, destEp=0, profileId=0, clusterId=0, messageData=00 F3 3B 01 0A AA 3E B0 7C 00 00]

2019-08-11 14:57:54.525 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis queue: 8

2019-08-11 14:57:54.552 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null

2019-08-11 14:57:54.554 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:SEQ:B0

2019-08-11 14:57:54.554 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000B2FEDC5: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2182ms before retry.

2019-08-11 14:57:54.556 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis Data:OK

2019-08-11 14:57:54.557 [DEBUG] [gesis.internal.TelegesisFrameHandler] - RX Telegesis: TelegesisSendUnicastCommand [address=45154, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1A 00 10 00, messageId=176, status=SUCCESS]

2019-08-11 14:57:54.557 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 00124B0008B2C211: NWK Discovery starting node rediscovery

2019-08-11 14:57:54.558 [DEBUG] [gesis.internal.TelegesisFrameHandler] - TX Telegesis: TelegesisSendUnicastCommand [address=8545, sourceEp=0, destEp=1, profileId=260, clusterId=1280, messageData=00 1D 00 10 00, messageId=null]

2019-08-11 14:57:54.561 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 60164: Node SVC Discovery: NetworkAddressRequest returned null

2019-08-11 14:57:54.561 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=24, ieeeAddr=00124B0008B2C211, requestType=0, startIndex=0]

2019-08-11 14:57:54.562 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA00AD0AC2: Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2239ms before retry.

2019-08-11 14:57:54.564 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 84182600000F88EE: NWK Discovery starting node rediscovery

2019-08-11 14:57:54.565 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=36, payload=00 11 C2 B2 08 00 4B 12 $

2019-08-11 14:57:54.566 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=25, ieeeAddr=84182600000F88EE, requestType=0, startIndex=0]

chris · August 11, 2019, 1:53pm

Please can you confirm what version of the binding you are now using? Have you upgraded yet?

I don’t really see any significant problem - I can only repeat what I have already said. Some devices are not responding on the network (some are in this log though). I can’t tell why that is - all I can tell is that the controller reports that it isn’t getting a response.

The error 72 you see here should be resolved if you are using the latest binding - the one you are using is very old. This error just means that the controller is trying to send a lot of messages at the same time - the newer bindings from earlier this year have improved transaction management that will resolve this. As above - I recommend to upgrade.

WeRo · August 11, 2019, 1:56pm

where do I find the latest version of the binding?