BV ZigBee Dongle: OFFLINE - COMMUNICATION_ERROR after 1-3 days

Skyhawk · January 9, 2020, 8:24am

Hello,

after view days, sometimes only hours, my ZigBee-Dongle switch to “OFFLINE - COMMUNICATION_ERROR”. Can anyone help?

my Setup:

Raspbian Pi 3B+
openHAB 2.5.0/openhabian (based an Debian buster)
Bitron Video ZigBee USB-Dongle (Ember EM35x Coordinator/Ember EM35x NCP)
433 Mhz USB-CUL

/etc/openhab2/things/zigbee_dongle:

  2020-01-08 23:48:20.296 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=1A], lastHopLqi=255, lastHopRssi=-80, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 A6 0A 00 00 10 01]
  2020-01-08 23:48:20.298 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=1A, payload=18 A6 0A 00 00 10 01]
  2020-01-08 23:48:20.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=166, commandId=10]
  2020-01-08 23:48:20.303 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: 11924/3 -> 0/1, cluster=0006, TID=A6, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]
  2020-01-08 23:48:20.305 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: 11924/3 -> 0/1, cluster=0006, TID=A6, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]] 
  2020-01-08 23:48:20.311 [DEBUG] [converter.ZigBeeConverterSwitchOnoff] - 7CB03EAA0A00A37F: ZigBee attribute reports ZclAttribute [cluster=com.zsmartsystems.zigbee.zcl.clusters.ZclOnOffCluster@a558ae, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Wed Jan 08 23:48:20 CET 2020]
  2020-01-08 23:48:20.314 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 7CB03EAA0A00A37F: Channel zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch updated to ON
  2020-01-08 23:48:20.318 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Updating ZigBee channel state zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch to ON
  2020-01-08 23:48:20.325 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:stick:7cb03eaa0a00a37f
  2020-01-08 23:48:20.328 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:stick:7cb03eaa0a00a37f
  2020-01-08 23:48:20.331 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:stick:7cb03eaa0a00a37f in 1830 seconds
  2020-01-08 23:59:00.107 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Command for channel zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch --> OFF [OnOffType]
  2020-01-08 23:59:00.122 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 7CB03EAA0A00A37F: Added transaction to queue, len=1, transaction=ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=OffCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=--]]
  2020-01-08 23:59:00.125 [DEBUG] [transaction.ZigBeeTransactionManager] - 11924/3: Sending ZigBeeTransaction [queueTime=4, state=WAITING, sendCnt=0, command=OffCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=17]]
  2020-01-08 23:59:00.129 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
  2020-01-08 23:59:00.132 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OffCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=17]
  2020-01-08 23:59:00.136 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=23, commandId=0]
  2020-01-08 23:59:00.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0/1, destinationAddress=11924/3, profile=0104, cluster=0006, addressMode=DEVICE, radius=31, apsSecurity=false, apsCounter=17, payload=01 17 00]
  2020-01-08 23:59:00.154 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [status=EMBER_SUCCESS, sequence=1A]
  2020-01-08 23:59:00.183 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [source=11924, sourceEui=7CB03EAA0A00A37F, lastHopLqi=255, lastHopRssi=-82, relayList=]
  2020-01-08 23:59:00.207 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [type=EMBER_OUTGOING_DIRECT, indexOrDestination=11924, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=1A], messageTag=17, status=EMBER_SUCCESS, messageContents=]
  2020-01-08 23:59:00.210 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=17 state=RX_ACK
  2020-01-08 23:59:00.211 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=17, state=RX_ACK, outstanding=1
  2020-01-08 23:59:00.214 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state updated: TID 17 -> RX_ACK == ACKED
  2020-01-08 23:59:00.228 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=1C], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 A7 0A 00 00 10 00]
  2020-01-08 23:59:00.232 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=1C, payload=18 A7 0A 00 00 10 00]
  2020-01-08 23:59:00.235 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=167, commandId=10]
  2020-01-08 23:59:00.237 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: 11924/3 -> 0/1, cluster=0006, TID=A7, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=false]]
  2020-01-08 23:59:00.239 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: 11924/3 -> 0/1, cluster=0006, TID=A7, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=false]] 
  2020-01-08 23:59:00.241 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: 11924/3 -> 0/1, cluster=0006, TID=A7, reports=[Attribute Report: attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=false]] ZigBeeTransaction [queueTime=120, state=ACKED, sendCnt=1, command=OffCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=17]]
  2020-01-08 23:59:00.245 [DEBUG] [converter.ZigBeeConverterSwitchOnoff] - 7CB03EAA0A00A37F: ZigBee attribute reports ZclAttribute [cluster=com.zsmartsystems.zigbee.zcl.clusters.ZclOnOffCluster@a558ae, id=0, name=On Off, dataType=BOOLEAN, lastValue=false, lastReportTime=Wed Jan 08 23:59:00 CET 2020]
  2020-01-08 23:59:00.248 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 7CB03EAA0A00A37F: Channel zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch updated to OFF
  2020-01-08 23:59:00.251 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Updating ZigBee channel state zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch to OFF
  2020-01-08 23:59:00.252 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[EMBER_APS_OPTION_RETRY], groupId=0, sequence=1B], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 17 0B 00 00]
  2020-01-08 23:59:00.255 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=1B, payload=18 17 0B 00 00]
  2020-01-08 23:59:00.258 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Reset timeout for handler with thingUID=zigbee:device:stick:7cb03eaa0a00a37f
  2020-01-08 23:59:00.261 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=23, commandId=11]
  2020-01-08 23:59:00.261 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Canceling timeout task for thingUID=zigbee:device:stick:7cb03eaa0a00a37f
  2020-01-08 23:59:00.263 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - Scheduling timeout task for thingUID=zigbee:device:stick:7cb03eaa0a00a37f in 1830 seconds
  2020-01-08 23:59:00.265 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [On/Off: 11924/3 -> 0/1, cluster=0006, TID=17, commandIdentifier=0, statusCode=SUCCESS]
  2020-01-08 23:59:00.268 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: 11924/3 -> 0/1, cluster=0006, TID=17, commandIdentifier=0, statusCode=SUCCESS] 
  2020-01-08 23:59:00.270 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: 11924/3 -> 0/1, cluster=0006, TID=17, commandIdentifier=0, statusCode=SUCCESS] ZigBeeTransaction [queueTime=149, state=ACKED, sendCnt=1, command=OffCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=17]]
  2020-01-08 23:59:00.277 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [queueTime=155, state=COMPLETE, sendCnt=1, command=OffCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=17]]
  2020-01-08 23:59:00.278 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
  2020-01-08 23:59:00.281 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 7CB03EAA0A00A37F: transactionComplete COMPLETE 0
  2020-01-09 00:00:30.742 [INFO ] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
  2020-01-09 00:00:30.825 [INFO ] [enhab.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:local
! 2020-01-09 00:01:07.735 [WARN ] [e.ember.internal.ash.AshFrameHandler] - ASH: ERROR received (code 81). Disconnecting.
! 2020-01-09 00:01:07.740 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager transport state updated to OFFLINE
! 2020-01-09 00:01:07.744 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to OFFLINE
! 2020-01-09 00:01:07.753 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=OFFLINE
! 2020-01-09 00:01:07.775 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Coordinator status changed to OFFLINE.
! 2020-01-09 00:01:07.779 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Coordinator is unknown or not online.
! 2020-01-09 00:01:07.784 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Polling stopped
! 2020-01-09 00:01:08.772 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager shutdown: networkState=OFFLINE
! 2020-01-09 00:01:08.775 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to SHUTDOWN
! 2020-01-09 00:01:08.779 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=SHUTDOWN
! 2020-01-09 00:01:08.783 [DEBUG] [pp.discovery.ZigBeeNetworkDiscoverer] - Network discovery task: shutdown
! 2020-01-09 00:01:08.788 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 000D6F000DC5596F: Node SVC Discovery: stopped
! 2020-01-09 00:01:08.793 [DEBUG] [iscovery.ZigBeeNodeServiceDiscoverer] - 7CB03EAA0A00A37F: Node SVC Discovery: stopped
! 2020-01-09 00:01:08.796 [DEBUG] [p.discovery.ZigBeeDiscoveryExtension] - DISCOVERY Extension: Shutdown
! 2020-01-09 00:01:08.800 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - Data store: shutting down.
! 2020-01-09 00:01:08.804 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - Ember NCP Shutdown
! 2020-01-09 00:01:08.876 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port '/dev/ttyUSBZigBeeDongle' closed.
! 2020-01-09 00:01:08.880 [DEBUG] [transaction.ZigBeeTransactionManager] - Shutting down transaction manager
! 2020-01-09 00:01:08.886 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Queue shutdown
! 2020-01-09 00:01:08.888 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Queue shutdown
! 2020-01-09 00:01:08.891 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 000D6F000DC5596F: Queue shutdown
! 2020-01-09 00:01:08.894 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 7CB03EAA0A00A37F: Queue shutdown
  2020-01-09 00:01:08.900 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Initialising ZigBee coordinator
  2020-01-09 00:01:08.904 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Default: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=50, maxRetries=2]
  2020-01-09 00:01:08.907 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Broadcast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0]
  2020-01-09 00:01:08.910 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - Multicast: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=3, interTransactionDelay=1200, maxRetries=0]
  2020-01-09 00:01:08.914 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - Mesh Update Period 86400
  2020-01-09 00:01:08.916 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 1280
  2020-01-09 00:01:08.919 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher starting
  2020-01-09 00:01:08.922 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster 1280
  2020-01-09 00:01:08.925 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Adding supported cluster 25
  2020-01-09 00:01:08.927 [DEBUG] [com.zsmartsystems.zigbee.ZigBeeNode ] - ClusterMatcher adding cluster 25
  2020-01-09 00:01:08.931 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - ZigBeeNetworkManager initialize: networkState=UNINITIALISED
  2020-01-09 00:01:08.933 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Network state is updated to INITIALISING
  2020-01-09 00:01:08.938 [DEBUG] [bee.handler.ZigBeeCoordinatorHandler] - null: networkStateUpdated called with state=INITIALISING
  2020-01-09 00:01:08.968 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 000D6F000DC5596F: ZigBee reading network state complete.
  2020-01-09 00:01:08.971 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 000D6F000DC5596F: Data store: Node was restored.
  2020-01-09 00:01:08.973 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 000D6F000DC5596F: Updating node NWK=0
  2020-01-09 00:01:09.278 [DEBUG] [ding.zigbee.internal.ZigBeeDataStore] - 7CB03EAA0A00A37F: ZigBee reading network state complete.
