openhab / org.openhab.binding.zigbee

openHAB binding for ZigBee
Eclipse Public License 2.0
73 stars 111 forks source link

Zigbee 4-gang switch toggles all gangs at once #830

Open stvred opened 4 months ago

stvred commented 4 months ago

Problem

Hi, i have a TS0004 4-gang switch and I have problems. When I press the physical button, everything works good. When i press button from OpenHAB, ON first channel they all 4 turn on, with turning off it’s the same

2024-02-13 13:17:13.599 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Unknown_ZigBee_Device_A4C138AB43A12D54_A4C138AB43A12D54_1_Switch' received command ON
2024-02-13 13:17:13.651 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Unknown_ZigBee_Device_A4C138AB43A12D54_A4C138AB43A12D54_1_Switch' changed from OFF to ON
2024-02-13 13:17:13.842 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Unknown_ZigBee_Device_A4C138AB43A12D54_A4C138AB43A12D54_2_Switch' changed from OFF to ON
2024-02-13 13:17:14.043 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Unknown_ZigBee_Device_A4C138AB43A12D54_A4C138AB43A12D54_3_Switch' changed from OFF to ON
2024-02-13 13:17:14.243 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Unknown_ZigBee_Device_A4C138AB43A12D54_A4C138AB43A12D54_4_Switch' changed from OFF to ON

I tried to find a solution to this problem on the Internet, but without success.

Configuration

Configuration Description
Coordinator used Zigbee 3.0 USB Dongle Plus V2
openHAB version openHAB 4.1.1 Release Build
Hardware
Memory
Java version openjdk version "17.0.10" 2024-01-16 LTS
Devices

Logs

openhab> openhab:zigbee ncpversion Ember NCP version 6.10.3.0, EZSP version 8

openhab> openhab:zigbee ncpstate

Ember NCP state     : EMBER_JOINED_NETWORK
Local Node Type     : EMBER_COORDINATOR
IEEE Address        : 6C5CB1FFFEFC71E4
Custom IEEE Address : FFFFFFFFFFFFFFFF
NWK Address         : 0000
Network PAN Id      : 1DCF
Network EPAN Id     : EFDF9CE60229DD43
Radio Channel       : 11
Network Manager Id  : 0000
Radio TX Power      : -1
Join Method         : EMBER_USE_MAC_ASSOCIATION
Board Name          :
Manufacturer Name   :
Stack Version       : 6.10.3.0
Custom Version      :

openhab:zigbee nodes

Total known nodes in network: 5
Network  Addr  IEEE Address      Logical Type  State      EP   Profile                    Device Type                Manufacturer     Model
      0  0000  6C5CB1FFFEFC71E4  COORDINATOR   ONLINE
  21126  5286  A4C13827AA7C9A44  ROUTER        ONLINE      1  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT               _TZ3000_lmlsduws  TS0002
                                                           2  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT
                                                         242  ZIGBEE_GREEN_POWER         0061
  32992  80E0  A4C138661985071E  ROUTER        ONLINE      1  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT               _TZ3000_lmlsduws  TS0002
                                                           2  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT
                                                         242  ZIGBEE_GREEN_POWER         0061
  35482  8A9A  A4C1381B4C2AE709  END_DEVICE    ONLINE      1  ZIGBEE_HOME_AUTOMATION     TEMPERATURE_SENSOR         _TZ3000_bjawzodf  TY0201
  53771  D20B  A4C138AB43A12D54  ROUTER        ONLINE      1  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT               _TZ3000_5ajpkyq6  TS0004
                                                           2  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT
                                                           3  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT
                                                           4  ZIGBEE_HOME_AUTOMATION     ON_OFF_LIGHT
                                                         242  ZIGBEE_GREEN_POWER         0061

log:set debug org.openhab.binding.zigbee log:set debug com.zsmartsystems.zigbee

