2021-11-04 16:16:53.324 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initializing ZigBee network [zigbee:coordinator_ember:ca29040ef2].
2021-11-04 16:16:53.326 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel 0
2021-11-04 16:16:53.326 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - PANID 0
2021-11-04 16:16:53.327 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - EPANID 0000000000000000
2021-11-04 16:16:53.327 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2021-11-04 16:16:53.328 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key 5A 69 67 42 65 65 41 6C 6C 69 61 6E 63 65 30 39
2021-11-04 16:16:53.328 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Config: zigbee_initialise found, initializeNetwork=false
2021-11-04 16:16:53.329 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ExtendedPanId or PanId not set: initializeNetwork=true
2021-11-04 16:16:53.329 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network Key String 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2021-11-04 16:16:53.330 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key initialised 0DF433F26A778D7DCDCAAD6F82EC56B1
2021-11-04 16:16:53.330 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Network key final array 0DF433F26A778D7DCDCAAD6F82EC56B1
2021-11-04 16:16:53.331 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link Key String 5A 69 67 42 65 65 41 6C 6C 69 61 6E 63 65 30 39
2021-11-04 16:16:53.331 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising network
2021-11-04 16:16:53.332 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Channel set to 11.
2021-11-04 16:16:53.343 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee PAN ID [8069].
2021-11-04 16:16:53.349 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Created random ZigBee extended PAN ID [A5DDA45F1AC965E5].
2021-11-04 16:16:53.360 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Link key final array 5A6967426565416C6C69616E63653039
2021-11-04 16:16:53.361 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler.
2021-11-04 16:16:53.362 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'rfc2217://192.168.1.167:8888' PAN:8069, EPAN:A5DDA45F1AC965E5, Channel:11
2021-11-04 16:16:53.363 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds
2021-11-04 16:16:53.364 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start
2021-11-04 16:16:54.365 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting
2021-11-04 16:16:54.366 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
2021-11-04 16:16:54.368 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2]
2021-11-04 16:16:54.369 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=4000, maxRetries=0]
2021-11-04 16:16:54.370 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0]
2021-11-04 16:16:54.371 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - Creating ZigBee persistence folder /var/lib/openhab/zigbee/zigbee_coordinator_ember_ca29040ef2/
2021-11-04 16:16:54.372 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED
2021-11-04 16:16:54.373 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
2021-11-04 16:16:54.374 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2.
2021-11-04 16:16:54.374 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
2021-11-04 16:16:54.375 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Connecting to serial port [rfc2217://192.168.1.167:8888] at 57600 baud, flow control FLOWCONTROL_OUT_RTSCTS.
2021-11-04 16:16:54.380 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Enabling receive timeout is unsupported on [rfc2217://192.168.1.167:8888]
2021-11-04 16:16:54.380 [DEBUG] [nding.zigbee.serial.ZigBeeSerialPort] - Serial port [rfc2217://192.168.1.167:8888] is initialized.
2021-11-04 16:16:54.382 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Connect
2021-11-04 16:16:54.382 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshReceiveParserThread thread started
2021-11-04 16:16:54.383 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect
2021-11-04 16:16:54.383 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst []
2021-11-04 16:16:54.385 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspVersionRequest [networkId=0, desiredProtocolVersion=8]
2021-11-04 16:16:54.386 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:55.465 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameRstAck [version=2, resetCode=11, Reset: Software]
2021-11-04 16:16:56.716 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Connected
2021-11-04 16:16:56.717 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to true, initialised=false, networkStateUp=false
2021-11-04 16:16:56.718 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to true ignored.
2021-11-04 16:16:56.719 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=0, reTx=false, data=B1 00 01 00 00 08]
2021-11-04 16:16:56.727 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=1, reTx=false, data=B1 80 01 00 00 08 02 80 67]
2021-11-04 16:16:56.727 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=0, ackNum=0, reTx=false, data=B1 00 01 00 00 08]
2021-11-04 16:16:56.728 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:56.728 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:56.729 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
2021-11-04 16:16:56.730 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=6780]
2021-11-04 16:16:56.731 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspVersionResponse [networkId=0, protocolVersion=8, stackType=2, stackVersion=6780]
2021-11-04 16:16:56.731 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetStandaloneBootloaderVersionPlatMicroPhyRequest [networkId=0]
2021-11-04 16:16:56.732 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:56.732 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=1, reTx=false, data=B2 00 01 91 00]
2021-11-04 16:16:56.774 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=2, reTx=false, data=B2 80 01 91 00 00 18 04 18 0F]
2021-11-04 16:16:56.775 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=1, ackNum=1, reTx=false, data=B2 00 01 91 00]
2021-11-04 16:16:56.775 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:56.775 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:56.776 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetStandaloneBootloaderVersionPlatMicroPhyResponse [networkId=0, bootloaderVersion=1800, nodePlat=4, nodeMicro=24, nodePhy=15]
2021-11-04 16:16:56.776 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_SOURCE_ROUTE_TABLE_SIZE]
2021-11-04 16:16:56.776 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
2021-11-04 16:16:56.776 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:56.777 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=2, reTx=false, data=B3 00 01 52 00 1A]
2021-11-04 16:16:56.814 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=B3 80 01 52 00 00 C8 00]
2021-11-04 16:16:56.814 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=2, ackNum=2, reTx=false, data=B3 00 01 52 00 1A]
2021-11-04 16:16:56.815 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:56.815 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=200]
2021-11-04 16:16:56.815 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 0
2021-11-04 16:16:56.815 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=200]
2021-11-04 16:16:56.816 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
2021-11-04 16:16:56.816 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_SECURITY_LEVEL]
2021-11-04 16:16:56.818 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:56.819 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=B4 00 01 52 00 0D]
2021-11-04 16:16:56.907 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=4, reTx=false, data=B4 80 01 52 00 00 05 00]
2021-11-04 16:16:56.908 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=3, ackNum=3, reTx=false, data=B4 00 01 52 00 0D]
2021-11-04 16:16:56.909 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:56.909 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:56.909 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
2021-11-04 16:16:56.910 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=5]
2021-11-04 16:16:56.910 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=5]
2021-11-04 16:16:56.910 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_ADDRESS_TABLE_SIZE]
2021-11-04 16:16:56.911 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:56.912 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=false, data=B5 00 01 52 00 05]
2021-11-04 16:16:56.954 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=5, reTx=false, data=B5 80 01 52 00 00 10 00]
2021-11-04 16:16:56.955 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=4, ackNum=4, reTx=false, data=B5 00 01 52 00 05]
2021-11-04 16:16:56.956 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:56.956 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:56.956 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=16]
2021-11-04 16:16:56.956 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
2021-11-04 16:16:56.956 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=16]
2021-11-04 16:16:56.957 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_TRUST_CENTER_ADDRESS_CACHE_SIZE]
2021-11-04 16:16:56.958 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:56.958 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=5, ackNum=5, reTx=false, data=B6 00 01 52 00 19]
2021-11-04 16:16:56.994 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=6, reTx=false, data=B6 80 01 52 00 00 00 00]
2021-11-04 16:16:56.995 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=5, ackNum=5, reTx=false, data=B6 00 01 52 00 19]
2021-11-04 16:16:56.995 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:56.995 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:56.996 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=0]
2021-11-04 16:16:56.996 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=0]
2021-11-04 16:16:56.996 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
2021-11-04 16:16:56.996 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_STACK_PROFILE]
2021-11-04 16:16:56.997 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:56.998 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=6, ackNum=6, reTx=false, data=B7 00 01 52 00 0C]
2021-11-04 16:16:57.075 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=7, reTx=false, data=B7 80 01 52 00 00 00 00]
2021-11-04 16:16:57.076 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=6, ackNum=6, reTx=false, data=B7 00 01 52 00 0C]
2021-11-04 16:16:57.077 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:57.077 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:57.077 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=0]
2021-11-04 16:16:57.077 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
2021-11-04 16:16:57.077 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=0]
2021-11-04 16:16:57.078 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_INDIRECT_TRANSMISSION_TIMEOUT]
2021-11-04 16:16:57.078 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:57.078 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=7, ackNum=7, reTx=false, data=B8 00 01 52 00 12]
2021-11-04 16:16:57.124 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=0, reTx=false, data=B8 80 01 52 00 00 B8 0B]
2021-11-04 16:16:57.125 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=7, ackNum=7, reTx=false, data=B8 00 01 52 00 12]
2021-11-04 16:16:57.125 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:57.125 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:57.126 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=3000]
2021-11-04 16:16:57.126 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=3000]
2021-11-04 16:16:57.126 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
2021-11-04 16:16:57.126 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_MAX_HOPS]
2021-11-04 16:16:57.127 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:57.127 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=0, ackNum=0, reTx=false, data=B9 00 01 52 00 10]
2021-11-04 16:16:57.164 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=1, reTx=false, data=B9 80 01 52 00 00 1E 00]
2021-11-04 16:16:57.164 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=0, ackNum=0, reTx=false, data=B9 00 01 52 00 10]
2021-11-04 16:16:57.165 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:57.165 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:57.165 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
2021-11-04 16:16:57.165 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=30]
2021-11-04 16:16:57.165 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=30]
2021-11-04 16:16:57.165 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_TX_POWER_MODE]
2021-11-04 16:16:57.166 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:57.166 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=1, ackNum=1, reTx=false, data=BA 00 01 52 00 17]
2021-11-04 16:16:57.248 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=2, reTx=false, data=BA 80 01 52 00 00 00 00]
2021-11-04 16:16:57.249 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=1, ackNum=1, reTx=false, data=BA 00 01 52 00 17]
2021-11-04 16:16:57.250 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:57.251 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
2021-11-04 16:16:57.251 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:57.252 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=0]
2021-11-04 16:16:57.252 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=0]
2021-11-04 16:16:57.253 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_SUPPORTED_NETWORKS]
2021-11-04 16:16:57.253 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:57.254 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=2, ackNum=2, reTx=false, data=BB 00 01 52 00 2D]
2021-11-04 16:16:57.294 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=3, reTx=false, data=BB 80 01 52 00 00 01 00]
2021-11-04 16:16:57.295 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=2, ackNum=2, reTx=false, data=BB 00 01 52 00 2D]
2021-11-04 16:16:57.295 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:57.295 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:57.296 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
2021-11-04 16:16:57.296 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=1]
2021-11-04 16:16:57.296 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=1]
2021-11-04 16:16:57.296 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_KEY_TABLE_SIZE]
2021-11-04 16:16:57.297 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:57.298 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=3, ackNum=3, reTx=false, data=BC 00 01 52 00 1E]
2021-11-04 16:16:57.334 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=4, reTx=false, data=BC 80 01 52 00 00 0C 00]
2021-11-04 16:16:57.335 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Frame acked and removed AshFrameData [frmNum=3, ackNum=3, reTx=false, data=BC 00 01 52 00 1E]
2021-11-04 16:16:57.335 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH added EZSP frame to receive queue. Queue length 1
2021-11-04 16:16:57.335 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH took EZSP frame from receive queue. Queue length 0
2021-11-04 16:16:57.336 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
2021-11-04 16:16:57.336 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=12]
2021-11-04 16:16:57.336 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [networkId=0, status=EZSP_SUCCESS, value=12]
2021-11-04 16:16:57.337 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspGetConfigurationValueRequest [networkId=0, configId=EZSP_CONFIG_APPLICATION_ZDO_FLAGS]
2021-11-04 16:16:57.337 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1
2021-11-04 16:16:57.338 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=false, data=BD 00 01 52 00 2A]
2021-11-04 16:16:57.372 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameNak [ackNum=4, notRdy=false]
2021-11-04 16:16:57.372 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Retry Sent Queue Length 1
2021-11-04 16:16:57.373 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=true, data=BD 00 01 52 00 2A]
2021-11-04 16:16:57.845 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Retry Sent Queue Length 1
2021-11-04 16:16:57.846 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=true, data=BD 00 01 52 00 2A]
2021-11-04 16:16:58.789 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Retry Sent Queue Length 1
2021-11-04 16:16:58.790 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=true, data=BD 00 01 52 00 2A]
2021-11-04 16:17:00.675 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Retry Sent Queue Length 1
2021-11-04 16:17:00.676 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=true, data=BD 00 01 52 00 2A]
2021-11-04 16:17:03.877 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Retry Sent Queue Length 1
2021-11-04 16:17:03.878 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=true, data=BD 00 01 52 00 2A]
2021-11-04 16:17:07.079 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Retry Sent Queue Length 1
2021-11-04 16:17:07.079 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=4, ackNum=4, reTx=true, data=BD 00 01 52 00 2A]
2021-11-04 16:17:07.337 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - Sending EZSP transaction timed out after 10 seconds
2021-11-04 16:17:07.339 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.NullPointerException: null
	at com.zsmartsystems.zigbee.dongle.ember.EmberNcp.getConfiguration(EmberNcp.java:446) ~[?:?]
	at com.zsmartsystems.zigbee.dongle.ember.internal.EmberStackConfiguration.getConfiguration(EmberStackConfiguration.java:72) ~[?:?]
	at com.zsmartsystems.zigbee.dongle.ember.ZigBeeDongleEzsp.initialize(ZigBeeDongleEzsp.java:430) ~[?:?]
	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.initialize(ZigBeeNetworkManager.java:420) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.initialiseZigBee(ZigBeeCoordinatorHandler.java:433) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.lambda$2(ZigBeeCoordinatorHandler.java:559) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
2021-11-04 16:17:10.280 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Error number of retries exceeded [6].
2021-11-04 16:17:10.281 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Disconnected!
2021-11-04 16:17:10.281 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler close.
2021-11-04 16:17:10.282 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false, initialised=false, networkStateUp=false
2021-11-04 16:17:10.283 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false ignored.
2021-11-04 16:17:10.285 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshReceiveParserThread exited.
2021-11-04 16:17:10.285 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler close complete.