! 2020-01-09 00:01:09.280 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 11924/3: Unsupported cluster 1000 - using ZclCustomCluster
! 2020-01-09 00:01:09.287 [DEBUG] [.zsmartsystems.zigbee.ZigBeeEndpoint] - 11924/3: Unsupported cluster FC0F - using ZclCustomCluster
! 2020-01-09 00:01:09.290 [DEBUG] [atabase.ZigBeeNetworkDatabaseManager] - 7CB03EAA0A00A37F: Data store: Node was restored.
  2020-01-09 00:01:09.292 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - 7CB03EAA0A00A37F: Updating node NWK=11924
  2020-01-09 00:01:09.293 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - EZSP dongle initialize with protocol ASH2.
  2020-01-09 00:01:09.295 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Connecting to serial port [/dev/ttyUSBZigBeeDongle] at 57600 baud, flow control FLOWCONTROL_OUT_XONOFF.
  2020-01-09 00:01:09.316 [DEBUG] [ding.zigbee.handler.ZigBeeSerialPort] - Serial port [/dev/ttyUSBZigBeeDongle] is initialized.
  2020-01-09 00:01:10.385 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspVersionResponse [protocolVersion=4, stackType=2, stackVersion=5800]
  2020-01-09 00:01:10.385 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspVersionResponse [protocolVersion=4, stackType=2, stackVersion=5800]
  2020-01-09 00:01:10.423 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.423 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.464 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=5]
  2020-01-09 00:01:10.466 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=5]
  2020-01-09 00:01:10.506 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=8]
  2020-01-09 00:01:10.506 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=8]
  2020-01-09 00:01:10.527 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.527 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.548 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.548 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.569 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=3000]
  2020-01-09 00:01:10.569 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=3000]
  2020-01-09 00:01:10.590 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=30]
  2020-01-09 00:01:10.590 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=30]
  2020-01-09 00:01:10.611 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.611 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
  2020-01-09 00:01:10.631 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
  2020-01-09 00:01:10.631 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=1]
  2020-01-09 00:01:10.654 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=6]
  2020-01-09 00:01:10.654 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=6]
  2020-01-09 00:01:10.675 [DEBUG] [systems.zigbee.dongle.ember.EmberNcp] - EzspGetConfigurationValueResponse [status=EZSP_SUCCESS, value=0]