2024-02-12 12:08:57.973 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - A4C138AB43A12D54: Command for channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch --> ON [OnOffType]
2024-02-12 12:08:57.974 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - A4C138AB43A12D54: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=A4C138AB43A12D54 queueTime=0, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> D20B/1, cluster=0006, TID=--]]
2024-02-12 12:08:57.974 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
2024-02-12 12:08:57.974 [DEBUG] [transaction.ZigBeeTransactionManager] - D20B/1: Sending ZigBeeTransaction [ieeeAddress=A4C138AB43A12D54 queueTime=1, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> D20B/1, cluster=0006, TID=F2]]
2024-02-12 12:08:57.974 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2024-02-12 12:08:57.974 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OnCommand [On/Off: 0000/0 -> D20B/1, cluster=0006, TID=F2]
2024-02-12 12:08:57.974 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=F2, commandId=1]
2024-02-12 12:08:57.974 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=D20B/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=66, rssi=--, lqi=--, payload=01 F2 01]
2024-02-12 12:08:57.974 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch waiting for response to ON
2024-02-12 12:08:57.974 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=D20B, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=66], messageTag=F2, messageContents=01 F2 01]
2024-02-12 12:08:57.975 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameData [frmNum=7, ackNum=0, reTx=false, data=5B 00 01 34 00 00 0B D2 04 01 06 00 01 01 40 11 00 00 66 F2 03 01 F2 01]
2024-02-12 12:08:57.982 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=0, ackNum=0, reTx=false, data=5B 80 01 34 00 00 FA]
2024-02-12 12:08:57.983 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=1, notRdy=false]
2024-02-12 12:08:57.983 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=FA]
2024-02-12 12:08:58.009 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=1, ackNum=0, reTx=false, data=5B 90 01 3F 00 00 0B D2 04 01 06 00 01 01 40 11 00 00 FA F2 00 00]
2024-02-12 12:08:58.009 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=2, notRdy=false]
2024-02-12 12:08:58.009 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=D20B, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY, EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY], groupId=0, sequence=FA], messageTag=F2, status=EMBER_SUCCESS, messageContents=]
2024-02-12 12:08:58.010 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=F2 state=RX_ACK
2024-02-12 12:08:58.010 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=F2, state=RX_ACK, outstanding=1
2024-02-12 12:08:58.010 [DEBUG] [zigbee.transaction.ZigBeeTransaction] - Transaction state changed: nwk=D20B, TID=F2, event=RX_ACK, state=ACKED
2024-02-12 12:08:58.029 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=2, ackNum=0, reTx=false, data=5B 90 01 45 00 00 04 01 06 00 01 01 00 01 00 00 10 80 BC 0B D2 FF FF 05 18 F2 0B 01 00 02]
2024-02-12 12:08:58.029 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=3, notRdy=false]
2024-02-12 12:08:58.030 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=10], lastHopLqi=128, lastHopRssi=-68, sender=D20B, bindingIndex=255, addressIndex=255, messageContents=18 F2 0B 01 00]
2024-02-12 12:08:58.030 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=D20B/1, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=10, rssi=-68, lqi=80, payload=18 F2 0B 01 00]
2024-02-12 12:08:58.030 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=3, ackNum=0, reTx=false, data=5B 90 01 45 00 00 04 01 06 00 01 01 00 01 00 00 11 80 BC 0B D2 FF FF 07 18 07 0A 00 00 10 01 02]
2024-02-12 12:08:58.030 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node update. NWK Address=NULL
2024-02-12 12:08:58.030 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=4, notRdy=false]
2024-02-12 12:08:58.030 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node D20B is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138AB43A12D54, NWK=----, endpoints=[]]
2024-02-12 12:08:58.030 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=F2, commandId=11]
2024-02-12 12:08:58.030 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [On/Off: D20B/1 -> 0000/1, cluster=0006, TID=F2, commandIdentifier=1, statusCode=SUCCESS]
2024-02-12 12:08:58.030 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: D20B/1 -> 0000/1, cluster=0006, TID=F2, commandIdentifier=1, statusCode=SUCCESS] 
2024-02-12 12:08:58.030 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=11], lastHopLqi=128, lastHopRssi=-68, sender=D20B, bindingIndex=255, addressIndex=255, messageContents=18 07 0A 00 00 10 01]
2024-02-12 12:08:58.030 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=A4C138AB43A12D54 queueTime=57, state=COMPLETE, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> D20B/1, cluster=0006, TID=F2]]
2024-02-12 12:08:58.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=D20B/1, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=11, rssi=-68, lqi=80, payload=18 07 0A 00 00 10 01]
2024-02-12 12:08:58.030 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch received SUCCESS in response to ON
2024-02-12 12:08:58.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node update. NWK Address=NULL
2024-02-12 12:08:58.031 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
2024-02-12 12:08:58.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node D20B is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138AB43A12D54, NWK=----, endpoints=[]]
2024-02-12 12:08:58.031 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - A4C138AB43A12D54: transactionComplete, state=COMPLETE, outstanding=0
2024-02-12 12:08:58.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=07, commandId=10]
2024-02-12 12:08:58.031 [DEBUG] [transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=0, sleepy=0/3
2024-02-12 12:08:58.031 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: D20B/1 -> 0000/1, cluster=0006, TID=07, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
2024-02-12 12:08:58.031 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch updated to ON
2024-02-12 12:08:58.031 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: D20B/1 -> 0000/1, cluster=0006, TID=07, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]] 
2024-02-12 12:08:58.031 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - A4C138AB43A12D54: Updating ZigBee channel state zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch to ON
2024-02-12 12:08:58.031 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.031 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.031 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54 in 1830 seconds
2024-02-12 12:08:58.031 [DEBUG] [converter.ZigBeeConverterSwitchOnoff] - A4C138AB43A12D54: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Feb 12 12:08:58 MSK 2024, implemented=true]
2024-02-12 12:08:58.032 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch updated to ON
2024-02-12 12:08:58.032 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - A4C138AB43A12D54: Updating ZigBee channel state zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_1_switch to ON
2024-02-12 12:08:58.032 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.032 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.032 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54 in 1830 seconds
2024-02-12 12:08:58.221 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=4, ackNum=0, reTx=false, data=5B 90 01 45 00 00 04 01 06 00 02 01 00 01 00 00 12 84 BD 0B D2 FF FF 07 18 08 0A 00 00 10 01 02]
2024-02-12 12:08:58.221 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=5, notRdy=false]
2024-02-12 12:08:58.221 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=2, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=12], lastHopLqi=132, lastHopRssi=-67, sender=D20B, bindingIndex=255, addressIndex=255, messageContents=18 08 0A 00 00 10 01]
2024-02-12 12:08:58.221 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=D20B/2, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=12, rssi=-67, lqi=84, payload=18 08 0A 00 00 10 01]
2024-02-12 12:08:58.221 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node update. NWK Address=NULL
2024-02-12 12:08:58.221 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node D20B is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138AB43A12D54, NWK=----, endpoints=[]]
2024-02-12 12:08:58.222 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=08, commandId=10]
2024-02-12 12:08:58.222 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: D20B/2 -> 0000/1, cluster=0006, TID=08, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
2024-02-12 12:08:58.222 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: D20B/2 -> 0000/1, cluster=0006, TID=08, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]] 
2024-02-12 12:08:58.222 [DEBUG] [converter.ZigBeeConverterSwitchOnoff] - A4C138AB43A12D54: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Feb 12 12:08:58 MSK 2024, implemented=true]
2024-02-12 12:08:58.222 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_2_switch updated to ON
2024-02-12 12:08:58.222 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - A4C138AB43A12D54: Updating ZigBee channel state zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_2_switch to ON
2024-02-12 12:08:58.222 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.222 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.222 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54 in 1830 seconds
2024-02-12 12:08:58.422 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=5, ackNum=0, reTx=false, data=5B 90 01 45 00 00 04 01 06 00 03 01 00 01 00 00 13 8C BF 0B D2 FF FF 07 18 09 0A 00 00 10 01 02]
2024-02-12 12:08:58.422 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=6, notRdy=false]
2024-02-12 12:08:58.422 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=3, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=13], lastHopLqi=140, lastHopRssi=-65, sender=D20B, bindingIndex=255, addressIndex=255, messageContents=18 09 0A 00 00 10 01]
2024-02-12 12:08:58.422 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=D20B/3, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=13, rssi=-65, lqi=8C, payload=18 09 0A 00 00 10 01]
2024-02-12 12:08:58.422 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node update. NWK Address=NULL
2024-02-12 12:08:58.422 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node D20B is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138AB43A12D54, NWK=----, endpoints=[]]
2024-02-12 12:08:58.422 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=09, commandId=10]
2024-02-12 12:08:58.422 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: D20B/3 -> 0000/1, cluster=0006, TID=09, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
2024-02-12 12:08:58.423 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: D20B/3 -> 0000/1, cluster=0006, TID=09, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]] 
2024-02-12 12:08:58.423 [DEBUG] [converter.ZigBeeConverterSwitchOnoff] - A4C138AB43A12D54: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Feb 12 12:08:58 MSK 2024, implemented=true]
2024-02-12 12:08:58.423 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_3_switch updated to ON
2024-02-12 12:08:58.423 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - A4C138AB43A12D54: Updating ZigBee channel state zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_3_switch to ON
2024-02-12 12:08:58.423 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.423 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.423 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54 in 1830 seconds
2024-02-12 12:08:58.622 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=6, ackNum=0, reTx=false, data=5B 90 01 45 00 00 04 01 06 00 04 01 00 01 00 00 14 8C BF 0B D2 FF FF 07 18 0A 0A 00 00 10 01 02]
2024-02-12 12:08:58.623 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=7, notRdy=false]
2024-02-12 12:08:58.623 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=4, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=14], lastHopLqi=140, lastHopRssi=-65, sender=D20B, bindingIndex=255, addressIndex=255, messageContents=18 0A 0A 00 00 10 01]
2024-02-12 12:08:58.623 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=D20B/4, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=14, rssi=-65, lqi=8C, payload=18 0A 0A 00 00 10 01]
2024-02-12 12:08:58.623 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node update. NWK Address=NULL
2024-02-12 12:08:58.623 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - A4C138AB43A12D54: Node D20B is not updated from ZigBeeNode [state=ONLINE, IEEE=A4C138AB43A12D54, NWK=----, endpoints=[]]
2024-02-12 12:08:58.623 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=0A, commandId=10]
2024-02-12 12:08:58.623 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: D20B/4 -> 0000/1, cluster=0006, TID=0A, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
2024-02-12 12:08:58.623 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: D20B/4 -> 0000/1, cluster=0006, TID=0A, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]] 
2024-02-12 12:08:58.624 [DEBUG] [converter.ZigBeeConverterSwitchOnoff] - A4C138AB43A12D54: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Mon Feb 12 12:08:58 MSK 2024, implemented=true]
2024-02-12 12:08:58.624 [DEBUG] [converter.ZigBeeBaseChannelConverter] - A4C138AB43A12D54: Channel zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_4_switch updated to ON
2024-02-12 12:08:58.624 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - A4C138AB43A12D54: Updating ZigBee channel state zigbee:device:bbd459ca36:a4c138ab43a12d54:A4C138AB43A12D54_4_switch to ON
2024-02-12 12:08:58.624 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.624 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54
2024-02-12 12:08:58.624 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:bbd459ca36:a4c138ab43a12d54 in 1830 seconds
stvred commented 4 months ago

