search

openhab / org.openhab.binding.zigbee

openHAB binding for ZigBee
Eclipse Public License 2.0
73 stars 111 forks source link

Xioami (aqara) devices do not complete discovery #163

Closed oysteinkrog closed 6 years ago

oysteinkrog commented 6 years ago

Outline

I've been able to find and add two aqara devices (a temperature and humidity sensor and a door latch sensor), but in Openhab it says that device disovery is not completed.

Configuration

My setup consists of RPI2, a CC2531 (flashed with CC2531ZNP-Pro-Secure_LinkKeyJoin.hex) and openhabian (with openhab 2.2). I'm running version 2.3.0.201803022259 of the binding (latest snapshot as of yesterday).

Logs

2018-03-07 18:34:55.649 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery running

2018-03-07 18:34:55.671 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=58, ieeeAddr=00124B000E896A5E, requestType=0, startIndex=0]

2018-03-07 18:34:55.691 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=88, payload=00 5E 6A 89 0E 00 4B 12 00 00 00]

2018-03-07 18:34:55.702 [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 58 30 1F 0B 00 5E 6A 89 0E 00 4B 12 00 00 00 A4, checksum=A4, error=false) 

2018-03-07 18:34:55.837 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:35:05.851 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:35:05.867 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery request NWK_ADDRESS failed. Retry 270, wait 676494ms before retry.

2018-03-07 18:35:40.572 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:36:40.585 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:36:57.156 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery running

2018-03-07 18:36:57.176 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=59, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 18:36:57.195 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=89, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 18:36:57.208 [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 59 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 39, checksum=39, error=false) 

2018-03-07 18:36:57.346 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:37:07.377 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 29499: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:37:07.394 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery request NWK_ADDRESS failed. Retry 287, wait 348645ms before retry.

2018-03-07 18:37:40.599 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:38:02.628 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery already scheduled or running

2018-03-07 18:38:02.646 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery already scheduled or running

2018-03-07 18:38:02.664 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery already scheduled or running

2018-03-07 18:38:36.834 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery running

2018-03-07 18:38:36.856 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=5A, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 18:38:36.877 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=90, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 18:38:36.889 [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 5A 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 0C, checksum=0C, error=false) 

2018-03-07 18:38:37.030 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:38:40.614 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:38:47.044 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 18510: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:38:47.061 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery request NWK_ADDRESS failed. Retry 293, wait 212660ms before retry.

2018-03-07 18:39:40.630 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:40:40.644 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:41:40.688 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:42:19.738 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery running

2018-03-07 18:42:19.759 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=5B, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 18:42:19.780 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=91, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 18:42:19.793 [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 5B 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 0D, checksum=0D, error=false) 

2018-03-07 18:42:19.930 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:42:29.941 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 18510: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:42:29.957 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery request NWK_ADDRESS failed. Retry 294, wait 635810ms before retry.

2018-03-07 18:42:40.702 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:42:56.057 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery running

2018-03-07 18:42:56.077 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=5C, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 18:42:56.096 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=92, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 18:42:56.109 [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 5C 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 3C, checksum=3C, error=false) 

2018-03-07 18:42:56.240 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:43:02.628 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery already scheduled or running

2018-03-07 18:43:02.646 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery already scheduled or running

2018-03-07 18:43:02.663 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery already scheduled or running

2018-03-07 18:43:06.254 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 29499: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:43:06.270 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery request NWK_ADDRESS failed. Retry 288, wait 460634ms before retry.

2018-03-07 18:43:40.716 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:44:40.733 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:45:40.748 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:46:22.378 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery running

2018-03-07 18:46:22.398 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=5D, ieeeAddr=00124B000E896A5E, requestType=0, startIndex=0]

2018-03-07 18:46:22.418 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=93, payload=00 5E 6A 89 0E 00 4B 12 00 00 00]

2018-03-07 18:46:22.430 [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 5D 30 1F 0B 00 5E 6A 89 0E 00 4B 12 00 00 00 A1, checksum=A1, error=false) 

2018-03-07 18:46:22.567 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:46:32.582 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:46:32.598 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery request NWK_ADDRESS failed. Retry 271, wait 319839ms before retry.

2018-03-07 18:46:40.765 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:47:40.779 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:48:02.628 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery already scheduled or running

2018-03-07 18:48:02.656 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery already scheduled or running

2018-03-07 18:48:02.673 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery already scheduled or running

2018-03-07 18:48:40.793 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:49:40.807 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:50:40.823 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:50:46.922 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery running