[...]
  2020-01-09 03:42:46.273 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=2B, payload=18 B6 0A 00 00 10 00]
  2020-01-09 03:57:41.387 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=2C], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 B7 0A 00 00 10 00]
  2020-01-09 03:57:41.391 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=2C, payload=18 B7 0A 00 00 10 00]
  2020-01-09 04:12:36.510 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=2D], lastHopLqi=255, lastHopRssi=-81, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 B8 0A 00 00 10 00]
  2020-01-09 04:12:36.518 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=2D, payload=18 B8 0A 00 00 10 00]
  2020-01-09 04:27:31.638 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=2E], lastHopLqi=255, lastHopRssi=-81, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 B9 0A 00 00 10 00]
  2020-01-09 04:27:31.644 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=2E, payload=18 B9 0A 00 00 10 00]
  2020-01-09 04:42:26.775 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=2F], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 BA 0A 00 00 10 00]
  2020-01-09 04:42:26.785 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=2F, payload=18 BA 0A 00 00 10 00]
  2020-01-09 04:57:21.880 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=30], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 BB 0A 00 00 10 00]
  2020-01-09 04:57:21.888 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=30, payload=18 BB 0A 00 00 10 00]
  2020-01-09 05:12:17.025 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=31], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 BC 0A 00 00 10 00]
  2020-01-09 05:12:17.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=31, payload=18 BC 0A 00 00 10 00]
  2020-01-09 05:27:12.174 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=32], lastHopLqi=255, lastHopRssi=-81, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 BD 0A 00 00 10 00]
  2020-01-09 05:27:12.182 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=32, payload=18 BD 0A 00 00 10 00]
  2020-01-09 05:30:00.116 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Command for channel zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch --> ON [OnOffType]
  2020-01-09 05:30:00.120 [DEBUG] [transaction.ZigBeeTransactionManager] - 7CB03EAA0A00A37F: Creating new Transaction Queue
  2020-01-09 05:30:00.124 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 7CB03EAA0A00A37F: Set profile to ZigBeeTransactionProfile [maxOutstandingTransactions=2, interTransactionDelay=50, maxRetries=2]
  2020-01-09 05:30:00.126 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 7CB03EAA0A00A37F: Added transaction to queue, len=1, transaction=ZigBeeTransaction [queueTime=0, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=--]]
  2020-01-09 05:30:00.128 [DEBUG] [transaction.ZigBeeTransactionManager] - 11924/3: Sending ZigBeeTransaction [queueTime=3, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0/0 -> 11924/3, cluster=0006, TID=18]]
  2020-01-09 05:30:00.130 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