I found a similar problem, but it was solved by abandoning Binding and switching to z2m link

cdjackson commented 4 months ago

If I look at the log you provided, it looks like the binding sends a single command to the device on endpoint 1, and the device turns on all switches -:

image

This seems not normal from the device, so I am not sure why it is doing that.

stvred commented 4 months ago

Yes, at first time it also look to me that the problem was in the device, change it and you will be happy. But as it turned out, this is not actually the problem. I put together a circuit link to which I published above (OH-mqttBinding-mosquitto-zidbee2mqtt-coordinator-device), and the device works correctly, all channels switch independently and everything works correctly. So, as it turned out, the problem is not in the device, but in the fact that in the circuit (OH-zigbeeBinging-coordinator-device) it sends a command to the coordinator for the device, and the device activates all channels at the same time. Also, I looked for similar problems in similar projects and found them in HA and zigbee2mqtt and judging by the messages, an update was released that solved problem.

cdjackson commented 4 months ago

Maybe there's a config setting in the device to change it's functionality - I don't know. To me, what the binding is doing by sending a single command to a single endpoint should result in a single switch coming on. This all looks fine. If the device has special, or non-standard functions, then unfortunately I'm not aware of this. You'd need to find out what the non-standard feature is before anything can be done here.

stvred commented 4 months ago