2018-03-07 18:50:46.942 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=5E, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 18:50:46.962 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=94, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 18:50:46.974 [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 5E 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 3E, checksum=3E, error=false) 

2018-03-07 18:50:47.112 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:50:57.126 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 29499: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:50:57.145 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery request NWK_ADDRESS failed. Retry 289, wait 564171ms before retry.

2018-03-07 18:51:40.837 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:51:52.455 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery running

2018-03-07 18:51:52.475 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=5F, ieeeAddr=00124B000E896A5E, requestType=0, startIndex=0]

2018-03-07 18:51:52.495 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=95, payload=00 5E 6A 89 0E 00 4B 12 00 00 00]

2018-03-07 18:51:52.507 [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 5F 30 1F 0B 00 5E 6A 89 0E 00 4B 12 00 00 00 A3, checksum=A3, error=false) 

2018-03-07 18:51:52.647 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:52:02.658 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:52:02.675 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery request NWK_ADDRESS failed. Retry 272, wait 358956ms before retry.

2018-03-07 18:52:40.851 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 18:53:02.627 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery already scheduled or running

2018-03-07 18:53:02.646 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery already scheduled or running

2018-03-07 18:53:02.663 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery already scheduled or running

2018-03-07 18:53:05.785 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery running

2018-03-07 18:53:05.804 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=60, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 18:53:05.824 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=96, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 18:53:05.836 [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 60 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 36, checksum=36, error=false) 

2018-03-07 18:53:05.965 [DEBUG] [31.network.impl.CommandInterfaceImpl] - <-  AF_DATA_SRSP (FE 01 64 01 00 64)

2018-03-07 18:53:15.976 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 18510: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 18:53:15.992 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery request NWK_ADDRESS failed. Retry 295, wait 414470ms before retry.

2018-03-07 18:53:40.880 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job
oysteinkrog commented 6 years ago

I tried CC2531ZNP-Pro-Secure_Standard.hex as well but it seems to be the same



==> /var/log/openhab2/openhab.log <==

2018-03-07 21:14:52.990 [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 9A 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FA, checksum=FA, error=false) 

2018-03-07 21:14:54.115 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:14:54.135 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:14:54.147 [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 9B 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 CD, checksum=CD, error=false) 

2018-03-07 21:14:55.282 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:14:55.296 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:14:56.318 [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 9B 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 CD, checksum=CD, error=false) 

2018-03-07 21:14:57.457 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:14:57.483 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:14:58.507 [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 9B 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 CD, checksum=CD, error=false) 

2018-03-07 21:14:59.632 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:14:59.651 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:04.156 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001AB3773: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:05.695 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0002273EC3: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:05.688 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=9C, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 21:15:05.761 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=156, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 21:15:05.773 [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 9C 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FC, checksum=FC, error=false) 

2018-03-07 21:15:06.910 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:06.925 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:07.225 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=9D, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 21:15:07.263 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=157, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 21:15:08.442 [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 9C 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FC, checksum=FC, error=false) 

2018-03-07 21:15:09.567 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:09.586 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:15:11.098 [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 9C 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FC, checksum=FC, error=false) 

2018-03-07 21:15:12.223 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:12.235 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:12.260 [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 9D 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 CB, checksum=CB, error=false) 

2018-03-07 21:15:13.397 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:13.417 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:14.428 [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 9D 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 CB, checksum=CB, error=false) 

2018-03-07 21:15:15.748 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:15.771 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:15:16.783 [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 9D 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 CB, checksum=CB, error=false) 

2018-03-07 21:15:17.905 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:17.922 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:22.280 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001AB3773: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:23.816 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0002273EC3: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:23.809 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=9E, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 21:15:23.868 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=158, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 21:15:23.904 [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 9E 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FE, checksum=FE, error=false) 

2018-03-07 21:15:25.052 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:25.065 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:25.367 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=9F, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 21:15:25.394 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=159, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 21:15:26.087 [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 9E 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FE, checksum=FE, error=false) 

2018-03-07 21:15:27.217 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:27.237 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:15:28.249 [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 9E 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 FE, checksum=FE, error=false) 

2018-03-07 21:15:29.403 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:29.425 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:29.436 [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 9F 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 C9, checksum=C9, error=false) 

2018-03-07 21:15:30.564 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:30.585 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:31.597 [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 9F 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 C9, checksum=C9, error=false) 

2018-03-07 21:15:32.725 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:32.738 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:15:34.262 [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 9F 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 C9, checksum=C9, error=false) 

2018-03-07 21:15:35.453 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:35.472 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:39.445 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001AB3773: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:40.995 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0002273EC3: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:41.012 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=A0, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 21:15:41.046 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=160, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 21:15:41.065 [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 A0 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 C0, checksum=C0, error=false) 