! 2020-01-09 05:30:00.133 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 7CB03EAA0A00A37F: Exception sending command to channel zigbee:device:stick:7cb03eaa0a00a37f:7CB03EAA0A00A37F_3_switch
! java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3546dd rejected from java.util.concurrent.ScheduledThreadPoolExecutor@ac343[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 31]
! 	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063) ~[?:1.8.0_222]
! 	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830) ~[?:1.8.0_222]
! 	at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:326) ~[?:1.8.0_222]
! 	at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:533) ~[?:1.8.0_222]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager.scheduleTask(ZigBeeTransactionManager.java:504) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransaction.startTimer(ZigBeeTransaction.java:360) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransaction.startTransaction(ZigBeeTransaction.java:209) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager.send(ZigBeeTransactionManager.java:443) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager.sendNextTransaction(ZigBeeTransactionManager.java:669) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager.queueTransaction(ZigBeeTransactionManager.java:371) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.transaction.ZigBeeTransactionManager.sendTransaction(ZigBeeTransactionManager.java:355) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.ZigBeeNetworkManager.sendTransaction(ZigBeeNetworkManager.java:1612) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.ZigBeeNode.sendTransaction(ZigBeeNode.java:857) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.ZigBeeEndpoint.sendTransaction(ZigBeeEndpoint.java:539) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.zcl.ZclCluster.send(ZclCluster.java:273) ~[bundleFile:?]
! 	at com.zsmartsystems.zigbee.zcl.clusters.ZclOnOffCluster.onCommand(ZclOnOffCluster.java:585) ~[bundleFile:?]
! 	at org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchOnoff.handleCommand(ZigBeeConverterSwitchOnoff.java:220) ~[bundleFile:?]
! 	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$3.run(ZigBeeThingHandler.java:721) [bundleFile:?]
! 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
! 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
! 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
  2020-01-09 05:42:07.256 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=33], lastHopLqi=255, lastHopRssi=-81, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 BE 0A 00 00 10 00]
  2020-01-09 05:42:07.263 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=33, payload=18 BE 0A 00 00 10 00]
  2020-01-09 05:57:02.372 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=34], lastHopLqi=255, lastHopRssi=-82, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 BF 0A 00 00 10 00]
  2020-01-09 05:57:02.376 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=34, payload=18 BF 0A 00 00 10 00]
  2020-01-09 06:11:57.509 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=35], lastHopLqi=255, lastHopRssi=-79, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 C0 0A 00 00 10 00]
  2020-01-09 06:11:57.517 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=35, payload=18 C0 0A 00 00 10 00]
  2020-01-09 06:26:52.622 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=36], lastHopLqi=255, lastHopRssi=-81, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 C1 0A 00 00 10 00]
  2020-01-09 06:26:52.628 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=36, payload=18 C1 0A 00 00 10 00]
  2020-01-09 06:41:47.757 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=37], lastHopLqi=255, lastHopRssi=-80, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 C2 0A 00 00 10 00]
  2020-01-09 06:41:47.764 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=37, payload=18 C2 0A 00 00 10 00]
  2020-01-09 06:56:42.876 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=260, clusterId=6, sourceEndpoint=3, destinationEndpoint=1, options=[], groupId=0, sequence=38], lastHopLqi=255, lastHopRssi=-80, sender=11924, bindingIndex=255, addressIndex=255, messageContents=18 C3 0A 00 00 10 00]
  2020-01-09 06:56:42.883 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - Dropping APS: state=INITIALISING, frame=ZigBeeApsFrame [sourceAddress=11924/3, destinationAddress=0/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, apsCounter=38, payload=18 C3 0A 00 00 10 00]

