20-12-19 21:01:21.698 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start 2020-12-19 21:01:22.703 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting 2020-12-19 21:01:22.708 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator 2020-12-19 21:01:22.714 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2020-12-19 21:01:22.718 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=4000, maxRetries=0] 2020-12-19 21:01:22.722 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0] 2020-12-19 21:01:22.725 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED 2020-12-19 21:01:22.729 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING 2020-12-19 21:01:22.732 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2. 2020-12-19 21:01:22.732 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING 2020-12-19 21:01:22.736 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB1] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS. 2020-12-19 21:01:22.778 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyUSB1] is initialized. 2020-12-19 21:01:22.781 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Connect 2020-12-19 21:01:22.785 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:22.785 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler thread started 2020-12-19 21:01:22.788 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:22.792 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspVersionRequest [networkId=0, desiredProtocolVersion=4] 2020-12-19 21:01:22.796 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1 2020-12-19 21:01:24.391 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:24.393 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:25.997 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:25.998 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:27.605 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:27.608 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:29.212 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:29.213 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:30.816 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:30.819 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:32.423 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:32.426 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:32.796 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - Sending EZSP transaction timed out after 10 seconds 2020-12-19 21:01:32.798 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - No response from ezspVersion command 2020-12-19 21:01:32.802 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Version returned null. ASH/EZSP not initialised. 2020-12-19 21:01:32.804 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE 2020-12-19 21:01:32.807 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE 2020-12-19 21:01:34.029 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:34.031 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:35.634 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:35.637 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:37.242 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:37.245 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:37.825 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE 2020-12-19 21:01:37.831 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms 2020-12-19 21:01:37.834 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time 2020-12-19 21:01:37.837 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms 2020-12-19 21:01:37.847 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN 2020-12-19 21:01:37.850 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Shutdown 2020-12-19 21:01:37.852 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN 2020-12-19 21:01:37.854 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown 2020-12-19 21:01:37.858 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler close. 2020-12-19 21:01:37.865 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false, initialised=false, networkStateUp=false 2020-12-19 21:01:37.868 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false ignored. 2020-12-19 21:01:37.873 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler exited. 2020-12-19 21:01:37.880 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler close complete. 2020-12-19 21:01:37.969 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port '/dev/ttyUSB1' closed. 2020-12-19 21:01:37.971 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Shutdown 2020-12-19 21:01:37.973 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown 2020-12-19 21:01:37.975 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown 2020-12-19 21:01:37.978 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler. 2020-12-19 21:01:37.981 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB1' PAN:7a69, EPAN:118E310BECC19219, Channel:0 2020-12-19 21:01:37.983 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds 2020-12-19 21:01:37.989 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start 2020-12-19 21:01:38.991 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting 2020-12-19 21:01:38.993 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator 2020-12-19 21:01:38.999 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=1, interTransactionDelay=50, maxRetries=2] 2020-12-19 21:01:39.003 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=4000, maxRetries=0] 2020-12-19 21:01:39.006 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0] 2020-12-19 21:01:39.010 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED 2020-12-19 21:01:39.013 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING 2020-12-19 21:01:39.017 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Initialize with protocol ASH2. 2020-12-19 21:01:39.017 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING 2020-12-19 21:01:39.020 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSB1] at 115200 baud, flow control FLOWCONTROL_OUT_RTSCTS. 2020-12-19 21:01:39.051 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyUSB1] is initialized. 2020-12-19 21:01:39.055 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler thread started 2020-12-19 21:01:39.055 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Connect 2020-12-19 21:01:39.058 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:39.061 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:39.067 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspVersionRequest [networkId=0, desiredProtocolVersion=4] 2020-12-19 21:01:39.071 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1 2020-12-19 21:01:40.666 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:40.668 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:42.273 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:42.275 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:43.878 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:43.881 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:45.484 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:45.486 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:47.089 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:47.092 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:48.695 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:48.697 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:49.071 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - Sending EZSP transaction timed out after 10 seconds 2020-12-19 21:01:49.076 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - No response from ezspVersion command 2020-12-19 21:01:49.079 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Version returned null. ASH/EZSP not initialised. 2020-12-19 21:01:49.083 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE 2020-12-19 21:01:49.086 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE 2020-12-19 21:01:50.300 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:50.303 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:51.906 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:51.909 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:53.512 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: Reconnect 2020-12-19 21:01:53.516 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameRst [] 2020-12-19 21:01:54.105 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE 2020-12-19 21:01:54.110 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set to 0ms 2020-12-19 21:01:54.113 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Deferred Write Time set less than Max Deferred Write Time 2020-12-19 21:01:54.115 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Max Deferred Write Time set to 0ms 2020-12-19 21:01:54.126 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN 2020-12-19 21:01:54.130 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN 2020-12-19 21:01:54.130 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: Shutdown 2020-12-19 21:01:54.133 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP Dongle: Shutdown 2020-12-19 21:01:54.137 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler close. 2020-12-19 21:01:54.146 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false, initialised=false, networkStateUp=false 2020-12-19 21:01:54.149 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember: Link State change to false ignored. 2020-12-19 21:01:54.158 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler exited. 2020-12-19 21:01:54.160 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - AshFrameHandler close complete. 2020-12-19 21:01:54.243 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port '/dev/ttyUSB1' closed. 2020-12-19 21:01:54.246 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Shutdown 2020-12-19 21:01:54.250 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown 2020-12-19 21:01:54.253 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown 2020-12-19 21:01:54.258 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Initializing ZigBee Ember serial bridge handler. 2020-12-19 21:01:54.264 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - ZigBee Ember Coordinator opening Port:'/dev/ttyUSB1' PAN:7a69, EPAN:118E310BECC19219, Channel:0 2020-12-19 21:01:54.268 [DEBUG] [ng.zigbee.ember.handler.EmberHandler] - Ember end device poll timeout set to (169 * 2^9) = 86528 seconds 2020-12-19 21:01:54.276 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Scheduling ZigBee start 2020-12-19 21:01:55.279 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - ZigBee network starting 2020-12-19 21:01:55.281 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator 2020-12-19 21:01:55.283 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfi 2020-12-20 11:12:38.781 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.initialiseZigBee(ZigBeeCoordinatorHandler.java:425) ~[?:?] at org.openhab.binding.zigbee.handler.ZigBeeCoordinatorHandler.lambda$2(ZigBeeCoordinatorHandler.java:543) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_265] at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_265] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_265] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_265] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]