Zigbee Coordinator Switch OFF Signal not sent

Hardware Home Automation
1

Hi everyone.

I was successful in binding my own custom HA Light/ON/OFF Zigbee device into OH 3.0.2.
But it looks like that I still have some problems with the status of my device in OH.

The toggle switch in openhab sends only a zigbee command to turn ON.
In the attached example you will notice that the confirmation of the toggle ON was successful. But right after toggle ON, I tried in OH to turn the zigbee device OFF again, which even did not result in a new log entry. OH just did nothing. Any idea?

2021-06-27 17:25:02.043 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 84FD27FFFEE65E1A: Command for channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch --> ON [OnOffType]
2021-06-27 17:25:02.043 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 84FD27FFFEE65E1A: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=0, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> 95B0/1, cluster=0006, TID=--]]
2021-06-27 17:25:02.043 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
2021-06-27 17:25:02.044 [DEBUG] [transaction.ZigBeeTransactionManager] - 95B0/1: Sending ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=1, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> 95B0/1, cluster=0006, TID=68]]
2021-06-27 17:25:02.044 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2021-06-27 17:25:02.044 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OnCommand [On/Off: 0000/0 -> 95B0/1, cluster=0006, TID=68]
2021-06-27 17:25:02.044 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=104, commandId=1]
2021-06-27 17:25:02.044 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=95B0/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=9E, rssi=--, lqi=--, payload=01 68 01]
2021-06-27 17:25:02.044 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=104, ieeeAddress=84FD27FFFEE65E1A, networkAddress=38320, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 68 01]
2021-06-27 17:25:02.045 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 84FD27FFFEE65E1A: Channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch waiting for response to ON
2021-06-27 17:25:02.045 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=68 state=TX_ACK
2021-06-27 17:25:02.045 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=178, ieeeAddress=84FD27FFFEE65E1A, networkAddress=38320, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 68 01]
2021-06-27 17:25:02.045 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=68, state=TX_ACK, outstanding=1
2021-06-27 17:25:02.045 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=178, ieeeAddress=84FD27FFFEE65E1A, networkAddress=38320, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 68 01]
2021-06-27 17:25:02.045 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=95B0, TID=68, event=TX_ACK, state=TRANSMITTED
2021-06-27 17:25:02.049 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 17 11 B2 84 FD 27 FF FE E6 5E 1A 95 B0 01 01 00 06 01 04 00 00 01 68 01 7D
2021-06-27 17:25:02.108 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 17 91 84 FD 27 FF FE E6 5E 1A 95 B0 01 01 00 06 01 04 01 08 68 0B 01 81 1B
2021-06-27 17:25:02.108 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeReceivePacketExplicitEvent [ieeeAddress=84FD27FFFEE65E1A, networkAddress=38320, sourceEndpoint=1, destinationEndpoint=1, clusterId=6, profileId=260, receiveOptions=PACKET_ACKNOWLEDGED, data=08 68 0B 01 81]
2021-06-27 17:25:02.108 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=95B0/1, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=null, radius=0, apsSecurity=false, ackRequest=false, apsCounter=--, rssi=--, lqi=--, payload=08 68 0B 01 81]
2021-06-27 17:25:02.109 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=104, commandId=11]
2021-06-27 17:25:02.109 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [On/Off: 95B0/1 -> 0000/1, cluster=0006, TID=68, commandIdentifier=1, statusCode=UNSUP_CLUSTER_COMMAND]
2021-06-27 17:25:02.109 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: 95B0/1 -> 0000/1, cluster=0006, TID=68, commandIdentifier=1, statusCode=UNSUP_CLUSTER_COMMAND] 
2021-06-27 17:25:02.109 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction response received - waiting TX_ACK: ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=66, state=RESPONDED, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> 95B0/1, cluster=0006, TID=68]]
2021-06-27 17:25:02.140 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B B2 95 B0 00 00 00 7D
2021-06-27 17:25:02.140 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=178, networkAddress=38320, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]
2021-06-27 17:25:02.140 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=68 state=RX_ACK
2021-06-27 17:25:02.140 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=68, state=RX_ACK, outstanding=1
2021-06-27 17:25:02.141 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 84FD27FFFEE65E1A: Channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch received ERROR in response to ON
2021-06-27 17:25:02.141 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=97, state=COMPLETE, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> 95B0/1, cluster=0006, TID=68]]
2021-06-27 17:25:02.141 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2021-06-27 17:25:02.141 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 84FD27FFFEE65E1A: Channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch received SUCCESS in response to ON
2021-06-27 17:25:02.141 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 84FD27FFFEE65E1A: transactionComplete, state=COMPLETE, outstanding=0
2021-06-27 17:25:02.141 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=0, sleepy=0/3
2021-06-27 17:25:02.141 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=95B0, TID=68, event=RX_ACK, state=COMPLETE
2

