zwave log

gistfile1.txt

14:07:02.511 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zigbee:coordinator_ember:dd875d4a' has been added.
14:07:02.511 [DEBUG] [zigbee.internal.ZigBeeHandlerFactory] - Creating coordinator handler for org.eclipse.smarthome.core.thing.internal.BridgeImpl@b23ebc2a
14:07:02.534 [DEBUG] [andler.ZigBeeCoordinatorEmberHandler] - Initializing ZigBee Ember serial bridge handler.
14:07:02.534 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_ember:dd875d4a].
14:07:02.534 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel -1
14:07:02.535 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 0
14:07:02.535 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID 0000000000000000
14:07:02.537 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zigbee:coordinator_ember:dd875d4a' changed from UNINITIALIZED to INITIALIZING
14:07:02.541 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
14:07:02.542 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising network
14:07:02.542 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee PAN ID [F4B2].
14:07:07.536 [WARN ] [ome.core.thing.internal.ThingManager] - Initializing handler for thing 'zigbee:coordinator_ember:dd875d4a' takes more than 5000ms.
14:07:07.539 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee extended PAN ID [0F4599F175CFB3C8].
14:07:07.552 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zigbee:coordinator_ember:dd875d4a' has been updated.
14:07:07.559 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zigbee:coordinator_ember:dd875d4a' has been updated.
14:07:07.589 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key String 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
14:07:07.589 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zigbee:coordinator_ember:dd875d4a' has been updated.
14:07:07.589 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key array [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]
14:07:07.590 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Creating random ZigBee network key.
14:07:07.610 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee network key.
14:07:07.610 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key initialised String 5D 04 0A 33 6F E5 B9 94 3F 1A 9C 0F 21 D5 53 B9
14:07:07.611 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key initialised array [93, 4, 10, 51, 111, 229, 185, 148, 63, 26, 156, 15, 33, 213, 83, 185]
14:07:07.611 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key final array [93, 4, 10, 51, 111, 229, 185, 148, 63, 26, 156, 15, 33, 213, 83, 185]
14:07:07.611 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zigbee:coordinator_ember:dd875d4a' has been updated.
14:07:07.622 [DEBUG] [andler.ZigBeeCoordinatorEmberHandler] - ZigBee Coordinator Ember opening Port:'/dev/ttyUSB1' PAN:f4b2, EPAN:0F4599F175CFB3C8, Channel:-1
14:07:07.626 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
14:07:08.628 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
14:07:08.629 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
14:07:08.632 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Creating ZigBee discovery service for zigbee:coordinator_ember:dd875d4a
14:07:08.633 [DEBUG] [bee.discovery.ZigBeeDiscoveryService] - Activating ZigBee discovery service for zigbee:coordinator_ember:dd875d4a
14:07:08.639 [DEBUG] [org.openhab.binding.zigbee          ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=348, service.bundleid=207, service.scope=singleton} - org.openhab.binding.zigbee
14:07:08.663 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Key initialise [93, 4, 10, 51, 111, 229, 185, 148, 63, 26, 156, 15, 33, 213, 83, 185]
14:07:08.667 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize.
14:07:08.671 [INFO ] [andler.ZigBeeCoordinatorEmberHandler] - Connecting to serial port [/dev/ttyUSB1] at 57600
14:07:08.683 [INFO ] [andler.ZigBeeCoordinatorEmberHandler] - Serial port [/dev/ttyUSB1] is initialized.
14:07:09.776 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspVersionResponse [protocolVersion=4, stackType=2, stackVersion=5410]
14:07:09.794 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=5]
14:07:09.804 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:09.814 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:09.822 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=30]
14:07:09.831 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:09.838 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
14:07:09.845 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:09.854 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=8]
14:07:09.868 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:09.876 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=6]
14:07:09.883 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=3000]
14:07:09.890 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:09.891 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SECURITY_LEVEL = 5
14:07:09.891 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_KEY_TABLE_SIZE = 0
14:07:09.891 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_APPLICATION_ZDO_FLAGS = 0
14:07:09.891 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_HOPS = 30
14:07:09.891 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_STACK_PROFILE = 0
14:07:09.891 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SUPPORTED_NETWORKS = 2
14:07:09.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE = 0
14:07:09.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_ADDRESS_TABLE_SIZE = 8
14:07:09.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE = 0
14:07:09.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_END_DEVICE_CHILDREN = 6
14:07:09.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT = 3000
14:07:09.892 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TX_POWER_MODE = 0
14:07:09.899 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_ALLOW_PRECONFIGURED_KEY_JOINS]
14:07:09.912 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_DISALLOW_BINDING_MODIFICATION]
14:07:09.919 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK]
14:07:09.919 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_TRUST_CENTER_POLICY = EZSP_ALLOW_PRECONFIGURED_KEY_JOINS
14:07:09.919 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_BINDING_MODIFICATION_POLICY = EZSP_DISALLOW_BINDING_MODIFICATION
14:07:09.919 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_MESSAGE_CONTENTS_IN_CALLBACK_POLICY = EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK
14:07:09.920 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_SECURITY_LEVEL, value=5]
14:07:09.932 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.933 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_KEY_TABLE_SIZE, value=4]
14:07:09.946 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.946 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_APPLICATION_ZDO_FLAGS, value=1]
14:07:09.959 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.959 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_MAX_HOPS, value=30]
14:07:09.971 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.971 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_STACK_PROFILE, value=2]
14:07:09.978 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.978 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_SUPPORTED_NETWORKS, value=2]
14:07:09.986 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.986 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE, value=16]
14:07:09.994 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:09.994 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_ADDRESS_TABLE_SIZE, value=2]
14:07:10.002 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:10.003 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE, value=2]
14:07:10.011 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:10.011 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_MAX_END_DEVICE_CHILDREN, value=16]
14:07:10.022 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:10.022 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT, value=7680]
14:07:10.029 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:10.030 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueRequest [configId=EZSP_CONFIG_TX_POWER_MODE, value=0]
14:07:10.037 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetConfigurationValueResponse [status=EZSP_SUCCESS]
14:07:10.048 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=5]
14:07:10.055 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=4]
14:07:10.067 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
14:07:10.080 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=30]
14:07:10.088 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
14:07:10.099 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
14:07:10.110 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=16]
14:07:10.118 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
14:07:10.124 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=2]
14:07:10.132 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=16]
14:07:10.143 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=7680]
14:07:10.163 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SECURITY_LEVEL = 5
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_KEY_TABLE_SIZE = 4
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_APPLICATION_ZDO_FLAGS = 1
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_HOPS = 30
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_STACK_PROFILE = 2
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SUPPORTED_NETWORKS = 2
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE = 16
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_ADDRESS_TABLE_SIZE = 2
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE = 2
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_MAX_END_DEVICE_CHILDREN = 16
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT = 7680
14:07:10.163 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Configuration state EZSP_CONFIG_TX_POWER_MODE = 0
14:07:10.175 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
14:07:10.187 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
14:07:10.194 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspSetPolicyResponse [status=EZSP_SUCCESS]
14:07:10.206 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_ALLOW_PRECONFIGURED_KEY_JOINS]
14:07:10.220 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_CHECK_BINDING_MODIFICATIONS_ARE_VALID_ENDPOINT_CLUSTERS]
14:07:10.231 [DEBUG] [ber.internal.EmberStackConfiguration] - EzspGetPolicyResponse [status=EZSP_SUCCESS, decisionId=EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK]
14:07:10.231 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_TRUST_CENTER_POLICY = EZSP_ALLOW_PRECONFIGURED_KEY_JOINS
14:07:10.231 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_BINDING_MODIFICATION_POLICY = EZSP_CHECK_BINDING_MODIFICATIONS_ARE_VALID_ENDPOINT_CLUSTERS
14:07:10.232 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Policy state EZSP_MESSAGE_CONTENTS_IN_CALLBACK_POLICY = EZSP_MESSAGE_TAG_ONLY_IN_CALLBACK
14:07:10.250 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspAddEndpointRequest [endpoint=1, profileId=260, deviceId=0, appFlags=0, inputClusterList=00 01 06, outputClusterList=00 01 06]
14:07:10.261 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspAddEndpointResponse [status=EZSP_SUCCESS]
14:07:10.276 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
14:07:10.283 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspNetworkInitResponse [status=EMBER_NOT_JOINED]
14:07:10.294 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
14:07:10.304 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=0001000000030000]]
14:07:10.304 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Error during retrieval of security parameters: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=0001000000030000]]
14:07:10.305 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize done: Initialised true
14:07:10.305 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - initResponse is NOT_JOINED
14:07:10.306 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - initializeNetwork is true
14:07:10.306 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Can't set channel to -1
14:07:10.306 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle startup.
14:07:10.313 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspNetworkStateResponse [status=EMBER_NO_NETWORK]
14:07:10.313 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP networkStateResponse EMBER_NO_NETWORK
14:07:10.314 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Reinitialising Ember NCP and forming network.
14:07:10.322 [DEBUG] [.internal.EmberNetworkInitialisation] - EzspNetworkStateResponse [status=EMBER_NO_NETWORK]
14:07:10.322 [DEBUG] [.internal.EmberNetworkInitialisation] - EZSP networkStateResponse EMBER_NO_NETWORK
14:07:10.331 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspStartScanResponse [status=EMBER_SUCCESS]
14:07:10.332 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspStartScanResponse [status=EMBER_SUCCESS]
14:07:10.383 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=11, maxRssiValue=-83]
14:07:10.383 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=11, maxRssiValue=-83]
14:07:10.432 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=12, maxRssiValue=-63]
14:07:10.432 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=12, maxRssiValue=-63]
14:07:10.482 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=13, maxRssiValue=-72]
14:07:10.482 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=13, maxRssiValue=-72]
14:07:10.533 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=14, maxRssiValue=-87]
14:07:10.533 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=14, maxRssiValue=-87]
14:07:10.583 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=15, maxRssiValue=-69]
14:07:10.583 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=15, maxRssiValue=-69]
14:07:10.633 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=16, maxRssiValue=-61]
14:07:10.633 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=16, maxRssiValue=-61]
14:07:10.683 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=17, maxRssiValue=-78]
14:07:10.683 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=17, maxRssiValue=-78]
14:07:10.738 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=18, maxRssiValue=-90]
14:07:10.738 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=18, maxRssiValue=-90]
14:07:10.785 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=19, maxRssiValue=-86]
14:07:10.785 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=19, maxRssiValue=-86]
14:07:10.835 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=20, maxRssiValue=-71]
14:07:10.835 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=20, maxRssiValue=-71]
14:07:10.885 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=21, maxRssiValue=-79]
14:07:10.885 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=21, maxRssiValue=-79]
14:07:10.935 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=22, maxRssiValue=-71]
14:07:10.935 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=22, maxRssiValue=-71]
14:07:10.986 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=23, maxRssiValue=-83]
14:07:10.986 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=23, maxRssiValue=-83]
14:07:11.036 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=24, maxRssiValue=-82]
14:07:11.036 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=24, maxRssiValue=-82]
14:07:11.086 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=25, maxRssiValue=-68]
14:07:11.086 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=25, maxRssiValue=-68]
14:07:11.137 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspEnergyScanResultHandler [channel=26, maxRssiValue=-85]
14:07:11.137 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspEnergyScanResultHandler [channel=26, maxRssiValue=-85]
14:07:11.142 [DEBUG] [.internal.EmberNetworkInitialisation] - EzspScanCompleteHandler [channel=6, status=EMBER_SUCCESS]
14:07:11.142 [DEBUG] [.internal.EmberNetworkInitialisation] - Energy scan reports quietest channel is 18
14:07:11.149 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspStartScanResponse [status=EMBER_SUCCESS]
14:07:11.149 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspStartScanResponse [status=EMBER_SUCCESS]
14:07:11.938 [DEBUG] [.internal.EmberNetworkInitialisation] - EzspScanCompleteHandler [channel=255, status=EMBER_SUCCESS]
14:07:11.949 [DEBUG] [.internal.EmberNetworkInitialisation] - EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
14:07:11.949 [DEBUG] [.internal.EmberNetworkInitialisation] - Error during retrieval of network parameters: EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
14:07:11.974 [DEBUG] [.internal.EmberNetworkInitialisation] - EzspSetInitialSecurityStateResponse [status=EMBER_SUCCESS]
14:07:11.986 [DEBUG] [.internal.EmberNetworkInitialisation] - EzspFormNetworkResponse [status=EMBER_INVALID_CALL]
14:07:11.986 [DEBUG] [.internal.EmberNetworkInitialisation] - Error during retrieval of network parameters: EzspFormNetworkResponse [status=EMBER_INVALID_CALL]
14:07:11.998 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetNetworkParametersResponse [status=EMBER_NOT_JOINED, nodeType=EMBER_UNKNOWN_DEVICE, parameters=EmberNetworkParameters [extendedPanId={00 00 00 00 00 00 00 00}, panId=65535, radioTxPower=255, radioChannel=0, joinMethod=EMBER_USE_MAC_ASSOCIATION, nwkManagerId=65535, nwkUpdateId=0, channels=00000000]]
14:07:12.009 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspNetworkStateResponse [status=EMBER_NO_NETWORK]
14:07:12.010 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP networkStateResponse EMBER_NO_NETWORK
14:07:12.030 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=000D000000030000]]
14:07:12.030 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Error during retrieval of security parameters: EzspGetCurrentSecurityStateResponse [status=EMBER_NOT_JOINED, state=EmberCurrentSecurityState [bitmask=[], trustCenterLongAddress=000D000000030000]]
14:07:12.030 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Current Security State = null
14:07:12.030 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle startup done.
14:07:12.031 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Scheduling node discovery
14:07:12.032 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialise done....... 18  65535  0F4599F175CFB3C8
14:07:12.033 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Starting node discovery
14:07:12.035 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zigbee:coordinator_ember:dd875d4a' has been updated.
14:07:12.038 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=00, nwkAddrOfInterest=0, requestType=1, startIndex=0]
14:07:12.038 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - Starting mesh update task with interval of 86400 seconds
14:07:12.058 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=0], messageTag=0, messageContents=00 00 00 01 00]
14:07:12.070 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=0]
14:07:12.070 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=0]
14:07:22.042 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: Starting mesh update
14:07:22.042 [DEBUG] [ee.internal.ZigBeeNetworkMeshMonitor] - 0: ZigBee node not found during mesh update
14:07:22.063 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - Ieee Address for 0 returned null
14:07:22.063 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request IEEE_ADDRESS failed. Wait before retry.
14:07:23.564 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=01, nwkAddrOfInterest=0, requestType=1, startIndex=0]
14:07:23.564 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=1], messageTag=1, messageContents=00 00 00 01 00]
14:07:23.969 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=1]
14:07:23.969 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=1]
14:07:33.569 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - Ieee Address for 0 returned null
14:07:33.570 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request IEEE_ADDRESS failed. Wait before retry.
14:07:35.070 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=02, nwkAddrOfInterest=0, requestType=1, startIndex=0]
14:07:35.071 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=2], messageTag=2, messageContents=00 00 00 01 00]
14:07:35.083 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=2]
14:07:35.083 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=2]
14:07:45.075 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - Ieee Address for 0 returned null
14:07:45.075 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request IEEE_ADDRESS failed. Wait before retry.
14:07:46.576 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: IeeeAddressRequest [0/0 -> 0/0, cluster=0001, TID=03, nwkAddrOfInterest=0, requestType=1, startIndex=0]
14:07:46.577 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EzspSendUnicastRequest [type=EMBER_OUTGOING_DIRECT, indexOrDestination=0, apsFrame=EmberApsFrame [profileId=0, clusterId=1, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=3], messageTag=3, messageContents=00 00 00 01 00]
14:07:46.589 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=3]
14:07:46.589 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Unhandled EZSP Frame: EzspSendUnicastResponse [status=EMBER_NETWORK_DOWN, sequence=3]
14:07:56.581 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - Ieee Address for 0 returned null
14:07:56.582 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Discovery request IEEE_ADDRESS failed. Wait before retry.
14:07:58.082 [DEBUG] [bee.internal.ZigBeeNetworkDiscoverer] - 0: Ending node discovery