2019-01-19 21:13:59.046 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 3, wait 4466ms before retry. 2019-01-19 21:14:03.528 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:14:03.550 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=08, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:14:03.575 [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 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:14:03.621 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 08 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 9D, checksum=9D, error=false) 2019-01-19 21:14:03.768 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:14:13.798 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:14:13.823 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 4, wait 8932ms before retry. 2019-01-19 21:14:22.784 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:14:22.809 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=09, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:14:22.819 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=9, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:14:22.830 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 09 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 9C, checksum=9C, error=false) 2019-01-19 21:14:22.954 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:14:32.964 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:14:32.974 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 5, wait 4466ms before retry. 2019-01-19 21:14:37.466 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:14:37.478 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0A, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:14:37.500 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=10, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:14:37.510 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 0A 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 9F, checksum=9F, error=false) 2019-01-19 21:14:37.634 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:14:41.854 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 00 8F) 2019-01-19 21:14:41.864 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 00 8F, checksum=8F, error=false 2019-01-19 21:14:41.873 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb 2019-01-19 21:14:47.644 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:14:47.654 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 6, wait 13398ms before retry. 2019-01-19 21:15:01.064 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:15:01.076 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0B, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:15:01.103 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=11, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:15:01.114 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 0B 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 9E, checksum=9E, error=false) 2019-01-19 21:15:01.238 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:15:11.249 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:15:11.261 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 7, wait 13398ms before retry. 2019-01-19 21:15:24.675 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:15:24.695 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0C, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:15:24.706 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=12, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:15:24.716 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 0C 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 99, checksum=99, error=false) 2019-01-19 21:15:24.840 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:15:34.851 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:15:34.861 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 8, wait 17864ms before retry. 2019-01-19 21:15:52.736 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:15:52.743 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0D, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:15:52.749 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=13, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:15:52.754 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 0D 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 98, checksum=98, error=false) 2019-01-19 21:15:52.874 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:02.658 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:c4e55e7d 2019-01-19 21:16:02.669 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds. 2019-01-19 21:16:02.688 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=0E, permitDuration=60, tcSignificance=true] 2019-01-19 21:16:02.710 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=14, payload=00 3C 01] 2019-01-19 21:16:02.729 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 FC FF 00 00 36 00 0E 30 1F 03 00 3C 01 02, checksum=02, error=false) 2019-01-19 21:16:02.854 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:02.864 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=0F, permitDuration=60, tcSignificance=true] 2019-01-19 21:16:02.880 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:16:02.879 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=15, payload=00 3C 01] 2019-01-19 21:16:02.900 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 9, wait 20097ms before retry. 2019-01-19 21:16:02.909 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 00 00 00 00 36 00 0F 30 1F 03 00 3C 01 00, checksum=00, error=false) 2019-01-19 21:16:03.046 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:03.062 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 3C B3) 2019-01-19 21:16:03.072 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 3C B3, checksum=B3, error=false 2019-01-19 21:16:03.081 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb 2019-01-19 21:16:03.090 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 03 45 B6 00 00 00 F0) 2019-01-19 21:16:03.100 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=3, apiId=45 B6, data=FE 03 45 B6 00 00 00 F0, checksum=F0, error=false 2019-01-19 21:16:03.124 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45b6 2019-01-19 21:16:03.140 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0A 45 FF 00 00 00 36 80 00 00 00 00 00 06) 2019-01-19 21:16:03.150 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=10, apiId=45 FF, data=FE 0A 45 FF 00 00 00 36 80 00 00 00 00 00 06, checksum=06, error=false 2019-01-19 21:16:03.160 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, sequence=0, payload=00 00] 2019-01-19 21:16:03.179 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS] 2019-01-19 21:16:21.275 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0C 45 CA 55 C0 38 0D 10 01 00 8D 15 00 00 00 AA) 2019-01-19 21:16:21.299 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=12, apiId=45 CA, data=FE 0C 45 CA 55 C0 38 0D 10 01 00 8D 15 00 00 00 AA, checksum=AA, error=false 2019-01-19 21:16:21.314 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45ca 2019-01-19 21:16:21.895 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0D 45 C1 55 C0 55 C0 38 0D 10 01 00 8D 15 00 80 B5) 2019-01-19 21:16:21.906 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=13, apiId=45 C1, data=FE 0D 45 C1 55 C0 55 C0 38 0D 10 01 00 8D 15 00 80 B5, checksum=B5, error=false 2019-01-19 21:16:21.921 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=19, addressMode=null, radius=0, sequence=0, payload=C0 55 C0 38 0D 10 01 00 8D 15 00 80] 2019-01-19 21:16:21.934 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [49237/0 -> 0/0, cluster=0013, TID=NULL, nwkAddrOfInterest=49237, ieeeAddr=00158D0001100D38, capability=128] 2019-01-19 21:16:21.951 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 14 45 FF 55 C0 01 13 00 00 AF 00 00 55 C0 38 0D 10 01 00 8D 15 00 80 2F) 2019-01-19 21:16:21.954 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 00158D0001100D38: Node 49237 added to the network 2019-01-19 21:16:21.970 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=20, apiId=45 FF, data=FE 14 45 FF 55 C0 01 13 00 00 AF 00 00 55 C0 38 0D 10 01 00 8D 15 00 80 2F, checksum=2F, error=false 2019-01-19 21:16:21.997 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=19, addressMode=null, radius=0, sequence=0, payload=00 55 C0 38 0D 10 01 00 8D 15 00 80] 2019-01-19 21:16:22.004 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001100D38: Discovery notification 2019-01-19 21:16:22.037 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DeviceAnnounce [49237/0 -> 0/0, cluster=0013, TID=NULL, nwkAddrOfInterest=49237, ieeeAddr=00158D0001100D38, capability=128] 2019-01-19 21:16:22.040 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-01-19 21:16:22.113 [INFO ] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001100D38: Starting ZigBee device discovery 2019-01-19 21:16:22.125 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 2F 44 81 00 00 00 00 55 C0 01 01 00 2A 00 48 E1 08 00 00 1B 18 00 0A 05 00 42 10 6C 75 6D 69 2E 73 65 6E 73 6F 72 5F 63 75 62 65 01 00 20 03 55 C0 1D 6B) 2019-01-19 21:16:22.176 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=47, apiId=44 81, data=FE 2F 44 81 00 00 00 00 55 C0 01 01 00 2A 00 48 E1 08 00 00 1B 18 00 0A 05 00 42 10 6C 75 6D 69 2E 73 65 6E 73 6F 72 5F 63 75 62 65 01 00 20 03 55 C0 1D 6B, checksum=6B, error=false 2019-01-19 21:16:22.244 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done. 2019-01-19 21:16:22.251 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, sequence=0, payload=18 00 0A 05 00 42 10 6C 75 6D 69 2E 73 65 6E 73 6F 72 5F 63 75 62 65 01 00 20 03] 2019-01-19 21:16:22.232 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001100D38: Creating ZigBee device zigbee:device with bridge zigbee:coordinator_cc2531:c4e55e7d 2019-01-19 21:16:22.275 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery scheduled [NODE_DESCRIPTOR, POWER_DESCRIPTOR, ACTIVE_ENDPOINTS, NEIGHBORS, NWK_ADDRESS] 2019-01-19 21:16:22.318 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=0, commandId=10] 2019-01-19 21:16:22.394 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zigbee:device:c4e55e7d:00158d0001100d38' to inbox. 2019-01-19 21:16:22.432 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - 00158D0001100D38: Node discovery not complete 2019-01-19 21:16:22.535 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:16:22.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NodeDescriptorRequest [0/0 -> 49237/0, cluster=0002, TID=10, nwkAddrOfInterest=49237] 2019-01-19 21:16:22.581 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=2, addressMode=DEVICE, radius=31, sequence=16, payload=00 55 C0] 2019-01-19 21:16:22.601 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 02 00 10 30 1F 03 00 55 C0 16, checksum=16, error=false) 2019-01-19 21:16:23.020 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:16:23.057 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=11, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:16:23.087 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=17, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:16:23.234 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Basic: 49237/1 -> 0/1, cluster=0000, TID=00, reports=[Attribute Report: attributeDataType=CHARACTER_STRING, attributeIdentifier=5, attributeValue=lumi.sensor_cube, Attribute Report: attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=1, attributeValue=3]] 2019-01-19 21:16:23.251 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:23.267 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 11 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 84, checksum=84, error=false) 2019-01-19 21:16:23.397 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 47 44 81 00 00 00 00 55 C0 01 01 00 37 00 67 EC 08 00 00 33 1C 5F 11 01 0A 01 FF 42 2A 01 21 E1 0A 03 28 15 04 21 A8 01 05 21 AF 03 06 24 01 00 00 00 00 0A 21 00 00 97 21 00 00 98 21 00 00 99 21 00 00 9A 21 03 00 55 C0 1D 21) 2019-01-19 21:16:23.407 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=71, apiId=44 81, data=FE 47 44 81 00 00 00 00 55 C0 01 01 00 37 00 67 EC 08 00 00 33 1C 5F 11 01 0A 01 FF 42 2A 01 21 E1 0A 03 28 15 04 21 A8 01 05 21 AF 03 06 24 01 00 00 00 00 0A 21 00 00 97 21 00 00 98 21 00 00 99 21 00 00 9A 21 03 00 55 C0 1D 21, checksum=21, error=false 2019-01-19 21:16:23.420 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, sequence=0, payload=1C 5F 11 01 0A 01 FF 42 2A 01 21 E1 0A 03 28 15 04 21 A8 01 05 21 AF 03 06 24 01 00 00 00 00 0A 21 00 00 97 21 00 00 98 21 00 00 99 21 00 00 9A 21 03 00] 2019-01-19 21:16:23.430 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=true, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=4447, sequenceNumber=1, commandId=10] 2019-01-19 21:16:23.444 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Basic: 49237/1 -> 0/1, cluster=0000, TID=01, reports=[Attribute Report: attributeDataType=CHARACTER_STRING, attributeIdentifier=65281, attributeValue=!? (!?!?$ ! ?! ?! ?! ?!]] 2019-01-19 21:16:23.459 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 12 45 82 55 C0 00 55 C0 02 40 80 37 10 7F 64 00 00 00 64 00 00 4F) 2019-01-19 21:16:23.468 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=18, apiId=45 82, data=FE 12 45 82 55 C0 00 55 C0 02 40 80 37 10 7F 64 00 00 00 64 00 00 4F, checksum=4F, error=false 2019-01-19 21:16:23.487 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32770, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 02 40 80 37 10 7F 64 00 00 00 64 00 00] 2019-01-19 21:16:23.511 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorResponse [49237/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=0]] 2019-01-19 21:16:23.524 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery NodeDescriptorResponse returned NodeDescriptorResponse [49237/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=0]] 2019-01-19 21:16:23.532 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 19 45 FF 55 C0 00 02 80 00 00 00 00 00 55 C0 02 40 80 37 10 7F 64 00 00 00 64 00 00 BB) 2019-01-19 21:16:23.543 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request NODE_DESCRIPTOR successful. Advanced to POWER_DESCRIPTOR. 2019-01-19 21:16:23.554 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=25, apiId=45 FF, data=FE 19 45 FF 55 C0 00 02 80 00 00 00 00 00 55 C0 02 40 80 37 10 7F 64 00 00 00 64 00 00 BB, checksum=BB, error=false 2019-01-19 21:16:23.565 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:16:23.586 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32770, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 02 40 80 37 10 7F 64 00 00 00 64 00 00] 2019-01-19 21:16:23.592 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 49237/0, cluster=0003, TID=12, nwkAddrOfInterest=49237] 2019-01-19 21:16:23.607 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NodeDescriptorResponse [49237/0 -> 0/0, cluster=8002, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, nodeDescriptor=NodeDescriptor [apsFlags=0, bufferSize=127, complexDescriptorAvailable=false, manufacturerCode=4151, logicalType=END_DEVICE, serverCapabilities=[], incomingTransferSize=100, outgoingTransferSize=100, userDescriptorAvailable=false, frequencyBands=[FREQ_2400_MHZ], macCapabilities=[REDUCED_FUNCTION_DEVICE], extendedEndpointListAvailable=false, extendedSimpleDescriptorListAvailable=false, stackCompliance=0]] 2019-01-19 21:16:23.615 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=18, payload=00 55 C0] 2019-01-19 21:16:23.636 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:23.647 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 03 00 12 30 1F 03 00 55 C0 15, checksum=15, error=false) 2019-01-19 21:16:23.768 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:33.646 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:16:33.657 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 10, wait 26796ms before retry. 2019-01-19 21:16:33.789 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery PowerDescriptorResponse returned null 2019-01-19 21:16:33.807 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request POWER_DESCRIPTOR failed. Retry 1, wait 2327ms before retry. 2019-01-19 21:16:36.153 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:16:36.163 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 49237/0, cluster=0003, TID=13, nwkAddrOfInterest=49237] 2019-01-19 21:16:36.172 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=19, payload=00 55 C0] 2019-01-19 21:16:36.182 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 03 00 13 30 1F 03 00 55 C0 14, checksum=14, error=false) 2019-01-19 21:16:36.302 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:46.312 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery PowerDescriptorResponse returned null 2019-01-19 21:16:46.322 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request POWER_DESCRIPTOR failed. Retry 2, wait 2327ms before retry. 2019-01-19 21:16:48.659 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:16:48.669 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 49237/0, cluster=0003, TID=14, nwkAddrOfInterest=49237] 2019-01-19 21:16:48.679 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=20, payload=00 55 C0] 2019-01-19 21:16:48.689 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 03 00 14 30 1F 03 00 55 C0 13, checksum=13, error=false) 2019-01-19 21:16:48.816 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:16:58.827 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery PowerDescriptorResponse returned null 2019-01-19 21:16:58.837 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request POWER_DESCRIPTOR failed. Retry 3, wait 4654ms before retry. 2019-01-19 21:17:00.463 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:17:00.474 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=15, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:17:00.497 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=21, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:17:00.507 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 15 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 80, checksum=80, error=false) 2019-01-19 21:17:00.631 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:03.037 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 01 45 CB 00 8F) 2019-01-19 21:17:03.046 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=1, apiId=45 CB, data=FE 01 45 CB 00 8F, checksum=8F, error=false 2019-01-19 21:17:03.055 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb 2019-01-19 21:17:03.501 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:17:03.511 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 49237/0, cluster=0003, TID=16, nwkAddrOfInterest=49237] 2019-01-19 21:17:03.522 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=22, payload=00 55 C0] 2019-01-19 21:17:03.531 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 03 00 16 30 1F 03 00 55 C0 11, checksum=11, error=false) 2019-01-19 21:17:03.651 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:05.581 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.ConfigDescriptionProvider}={service.id=399, service.bundleid=245, service.scope=singleton} - org.openhab.binding.zigbee 2019-01-19 21:17:05.695 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.firmware.FirmwareUpdateHandler}={service.id=400, service.bundleid=245, service.scope=singleton} - org.openhab.binding.zigbee 2019-01-19 21:17:05.840 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D0001100D38: Initializing ZigBee thing handler zigbee:device:c4e55e7d:00158d0001100d38 2019-01-19 21:17:05.886 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D0001100D38: Coordinator status changed to ONLINE. 2019-01-19 21:17:05.918 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D0001100D38: Coordinator is ONLINE. Starting device initialisation. 2019-01-19 21:17:05.955 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001100D38: NWK Discovery starting node rediscovery 2019-01-19 21:17:05.973 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 00158D0001100D38: Node has not finished discovery 2019-01-19 21:17:05.996 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=17, ieeeAddr=00158D0001100D38, requestType=0, startIndex=0] 2019-01-19 21:17:06.078 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=23, payload=00 38 0D 10 01 00 8D 15 00 00 00] 2019-01-19 21:17:06.129 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FD FF 00 00 00 00 17 30 1F 0B 00 38 0D 10 01 00 8D 15 00 00 00 BD, checksum=BD, error=false) 2019-01-19 21:17:06.294 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:10.641 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:17:10.659 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 11, wait 29029ms before retry. 2019-01-19 21:17:13.662 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery PowerDescriptorResponse returned null 2019-01-19 21:17:13.672 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request POWER_DESCRIPTOR failed. Retry 4, wait 6981ms before retry. 2019-01-19 21:17:16.348 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001100D38: NWK Discovery node rediscovery request failed. Wait before retry. 2019-01-19 21:17:17.859 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=18, ieeeAddr=00158D0001100D38, requestType=0, startIndex=0] 2019-01-19 21:17:17.869 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=24, payload=00 38 0D 10 01 00 8D 15 00 00 00] 2019-01-19 21:17:17.885 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FD FF 00 00 00 00 18 30 1F 0B 00 38 0D 10 01 00 8D 15 00 00 00 B2, checksum=B2, error=false) 2019-01-19 21:17:18.018 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:19.955 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 2B 44 81 00 00 00 00 55 C0 01 01 00 1C 00 E5 A5 0B 00 00 17 18 02 0A 05 00 42 10 6C 75 6D 69 2E 73 65 6E 73 6F 72 5F 63 75 62 65 55 C0 1D 9F) 2019-01-19 21:17:19.965 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=43, apiId=44 81, data=FE 2B 44 81 00 00 00 00 55 C0 01 01 00 1C 00 E5 A5 0B 00 00 17 18 02 0A 05 00 42 10 6C 75 6D 69 2E 73 65 6E 73 6F 72 5F 63 75 62 65 55 C0 1D 9F, checksum=9F, error=false 2019-01-19 21:17:19.984 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/1, destinationAddress=0/1, profile=0104, cluster=0, addressMode=null, radius=0, sequence=0, payload=18 02 0A 05 00 42 10 6C 75 6D 69 2E 73 65 6E 73 6F 72 5F 63 75 62 65] 2019-01-19 21:17:19.995 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=2, commandId=10] 2019-01-19 21:17:20.004 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Basic: 49237/1 -> 0/1, cluster=0000, TID=02, reports=[Attribute Report: attributeDataType=CHARACTER_STRING, attributeIdentifier=5, attributeValue=lumi.sensor_cube]] 2019-01-19 21:17:20.670 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:17:20.696 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 49237/0, cluster=0003, TID=19, nwkAddrOfInterest=49237] 2019-01-19 21:17:20.715 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=25, payload=00 55 C0] 2019-01-19 21:17:20.742 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 03 00 19 30 1F 03 00 55 C0 1E, checksum=1E, error=false) 2019-01-19 21:17:20.880 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:22.767 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 1C 44 81 00 00 12 00 55 C0 02 01 00 1F 00 66 C8 0B 00 00 08 18 03 0A 55 00 21 5D 00 55 C0 1D 5F) 2019-01-19 21:17:22.777 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=28, apiId=44 81, data=FE 1C 44 81 00 00 12 00 55 C0 02 01 00 1F 00 66 C8 0B 00 00 08 18 03 0A 55 00 21 5D 00 55 C0 1D 5F, checksum=5F, error=false 2019-01-19 21:17:22.795 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/2, destinationAddress=0/1, profile=0104, cluster=18, addressMode=null, radius=0, sequence=0, payload=18 03 0A 55 00 21 5D 00] 2019-01-19 21:17:22.807 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=3, commandId=10] 2019-01-19 21:17:22.817 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Multistate Input (Basic): 49237/2 -> 0/1, cluster=0012, TID=03, reports=[Attribute Report: attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=85, attributeValue=93]] 2019-01-19 21:17:28.027 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001100D38: NWK Discovery node rediscovery request failed. Wait before retry. 2019-01-19 21:17:29.541 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery PowerDescriptorResponse returned null 2019-01-19 21:17:29.539 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=1A, ieeeAddr=00158D0001100D38, requestType=0, startIndex=0] 2019-01-19 21:17:29.561 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request POWER_DESCRIPTOR failed. Retry 5, wait 11635ms before retry. 2019-01-19 21:17:29.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=26, payload=00 38 0D 10 01 00 8D 15 00 00 00] 2019-01-19 21:17:29.580 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FD FF 00 00 00 00 1A 30 1F 0B 00 38 0D 10 01 00 8D 15 00 00 00 B0, checksum=B0, error=false) 2019-01-19 21:17:29.705 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:39.706 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:17:39.715 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001100D38: NWK Discovery node rediscovery request failed. Wait before retry. 2019-01-19 21:17:39.723 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=1B, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:17:39.749 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=27, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:17:39.769 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 1B 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 8E, checksum=8E, error=false) 2019-01-19 21:17:39.901 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:41.211 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:17:41.222 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: PowerDescriptorRequest [0/0 -> 49237/0, cluster=0003, TID=1C, nwkAddrOfInterest=49237] 2019-01-19 21:17:41.232 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=3, addressMode=DEVICE, radius=31, sequence=28, payload=00 55 C0] 2019-01-19 21:17:41.236 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=1D, ieeeAddr=00158D0001100D38, requestType=0, startIndex=0] 2019-01-19 21:17:41.251 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 03 00 1C 30 1F 03 00 55 C0 1B, checksum=1B, error=false) 2019-01-19 21:17:41.255 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=29, payload=00 38 0D 10 01 00 8D 15 00 00 00] 2019-01-19 21:17:41.384 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:41.400 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FD FF 00 00 00 00 1D 30 1F 0B 00 38 0D 10 01 00 8D 15 00 00 00 B7, checksum=B7, error=false) 2019-01-19 21:17:41.529 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:46.507 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 07 45 83 55 C0 00 55 C0 40 C4 45) 2019-01-19 21:17:46.516 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=7, apiId=45 83, data=FE 07 45 83 55 C0 00 55 C0 40 C4 45, checksum=45, error=false 2019-01-19 21:17:46.526 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32771, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 40 C4] 2019-01-19 21:17:46.535 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: PowerDescriptorResponse [49237/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL] 2019-01-19 21:17:46.559 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 0E 45 FF 55 C0 00 03 80 00 00 00 00 00 55 C0 40 C4 B3) 2019-01-19 21:17:46.591 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=14, apiId=45 FF, data=FE 0E 45 FF 55 C0 00 03 80 00 00 00 00 00 55 C0 40 C4 B3, checksum=B3, error=false 2019-01-19 21:17:46.595 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery PowerDescriptorResponse returned PowerDescriptorResponse [49237/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL] 2019-01-19 21:17:46.618 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32771, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 40 C4] 2019-01-19 21:17:46.625 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request POWER_DESCRIPTOR successful. Advanced to ACTIVE_ENDPOINTS. 2019-01-19 21:17:46.656 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:17:46.649 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: PowerDescriptorResponse [49237/0 -> 0/0, cluster=8003, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, powerDescriptor=RECEIVER_ON_IDLE, [DISPOSABLE_BATTERY], DISPOSABLE_BATTERY, FULL] 2019-01-19 21:17:46.677 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=1E, nwkAddrOfInterest=49237] 2019-01-19 21:17:46.693 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=30, payload=00 55 C0] 2019-01-19 21:17:46.703 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 1E 30 1F 03 00 55 C0 1F, checksum=1F, error=false) 2019-01-19 21:17:46.824 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:49.758 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA) 2019-01-19 21:17:49.768 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=9, apiId=45 85, data=FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA, checksum=CA, error=false 2019-01-19 21:17:49.794 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 03 01 02 03] 2019-01-19 21:17:49.809 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:17:49.836 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C) 2019-01-19 21:17:49.839 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]]] 2019-01-19 21:17:49.856 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=16, apiId=45 FF, data=FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C, checksum=2C, error=false 2019-01-19 21:17:49.866 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=1F, nwkAddrOfInterest=49237, endpoint=1] 2019-01-19 21:17:49.862 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:17:49.860 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001100D38: NWK Discovery node rediscovery request failed. Wait before retry. 2019-01-19 21:17:49.877 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 03 01 02 03] 2019-01-19 21:17:49.906 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 12, wait 31262ms before retry. 2019-01-19 21:17:49.901 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=31, payload=00 55 C0 01] 2019-01-19 21:17:49.918 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:17:49.942 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 1F 30 1F 04 00 55 C0 01 1A, checksum=1A, error=false) 2019-01-19 21:17:50.084 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:17:51.400 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001100D38: NWK Discovery finishing node rediscovery 2019-01-19 21:17:53.002 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 22 45 84 55 C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 A7) 2019-01-19 21:17:53.007 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=34, apiId=45 84, data=FE 22 45 84 55 C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 A7, checksum=A7, error=false 2019-01-19 21:17:53.025 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00] 2019-01-19 21:17:53.041 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:17:53.059 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:17:53.069 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 29 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 53) 2019-01-19 21:17:53.094 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=41, apiId=45 FF, data=FE 29 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 53, checksum=53, error=false 2019-01-19 21:17:53.108 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00] 2019-01-19 21:17:53.118 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:17:53.125 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting input clusters [0, 3, 25, 18] 2019-01-19 21:17:53.155 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster BASIC as server 2019-01-19 21:17:53.162 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster IDENTIFY as server 2019-01-19 21:17:53.173 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster OTA_UPGRADE as server 2019-01-19 21:17:53.183 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster MULTISTATE_INPUT__BASIC as server 2019-01-19 21:17:53.188 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting output clusters [0, 4, 3, 5, 25, 18] 2019-01-19 21:17:53.193 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster BASIC as client 2019-01-19 21:17:53.200 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster GROUPS as client 2019-01-19 21:17:53.205 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster IDENTIFY as client 2019-01-19 21:17:53.214 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster SCENES as client 2019-01-19 21:17:53.220 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster OTA_UPGRADE as client 2019-01-19 21:17:53.225 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster MULTISTATE_INPUT__BASIC as client 2019-01-19 21:17:53.231 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=20, nwkAddrOfInterest=49237, endpoint=2] 2019-01-19 21:17:53.236 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=32, payload=00 55 C0 02] 2019-01-19 21:17:53.241 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 20 30 1F 04 00 55 C0 02 26, checksum=26, error=false) 2019-01-19 21:17:53.357 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:03.363 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned null 2019-01-19 21:18:03.368 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 1, wait 2327ms before retry. 2019-01-19 21:18:05.700 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:18:05.706 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=21, nwkAddrOfInterest=49237] 2019-01-19 21:18:05.711 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=33, payload=00 55 C0] 2019-01-19 21:18:05.721 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 21 30 1F 03 00 55 C0 20, checksum=20, error=false) 2019-01-19 21:18:05.837 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:08.797 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA) 2019-01-19 21:18:08.803 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=9, apiId=45 85, data=FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA, checksum=CA, error=false 2019-01-19 21:18:08.808 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 03 01 02 03] 2019-01-19 21:18:08.813 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:18:08.824 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C) 2019-01-19 21:18:08.828 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]]] 2019-01-19 21:18:08.831 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=22, nwkAddrOfInterest=49237, endpoint=1] 2019-01-19 21:18:08.835 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=16, apiId=45 FF, data=FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C, checksum=2C, error=false 2019-01-19 21:18:08.841 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=34, payload=00 55 C0 01] 2019-01-19 21:18:08.845 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 03 01 02 03] 2019-01-19 21:18:08.852 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 22 30 1F 04 00 55 C0 01 27, checksum=27, error=false) 2019-01-19 21:18:08.848 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:18:08.971 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:12.037 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 22 45 84 55 C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 A7) 2019-01-19 21:18:12.041 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=34, apiId=45 84, data=FE 22 45 84 55 C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 A7, checksum=A7, error=false 2019-01-19 21:18:12.048 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00] 2019-01-19 21:18:12.053 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:18:12.064 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:18:12.070 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 29 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 53) 2019-01-19 21:18:12.075 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting input clusters [0, 3, 25, 18] 2019-01-19 21:18:12.080 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster BASIC as server 2019-01-19 21:18:12.083 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=41, apiId=45 FF, data=FE 29 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 53, checksum=53, error=false 2019-01-19 21:18:12.089 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster IDENTIFY as server 2019-01-19 21:18:12.094 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00] 2019-01-19 21:18:12.100 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster OTA_UPGRADE as server 2019-01-19 21:18:12.103 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster MULTISTATE_INPUT__BASIC as server 2019-01-19 21:18:12.108 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:18:12.117 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting output clusters [0, 4, 3, 5, 25, 18] 2019-01-19 21:18:12.122 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster BASIC as client 2019-01-19 21:18:12.133 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster GROUPS as client 2019-01-19 21:18:12.139 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster IDENTIFY as client 2019-01-19 21:18:12.144 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster SCENES as client 2019-01-19 21:18:12.150 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster OTA_UPGRADE as client 2019-01-19 21:18:12.155 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster MULTISTATE_INPUT__BASIC as client 2019-01-19 21:18:12.167 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=23, nwkAddrOfInterest=49237, endpoint=2] 2019-01-19 21:18:12.175 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=35, payload=00 55 C0 02] 2019-01-19 21:18:12.185 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 23 30 1F 04 00 55 C0 02 25, checksum=25, error=false) 2019-01-19 21:18:12.304 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:15.269 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 1A 45 84 55 C0 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 93) 2019-01-19 21:18:15.274 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=26, apiId=45 84, data=FE 1A 45 84 55 C0 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 93, checksum=93, error=false 2019-01-19 21:18:15.297 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00] 2019-01-19 21:18:15.303 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=20, simpleDescriptor=SimpleDescriptor [endpoint=2, profileId=0104, deviceId=24322, deviceVersion=1, inputClusterList=[3, 18], outputClusterList=[4, 3, 5, 18]]] 2019-01-19 21:18:15.313 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 21 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 57) 2019-01-19 21:18:15.316 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=20, simpleDescriptor=SimpleDescriptor [endpoint=2, profileId=0104, deviceId=24322, deviceVersion=1, inputClusterList=[3, 18], outputClusterList=[4, 3, 5, 18]]] 2019-01-19 21:18:15.321 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting input clusters [3, 18] 2019-01-19 21:18:15.327 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster IDENTIFY as server 2019-01-19 21:18:15.330 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=33, apiId=45 FF, data=FE 21 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 57, checksum=57, error=false 2019-01-19 21:18:15.338 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster MULTISTATE_INPUT__BASIC as server 2019-01-19 21:18:15.334 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00] 2019-01-19 21:18:15.343 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=20, simpleDescriptor=SimpleDescriptor [endpoint=2, profileId=0104, deviceId=24322, deviceVersion=1, inputClusterList=[3, 18], outputClusterList=[4, 3, 5, 18]]] 2019-01-19 21:18:15.347 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting output clusters [4, 3, 5, 18] 2019-01-19 21:18:15.351 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster GROUPS as client 2019-01-19 21:18:15.354 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster IDENTIFY as client 2019-01-19 21:18:15.363 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster SCENES as client 2019-01-19 21:18:15.369 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster MULTISTATE_INPUT__BASIC as client 2019-01-19 21:18:15.373 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=24, nwkAddrOfInterest=49237, endpoint=3] 2019-01-19 21:18:15.379 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=36, payload=00 55 C0 03] 2019-01-19 21:18:15.384 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 24 30 1F 04 00 55 C0 03 23, checksum=23, error=false) 2019-01-19 21:18:15.499 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:21.207 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:18:21.213 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=25, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:18:21.219 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=37, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:18:21.224 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 25 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 B0, checksum=B0, error=false) 2019-01-19 21:18:22.232 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-01-19 21:18:22.237 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-01-19 21:18:23.744 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 25 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 B0, checksum=B0, error=false) 2019-01-19 21:18:24.091 [DEBUG] [tems.zigbee.ZigBeeNetworkMeshMonitor] - Starting mesh update task with interval of 300 seconds 2019-01-19 21:18:24.114 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery already scheduled or running 2019-01-19 21:18:24.126 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery already scheduled or running 2019-01-19 21:18:24.751 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-01-19 21:18:24.756 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-01-19 21:18:25.505 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned null 2019-01-19 21:18:25.510 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 2, wait 4654ms before retry. 2019-01-19 21:18:26.262 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 25 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 B0, checksum=B0, error=false) 2019-01-19 21:18:27.270 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-01-19 21:18:27.275 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-01-19 21:18:30.169 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:18:30.174 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:18:30.179 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 13, wait 15631ms before retry. 2019-01-19 21:18:30.182 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=26, nwkAddrOfInterest=49237] 2019-01-19 21:18:30.187 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=38, payload=00 55 C0] 2019-01-19 21:18:30.193 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 26 30 1F 03 00 55 C0 27, checksum=27, error=false) 2019-01-19 21:18:31.200 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-01-19 21:18:31.204 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-01-19 21:18:31.462 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA) 2019-01-19 21:18:31.468 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=9, apiId=45 85, data=FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA, checksum=CA, error=false 2019-01-19 21:18:31.473 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 03 01 02 03] 2019-01-19 21:18:31.478 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:18:31.498 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C) 2019-01-19 21:18:31.503 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=16, apiId=45 FF, data=FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C, checksum=2C, error=false 2019-01-19 21:18:31.514 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 03 01 02 03] 2019-01-19 21:18:31.520 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:18:32.710 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 26 30 1F 03 00 55 C0 27, checksum=27, error=false) 2019-01-19 21:18:32.826 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:32.834 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]]] 2019-01-19 21:18:32.840 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=27, nwkAddrOfInterest=49237, endpoint=1] 2019-01-19 21:18:32.845 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=39, payload=00 55 C0 01] 2019-01-19 21:18:32.850 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 27 30 1F 04 00 55 C0 01 22, checksum=22, error=false) 2019-01-19 21:18:32.966 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:42.972 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned null 2019-01-19 21:18:42.979 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 3, wait 2327ms before retry. 2019-01-19 21:18:45.320 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:18:45.326 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=28, nwkAddrOfInterest=49237] 2019-01-19 21:18:45.332 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=40, payload=00 55 C0] 2019-01-19 21:18:45.337 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 28 30 1F 03 00 55 C0 29, checksum=29, error=false) 2019-01-19 21:18:45.453 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:45.822 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:18:45.829 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=29, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:18:45.835 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=41, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:18:45.841 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 29 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 BC, checksum=BC, error=false) 2019-01-19 21:18:45.961 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:49.846 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA) 2019-01-19 21:18:49.851 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=9, apiId=45 85, data=FE 09 45 85 55 C0 00 55 C0 03 01 02 03 CA, checksum=CA, error=false 2019-01-19 21:18:49.856 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 03 01 02 03] 2019-01-19 21:18:49.862 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:18:49.873 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C) 2019-01-19 21:18:49.876 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [SUCCESS, ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]]] 2019-01-19 21:18:49.887 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=16, apiId=45 FF, data=FE 10 45 FF 55 C0 00 05 80 00 00 00 00 00 55 C0 03 01 02 03 2C, checksum=2C, error=false 2019-01-19 21:18:49.884 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=2A, nwkAddrOfInterest=49237, endpoint=1] 2019-01-19 21:18:49.892 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32773, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 03 01 02 03] 2019-01-19 21:18:49.899 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=42, payload=00 55 C0 01] 2019-01-19 21:18:49.903 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ActiveEndpointsResponse [49237/0 -> 0/0, cluster=8005, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, activeEpList=[1, 2, 3]] 2019-01-19 21:18:49.907 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 2A 30 1F 04 00 55 C0 01 2F, checksum=2F, error=false) 2019-01-19 21:18:50.028 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:53.100 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 22 45 84 55 C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 A7) 2019-01-19 21:18:53.119 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=34, apiId=45 84, data=FE 22 45 84 55 C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 A7, checksum=A7, error=false 2019-01-19 21:18:53.135 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00] 2019-01-19 21:18:53.146 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:18:53.158 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:18:53.173 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 29 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 53) 2019-01-19 21:18:53.199 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=41, apiId=45 FF, data=FE 29 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00 53, checksum=53, error=false 2019-01-19 21:18:53.207 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting input clusters [0, 3, 25, 18] 2019-01-19 21:18:53.229 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster BASIC as server 2019-01-19 21:18:53.233 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 1C 01 04 01 01 5F 01 04 00 00 03 00 19 00 12 00 06 00 00 04 00 03 00 05 00 19 00 12 00] 2019-01-19 21:18:53.248 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=28, simpleDescriptor=SimpleDescriptor [endpoint=1, profileId=0104, deviceId=24321, deviceVersion=1, inputClusterList=[0, 3, 25, 18], outputClusterList=[0, 4, 3, 5, 25, 18]]] 2019-01-19 21:18:53.256 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster IDENTIFY as server 2019-01-19 21:18:53.267 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster OTA_UPGRADE as server 2019-01-19 21:18:53.288 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster MULTISTATE_INPUT__BASIC as server 2019-01-19 21:18:53.296 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting output clusters [0, 4, 3, 5, 25, 18] 2019-01-19 21:18:53.306 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster BASIC as client 2019-01-19 21:18:53.315 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster GROUPS as client 2019-01-19 21:18:53.325 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster IDENTIFY as client 2019-01-19 21:18:53.335 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster SCENES as client 2019-01-19 21:18:53.344 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster OTA_UPGRADE as client 2019-01-19 21:18:53.353 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/1: Setting cluster MULTISTATE_INPUT__BASIC as client 2019-01-19 21:18:53.363 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=2B, nwkAddrOfInterest=49237, endpoint=2] 2019-01-19 21:18:53.373 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=43, payload=00 55 C0 02] 2019-01-19 21:18:53.388 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 2B 30 1F 04 00 55 C0 02 2D, checksum=2D, error=false) 2019-01-19 21:18:53.514 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:18:55.966 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:18:55.977 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 14, wait 33495ms before retry. 2019-01-19 21:18:56.330 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 1A 45 84 55 C0 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 93) 2019-01-19 21:18:56.340 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=26, apiId=45 84, data=FE 1A 45 84 55 C0 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 93, checksum=93, error=false 2019-01-19 21:18:56.356 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=C0 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00] 2019-01-19 21:18:56.366 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=20, simpleDescriptor=SimpleDescriptor [endpoint=2, profileId=0104, deviceId=24322, deviceVersion=1, inputClusterList=[3, 18], outputClusterList=[4, 3, 5, 18]]] 2019-01-19 21:18:56.403 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- ZToolPacket (FE 21 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 57) 2019-01-19 21:18:56.407 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=20, simpleDescriptor=SimpleDescriptor [endpoint=2, profileId=0104, deviceId=24322, deviceVersion=1, inputClusterList=[3, 18], outputClusterList=[4, 3, 5, 18]]] 2019-01-19 21:18:56.421 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting input clusters [3, 18] 2019-01-19 21:18:56.427 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=33, apiId=45 FF, data=FE 21 45 FF 55 C0 00 04 80 00 00 00 00 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00 57, checksum=57, error=false 2019-01-19 21:18:56.442 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/0, destinationAddress=0/0, profile=0000, cluster=32772, addressMode=null, radius=0, sequence=0, payload=00 00 55 C0 14 02 04 01 02 5F 01 02 03 00 12 00 04 04 00 03 00 05 00 12 00] 2019-01-19 21:18:56.447 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster IDENTIFY as server 2019-01-19 21:18:56.467 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: SimpleDescriptorResponse [49237/0 -> 0/0, cluster=8004, TID=NULL, status=SUCCESS, nwkAddrOfInterest=49237, length=20, simpleDescriptor=SimpleDescriptor [endpoint=2, profileId=0104, deviceId=24322, deviceVersion=1, inputClusterList=[3, 18], outputClusterList=[4, 3, 5, 18]]] 2019-01-19 21:18:56.474 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster MULTISTATE_INPUT__BASIC as server 2019-01-19 21:18:56.492 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting output clusters [4, 3, 5, 18] 2019-01-19 21:18:56.501 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster GROUPS as client 2019-01-19 21:18:56.511 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster IDENTIFY as client 2019-01-19 21:18:56.520 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster SCENES as client 2019-01-19 21:18:56.529 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 49237/2: Setting cluster MULTISTATE_INPUT__BASIC as client 2019-01-19 21:18:56.539 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: SimpleDescriptorRequest [0/0 -> 49237/0, cluster=0004, TID=2C, nwkAddrOfInterest=49237, endpoint=3] 2019-01-19 21:18:56.549 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=4, addressMode=DEVICE, radius=31, sequence=44, payload=00 55 C0 03] 2019-01-19 21:18:56.558 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=14, apiId=24 01, data=FE 0E 24 01 55 C0 00 00 04 00 2C 30 1F 04 00 55 C0 03 2B, checksum=2B, error=false) 2019-01-19 21:18:56.684 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:19:06.703 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery SimpleDescriptorResponse returned null 2019-01-19 21:19:06.713 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 4, wait 4654ms before retry. 2019-01-19 21:19:06.751 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 1C 44 81 00 00 12 00 55 C0 02 01 00 2C 00 BD BD 10 00 00 08 18 00 0A 55 00 21 00 01 55 C0 1D 86) 2019-01-19 21:19:06.765 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=28, apiId=44 81, data=FE 1C 44 81 00 00 12 00 55 C0 02 01 00 2C 00 BD BD 10 00 00 08 18 00 0A 55 00 21 00 01 55 C0 1D 86, checksum=86, error=false 2019-01-19 21:19:06.776 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/2, destinationAddress=0/1, profile=0104, cluster=18, addressMode=null, radius=0, sequence=0, payload=18 00 0A 55 00 21 00 01] 2019-01-19 21:19:06.786 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=0, commandId=10] 2019-01-19 21:19:06.796 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Multistate Input (Basic): 49237/2 -> 0/1, cluster=0012, TID=00, reports=[Attribute Report: attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=85, attributeValue=256]] 2019-01-19 21:19:11.376 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:19:11.397 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=2D, nwkAddrOfInterest=49237] 2019-01-19 21:19:11.407 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=45, payload=00 55 C0] 2019-01-19 21:19:11.417 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 2D 30 1F 03 00 55 C0 2C, checksum=2C, error=false) 2019-01-19 21:19:11.537 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:19:21.548 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:19:21.559 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 5, wait 13962ms before retry. 2019-01-19 21:19:21.785 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 1C 44 81 00 00 12 00 55 C0 02 01 00 2C 00 52 75 11 00 00 08 18 01 0A 55 00 21 44 00 55 C0 1D E4) 2019-01-19 21:19:21.794 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=28, apiId=44 81, data=FE 1C 44 81 00 00 12 00 55 C0 02 01 00 2C 00 52 75 11 00 00 08 18 01 0A 55 00 21 44 00 55 C0 1D E4, checksum=E4, error=false 2019-01-19 21:19:21.804 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/2, destinationAddress=0/1, profile=0104, cluster=18, addressMode=null, radius=0, sequence=0, payload=18 01 0A 55 00 21 44 00] 2019-01-19 21:19:21.813 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=1, commandId=10] 2019-01-19 21:19:21.827 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Multistate Input (Basic): 49237/2 -> 0/1, cluster=0012, TID=01, reports=[Attribute Report: attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=85, attributeValue=68]] 2019-01-19 21:19:27.972 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 1C 44 81 00 00 12 00 55 C0 02 01 00 24 00 D9 C0 11 00 00 08 18 02 0A 55 00 21 65 00 55 C0 1D F0) 2019-01-19 21:19:27.982 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=28, apiId=44 81, data=FE 1C 44 81 00 00 12 00 55 C0 02 01 00 24 00 D9 C0 11 00 00 08 18 02 0A 55 00 21 65 00 55 C0 1D F0, checksum=F0, error=false 2019-01-19 21:19:27.991 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/2, destinationAddress=0/1, profile=0104, cluster=18, addressMode=null, radius=0, sequence=0, payload=18 02 0A 55 00 21 65 00] 2019-01-19 21:19:28.001 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=2, commandId=10] 2019-01-19 21:19:28.010 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Multistate Input (Basic): 49237/2 -> 0/1, cluster=0012, TID=02, reports=[Attribute Report: attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=85, attributeValue=101]] 2019-01-19 21:19:29.481 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:19:29.501 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=2E, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:19:29.512 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=46, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:19:29.521 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 2E 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 BB, checksum=BB, error=false) 2019-01-19 21:19:29.645 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:19:35.531 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:19:35.542 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=2F, nwkAddrOfInterest=49237] 2019-01-19 21:19:35.552 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=47, payload=00 55 C0] 2019-01-19 21:19:35.561 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 2F 30 1F 03 00 55 C0 2E, checksum=2E, error=false) 2019-01-19 21:19:35.684 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:19:39.665 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:19:39.675 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 15, wait 26796ms before retry. 2019-01-19 21:19:44.235 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 23 44 81 00 00 0C 00 55 C0 03 01 00 1A 00 5E 87 12 00 00 0F 18 04 0A 05 FF 21 F4 01 55 00 39 66 66 32 42 55 C0 1D 0F) 2019-01-19 21:19:44.246 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=35, apiId=44 81, data=FE 23 44 81 00 00 0C 00 55 C0 03 01 00 1A 00 5E 87 12 00 00 0F 18 04 0A 05 FF 21 F4 01 55 00 39 66 66 32 42 55 C0 1D 0F, checksum=0F, error=false 2019-01-19 21:19:44.255 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/3, destinationAddress=0/1, profile=0104, cluster=12, addressMode=null, radius=0, sequence=0, payload=18 04 0A 05 FF 21 F4 01 55 00 39 66 66 32 42] 2019-01-19 21:19:44.272 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=4, commandId=10] 2019-01-19 21:19:44.309 [ERROR] [tworkManager$AFMessageListenerFilter] - Error AF message listener notify. java.lang.NullPointerException: null at com.zsmartsystems.zigbee.serialization.DefaultDeserializer.readZigBeeType(DefaultDeserializer.java:70) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.field.AttributeReport.deserialize(AttributeReport.java:100) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.ZclFieldDeserializer.deserialize(ZclFieldDeserializer.java:73) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.clusters.general.ReportAttributesCommand.deserialize(ReportAttributesCommand.java:88) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.receiveZclCommand(ZigBeeNetworkManager.java:717) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.receiveCommand(ZigBeeNetworkManager.java:641) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.ZigBeeDongleTiCc2531.notify(ZigBeeDongleTiCc2531.java:289) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.ZigBeeNetworkManager$AFMessageListenerFilter.receivedAsynchronousCommand(ZigBeeNetworkManager.java:1303) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.impl.CommandInterfaceImpl.notifyAsynchronousCommand(CommandInterfaceImpl.java:382) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.impl.CommandInterfaceImpl.handlePacket(CommandInterfaceImpl.java:160) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:116) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at java.lang.Thread.run(Thread.java:745) [?:?] 2019-01-19 21:19:45.699 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:19:45.710 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 6, wait 4654ms before retry. 2019-01-19 21:19:50.373 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:19:50.388 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=30, nwkAddrOfInterest=49237] 2019-01-19 21:19:50.403 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=48, payload=00 55 C0] 2019-01-19 21:19:50.413 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 30 30 1F 03 00 55 C0 31, checksum=31, error=false) 2019-01-19 21:19:50.533 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:19:55.697 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 1C 44 81 00 00 12 00 55 C0 02 01 00 1C 00 4F 13 13 00 00 08 18 05 0A 55 00 21 03 01 55 C0 1D EF) 2019-01-19 21:19:55.709 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=28, apiId=44 81, data=FE 1C 44 81 00 00 12 00 55 C0 02 01 00 1C 00 4F 13 13 00 00 08 18 05 0A 55 00 21 03 01 55 C0 1D EF, checksum=EF, error=false 2019-01-19 21:19:55.724 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/2, destinationAddress=0/1, profile=0104, cluster=18, addressMode=null, radius=0, sequence=0, payload=18 05 0A 55 00 21 03 01] 2019-01-19 21:19:55.733 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=5, commandId=10] 2019-01-19 21:19:55.743 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Multistate Input (Basic): 49237/2 -> 0/1, cluster=0012, TID=05, reports=[Attribute Report: attributeDataType=UNSIGNED_16_BIT_INTEGER, attributeIdentifier=85, attributeValue=259]] 2019-01-19 21:20:00.544 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:20:00.554 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 7, wait 6981ms before retry. 2019-01-19 21:20:04.074 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 23 44 81 00 00 0C 00 55 C0 03 01 00 1C 00 8A 79 13 00 00 0F 18 06 0A 05 FF 21 F4 01 55 00 39 C3 F5 2E C2 55 C0 1D 8A) 2019-01-19 21:20:04.085 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=35, apiId=44 81, data=FE 23 44 81 00 00 0C 00 55 C0 03 01 00 1C 00 8A 79 13 00 00 0F 18 06 0A 05 FF 21 F4 01 55 00 39 C3 F5 2E C2 55 C0 1D 8A, checksum=8A, error=false 2019-01-19 21:20:04.097 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/3, destinationAddress=0/1, profile=0104, cluster=12, addressMode=null, radius=0, sequence=0, payload=18 06 0A 05 FF 21 F4 01 55 00 39 C3 F5 2E C2] 2019-01-19 21:20:04.106 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=6, commandId=10] 2019-01-19 21:20:04.122 [ERROR] [tworkManager$AFMessageListenerFilter] - Error AF message listener notify. java.lang.NullPointerException: null at com.zsmartsystems.zigbee.serialization.DefaultDeserializer.readZigBeeType(DefaultDeserializer.java:70) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.field.AttributeReport.deserialize(AttributeReport.java:100) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.ZclFieldDeserializer.deserialize(ZclFieldDeserializer.java:73) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.clusters.general.ReportAttributesCommand.deserialize(ReportAttributesCommand.java:88) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.receiveZclCommand(ZigBeeNetworkManager.java:717) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.receiveCommand(ZigBeeNetworkManager.java:641) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.ZigBeeDongleTiCc2531.notify(ZigBeeDongleTiCc2531.java:289) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.ZigBeeNetworkManager$AFMessageListenerFilter.receivedAsynchronousCommand(ZigBeeNetworkManager.java:1303) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.impl.CommandInterfaceImpl.notifyAsynchronousCommand(CommandInterfaceImpl.java:382) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.impl.CommandInterfaceImpl.handlePacket(CommandInterfaceImpl.java:160) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:116) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at java.lang.Thread.run(Thread.java:745) [?:?] 2019-01-19 21:20:06.485 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:20:06.501 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=31, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:20:06.517 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=49, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:20:06.530 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 31 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 A4, checksum=A4, error=false) 2019-01-19 21:20:06.654 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:20:07.546 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:20:07.555 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=32, nwkAddrOfInterest=49237] 2019-01-19 21:20:07.565 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=50, payload=00 55 C0] 2019-01-19 21:20:07.574 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 32 30 1F 03 00 55 C0 33, checksum=33, error=false) 2019-01-19 21:20:07.694 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:20:16.664 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:20:16.674 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 16, wait 31262ms before retry. 2019-01-19 21:20:17.369 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-- AF_INCOMING_MSG (FE 23 44 81 00 00 0C 00 55 C0 03 01 00 1F 00 D5 1B 14 00 00 0F 18 08 0A 05 FF 21 68 01 55 00 39 27 5C 73 C2 55 C0 1D 31) 2019-01-19 21:20:17.385 [DEBUG] [31.network.impl.CommandInterfaceImpl] - Received Async Cmd: Packet: subsystem=null, length=35, apiId=44 81, data=FE 23 44 81 00 00 0C 00 55 C0 03 01 00 1F 00 D5 1B 14 00 00 0F 18 08 0A 05 FF 21 68 01 55 00 39 27 5C 73 C2 55 C0 1D 31, checksum=31, error=false 2019-01-19 21:20:17.401 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=49237/3, destinationAddress=0/1, profile=0104, cluster=12, addressMode=null, radius=0, sequence=0, payload=18 08 0A 05 FF 21 68 01 55 00 39 27 5C 73 C2] 2019-01-19 21:20:17.410 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=8, commandId=10] 2019-01-19 21:20:17.420 [ERROR] [tworkManager$AFMessageListenerFilter] - Error AF message listener notify. java.lang.NullPointerException: null at com.zsmartsystems.zigbee.serialization.DefaultDeserializer.readZigBeeType(DefaultDeserializer.java:70) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.field.AttributeReport.deserialize(AttributeReport.java:100) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.ZclFieldDeserializer.deserialize(ZclFieldDeserializer.java:73) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.zcl.clusters.general.ReportAttributesCommand.deserialize(ReportAttributesCommand.java:88) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.receiveZclCommand(ZigBeeNetworkManager.java:717) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.receiveCommand(ZigBeeNetworkManager.java:641) [235:com.zsmartsystems.zigbee:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.ZigBeeDongleTiCc2531.notify(ZigBeeDongleTiCc2531.java:289) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.ZigBeeNetworkManager$AFMessageListenerFilter.receivedAsynchronousCommand(ZigBeeNetworkManager.java:1303) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.impl.CommandInterfaceImpl.notifyAsynchronousCommand(CommandInterfaceImpl.java:382) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.impl.CommandInterfaceImpl.handlePacket(CommandInterfaceImpl.java:160) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:116) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.0.11] at java.lang.Thread.run(Thread.java:745) [?:?] 2019-01-19 21:20:17.705 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:20:17.715 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 8, wait 13962ms before retry. 2019-01-19 21:20:31.687 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:20:31.700 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=33, nwkAddrOfInterest=49237] 2019-01-19 21:20:31.705 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=51, payload=00 55 C0] 2019-01-19 21:20:31.711 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 33 30 1F 03 00 55 C0 32, checksum=32, error=false) 2019-01-19 21:20:31.826 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:20:41.833 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:20:41.839 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 9, wait 9308ms before retry. 2019-01-19 21:20:47.946 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:20:47.953 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=34, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:20:47.959 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=52, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:20:47.965 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 34 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 A1, checksum=A1, error=false) 2019-01-19 21:20:48.085 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:20:51.153 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:20:51.159 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=35, nwkAddrOfInterest=49237] 2019-01-19 21:20:51.165 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=53, payload=00 55 C0] 2019-01-19 21:20:51.170 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 35 30 1F 03 00 55 C0 34, checksum=34, error=false) 2019-01-19 21:20:51.285 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:20:58.090 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:20:58.096 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 17, wait 29029ms before retry. 2019-01-19 21:21:01.296 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:21:01.302 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 10, wait 25597ms before retry. 2019-01-19 21:21:26.905 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:21:26.911 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=36, nwkAddrOfInterest=49237] 2019-01-19 21:21:26.916 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=54, payload=00 55 C0] 2019-01-19 21:21:26.922 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 36 30 1F 03 00 55 C0 37, checksum=37, error=false) 2019-01-19 21:21:27.037 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:21:27.130 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:21:27.144 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=37, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:21:27.150 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=55, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:21:27.163 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 37 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 A2, checksum=A2, error=false) 2019-01-19 21:21:27.285 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:21:37.043 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:21:37.049 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 11, wait 16289ms before retry. 2019-01-19 21:21:37.295 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null 2019-01-19 21:21:37.301 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery request NWK_ADDRESS failed. Retry 18, wait 33495ms before retry. 2019-01-19 21:21:53.343 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery running 2019-01-19 21:21:53.349 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ActiveEndpointsRequest [0/0 -> 49237/0, cluster=0005, TID=38, nwkAddrOfInterest=49237] 2019-01-19 21:21:53.355 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=49237/0, profile=0000, cluster=5, addressMode=DEVICE, radius=31, sequence=56, payload=00 55 C0] 2019-01-19 21:21:53.361 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=13, apiId=24 01, data=FE 0D 24 01 55 C0 00 00 05 00 38 30 1F 03 00 55 C0 39, checksum=39, error=false) 2019-01-19 21:21:53.477 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64) 2019-01-19 21:22:03.483 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery ActiveEndpointsResponse returned CommandResult [TIMEOUT] 2019-01-19 21:22:03.489 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001100D38: Node SVC Discovery request ACTIVE_ENDPOINTS failed. Retry 12, wait 27924ms before retry. 2019-01-19 21:22:10.803 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B0018ECDAF6: Node SVC Discovery running 2019-01-19 21:22:10.809 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=39, ieeeAddr=00124B0018ECDAF6, requestType=0, startIndex=0] 2019-01-19 21:22:10.815 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=57, payload=00 F6 DA EC 18 00 4B 12 00 00 00] 2019-01-19 21:22:10.826 [DEBUG] [31.network.impl.CommandInterfaceImpl] - -> AF_DATA_REQUEST (Packet: subsystem=null, length=21, apiId=24 01, data=FE 15 24 01 FF FF 00 00 00 00 39 30 1F 0B 00 F6 DA EC 18 00 4B 12 00 00 00 AC, checksum=AC, error=false) 2019-01-19 21:22:10.950 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <- AF_DATA_SRSP (FE 01 64 01 00 64)