log files below shown.
Initialising ZigBee console...
10:46:37.776 DEBUG Adding supported cluster 1280
10:46:37.786 DEBUG ClusterMatcher starting
10:46:37.957 DEBUG ClusterMatcher adding cluster IAS_ZONE
10:46:37.958 DEBUG Adding supported cluster 25
10:46:37.960 DEBUG ClusterMatcher adding cluster OTA_UPGRADE
10:46:38.074 DEBUG CC2531 transport initialize
ZigBee network state updated to UNINITIALISED
10:46:38.080 DEBUG Opening port COM7 at 115200 baud with FLOWCONTROL_OUT_XONOFF.
10:46:38.110 DEBUG -> SYS_RESET (Packet: subsystem=null, length=1, apiId=41 00, data=FE 01 41 00 01 41, checksum=41, error=false)
10:46:38.570 DEBUG <-- SYS_RESET_RESPONSE (FE 06 41 80 00 02 00 02 07 00 C0)
10:46:38.570 DEBUG Received Async Cmd: Packet: subsystem=null, length=6, apiId=41 80, data=FE 06 41 80 00 02 00 02 07 00 C0, checksum=C0, error=false
10:46:38.578 DEBUG -> SYS_VERSION (Packet: subsystem=null, length=0, apiId=21 02, data=FE 00 21 02 23, checksum=23, error=false)
10:46:38.581 DEBUG <- SYS_VERSION_RESPONSE (FE 05 61 02 02 00 02 07 00 61)
10:46:38.581 DEBUG CC2531 version is Software=2.7 Product=0 Hardware=0 Transport=2
ZigBee network state updated to INITIALISING
10:46:38.586 INFO Loading network state...
10:46:39.178 DEBUG 063A490C00124B00: Node 0 added to the network
10:46:39.182 INFO Loading network state complete.
10:46:39.182 DEBUG Network discovery task starting
10:46:39.182 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 06 27, checksum=27, error=false)
10:46:39.184 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 06 FE FF 00 9C 01 FF FF 10 E3)
PAN ID = -2
10:46:39.186 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 07 26, checksum=26, error=false)
10:46:39.188 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 07 21 43 65 87 09 00 00 00 E7)
Extended PAN ID = 0000000987654321
10:46:39.191 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 05 24, checksum=24, error=false)
10:46:39.191 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 05 00 43 65 87 09 00 00 00 C4)
Channel = CHANNEL_00
*** Resetting network
* Channel = 11
* PAN ID = 8192
* Extended PAN ID = 0000000987654321
* Link Key = 5A6967426565416C6C69616E63653039
* Network Key = AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
10:46:39.201 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=6, apiId=26 05, data=FE 06 26 05 84 04 00 08 00 00 AD, checksum=AD, error=false)
10:46:39.201 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.206 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=4, apiId=26 05, data=FE 04 26 05 83 02 00 20 86, checksum=86, error=false)
10:46:39.208 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.208 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=10, apiId=26 05, data=FE 0A 26 05 2D 08 21 43 65 87 09 00 00 00 85, checksum=85, error=false)
10:46:39.208 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.215 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=18, apiId=26 05, data=FE 12 26 05 62 10 AA 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 E9, checksum=E9, error=false)
10:46:39.219 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.219 DEBUG Unsupported configuration option "TRUST_CENTRE_LINK_KEY" in Telegesis dongle
10:46:39.219 DEBUG CC2531 transport startup
10:46:39.219 DEBUG Resetting network stack.
10:46:39.219 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=3, apiId=26 05, data=FE 03 26 05 03 01 03 21, checksum=21, error=false)
10:46:39.227 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.229 DEBUG Changing the Network Mode to Coordinator.
10:46:39.229 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=3, apiId=26 05, data=FE 03 26 05 87 01 00 A6, checksum=A6, error=false)
10:46:39.229 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.229 DEBUG Resetting CC2531 dongle.
10:46:39.229 DEBUG -> SYS_RESET (Packet: subsystem=null, length=1, apiId=41 00, data=FE 01 41 00 01 41, checksum=41, error=false)
10:46:39.576 DEBUG <-- SYS_RESET_RESPONSE (FE 06 41 80 00 02 00 02 07 00 C0)
10:46:39.586 DEBUG Received Async Cmd: Packet: subsystem=null, length=6, apiId=41 80, data=FE 06 41 80 00 02 00 02 07 00 C0, checksum=C0, error=false
10:46:39.586 DEBUG Setting channel to 11.
10:46:39.586 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=6, apiId=26 05, data=FE 06 26 05 84 04 00 08 00 00 AD, checksum=AD, error=false)
10:46:39.590 DEBUG Unhandled ZToolPacket type 0x4180
10:46:39.590 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.590 DEBUG Setting PAN to 2000.
10:46:39.590 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=4, apiId=26 05, data=FE 04 26 05 83 02 00 20 86, checksum=86, error=false)
10:46:39.597 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.600 DEBUG Setting Extended PAN ID to 0000000987654321.
10:46:39.600 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=10, apiId=26 05, data=FE 0A 26 05 2D 08 21 43 65 87 09 00 00 00 85, checksum=85, error=false)
10:46:39.600 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.600 DEBUG Setting NETWORK_KEY.
10:46:39.606 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=18, apiId=26 05, data=FE 12 26 05 62 10 AA 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 E9, checksum=E9, error=false)
10:46:39.610 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.610 DEBUG Setting Distribute Network Key to true.
10:46:39.610 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=3, apiId=26 05, data=FE 03 26 05 63 01 00 42, checksum=42, error=false)
10:46:39.616 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.616 DEBUG Setting Security Mode to 1.
10:46:39.616 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=3, apiId=26 05, data=FE 03 26 05 64 01 01 44, checksum=44, error=false)
10:46:39.620 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.620 DEBUG Creating network as Coordinator
10:46:39.620 DEBUG -> ZDO_MSG_CB_REGISTER (Packet: subsystem=null, length=2, apiId=25 3E, data=FE 02 25 3E FF FF 19, checksum=19, error=false)
10:46:39.620 DEBUG <- ZDO_MSG_CB_REGISTER_SRSP (FE 01 65 3E 00 5A)
10:46:39.620 DEBUG -> ZB_WRITE_CONFIGURATION (Packet: subsystem=null, length=3, apiId=26 05, data=FE 03 26 05 8F 01 01 AF, checksum=AF, error=false)
10:46:39.626 DEBUG <- ZB_WRITE_CONFIGURATION_RSP (FE 01 66 05 00 62)
10:46:39.626 DEBUG -> ZDO_STARTUP_FROM_APP (Packet: subsystem=null, length=2, apiId=25 40, data=FE 02 25 40 00 00 67, checksum=67, error=false)
10:46:39.776 DEBUG <- ZDO_STARTUP_FROM_APP_SRSP (FE 01 65 40 01 25)
10:46:39.776 INFO Initialized ZigBee network with new or reset network state.
10:46:40.047 DEBUG <-- ZDO_STATE_CHANGE_IND (FE 01 45 C0 08 8C)
10:46:40.047 DEBUG Received Async Cmd: ZDO_STATE_CHANGE_IND{State=DEV_COORD_STARTING}
10:46:40.047 DEBUG Unhandled ZToolPacket type 0x45c0
10:46:40.308 DEBUG <-- ZDO_STATE_CHANGE_IND (FE 01 45 C0 08 8C)
10:46:40.308 DEBUG Received Async Cmd: ZDO_STATE_CHANGE_IND{State=DEV_COORD_STARTING}
10:46:40.311 DEBUG Unhandled ZToolPacket type 0x45c0
10:46:40.567 DEBUG <-- ZDO_STATE_CHANGE_IND (FE 01 45 C0 08 8C)
10:46:40.567 DEBUG Received Async Cmd: ZDO_STATE_CHANGE_IND{State=DEV_COORD_STARTING}
10:46:40.567 DEBUG Unhandled ZToolPacket type 0x45c0
10:46:40.826 DEBUG <-- ZDO_STATE_CHANGE_IND (FE 01 45 C0 08 8C)
10:46:40.826 DEBUG Received Async Cmd: ZDO_STATE_CHANGE_IND{State=DEV_COORD_STARTING}
10:46:40.826 DEBUG Unhandled ZToolPacket type 0x45c0
10:46:41.357 DEBUG <-- ZDO_STATE_CHANGE_IND (FE 01 45 C0 09 8D)
10:46:41.357 DEBUG Received Async Cmd: ZDO_STATE_CHANGE_IND{State=DEV_COORD_STARTED}
10:46:41.360 DEBUG Started as ZigBee Coordinator
10:46:41.360 DEBUG Unhandled ZToolPacket type 0x45c0
10:46:41.387 DEBUG -> AF_REGISTER (Packet: subsystem=null, length=9, apiId=24 00, data=FE 09 24 00 01 04 01 00 00 00 00 00 00 29, checksum=29, error=false)
10:46:41.387 DEBUG <- AF_REGISTER_SRSP (FE 01 64 00 00 65)
10:46:41.387 DEBUG Registered endpoint 1 with profile: 260
ZigBee network state updated to ONLINE
10:46:41.392 DEBUG 0: NWK Discovery scheduling node discovery
Node Added ZigBeeNode [IEEE=063A490C00124B00, NWK=0000, Type=UNKNOWN]
10:46:41.400 DEBUG 063A490C00124B00: Node SVC Discovery scheduled [NEIGHBORS, NODE_DESCRIPTOR, POWER_DESCRIPTOR, NWK_ADDRESS]
ZigBee console starting up ... [OK]
10:46:41.420 DEBUG 0: NWK Discovery starting node discovery
10:46:41.420 DEBUG Starting mesh update task with interval of 60 seconds
10:46:41.425 DEBUG Adding supported cluster 1280
10:46:41.425 DEBUG ClusterMatcher adding cluster IAS_ZONE
ZigBee API starting up...
ZigBee console ready.
10:46:41.425 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 06 27, checksum=27, error=false)
10:46:41.429 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 06 00 20 00 02 00 FF 20 D1 43)
PAN ID = 8192
10:46:41.433 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 07 26, checksum=26, error=false)
10:46:41.437 DEBUG 063A490C00124B00: Node SVC Discovery already scheduled or running
10:46:41.445 DEBUG TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0]
10:46:41.466 DEBUG 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]
10:46:42.437 DEBUG ZB_GET_DEVICE_INFO executed and timed out while waiting for response.
10:46:42.439 DEBUG Failed to send ZB_GET_DEVICE_INFO [attempt 1]
10:46:43.442 DEBUG -> AF_DATA_REQUEST (Packet: subsystem=null, length=15, apiId=24 01, data=FE 0F 24 01 00 00 00 00 01 00 00 30 1F 05 00 00 00 01 00 00, checksum=00, error=false)
10:46:43.442 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 07 26, checksum=26, error=false)
10:46:43.445 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 07 00 4B 12 00 0C 49 3A 06 4E)
10:46:43.445 DEBUG <- AF_DATA_SRSP (FE 01 64 01 00 64)
Extended PAN ID = 063A490C00124B00
10:46:43.477 DEBUG <-- ZToolPacket (FE 0D 45 81 00 00 4B 12 00 0C 49 3A 06 00 00 FF 00 16)
10:46:43.477 DEBUG Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 81, data=FE 0D 45 81 00 00 4B 12 00 0C 49 3A 06 00 00 FF 00 16, checksum=16, error=false
10:46:43.576 DEBUG 063A490C00124B00: Node SVC Discovery running
10:46:43.576 DEBUG TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=01, startIndex=0]
10:46:43.576 DEBUG TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=1, payload=00 00]
10:46:43.599 DEBUG RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32769, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 4B 12 00 0C 49 3A 06 00 00 00 FF]
10:46:43.610 DEBUG RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=063A490C00124B00, nwkAddrRemoteDev=0, startIndex=255, nwkAddrAssocDevList=[]]
10:46:43.610 DEBUG <-- ZToolPacket (FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 00 4B 12 00 0C 49 3A 06 00 00 00 0E)
10:46:43.616 DEBUG Received Async Cmd: Packet: subsystem=null, length=21, apiId=45 FF, data=FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 00 4B 12 00 0C 49 3A 06 00 00 00 0E, checksum=0E, error=false
10:46:43.620 DEBUG RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32769, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 4B 12 00 0C 49 3A 06 00 00 00]
10:46:43.620 DEBUG RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=063A490C00124B00, nwkAddrRemoteDev=0, startIndex=null, nwkAddrAssocDevList=[]]
10:46:43.620 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 07 00 4B 12 00 0C 49 3A 06 4E)
10:46:44.445 DEBUG AF_DATA_REQUEST executed and timed out while waiting for response.
10:46:44.445 DEBUG Failed to send AF_DATA_REQUEST [attempt 1]
10:46:44.446 DEBUG -> AF_DATA_REQUEST (Packet: subsystem=null, length=15, apiId=24 01, data=FE 0F 24 01 00 00 00 00 01 00 00 30 1F 05 00 00 00 01 00 00, checksum=00, error=false)
10:46:44.448 DEBUG <- AF_DATA_SRSP (FE 01 64 01 00 64)
10:46:44.452 DEBUG -> AF_DATA_REQUEST (Packet: subsystem=null, length=12, apiId=24 01, data=FE 0C 24 01 00 00 00 00 31 00 01 30 1F 02 00 00 34, checksum=34, error=false)
10:46:44.452 DEBUG Transaction complete: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0]
10:46:44.452 DEBUG <-- ZToolPacket (FE 0D 45 81 00 00 4B 12 00 0C 49 3A 06 00 00 64 00 8D)
10:46:44.452 DEBUG Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 81, data=FE 0D 45 81 00 00 4B 12 00 0C 49 3A 06 00 00 64 00 8D, checksum=8D, error=false
10:46:44.456 DEBUG RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32769, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 4B 12 00 0C 49 3A 06 00 00 00 64]
10:46:44.460 DEBUG RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=063A490C00124B00, nwkAddrRemoteDev=0, startIndex=100, nwkAddrAssocDevList=[]]
10:46:44.460 DEBUG 0: NWK Discovery IeeeAddressRequest returned IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=063A490C00124B00, nwkAddrRemoteDev=0, startIndex=null, nwkAddrAssocDevList=[]]
10:46:44.460 DEBUG 063A490C00124B00: Node 0 update
10:46:44.464 DEBUG <-- ZToolPacket (FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 00 4B 12 00 0C 49 3A 06 00 00 00 0E)
10:46:44.464 DEBUG Received Async Cmd: Packet: subsystem=null, length=21, apiId=45 FF, data=FE 15 45 FF 00 00 00 01 80 00 00 00 00 00 00 4B 12 00 0C 49 3A 06 00 00 00 0E, checksum=0E, error=false
10:46:44.468 DEBUG RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32769, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 4B 12 00 0C 49 3A 06 00 00 00]
10:46:44.472 DEBUG RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=063A490C00124B00, nwkAddrRemoteDev=0, startIndex=null, nwkAddrAssocDevList=[]]
10:46:44.476 DEBUG <- AF_DATA_SRSP (FE 01 64 01 00 64)
10:46:44.476 DEBUG <-- ZToolPacket (FE 06 45 B1 00 00 00 00 00 00 F2)
10:46:44.480 DEBUG Received Async Cmd: Packet: subsystem=null, length=6, apiId=45 B1, data=FE 06 45 B1 00 00 00 00 00 00 F2, checksum=F2, error=false
10:46:44.484 DEBUG RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 00 00]
10:46:44.484 DEBUG RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]
10:46:44.488 DEBUG <-- ZToolPacket (FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06)
10:46:44.488 DEBUG Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 FF, data=FE 0D 45 FF 00 00 00 31 80 00 00 00 00 00 00 00 00 06, checksum=06, error=false
10:46:44.488 DEBUG RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 00 00 00]
10:46:44.488 DEBUG RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=0, startIndex=0, neighborTableList=[]]
10:46:44.460 DEBUG Transaction complete: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0]
10:46:44.492 DEBUG -> ZB_GET_DEVICE_INFO (Packet: subsystem=null, length=1, apiId=26 06, data=FE 01 26 06 05 24, checksum=24, error=false)
10:46:44.492 DEBUG <- ZB_GET_DEVICE_INFO_RSP (FE 09 66 06 05 0B 00 00 00 00 FF AB FD CE)
Channel = CHANNEL_11