2019-07-02 18:00:00.956 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=128, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService, component.id=16} - org.openhab.binding.zigbee 2019-07-02 18:00:00.990 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.converter.ZigBeeChannelConverterProvider}={service.id=129, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeDefaultChannelConverterProvider, component.id=17} - org.openhab.binding.zigbee 2019-07-02 18:00:01.005 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryParticipant}={service.id=130, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.internal.ZigBeeDefaultDiscoveryParticipant, component.id=18} - org.openhab.binding.zigbee 2019-07-02 18:00:01.038 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=132, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.ZigBeeHandlerFactory, component.id=20} - org.openhab.binding.zigbee 2019-07-02 18:00:01.056 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory}={service.id=131, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory, component.id=19} - org.openhab.binding.zigbee 2019-07-02 18:00:01.087 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STOPPING - org.openhab.binding.zigbee 2019-07-02 18:00:01.096 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STOPPED - org.openhab.binding.zigbee 2019-07-02 18:00:01.106 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=133, service.bundleid=247, service.scope=bundle, component.name=org.openhab.binding.zigbee.cc2531.internal.CC2531HandlerFactory, component.id=21} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:01.118 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state 2019-07-02 18:00:01.134 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-07-02 18:00:01.154 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done. 2019-07-02 18:00:01.157 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - Network discovery task: shutdown 2019-07-02 18:00:01.160 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Shutdown 2019-07-02 18:00:01.188 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port '/dev/ttyACM0' closed. 2019-07-02 18:00:06.138 [WARN ] [core.thing.internal.ThingManagerImpl] - Disposing handler for thing 'zigbee:coordinator_cc2531:b571d5fb' takes more than 5000ms. 2019-07-02 18:00:06.155 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=325, service.bundleid=247, service.scope=singleton} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.174 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STOPPING - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.180 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STOPPED - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.284 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBeeDiscoveryService 2019-07-02 18:00:06.289 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=441, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService, component.id=291} - org.openhab.binding.zigbee 2019-07-02 18:00:06.301 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.converter.ZigBeeChannelConverterProvider}={service.id=442, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeDefaultChannelConverterProvider, component.id=292} - org.openhab.binding.zigbee 2019-07-02 18:00:06.314 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryParticipant}={service.id=443, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.internal.ZigBeeDefaultDiscoveryParticipant, component.id=293} - org.openhab.binding.zigbee 2019-07-02 18:00:06.331 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory}={service.id=444, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory, component.id=294} - org.openhab.binding.zigbee 2019-07-02 18:00:06.348 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=445, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.ZigBeeHandlerFactory, component.id=295} - org.openhab.binding.zigbee 2019-07-02 18:00:06.361 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STARTING - org.openhab.binding.zigbee 2019-07-02 18:00:06.368 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STARTED - org.openhab.binding.zigbee 2019-07-02 18:00:06.408 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=446, service.bundleid=247, service.scope=bundle, component.name=org.openhab.binding.zigbee.cc2531.internal.CC2531HandlerFactory, component.id=296} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.429 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STARTING - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.440 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STARTED - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.500 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=447, service.bundleid=247, service.scope=singleton} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:00:06.519 [DEBUG] [.zigbee.cc2531.handler.CC2531Handler] - Initializing ZigBee CC2531 serial bridge handler. 2019-07-02 18:00:06.524 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_cc2531:b571d5fb]. 2019-07-02 18:00:06.539 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11 2019-07-02 18:00:06.547 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 65534 2019-07-02 18:00:06.550 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID 2019-07-02 18:00:06.553 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key 2019-07-02 18:00:06.556 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key 2019-07-02 18:00:06.560 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false 2019-07-02 18:00:06.563 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String 2019-07-02 18:00:06.568 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array 2019-07-02 18:00:06.572 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String 2019-07-02 18:00:06.576 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array 2019-07-02 18:00:06.581 [DEBUG] [.zigbee.cc2531.handler.CC2531Handler] - ZigBee CC2531 Coordinator opening Port:'/dev/ttyACM0' PAN:fffe, EPAN:, Channel:11 2019-07-02 18:00:06.587 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start 2019-07-02 18:00:07.596 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting 2019-07-02 18:00:07.600 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator 2019-07-02 18:00:07.605 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400 2019-07-02 18:00:07.609 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280 2019-07-02 18:00:07.613 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting 2019-07-02 18:00:07.616 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE 2019-07-02 18:00:07.619 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25 2019-07-02 18:00:07.621 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster OTA_UPGRADE 2019-07-02 18:00:07.632 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start. 2019-07-02 18:00:07.658 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - : Node 0 added to the network 2019-07-02 18:00:07.659 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Done. 2019-07-02 18:00:07.661 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - CC2531 transport initialize 2019-07-02 18:00:07.662 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to UNINITIALISED 2019-07-02 18:00:07.663 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyACM0] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS. 2019-07-02 18:00:07.667 [ERROR] [ding.zigbee.handler.ZigBeeSerialPort] - Serial Error: Port /dev/ttyACM0 does not exist. 2019-07-02 18:00:07.666 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=UNINITIALISED 2019-07-02 18:00:07.668 [ERROR] [.cc2531.network.ZigBeeNetworkManager] - Failed to open the dongle. 2019-07-02 18:00:07.670 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE 2019-07-02 18:00:07.673 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE 2019-07-02 18:00:08.701 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state 2019-07-02 18:00:08.717 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-07-02 18:00:08.748 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done. 2019-07-02 18:00:17.650 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:b571d5fb 2019-07-02 18:00:17.666 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee coordinator is offline - aborted scan for zigbee:coordinator_cc2531:b571d5fb 2019-07-02 18:01:02.472 [DEBUG] [org.openhab.binding.zigbee.ember ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=134, service.bundleid=248, service.scope=bundle, component.name=org.openhab.binding.zigbee.ember.internal.EmberHandlerFactory, component.id=22} - org.openhab.binding.zigbee.ember 2019-07-02 18:01:02.478 [DEBUG] [org.openhab.binding.zigbee.ember ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.usbserial.UsbSerialDiscoveryParticipant}={service.id=135, service.bundleid=248, service.scope=bundle, component.name=org.openhab.binding.zigbee.ember.internal.discovery.ZigBeeEmberUsbSerialDiscoveryParticipant, component.id=23} - org.openhab.binding.zigbee.ember 2019-07-02 18:01:02.486 [DEBUG] [org.openhab.binding.zigbee.ember ] - BundleEvent STOPPING - org.openhab.binding.zigbee.ember 2019-07-02 18:01:02.489 [DEBUG] [org.openhab.binding.zigbee.ember ] - BundleEvent STOPPED - org.openhab.binding.zigbee.ember 2019-07-02 18:01:02.493 [DEBUG] [org.openhab.binding.zigbee.telegesis] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.usbserial.UsbSerialDiscoveryParticipant}={service.id=136, service.bundleid=249, service.scope=bundle, component.name=org.openhab.binding.zigbee.telegesis.internal.discovery.ZigBeeTelegesisUsbSerialDiscoveryParticipant, component.id=24} - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:02.498 [DEBUG] [org.openhab.binding.zigbee.telegesis] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=137, service.bundleid=249, service.scope=bundle, component.name=org.openhab.binding.zigbee.telegesis.internal.TelegesisHandlerFactory, component.id=25} - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:02.506 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent STOPPING - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:02.509 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent STOPPED - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:02.521 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=446, service.bundleid=247, service.scope=bundle, component.name=org.openhab.binding.zigbee.cc2531.internal.CC2531HandlerFactory, component.id=296} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:02.535 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state 2019-07-02 18:01:02.547 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-07-02 18:01:02.561 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done. 2019-07-02 18:01:02.564 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.dispose()' on 'org.openhab.binding.zigbee.cc2531.handler.CC2531Handler@12e5e2c': null at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?] at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:325) ~[?:?] 2019-07-02 18:01:02.578 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while disposing handler of thing 'zigbee:coordinator_cc2531:b571d5fb': null at com.zsmartsystems.zigbee.app.discovery.ZigBeeDiscoveryExtension.extensionShutdown(ZigBeeDiscoveryExtension.java:96) ~[?:?] at com.zsmartsystems.zigbee.ZigBeeNetworkManager.shutdown(ZigBeeNetworkManager.java:529) ~[?:?] at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.dispose(ZigBeeCoordinatorHandler.java:325) ~[?:?] 2019-07-02 18:01:02.593 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=447, service.bundleid=247, service.scope=singleton} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:02.622 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STOPPING - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:02.627 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STOPPED - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:02.631 [DEBUG] [org.openhab.binding.zigbee.xbee ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=138, service.bundleid=250, service.scope=bundle, component.name=org.openhab.binding.zigbee.xbee.internal.XBeeHandlerFactory, component.id=26} - org.openhab.binding.zigbee.xbee 2019-07-02 18:01:02.638 [DEBUG] [org.openhab.binding.zigbee.xbee ] - BundleEvent STOPPING - org.openhab.binding.zigbee.xbee 2019-07-02 18:01:02.641 [DEBUG] [org.openhab.binding.zigbee.xbee ] - BundleEvent STOPPED - org.openhab.binding.zigbee.xbee 2019-07-02 18:01:02.645 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=441, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService, component.id=291} - org.openhab.binding.zigbee 2019-07-02 18:01:02.670 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.converter.ZigBeeChannelConverterProvider}={service.id=442, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeDefaultChannelConverterProvider, component.id=292} - org.openhab.binding.zigbee 2019-07-02 18:01:02.679 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryParticipant}={service.id=443, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.internal.ZigBeeDefaultDiscoveryParticipant, component.id=293} - org.openhab.binding.zigbee 2019-07-02 18:01:02.705 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=445, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.ZigBeeHandlerFactory, component.id=295} - org.openhab.binding.zigbee 2019-07-02 18:01:02.752 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent UNREGISTERING - {org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory}={service.id=444, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory, component.id=294} - org.openhab.binding.zigbee 2019-07-02 18:01:02.777 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STOPPING - org.openhab.binding.zigbee 2019-07-02 18:01:02.780 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STOPPED - org.openhab.binding.zigbee 2019-07-02 18:01:04.318 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STOPPING - com.zsmartsystems.zigbee.dongle.cc2531 2019-07-02 18:01:04.320 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STOPPED - com.zsmartsystems.zigbee.dongle.cc2531 2019-07-02 18:01:04.322 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STOPPING - com.zsmartsystems.zigbee.dongle.ember 2019-07-02 18:01:04.324 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STOPPED - com.zsmartsystems.zigbee.dongle.ember 2019-07-02 18:01:04.325 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STOPPING - com.zsmartsystems.zigbee.dongle.telegesis 2019-07-02 18:01:04.327 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STOPPED - com.zsmartsystems.zigbee.dongle.telegesis 2019-07-02 18:01:04.329 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STOPPING - com.zsmartsystems.zigbee.dongle.xbee 2019-07-02 18:01:04.331 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STOPPED - com.zsmartsystems.zigbee.dongle.xbee 2019-07-02 18:01:04.333 [DEBUG] [com.zsmartsystems.zigbee ] - BundleEvent STOPPING - com.zsmartsystems.zigbee 2019-07-02 18:01:04.335 [DEBUG] [com.zsmartsystems.zigbee ] - BundleEvent STOPPED - com.zsmartsystems.zigbee 2019-07-02 18:01:58.773 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee 2019-07-02 18:01:58.854 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=127, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryService, component.id=16} - org.openhab.binding.zigbee 2019-07-02 18:01:58.866 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STARTING - org.openhab.binding.zigbee 2019-07-02 18:01:58.874 [DEBUG] [org.openhab.binding.zigbee ] - BundleEvent STARTED - org.openhab.binding.zigbee 2019-07-02 18:01:58.893 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBeeDiscoveryService 2019-07-02 18:01:59.004 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.converter.ZigBeeChannelConverterProvider}={service.id=128, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeDefaultChannelConverterProvider, component.id=17} - org.openhab.binding.zigbee 2019-07-02 18:01:59.309 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.discovery.ZigBeeDiscoveryParticipant}={service.id=129, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.discovery.internal.ZigBeeDefaultDiscoveryParticipant, component.id=18} - org.openhab.binding.zigbee 2019-07-02 18:01:59.364 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory}={service.id=130, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.converter.ZigBeeChannelConverterFactory, component.id=19} - org.openhab.binding.zigbee 2019-07-02 18:01:59.438 [DEBUG] [org.openhab.binding.zigbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=131, service.bundleid=246, service.scope=bundle, component.name=org.openhab.binding.zigbee.internal.ZigBeeHandlerFactory, component.id=20} - org.openhab.binding.zigbee 2019-07-02 18:01:59.470 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:59.493 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=132, service.bundleid=247, service.scope=bundle, component.name=org.openhab.binding.zigbee.cc2531.internal.CC2531HandlerFactory, component.id=21} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:59.506 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STARTING - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:59.525 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - BundleEvent STARTED - org.openhab.binding.zigbee.cc2531 2019-07-02 18:01:59.559 [DEBUG] [org.openhab.binding.zigbee.ember ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.ember 2019-07-02 18:01:59.575 [DEBUG] [org.openhab.binding.zigbee.ember ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=134, service.bundleid=248, service.scope=bundle, component.name=org.openhab.binding.zigbee.ember.internal.EmberHandlerFactory, component.id=22} - org.openhab.binding.zigbee.ember 2019-07-02 18:01:59.585 [DEBUG] [org.openhab.binding.zigbee.ember ] - BundleEvent STARTING - org.openhab.binding.zigbee.ember 2019-07-02 18:01:59.592 [DEBUG] [org.openhab.binding.zigbee.ember ] - BundleEvent STARTED - org.openhab.binding.zigbee.ember 2019-07-02 18:01:59.630 [DEBUG] [org.openhab.binding.zigbee.ember ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.usbserial.UsbSerialDiscoveryParticipant}={service.id=135, service.bundleid=248, service.scope=bundle, component.name=org.openhab.binding.zigbee.ember.internal.discovery.ZigBeeEmberUsbSerialDiscoveryParticipant, component.id=23} - org.openhab.binding.zigbee.ember 2019-07-02 18:01:59.634 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:59.659 [DEBUG] [org.openhab.binding.zigbee.telegesis] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.usbserial.UsbSerialDiscoveryParticipant}={service.id=136, service.bundleid=249, service.scope=bundle, component.name=org.openhab.binding.zigbee.telegesis.internal.discovery.ZigBeeTelegesisUsbSerialDiscoveryParticipant, component.id=24} - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:59.664 [DEBUG] [org.openhab.binding.zigbee.telegesis] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=137, service.bundleid=249, service.scope=bundle, component.name=org.openhab.binding.zigbee.telegesis.internal.TelegesisHandlerFactory, component.id=25} - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:59.679 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent STARTING - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:59.683 [DEBUG] [org.openhab.binding.zigbee.telegesis] - BundleEvent STARTED - org.openhab.binding.zigbee.telegesis 2019-07-02 18:01:59.694 [DEBUG] [org.openhab.binding.zigbee.xbee ] - BundleEvent [unknown:512] - org.openhab.binding.zigbee.xbee 2019-07-02 18:01:59.710 [DEBUG] [org.openhab.binding.zigbee.xbee ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=138, service.bundleid=250, service.scope=bundle, component.name=org.openhab.binding.zigbee.xbee.internal.XBeeHandlerFactory, component.id=26} - org.openhab.binding.zigbee.xbee 2019-07-02 18:01:59.729 [DEBUG] [org.openhab.binding.zigbee.xbee ] - BundleEvent STARTING - org.openhab.binding.zigbee.xbee 2019-07-02 18:01:59.739 [DEBUG] [org.openhab.binding.zigbee.xbee ] - BundleEvent STARTED - org.openhab.binding.zigbee.xbee 2019-07-02 18:02:27.833 [DEBUG] [org.openhab.binding.zigbee.cc2531 ] - ServiceEvent REGISTERED - {org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler}={service.id=320, service.bundleid=247, service.scope=singleton} - org.openhab.binding.zigbee.cc2531 2019-07-02 18:02:27.899 [DEBUG] [.zigbee.cc2531.handler.CC2531Handler] - Initializing ZigBee CC2531 serial bridge handler. 2019-07-02 18:02:27.902 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_cc2531:b571d5fb]. 2019-07-02 18:02:27.908 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 11 2019-07-02 18:02:27.911 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 65534 2019-07-02 18:02:27.914 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID 2019-07-02 18:02:27.921 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key 2019-07-02 18:02:27.923 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key 2019-07-02 18:02:27.926 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false 2019-07-02 18:02:27.928 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String 2019-07-02 18:02:27.933 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array 2019-07-02 18:02:27.935 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String 2019-07-02 18:02:27.939 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array 2019-07-02 18:02:28.038 [DEBUG] [.zigbee.cc2531.handler.CC2531Handler] - ZigBee CC2531 Coordinator opening Port:'/dev/ttyACM0' PAN:fffe, EPAN:, Channel:11 2019-07-02 18:02:28.054 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start 2019-07-02 18:02:29.060 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting 2019-07-02 18:02:29.062 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator 2019-07-02 18:02:29.126 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400 2019-07-02 18:02:29.138 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280 2019-07-02 18:02:29.146 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting 2019-07-02 18:02:29.374 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE 2019-07-02 18:02:29.378 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25 2019-07-02 18:02:29.379 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster OTA_UPGRADE 2019-07-02 18:02:29.397 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Start. 2019-07-02 18:02:29.557 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - : Node 0 added to the network 2019-07-02 18:02:29.560 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Loading ZigBee network state: Done. 2019-07-02 18:02:29.564 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - CC2531 transport initialize 2019-07-02 18:02:29.579 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyACM0] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS. 2019-07-02 18:02:29.568 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to UNINITIALISED 2019-07-02 18:02:29.592 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=UNINITIALISED 2019-07-02 18:02:29.702 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyACM0] is initialized. 2019-07-02 18:02:31.476 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - CC2531 version is Software=2.6 Product=0 Hardware=3 Transport=2 2019-07-02 18:02:31.616 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING 2019-07-02 18:02:31.621 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING 2019-07-02 18:02:31.984 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise: Previous device configuration was: channel=CHANNEL_11, PanID=31369, EPanId= 2019-07-02 18:02:32.003 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - CC2531 transport startup 2019-07-02 18:02:32.010 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Creating network as Coordinator 2019-07-02 18:02:33.024 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Started as ZigBee Coordinator 2019-07-02 18:02:33.026 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45c0 2019-07-02 18:02:33.018 [INFO ] [.cc2531.network.ZigBeeNetworkManager] - Initialized ZigBee network with existing network state. 2019-07-02 18:02:33.160 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Registered endpoint 1 with profile: 260 2019-07-02 18:02:33.163 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to ONLINE 2019-07-02 18:02:33.165 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Startup 2019-07-02 18:02:33.184 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - Network discovery task: starting 2019-07-02 18:02:33.187 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery scheduling node discovery 2019-07-02 18:02:33.204 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery starting node discovery 2019-07-02 18:02:33.227 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Starting mesh update 2019-07-02 18:02:33.237 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0] 2019-07-02 18:02:33.236 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Adding discoverer for 2019-07-02 18:02:33.236 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - : networkStateUpdated called with state=ONLINE 2019-07-02 18:02:33.281 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: start discovery 2019-07-02 18:02:33.301 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=0, payload=00 00 00 01 00] 2019-07-02 18:02:33.301 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: scheduled [NWK_ADDRESS, NEIGHBORS] 2019-07-02 18:02:33.442 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee Initialise done. channel=CHANNEL_11, PanId=31369 EPanId= 2019-07-02 18:02:33.484 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280 2019-07-02 18:02:33.487 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster IAS_ZONE 2019-07-02 18:02:33.805 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32769, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 9F AD E1 18 00 4B 12 00 00 00 01 00 69 48] 2019-07-02 18:02:33.830 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=, nwkAddrRemoteDev=0, startIndex=0, nwkAddrAssocDevList=[18537]] 2019-07-02 18:02:33.864 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0] 2019-07-02 18:02:33.870 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery IeeeAddressRequest returned IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=, nwkAddrRemoteDev=0, startIndex=0, nwkAddrAssocDevList=[18537]] 2019-07-02 18:02:33.893 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - : Node 0 update 2019-07-02 18:02:33.943 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state 2019-07-02 18:02:33.951 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-07-02 18:02:33.974 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32769, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 9F AD E1 18 00 4B 12 00 00 00 01 00 69 48] 2019-07-02 18:02:33.987 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: IeeeAddressResponse [0/0 -> 0/0, cluster=8001, TID=NULL, status=SUCCESS, ieeeAddrRemoteDev=, nwkAddrRemoteDev=0, startIndex=0, nwkAddrAssocDevList=[18537]] 2019-07-02 18:02:34.145 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done. 2019-07-02 18:02:34.183 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 18537: NWK Discovery scheduling node discovery 2019-07-02 18:02:34.185 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 18537: NWK Discovery starting node discovery 2019-07-02 18:02:34.189 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=01, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:02:34.191 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=18537/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=1, payload=00 69 48 01 00] 2019-07-02 18:02:34.188 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 0: NWK Discovery ending node discovery 2019-07-02 18:02:35.034 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:02:35.045 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=02, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:02:35.048 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=2, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:02:42.188 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=01, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:02:43.121 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=02, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:02:43.139 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:02:43.143 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 1, wait 2222ms before retry. 2019-07-02 18:02:43.692 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=03, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:02:43.695 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=18537/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=3, payload=00 69 48 01 00] 2019-07-02 18:02:45.393 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:02:45.397 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=04, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:02:45.400 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=4, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:02:47.181 [DEBUG] [com.zsmartsystems.zigbee ] - BundleEvent STARTING - com.zsmartsystems.zigbee 2019-07-02 18:02:47.197 [DEBUG] [com.zsmartsystems.zigbee ] - BundleEvent STARTED - com.zsmartsystems.zigbee 2019-07-02 18:02:47.219 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.cc2531 2019-07-02 18:02:47.227 [DEBUG] [m.zsmartsystems.zigbee.dongle.cc2531] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.cc2531 2019-07-02 18:02:47.238 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.ember 2019-07-02 18:02:47.253 [DEBUG] [om.zsmartsystems.zigbee.dongle.ember] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.ember 2019-07-02 18:02:47.271 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.telegesis 2019-07-02 18:02:47.332 [DEBUG] [smartsystems.zigbee.dongle.telegesis] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.telegesis 2019-07-02 18:02:47.345 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTING - com.zsmartsystems.zigbee.dongle.xbee 2019-07-02 18:02:47.366 [DEBUG] [com.zsmartsystems.zigbee.dongle.xbee] - BundleEvent STARTED - com.zsmartsystems.zigbee.dongle.xbee 2019-07-02 18:02:51.692 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=03, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:02:53.287 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=05, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:02:53.291 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=18537/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=5, payload=00 69 48 01 00] 2019-07-02 18:02:53.398 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=04, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:02:53.404 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:02:53.409 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 2, wait 4444ms before retry. 2019-07-02 18:02:57.858 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:02:57.863 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=06, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:02:57.867 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=6, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:03:01.287 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=05, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:03:02.802 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=07, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:03:02.805 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=18537/0, profile=0000, cluster=1, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=7, payload=00 69 48 01 00] 2019-07-02 18:03:05.863 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=06, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:05.875 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:03:05.881 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 3, wait 4444ms before retry. 2019-07-02 18:03:10.331 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:03:10.334 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=08, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:10.336 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=8, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:03:10.802 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: IeeeAddressRequest [0/0 -> 18537/0, cluster=0001, TID=07, nwkAddrOfInterest=18537, requestType=1, startIndex=0] 2019-07-02 18:03:12.311 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - 18537: NWK Discovery ending node discovery 2019-07-02 18:03:16.942 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:b571d5fb 2019-07-02 18:03:16.945 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds. 2019-07-02 18:03:16.949 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=09, permitDuration=60, tcSignificance=true] 2019-07-02 18:03:16.952 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=9, payload=00 3C 01] 2019-07-02 18:03:17.084 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=0A, permitDuration=60, tcSignificance=true] 2019-07-02 18:03:17.088 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=10, payload=00 3C 01] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:03:17.241 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00] 2019-07-02 18:03:17.244 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS] 2019-07-02 18:03:18.096 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:18.100 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:03:18.334 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=08, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:18.337 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:03:18.340 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 4, wait 11110ms before retry. 2019-07-02 18:03:19.739 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45b6 2019-07-02 18:03:19.749 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32822, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00] 2019-07-02 18:03:19.752 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementPermitJoiningResponse [0/0 -> 0/0, cluster=8036, TID=NULL, status=SUCCESS] 2019-07-02 18:03:20.609 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:20.612 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:03:22.621 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:22.628 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:03:29.452 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:03:29.455 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0B, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:29.458 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=11, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:03:30.468 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:30.470 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:03:37.455 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0B, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:37.460 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:03:37.463 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 5, wait 4444ms before retry. 2019-07-02 18:03:41.910 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:03:41.914 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0C, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:41.920 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=12, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:03:42.936 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:42.938 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:03:45.451 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:45.454 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:03:48.016 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:03:48.018 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:03:49.914 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0C, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:03:49.923 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:03:49.926 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 6, wait 15554ms before retry. 2019-07-02 18:04:05.483 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:04:05.489 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0D, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:04:05.495 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=13, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:04:06.510 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:06.511 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:04:09.027 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:09.029 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:11.543 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:11.544 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:04:13.489 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0D, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:04:13.493 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:04:13.495 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 7, wait 11110ms before retry. 2019-07-02 18:04:24.609 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:04:24.614 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0E, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:04:24.620 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=14, payload=00 9F AD E1 18 00 4B 12 00 00 00] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:25.635 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:25.637 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:04:27.648 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:27.651 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:29.666 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:29.669 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:04:32.613 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=0E, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:04:32.618 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:04:32.621 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 8, wait 19998ms before retry. 2019-07-02 18:04:33.406 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:b571d5fb 2019-07-02 18:04:33.410 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds. 2019-07-02 18:04:33.413 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=0F, permitDuration=60, tcSignificance=true] 2019-07-02 18:04:33.421 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=15, payload=00 3C 01] 2019-07-02 18:04:33.554 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=10, permitDuration=60, tcSignificance=true] 2019-07-02 18:04:33.557 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=16, payload=00 3C 01] 2019-07-02 18:04:33.699 [DEBUG] [e.dongle.cc2531.ZigBeeDongleTiCc2531] - Unhandled ZToolPacket type 0x45cb com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:46.450 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Starting ZigBee scan for zigbee:coordinator_cc2531:b571d5fb 2019-07-02 18:04:46.452 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Permit join to 65532/0 for 60 seconds. 2019-07-02 18:04:46.455 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 65532/0, cluster=0036, TID=11, permitDuration=60, tcSignificance=true] 2019-07-02 18:04:46.459 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65532/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=17, payload=00 3C 01] 2019-07-02 18:04:47.465 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:47.469 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:49.480 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:49.482 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:04:50.612 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementPermitJoiningRequest [0/0 -> 0/0, cluster=0036, TID=12, permitDuration=60, tcSignificance=true] 2019-07-02 18:04:50.615 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=54, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=18, payload=00 3C 01] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:51.620 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:51.623 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:04:52.621 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:04:52.625 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=13, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:04:52.628 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=19, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:04:53.633 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:53.640 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:04:55.652 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:55.656 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:04:56.676 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:56.679 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:04:59.195 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:04:59.197 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:05:00.625 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=13, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:05:01.208 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:05:01.210 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:05:11.212 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:05:11.215 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 9, wait 11110ms before retry. 2019-07-02 18:05:22.328 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:05:22.331 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=14, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:05:22.334 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=20, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:05:23.343 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:05:23.345 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:05:30.332 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=14, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:05:30.340 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:05:30.343 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 10, wait 8888ms before retry. 2019-07-02 18:05:39.234 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:05:39.239 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=15, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:05:39.243 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=21, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:05:47.238 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=15, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:05:47.243 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:05:47.246 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 11, wait 28886ms before retry. 2019-07-02 18:06:16.134 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:06:16.137 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=16, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:06:16.141 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=22, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:06:17.153 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:06:17.156 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:06:24.138 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=16, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:06:24.148 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:06:24.152 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed. Retry 12, wait 8888ms before retry. 2019-07-02 18:06:33.044 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:06:33.048 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=17, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:06:33.051 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=65535/0, profile=0000, cluster=0, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=23, payload=00 9F AD E1 18 00 4B 12 00 00 00] 2019-07-02 18:06:41.047 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: NetworkAddressRequest [0/0 -> 65535/0, cluster=0000, TID=17, ieeeAddr=, requestType=0, startIndex=0] 2019-07-02 18:06:41.053 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 0: Node SVC Discovery: NetworkAddressRequest returned null 2019-07-02 18:06:41.057 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NWK_ADDRESS failed after 13 attempts. 2019-07-02 18:06:41.063 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:06:41.067 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=18, startIndex=0] 2019-07-02 18:06:41.071 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=24, payload=00 00] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:06:49.067 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=18, startIndex=0] 2019-07-02 18:06:49.074 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-07-02 18:06:49.076 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS failed. Retry 1, wait 2222ms before retry. 2019-07-02 18:06:51.301 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:06:51.303 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=19, startIndex=0] 2019-07-02 18:06:51.306 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=25, payload=00 00] 2019-07-02 18:06:52.311 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:06:52.313 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:06:55.157 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:06:55.158 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:06:57.170 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:06:57.173 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:06:59.303 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=19, startIndex=0] 2019-07-02 18:06:59.310 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-07-02 18:06:59.313 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS failed. Retry 2, wait 4444ms before retry. 2019-07-02 18:07:03.762 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:07:03.766 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1A, startIndex=0] 2019-07-02 18:07:03.770 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=26, payload=00 00] 2019-07-02 18:07:04.777 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:04.780 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] 2019-07-02 18:07:07.285 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:07.286 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:07:09.794 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:09.796 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:07:11.765 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1A, startIndex=0] 2019-07-02 18:07:11.775 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-07-02 18:07:11.780 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS failed. Retry 3, wait 4444ms before retry. 2019-07-02 18:07:16.234 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:07:16.238 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1B, startIndex=0] 2019-07-02 18:07:16.241 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=27, payload=00 00] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:07:17.247 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:17.249 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:07:24.238 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1B, startIndex=0] 2019-07-02 18:07:24.244 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-07-02 18:07:24.247 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS failed. Retry 4, wait 8888ms before retry. 2019-07-02 18:07:33.137 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:07:33.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1C, startIndex=0] 2019-07-02 18:07:33.143 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=28, payload=00 00] 2019-07-02 18:07:41.140 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction timeout: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1C, startIndex=0] 2019-07-02 18:07:41.153 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [TIMEOUT] 2019-07-02 18:07:41.161 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS failed. Retry 5, wait 4444ms before retry. 2019-07-02 18:07:45.612 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:07:45.616 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1D, startIndex=0] 2019-07-02 18:07:45.620 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=49, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=29, payload=00 00] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:07:46.629 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:46.635 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 1] com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolParseException: Packet checksum failed at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketStream.parsePacket(ZToolPacketStream.java:140) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] at com.zsmartsystems.zigbee.dongle.cc2531.network.packet.ZToolPacketParser.run(ZToolPacketParser.java:107) [236:com.zsmartsystems.zigbee.dongle.cc2531:1.1.6] 2019-07-02 18:07:48.303 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=0/0, destinationAddress=0/0, profile=0000, cluster=32817, addressMode=null, radius=0, apsSecurity=false, apsCounter=0, payload=00 00 01 00 01 9F AD E1 18 00 4B 12 00 8A 73 F8 02 00 8D 15 00 69 48 12 02 01 AA] 2019-07-02 18:07:48.316 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=, extendedAddress=00158D0002F8738A, networkAddress=18537, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]]] 2019-07-02 18:07:49.148 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:49.151 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 2] 2019-07-02 18:07:51.157 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - AF_DATA_REQUEST executed and timed out while waiting for response. 2019-07-02 18:07:51.159 [DEBUG] [.cc2531.network.ZigBeeNetworkManager] - Failed to send AF_DATA_REQUEST [attempt 3] 2019-07-02 18:07:51.162 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction complete: ManagementLqiRequest [0/0 -> 0/0, cluster=0031, TID=1D, startIndex=0] 2019-07-02 18:07:51.167 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest response CommandResult [SUCCESS, ManagementLqiResponse [0/0 -> 0/0, cluster=8031, TID=NULL, status=SUCCESS, neighborTableEntries=1, startIndex=0, neighborTableList=[NeighborTable [extendedPanId=, extendedAddress=00158D0002F8738A, networkAddress=18537, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]]]] 2019-07-02 18:07:51.170 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: ManagementLqiRequest complete [1 neighbors] 2019-07-02 18:07:51.175 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - : Neighbor table updated: [NeighborTable [extendedPanId=, extendedAddress=00158D0002F8738A, networkAddress=18537, deviceType=END_DEVICE, rxOnWhenIdle=RX_OFF, relationship=CHILD, permitJoining=UNKNOWN, depth=1, lqi=170]] 2019-07-02 18:07:51.177 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: request NEIGHBORS successful. Advanced to null. 2019-07-02 18:07:51.180 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: running 2019-07-02 18:07:51.186 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - : Node SVC Discovery: complete 2019-07-02 18:07:51.189 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - : Node 0 update 2019-07-02 18:07:51.191 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state 2019-07-02 18:07:51.204 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Start. 2019-07-02 18:07:51.230 [DEBUG] [nal.ZigBeeNetworkStateSerializerImpl] - Saving ZigBee network state: Done.