Unfortunately, I don’t have an additional device to sniff the transfer from the coordinator to the device, I only see logs. The logs that I see are the debug log between the binding and the coordinator. If I can get some additional data in this connection, then tell me how to do it. In conjunction with Z2M at the mqtt level, i see that depending on the channel, a different command is transmitted, here is an example: payload{"indicator_mode":null,"linkquality":152,"power_on_behavior":null,"state_l1":"ON","state_l2":"OFF","state_l3":"OFF","state_l4":"OFF","switch_type":"toggle"}' payload{"indicator_mode":null,"linkquality":152,"power_on_behavior":null,"state_l1":"OFF","state_l2":"OFF","state_l3":"OFF","state_l4":"OFF","switch_type":"toggle"}' payload{"indicator_mode":null,"linkquality":152,"power_on_behavior":null,"state_l1":"OFF","state_l2":"ON","state_l3":"OFF","state_l4":"OFF","switch_type":"toggle"}' payload{"indicator_mode":null,"linkquality":152,"power_on_behavior":null,"state_l1":"OFF","state_l2":"OFF","state_l3":"OFF","state_l4":"OFF","switch_type":"toggle"}'

It seems to me that the problem is that the binding sends a command to the device in the payload with one command for one channel, and the device waits for four and interprets this command for all channels. I think the device receives the state of all four channels at once in one command. But these are my thoughts ;) based on the Z2M log.

cdjackson commented 4 months ago

It seems to me that the problem is that the binding sends a command to the device in the payload with one command for one channel, and the device waits for four and interprets this command for all channels.

Are you sure? This would be very strange. You migth be right of course, but it's very non-standard and it's not really possible to support this.

stvred commented 4 months ago

I can only see what the binding sends based on the logs. Well, again, z2m, as I see, sends the statuses of all channels at once.

cdjackson commented 4 months ago

Again, this is completely non-standard. Every endpoint should be separate - as though it is a separate device. So maybe there is other configuration that you are not seeing that gets sent before. I don't know, but this change is not easy for the binding to implement since it now bridges across multiple channels, and within the binding, the implementation is separate.

Maybe you can implement this as a rule if you are sure this is the issue.

stvred commented 4 months ago

Problem solved by using z2m. Thank you @cdjackson for your involvement