Skyhawk · January 9, 2020, 8:30am

Supplement:
I’m using the ZigBee-dongle with only one ZigBee-thing: a Osram/Levance Outdoor Plug.

chris · January 9, 2020, 9:34am

This error (from memory) is caused by the dongle getting into a confused state. The binding should try to recover this be restarting communications with the dongle, but depending on what has happened in the dongle, it may require a hardware reset.

The exception you see is just the framework closing down and rejecting all the currently queued frames. This in itself is ok.

I spent quite a lot of time discussing this with Silabs and there is no other way out if it requires a hardware reset. Unfortunately as far as I know, no current dongles provide this (even though it is Silabs recommendation).

Skyhawk · January 9, 2020, 9:54am

Ok. On reading the documentation on
-> https://www.openhab.org/addons/bindings/zigbee/
I thought an Ember based USB-Dongle would be the best option (future-proof => ZigBee 3). Maybe it would be a good option, to mention this issue an the documentation-website.
In an other thread recommended the Telegesis-Dongles. But this ones thems not very compatible with ZigBee-Devices.
So, now I’m a little bit confused. Which Dongle would be the best for me? I plan to use Osram/Ledvance, Tradfri, and sensors from Xiaomi Mi Aqara.
Can you give me a hint, which USB-Dongle should I prefere. (I’m located in Germany.)

chris · January 9, 2020, 2:25pm

Absolutely - it is.

An Ember based dongle is definitely the best option.

I have a new dongle here that I’ve built myself using the latest Silabs chipset and it should support both the binding and network sniffer functions and also has a hardware reset available. I currently only have a small number for evaluation and I should get them CE certified before making them available, but I would say once it’s ready it will be the best option, but there’s nothing too much wrong with most of the other Ember devices.

Kim_Andersen · January 9, 2020, 2:38pm

“…too much wrong…”
So they´re just a little wrong

chris · January 9, 2020, 2:48pm

No - they are all fine. In my experience they are the best around, although I’ve not used every device that is out there, but we support a LOT of these devices in many systems (probably many tens of thousands at least) and they work very well.

Skyhawk · January 12, 2020, 3:50pm

@chris:

Somehow it is strange: this is a commercial ZigBee-USB-dongle and it is actually intended primarily for use with “QIVICON Home Base 1” and the “Telekom Speedport Smart”, right? Since these problems do not seem to come in bulk, at least I can not find anything on the web.

If a hardware reset is required, it should actually be enough to unplug the stick and then plug in again. However, in my case this does not help. I have to restart the raspbian pi, so that the ZigBee-USB-dongle starts working again.

Could you provide me with one of your new sticks (prerelease)? I would offer myself as a beta tester.

chris · January 12, 2020, 4:14pm

Possibly. However, this is a standard dongle - there is nothing specific about this for Qivicon, It runs the standard ZigBee firmware from Silabs, so everything is standard.

Qivicon are using the same binding software - I developed this for them and trained their engineers.

Yes, that’s correct.

In this case, it would seem to be a problem with the RPi to me.

At the moment I want to get the remaining driver issues resolved before I release them. I also only have 2 spare at the moment until I get some more made. I’m not really sure that the issue is with the stick though at the moment, so it may not solve the issue.