2018-03-07 21:15:42.185 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:42.205 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:42.543 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=A1, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 21:15:42.571 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=161, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 21:15:43.196 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 21:15:43.218 [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 A0 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 C0, checksum=C0, error=false) 

2018-03-07 21:15:44.408 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:44.426 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:15:45.448 [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 A0 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 C0, checksum=C0, error=false) 

2018-03-07 21:15:46.575 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:46.595 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:46.606 [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 A1 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 F7, checksum=F7, error=false) 

2018-03-07 21:15:47.724 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:47.738 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:48.506 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Configuration received (Coordinator).

2018-03-07 21:15:48.584 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_port >> /dev/ttyACM0.

2018-03-07 21:15:48.626 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_initialise >> true.

2018-03-07 21:15:48.655 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_channel >> -1.

2018-03-07 21:15:48.682 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_panid >> 5873.

2018-03-07 21:15:48.715 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_znp_magicnumber >> 239.

2018-03-07 21:15:48.741 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_extendedpanid >> 78348EBA95BAB413.

2018-03-07 21:15:48.774 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: Unhandled configuration parameter zigbee_networkkey >> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00.

2018-03-07 21:15:48.757 [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 A1 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 F7, checksum=F7, error=false) 

==> /var/log/openhab2/events.log <==

2018-03-07 21:15:49.013 [me.event.ThingUpdatedEvent] - Thing 'zigbee:coordinator_cc2531:a55020c4' has been updated.

==> /var/log/openhab2/openhab.log <==

2018-03-07 21:15:50.152 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:50.162 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:15:51.188 [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 A1 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 F7, checksum=F7, error=false) 

2018-03-07 21:15:52.327 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:52.353 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:15:56.617 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001AB3773: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:57.366 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery running

2018-03-07 21:15:57.403 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0002273EC3: NWK Discovery node rediscovery request failed. Wait before retry.

2018-03-07 21:15:57.415 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=A2, ieeeAddr=00158D0001AB3773, requestType=0, startIndex=0]

2018-03-07 21:15:57.446 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=162, payload=00 73 37 AB 01 00 8D 15 00 00 00]

2018-03-07 21:15:57.502 [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 A2 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 C2, checksum=C2, error=false) 

2018-03-07 21:15:58.160 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0001AB3773: NWK Discovery finishing node rediscovery

2018-03-07 21:15:58.629 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:15:58.645 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:15:58.950 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 00158D0002273EC3: NWK Discovery finishing node rediscovery

2018-03-07 21:15:59.668 [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 A2 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 C2, checksum=C2, error=false) 

2018-03-07 21:16:00.802 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:00.817 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:16:02.339 [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 A2 30 1F 0B 00 73 37 AB 01 00 8D 15 00 00 00 C2, checksum=C2, error=false) 

2018-03-07 21:16:03.475 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:03.506 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:16:13.526 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 29499: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 21:16:13.561 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery request NWK_ADDRESS failed. Retry 307, wait 323289ms before retry.

2018-03-07 21:16:24.992 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:a55020c4

2018-03-07 21:16:25.026 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds.

2018-03-07 21:16:25.051 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=A3, permitDuration=60, tcSignificance=true]

2018-03-07 21:16:25.088 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=163, payload=00 3C 01]

2018-03-07 21:16:25.106 [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 A3 30 1F 03 00 3C 01 AF, checksum=AF, error=false) 

2018-03-07 21:16:26.225 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:26.246 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:16:27.770 [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 A3 30 1F 03 00 3C 01 AF, checksum=AF, error=false) 

2018-03-07 21:16:28.910 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:28.941 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:16:29.969 [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 A3 30 1F 03 00 3C 01 AF, checksum=AF, error=false) 

2018-03-07 21:16:31.158 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:31.182 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:16:31.206 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=A4, permitDuration=60, tcSignificance=true]

2018-03-07 21:16:31.225 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, sequence=164, payload=00 3C 01]

2018-03-07 21:16:31.249 [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 A4 30 1F 03 00 3C 01 AB, checksum=AB, error=false) 

2018-03-07 21:16:32.372 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:32.395 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:16:33.417 [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 A4 30 1F 03 00 3C 01 AB, checksum=AB, error=false) 

2018-03-07 21:16:34.539 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:34.559 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:16:36.080 [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 A4 30 1F 03 00 3C 01 AB, checksum=AB, error=false) 

2018-03-07 21:16:37.193 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:16:37.215 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:16:43.228 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 21:16:59.860 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery running

2018-03-07 21:16:59.899 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=A5, ieeeAddr=00124B000E896A5E, requestType=0, startIndex=0]