You need to look early in the chain - ie the UI, or somewhere like this as the command is not even making it to the binding (based on the log above).

3

exactly that is the reason why i am suprised. I configured the device as HA Light ON/OFF Zigbee Device.
And openhab recognizes the device correctly. I expected to see a reaction in the log if I move the test toggle switch in the dialog. But only for the ON toggle the command gets send…

Maybe openhab does not receive the status correctly and does not want to send the “OFF” toggle because it thinks the “ON” toggle state was unsuccessful?

I also noticed the unsup_cluster confirmation, is that crucial in the logs? Or can this be ignored because the ON Toggle was successful?

Regards,

Sebastian

4

I did not create any rules, special configurations. I am still in the very early phase of testing the “thing” creation in openhab…

5

It’s not clear, but I think you are issuing commands from some UI or other? Most UI switch widgets will not issue an OFF command to an Item it thinks is already OFF.

Your events.log will show you what is going on.

6

You might be hitting this bug:

7 
2021-06-28 19:44:31.285 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'test_Switch' received command ON
2021-06-28 19:44:31.285 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'test_Switch' predicted to become OFF
8 
2021-06-28 19:44:39.300 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
2021-06-28 19:44:39.300 [DEBUG] [transaction.ZigBeeTransactionManager] - E855/1: Sending ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=8014, state=WAITING, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> E855/1, cluster=0006, TID=66]]
2021-06-28 19:44:39.300 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2021-06-28 19:44:39.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OnCommand [On/Off: 0000/0 -> E855/1, cluster=0006, TID=66]
2021-06-28 19:44:39.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=102, commandId=1]
2021-06-28 19:44:39.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=E855/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=7E, rssi=--, lqi=--, payload=01 66 01]
2021-06-28 19:44:39.300 [DEBUG] [.zigbee.dongle.xbee.ZigBeeDongleXBee] - XBee send: XBeeTransmitRequestExplicitCommand [frameId=102, ieeeAddress=84FD27FFFEE65E1A, networkAddress=59477, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 66 01]
2021-06-28 19:44:39.300 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=66 state=TX_ACK
2021-06-28 19:44:39.300 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE queue: 1: XBeeTransmitRequestExplicitCommand [frameId=146, ieeeAddress=84FD27FFFEE65E1A, networkAddress=59477, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 66 01]
2021-06-28 19:44:39.300 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=66, state=TX_ACK, outstanding=1
2021-06-28 19:44:39.300 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE: XBeeTransmitRequestExplicitCommand [frameId=146, ieeeAddress=84FD27FFFEE65E1A, networkAddress=59477, sourceEndpoint=1, destinationEndpoint=1, cluster=6, profileId=260, broadcastRadius=0, options=[], data=01 66 01]
2021-06-28 19:44:39.300 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E855, TID=66, event=TX_ACK, state=TRANSMITTED
2021-06-28 19:44:39.304 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - TX XBEE Data: 00 17 11 92 84 FD 27 FF FE E6 5E 1A E8 55 01 01 00 06 01 04 00 00 01 66 01 A7
2021-06-28 19:44:39.348 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE Data: 00 07 8B 92 E8 55 00 00 00 A5
2021-06-28 19:44:39.348 [DEBUG] [ongle.xbee.internal.XBeeFrameHandler] - RX XBEE: XBeeTransmitStatusResponse [frameId=146, networkAddress=59477, transmitRetryCount=0, deliveryStatus=SUCCESS, discoveryStatus=NO_DISCOVERY_OVERHEAD]
2021-06-28 19:44:39.348 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=66 state=RX_ACK
2021-06-28 19:44:39.348 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=66, state=RX_ACK, outstanding=1
2021-06-28 19:44:39.348 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=E855, TID=66, event=RX_ACK, state=ACKED
2021-06-28 19:44:47.316 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=16030, state=FAILED, sendCnt=2, command=OnCommand [On/Off: 0000/0 -> E855/1, cluster=0006, TID=66]]
2021-06-28 19:44:47.316 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2021-06-28 19:44:47.316 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 84FD27FFFEE65E1A: transactionComplete, state=FAILED, outstanding=0
2021-06-28 19:44:47.316 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 84FD27FFFEE65E1A: transactionComplete exceeded max retries 2
2021-06-28 19:44:47.316 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction cancelled: ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=16030, state=CANCELLED, sendCnt=2, command=OnCommand [On/Off: 0000/0 -> E855/1, cluster=0006, TID=66]]
2021-06-28 19:44:47.316 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=84FD27FFFEE65E1A queueTime=16030, state=CANCELLED, sendCnt=2, command=OnCommand [On/Off: 0000/0 -> E855/1, cluster=0006, TID=66]]
2021-06-28 19:44:47.316 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 84FD27FFFEE65E1A: Channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch received TIMEOUT in response to ON
2021-06-28 19:44:47.316 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2021-06-28 19:44:47.316 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 84FD27FFFEE65E1A: transactionComplete but not outstanding, state=CANCELLED, outstanding=0
2021-06-28 19:44:47.316 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 84FD27FFFEE65E1A: Channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch received ERROR in response to ON
2021-06-28 19:44:47.316 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=0, sleepy=0/3
2021-06-28 19:44:47.316 [DEBUG] [converter.ZigBeeBaseChannelConverter] - 84FD27FFFEE65E1A: Channel zigbee:device:03539ad1d6:84fd27fffee65e1a:84FD27FFFEE65E1A_1_switch received SUCCESS in response to ON
2021-06-28 19:44:47.316 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=0, sleepy=0/3
9

Autoupdate’s rejection of the command is usually an indication that the Item is linked to one or more channels that are broken in some way, and so autoupdate considers the command cannot be carried out.

I thought it was the OFF command you are having trouble with, see any of those? No OFF command to Item, no OFF for binding to process.

EDIT - ah wait, Zigbee binding. This has some unusual behaviour - it vetoes autoupdate for some devices as a fallback mode, which explains the non-prediction.
What should happen later, is a real update comes along from the device.
Worth a read -

Possible circumvention is at end of thread.

1 Like
10

Yes, I agree and will test your idea with the autoupdate. Thank you so much for your efforts!
But overall I am getting the feeling that the zigbee bindings are quite unstable, even if I create my own zigbee 3.0 zigbee device based on silicon labs… HA Light ON/OFF Cluster Functionalities.
Do I have to return a custom status value back to OPENHAB? As I see in the logs ACK and ON succeded messages appear correctly. I would assume that the device acts correctly and it´s a problem in the binding of openhab?

11

I know little of the zigbee detail that you speak of.
“Not implementing all possible features” has nothing to do with “unstable”.

12

No - there is no “custom status” required. Zigbee uses a standard, so you just need to return the standard responses (so the network level ACK and the application level response).