2018-03-07 21:16:59.927 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=165, payload=00 5E 6A 89 0E 00 4B 12 00 00 00]

2018-03-07 21:16:59.961 [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 A5 30 1F 0B 00 5E 6A 89 0E 00 4B 12 00 00 00 59, checksum=59, error=false) 

2018-03-07 21:17:01.082 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:17:01.096 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:17:02.123 [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 A5 30 1F 0B 00 5E 6A 89 0E 00 4B 12 00 00 00 59, checksum=59, error=false) 

2018-03-07 21:17:03.252 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:17:03.265 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:17:04.285 [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 A5 30 1F 0B 00 5E 6A 89 0E 00 4B 12 00 00 00 59, checksum=59, error=false) 

2018-03-07 21:17:05.419 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:17:05.450 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:17:15.476 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 21:17:15.501 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery request NWK_ADDRESS failed. Retry 290, wait 255411ms before retry.

2018-03-07 21:17:43.258 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 21:18:02.628 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0001AB3773: Node SVC Discovery already scheduled or running

2018-03-07 21:18:02.670 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00124B000E896A5E: Node SVC Discovery already scheduled or running

2018-03-07 21:18:02.684 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery already scheduled or running

2018-03-07 21:18:23.833 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery running

2018-03-07 21:18:23.891 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65533/0, cluster=0000, TID=A6, ieeeAddr=00158D0002273EC3, requestType=0, startIndex=0]

2018-03-07 21:18:23.921 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65533/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, sequence=166, payload=00 C3 3E 27 02 00 8D 15 00 00 00]

2018-03-07 21:18:23.942 [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 A6 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 F0, checksum=F0, error=false) 

2018-03-07 21:18:25.069 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:18:25.095 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1]

2018-03-07 21:18:26.107 [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 A6 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 F0, checksum=F0, error=false) 

2018-03-07 21:18:27.240 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:18:27.255 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2]

2018-03-07 21:18:28.281 [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 A6 30 1F 0B 00 C3 3E 27 02 00 8D 15 00 00 00 F0, checksum=F0, error=false) 

2018-03-07 21:18:29.426 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response.

2018-03-07 21:18:29.446 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3]

2018-03-07 21:18:39.466 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 18510: Node SVC Discovery NetworkAddressRequest returned null

2018-03-07 21:18:39.522 [DEBUG] [internal.ZigBeeNodeServiceDiscoverer] - 00158D0002273EC3: Node SVC Discovery request NWK_ADDRESS failed. Retry 311, wait 774690ms before retry.

2018-03-07 21:18:43.301 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job

2018-03-07 21:19:43.331 [DEBUG] [core.karaf.internal.FeatureInstaller] - Running scheduled sync job```
cdjackson commented 6 years ago

The device works fine and a few people are using these devices (I have personally tested this with Telegesis and Ember dongles, and maybe with XBee). You need to keep pressing the button while the discovery is taking place as the device has a habbit of sleeping quicker than it should (as is seen by other controllers such as SmartThings).

horgi007 commented 6 years ago

I have the same issue with xiaomi devices.

oysteinkrog commented 6 years ago

I've tried a lot of button pressing now, but it does not seem to work. Is there a specific timing needed?

cdjackson commented 6 years ago

Please discuss on the community forum. These devices are not ZigBee devices so are a bit of a problem, but there are people using them with some constraints, but the forum is the place to discuss your question.

hansaya commented 6 years ago

I have the same issue and I own few Xioami devices. I would like to follow this discussion. @oysteinkrog let us know when you create a discussion and link to it :)

cdjackson commented 6 years ago

Again, the Xiaomi devices, at least the temperature sensors, work fine. This has been discussed a bit on the forum. Some other devices do not work (eg buttons) and will not work in future (most likely).

These devices are not ZigBee devices so they don't necessarily work unfortunately...

As this issue is closed, and as this is not a support forum, I'd suggest to start a discussion on the forum - anyone can do it.

horgi007 commented 6 years ago

I see my two xiaomi devices (temp sens WSDCGQ01LM and button WXKG01LM) in the inbox and I can add to Things but both of them offline. Any idea?

cdjackson commented 6 years ago

Again, the Xiaomi devices, at least the temperature sensors, work fine. This has been discussed a bit on the forum. Some other devices do not work (eg buttons) and will not work in future (most likely). You might need to press the button a few times after association to wake it up so it downloads all the required data.

These devices are not ZigBee devices so they don't necessarily work unfortunately...

As this issue is closed, and as this is not a support forum, I'd suggest to start a discussion on the forum - anyone can do it.