[OH2] Can't set color on bulbs from certain manufacturers

anon71759204 · November 26, 2021, 1:12am

No luck … no channel options, Delete Thing, Things +, ZigBee Binding, Scan, it doesn’t recognize the bulb anymore (tried several times):

After adding it as Thing from the Inbox:



Total known nodes in network: 6
Network  Addr  IEEE Address      Logical Type  State      EP   Profile                    Device Type                Manufacturer     Model
      0  0000  5C0272FFFE4BC7B4  COORDINATOR   ONLINE
  14589  38FD  60A423FFFE139306  ROUTER        UNKNOWN    11  ZIGBEE_HOME_AUTOMATION     ON_OFF_PLUG_IN_UNIT        _TZ3000_kdi2o9m6  TS011F
                                                         242  ZIGBEE_GREEN_POWER         0061
  17296  4390  00158D00012E5426  ROUTER        UNKNOWN     1  ZIGBEE_HOME_AUTOMATION     EXTENDED_COLOR_LIGHT       MLI              tint-ExtendedColor
                                                         242  ZIGBEE_GREEN_POWER         0061
  49993  C349  804B50FFFEE11DD7  ROUTER        ONLINE      1  ZIGBEE_HOME_AUTOMATION     ON_OFF_PLUG_IN_UNIT        _TZ3000_1obwwnmq  TS011F
                                                           2  ZIGBEE_HOME_AUTOMATION     ON_OFF_PLUG_IN_UNIT
                                                           3  ZIGBEE_HOME_AUTOMATION     ON_OFF_PLUG_IN_UNIT
                                                         242  ZIGBEE_GREEN_POWER         0061
  60641  ECE1  842E14FFFE2C2E14  ROUTER        ONLINE      1  ZIGBEE_HOME_AUTOMATION     EXTENDED_COLOR_LIGHT       _TZ3000_dbou1ap4  TS0505A
                                                         242  ZIGBEE_GREEN_POWER         0061
  63671  F8B7  00178801094009C0  ROUTER        UNKNOWN    11  ZIGBEE_HOME_AUTOMATION     DIMMABLE_LIGHT             Philips          LWA009
                                                         242  ZIGBEE_GREEN_POWER         0061

openhab> zigbee fingerprint 842E14FFFE2C2E14
|>| Node Descriptor
| |> Logical Type               ROUTER
| |> MAC Capabilities           [FULL_FUNCTION_DEVICE, MAINS_POWER, RECEIVER_ON_WHEN_IDLE]
| |> Stack Compliance           22
| |> Server Capabilities        []
| |> Buffer Size                82
| |> Incoming Transfer Size     82
| |> Outgoing Transfer Size     82
|
|>| Power Descriptor
| |> Available Power Sources    [MAINS]
| |> Current Power Source       MAINS
| |> Current Power Mode         RECEIVER_ON_IDLE
| |> Power Level                FULL
|
|>| ZDO
| |> ManagementBindRequest      SUCCESS
| |> IeeeAddressRequest         SUCCESS
| |> ManagementLqiRequest       SUCCESS
| |> ManagementRoutingRequest   SUCCESS
|
|>| Basic Information
| |> Generic Device Class
| |> Generic Device Type
| |> Manufacturer Name          _TZ3000_dbou1ap4
| |> Model Indentifier          TS0505A
| |> Product Code
| |> Product URL
| |> Date Code
| |> Application Version        80
| |> Software Build ID
| |> Hardware Version           1
| |> Zcl Version                3
| |> Stack Version              0
| |
| |>| Endpoint 1
| | |> Profile                  0104  ZIGBEE_HOME_AUTOMATION
| | |> Device Type              010D  EXTENDED_COLOR_LIGHT
| | |> Device Version           1
| | |
| | |>| Input Clusters
| | | |
| | | |>| Cluster 0000 Basic
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> FAILURE
| | | | |
| | | | |>| Commands Received
| | | | |> FAILURE
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 ZCL Version
| | | | | |> 0001 Application Version
| | | | | |> 0002 Stack Version
| | | | | |> 0003 HW Version
| | | | | |> 0004 Manufacturer Name
| | | | | |> 0005 Model Identifier
| | | | | |> 0006 Date Code
| | | | | |> 0007 Power Source
| | | | | |> FFDE Unknown
| | | | | |> FFFD Unknown
| | | | | |> FFFE Unknown
| | | |
| | | |>| Cluster 0003 Identify
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0004 Groups
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0005 Scenes
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> FAILURE
| | | | |
| | | | |>| Commands Received
| | | | |> FAILURE
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Scene Count
| | | | | |> 0001 Current Scene
| | | | | |> 0002 Current Group
| | | | | |> 0003 Scene Valid
| | | | | |> 0004 Name Support
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0006 On/Off
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> FAILURE
| | | | |
| | | | |>| Commands Received
| | | | |> FAILURE
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 On Off
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0008 Level Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> FAILURE
| | | | |
| | | | |>| Commands Received
| | | | |> FAILURE
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Current Level
| | | | | |> 000F Options
| | | | | |> FFFD Unknown
| | | |
| | | |>| Cluster 0300 Color Control
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 1000
| | | | |> Type                 Server [Input]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | |
| | |>| Output Clusters
| | | |
| | | |>| Cluster 000A Time
| | | | |> Type                 Client [Output]
| | | | |> Manufacturer Spec.   No
| | | | |> Unsupported locally
| | | |
| | | |>| Cluster 0019 Ota Upgrade
| | | | |> Type                 Client [Output]
| | | | |> Manufacturer Spec.   No
| | | | |
| | | | |>| Commands Generated
| | | | | |> FAILURE
| | | | |
| | | | |>| Commands Received
| | | | |> FAILURE
| | | | |
| | | | |>| Attributes Supported
| | | | | |> 0000 Upgrade Server ID
| | | | | |> 0001 File Offset
| | | | | |> 0006 Image Upgrade Status
| | | | | |> FFFD Unknown
| |
| |>| Endpoint 242
| | |> Profile                  A1E0  ZIGBEE_GREEN_POWER
| | |> Device Type              0061
| | |> Device Version           0

anon71759204 · November 26, 2021, 1:25am

I would say: FUBAR … please note the the three Init. dev. toggle items …

Time for a complete deinstallation of the ZigBee binding and a clean re-install. Please advise how to proceed (bundle:uninstall all ZigBee bundles or remove ZigBee Bundle via UI or …).

Re-Install:
Upgrade openhabian to latest snapshot, install ZigBee Binding via UI, install ‘pdf’ snapshot via karaf?

chris · November 26, 2021, 1:34am

Please can you provide a debug log so I can see what is going on. I’ve not currently got any color bulbs hooked up so maybe I need to do this, but I’ll need to find some time. Currently I’m just testing this using test cases in the compiler, which show that the options should show up, but I suspect something else is throwing an exception somewhere.

If you have a log then I can hopefully work out what…

anon71759204 · November 26, 2021, 2:48am

Remove bulb
Things, +, ZigBee Binding, Scan

openhab.log.zip.txt (17.3 KB)

chris · November 26, 2021, 6:56pm

Thanks. Sorry, I forgot to post an update last night. Attached is an updated JAR with protection for this NPE.

org.openhab.binding.zigbee-3.2.0-SNAPSHOT.pdf (300.3 KB)

anon71759204 · November 27, 2021, 12:48am

Thanks for your daily update.

330 x Active x  80 x 3.2.0.202111260610    x openHAB Add-ons :: Bundles :: ZigBee Binding
331 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee CC2531 Bridge
332 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee Console
333 x Active x  80 x 3.2.0.202111230339    x openHAB Add-ons :: Bundles :: ZigBee Console Ember
334 x Active x  80 x 3.2.0.202111230339    x openHAB Add-ons :: Bundles :: ZigBee Console Telegesis
335 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee Ember Bridge
336 x Active x  80 x 3.2.0.202111230337    x openHAB Add-ons :: Bundles :: ZigBee Serial Driver
337 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee Telegesis Bridge
338 x Active x  80 x 3.2.0.202111230339    x openHAB Add-ons :: Bundles :: ZigBee XBee Bridge

No progress:
log_v260610.zip.txt (10.5 KB)

chris · November 27, 2021, 3:40am

Another update
org.openhab.binding.zigbee-3.2.0-SNAPSHOT.pdf (300.3 KB)

anon71759204 · November 28, 2021, 12:29am

Success (‘XY Commands’ works, ‘Auto’ doesn’t work):

Thanks a lot for your perseverence.

One problem (not sure whether it is problem or whether I’m stretching the openHAB specification …) remains:

The toggle switch (bound to the Group, not to the Color/Dimmer Point) switches the bulb on, but doesn’t switch the bulb off (same problem as with the power strip?).

chris · November 28, 2021, 12:33am

Thanks for testing.

Ok, Ill take another look at this before I think about merging as it might screw with others setups.

This might be the same issue - I need to check what I fixed on the previous update. I might have only updated that for the level and onoff channels, and it might also need doing for the color channel.

chris · November 28, 2021, 2:45am

We should be clear here - what “doesn’t work”?

By this, do you mean when initialising the device in AUTO, that your device cannot set the color? If so, I would say that AUTO does work since AUTO should work exactly the same as it did in the past (Which for your bulb, didn’t work, and is why we’re making the option to override this).

Is that what you mean? Or does it “not work” in some other way? From my testing here, it should run through the same code as it always did if it is set to AUTO, and detect the commands to use as it did previously.

chris · November 28, 2021, 2:50am

This will indeed be the same issue as previously. I will take a look at this, but the coior converter needs a little bit more refactoring to implement this so let’s first clear out the Color Control Method issue, get that merged, and then I’ll take a look at resolving the management of commands.

anon71759204 · November 28, 2021, 12:28pm

Exactly. It wasn’t clear to me whether ‘AUTO’ tries to work around the misleading information from the bulb or not. If ‘AUTO’ means ‘control the bulb as in the past’, everything is fine. IMHO ‘AUTO’ should be replaced with ‘DEFAULT’ (defined as: HUE, if support for HUE is reported by the device, XY otherwise).

chris · November 28, 2021, 7:58pm

I’ll add this to the description - I think AUTO or DEFAULT provide the same uncertainty so I don’t really see a need to change from AUTO, but I agree maybe adding a description. At the end of the day, if AUTO was guaranteed to work and always select the right option, then we wouldn’t need the override . I think changing to DEFAULT only really means anything if you’re already using the binding - then yes, this the current default behaviour, and this option is really only required to work around bulbs that don’t work properly so most people should be able to leave it as is.

chris · December 2, 2021, 11:35pm

Please can you confirm if this is now fixed in the latest snapshot? I’ve updated the binding so that the color control will now also reflect the command state back once the commands are acked.

anon71759204 · December 3, 2021, 12:56am

299 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee
300 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.console
301 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.console.ember
302 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.console.telegesis
303 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.dongle.cc2531
304 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.dongle.ember
305 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.dongle.telegesis
306 x Active x  80 x 1.4.2                 x com.zsmartsystems.zigbee.dongle.xbee
330 x Active x  80 x 3.2.0.202112020338    x openHAB Add-ons :: Bundles :: ZigBee Binding
331 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee CC2531 Bridge
332 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee Console
333 x Active x  80 x 3.2.0.202111230339    x openHAB Add-ons :: Bundles :: ZigBee Console Ember
334 x Active x  80 x 3.2.0.202111230339    x openHAB Add-ons :: Bundles :: ZigBee Console Telegesis
335 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee Ember Bridge
336 x Active x  80 x 3.2.0.202111230337    x openHAB Add-ons :: Bundles :: ZigBee Serial Driver
337 x Active x  80 x 3.2.0.202111230338    x openHAB Add-ons :: Bundles :: ZigBee Telegesis Bridge
338 x Active x  80 x 3.2.0.202111230339    x openHAB Add-ons :: Bundles :: ZigBee XBee Bridge

openhab> openhab:send TZ30001obwwnmqTS011F_804B50FFFEE11DD7_1_Switch ON
Command has been sent successfully.
openhab> openhab:send TZ30001obwwnmqTS011F_804B50FFFEE11DD7_1_Switch OFF
Command has been sent successfully.
openhab> openhab:send TZ30001obwwnmqTS011F ON
Command has been sent successfully.
openhab> openhab:send TZ30001obwwnmqTS011F OFF
Command has been sent successfully.
openhab> openhab:send TZ30001obwwnmqTS011F ON
Command has been sent successfully.
openhab> openhab:send TZ30001obwwnmqTS011F OFF
Command has been sent successfully.

It works from the openhabian console, but it doesn’t work from the UI:

Definition for UI element ‘All on/off’:

UI (edit mode):
grafik

‘Toggling All on’ works, ‘toggling All off’ doesn’t work.

chris · December 3, 2021, 1:04am

When you toggle this, what happens to the toggle - does it stay ON or does it go back to OFF?

I’m assuming that this was caused by the status not being updated - so now it should be updated ok I think.

If you have a log I’m happy to take a look to see if I can spot what is going on.

anon71759204 · December 3, 2021, 1:16am

The UI element behaves as one would expect (clicking toggles the UI element between the two states …), but only the transition off → on changes the state of the physical device.

02:13:44.634 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'TZ30001obwwnmqTS011F' received command ON
02:13:44.638 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'TZ30001obwwnmqTS011F_804B50FFFEE11DD7_1_Switch' received command ON
02:13:44.640 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'TZ30001obwwnmqTS011F_804B50FFFEE11DD7_3_Switch' received command ON
02:13:44.642 [INFO ] [openhab.event.ItemCommandEvent       ] - Item 'TZ30001obwwnmqTS011F_804B50FFFEE11DD7_2_Switch' received command ON
02:13:44.646 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Command for channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch --> ON [OnOffType]
02:13:44.648 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFEE11DD7: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=0, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> A72C/1, cluster=0006, TID=--]]
02:13:44.656 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
02:13:44.658 [DEBUG] [.transaction.ZigBeeTransactionManager] - A72C/1: Sending ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=10, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> A72C/1, cluster=0006, TID=A4]]
02:13:44.659 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
02:13:44.661 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OnCommand [On/Off: 0000/0 -> A72C/1, cluster=0006, TID=A4]
02:13:44.662 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Command for channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch --> ON [OnOffType]
02:13:44.663 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=164, commandId=1]
02:13:44.665 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=A72C/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=A4, rssi=--, lqi=--, payload=01 A4 01]
02:13:44.667 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch waiting for response to ON
02:13:44.667 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFEE11DD7: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=0, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> A72C/3, cluster=0006, TID=--]]
02:13:44.668 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
02:13:44.669 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch waiting for response to ON
02:13:44.672 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Command for channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch --> ON [OnOffType]
02:13:44.674 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFEE11DD7: Added transaction to queue, len=2, transaction=ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=0, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> A72C/2, cluster=0006, TID=--]]
02:13:44.675 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
02:13:44.677 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch waiting for response to ON
02:13:44.695 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=99]
02:13:44.697 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=184, lastHopRssi=-54, relayList=]
02:13:44.708 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
02:13:44.716 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=184, lastHopRssi=-54, relayList=]
02:13:44.736 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=184, lastHopRssi=-54, relayList=]
02:13:44.787 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=2C], lastHopLqi=184, lastHopRssi=-54, sender=A72C, bindingIndex=255, addressIndex=255, messageContents=08 A4 0B 01 00]
02:13:44.790 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A72C/1, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=2C, rssi=-54, lqi=B8, payload=08 A4 0B 01 00]
02:13:44.792 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node update. NWK Address=A72C
02:13:44.794 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node A72C is not updated
02:13:44.796 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=164, commandId=11]
02:13:44.799 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [On/Off: A72C/1 -> 0000/1, cluster=0006, TID=A4, commandIdentifier=1, statusCode=SUCCESS]
02:13:44.800 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: A72C/1 -> 0000/1, cluster=0006, TID=A4, commandIdentifier=1, statusCode=SUCCESS]
02:13:44.802 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch received SUCCESS in response to ON
02:13:44.802 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=155, state=COMPLETE, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> A72C/1, cluster=0006, TID=A4]]
02:13:44.803 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=A72C, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=99], messageTag=A4, status=EMBER_SUCCESS, messageContents=]
02:13:44.804 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch updated to ON
02:13:44.804 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
02:13:44.804 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=2D], lastHopLqi=184, lastHopRssi=-54, sender=A72C, bindingIndex=255, addressIndex=255, messageContents=18 39 0A 00 00 10 01]
02:13:44.804 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=A4 state=RX_ACK
02:13:44.805 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Updating ZigBee channel state zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch to ON
02:13:44.805 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFEE11DD7: transactionComplete, state=COMPLETE, outstanding=0
02:13:44.805 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=A4, state=RX_ACK, outstanding=0
02:13:44.806 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A72C/1, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=2D, rssi=-54, lqi=B8, payload=18 39 0A 00 00 10 01]
02:13:44.806 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
02:13:44.806 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.807 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node update. NWK Address=A72C
02:13:44.809 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TZ30001obwwnmqTS011F_804B50FFFEE11DD7_1_Switch' changed from OFF to ON
02:13:44.809 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node A72C is not updated
02:13:44.809 [DEBUG] [.transaction.ZigBeeTransactionManager] - A72C/3: Sending ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=142, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> A72C/3, cluster=0006, TID=A5]]
02:13:44.809 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.811 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=57, commandId=10]
02:13:44.811 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
02:13:44.812 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OnCommand [On/Off: 0000/0 -> A72C/3, cluster=0006, TID=A5]
02:13:44.812 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: A72C/1 -> 0000/1, cluster=0006, TID=39, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:44.812 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7 in 1830 seconds
02:13:44.813 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=165, commandId=1]
02:13:44.813 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: A72C/1 -> 0000/1, cluster=0006, TID=39, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:44.814 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=A72C/3, profile=0104, cluster=0006, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=A5, rssi=--, lqi=--, payload=01 A5 01]
02:13:44.816 [DEBUG] [.converter.ZigBeeConverterSwitchOnoff] - 804B50FFFEE11DD7: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Fri Dec 03 02:13:44 CET 2021, implemented=true]
02:13:44.817 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch updated to ON
02:13:44.819 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Updating ZigBee channel state zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_1_switch to ON
02:13:44.820 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.821 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.822 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7 in 1830 seconds
02:13:44.853 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=9A]
02:13:44.855 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=184, lastHopRssi=-54, relayList=]
02:13:44.859 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=1, outstandingQueues=1, sleepy=0/3
02:13:44.874 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=184, lastHopRssi=-54, relayList=]
02:13:44.894 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=180, lastHopRssi=-55, relayList=]
02:13:44.941 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Localcomputer_Memory_Available' changed from 3366 to 3365
02:13:44.947 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=2E], lastHopLqi=180, lastHopRssi=-55, sender=A72C, bindingIndex=255, addressIndex=255, messageContents=08 A5 0B 01 00]
02:13:44.949 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A72C/3, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=2E, rssi=-55, lqi=B4, payload=08 A5 0B 01 00]
02:13:44.950 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node update. NWK Address=A72C
02:13:44.951 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node A72C is not updated
02:13:44.952 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=165, commandId=11]
02:13:44.953 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [On/Off: A72C/3 -> 0000/1, cluster=0006, TID=A5, commandIdentifier=1, statusCode=SUCCESS]
02:13:44.954 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: A72C/3 -> 0000/1, cluster=0006, TID=A5, commandIdentifier=1, statusCode=SUCCESS]
02:13:44.957 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=291, state=COMPLETE, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> A72C/3, cluster=0006, TID=A5]]
02:13:44.957 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=A72C, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=3, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=9A], messageTag=A5, status=EMBER_SUCCESS, messageContents=]
02:13:44.958 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch received SUCCESS in response to ON
02:13:44.958 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
02:13:44.959 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch updated to ON
02:13:44.959 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFEE11DD7: transactionComplete, state=COMPLETE, outstanding=0
02:13:44.960 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=1, sleepy=0/3
02:13:44.960 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Updating ZigBee channel state zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch to ON
02:13:44.961 [DEBUG] [.transaction.ZigBeeTransactionManager] - A72C/2: Sending ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=288, state=WAITING, sendCnt=0, command=OnCommand [On/Off: 0000/0 -> A72C/2, cluster=0006, TID=A6]]
02:13:44.961 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.962 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
02:13:44.964 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=A5 state=RX_ACK
02:13:44.964 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=2F], lastHopLqi=180, lastHopRssi=-55, sender=A72C, bindingIndex=255, addressIndex=255, messageContents=18 3A 0A 00 00 10 01]
02:13:44.964 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX CMD: OnCommand [On/Off: 0000/0 -> A72C/2, cluster=0006, TID=A6]
02:13:44.964 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.965 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TZ30001obwwnmqTS011F_804B50FFFEE11DD7_3_Switch' changed from OFF to ON
02:13:44.965 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=A5, state=RX_ACK, outstanding=1
02:13:44.967 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=166, commandId=1]
02:13:44.967 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7 in 1830 seconds
02:13:44.967 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A72C/3, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=2F, rssi=-55, lqi=B4, payload=18 3A 0A 00 00 10 01]
02:13:44.968 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=A72C/2, profile=0104, cluster=0006, addressMode=DEVICE, radius=8, apsSecurity=false, ackRequest=true, apsCounter=A6, rssi=--, lqi=--, payload=01 A6 01]
02:13:44.969 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node update. NWK Address=A72C
02:13:44.970 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node A72C is not updated
02:13:44.971 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=58, commandId=10]
02:13:44.973 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: A72C/3 -> 0000/1, cluster=0006, TID=3A, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:44.974 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: A72C/3 -> 0000/1, cluster=0006, TID=3A, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:44.976 [DEBUG] [.converter.ZigBeeConverterSwitchOnoff] - 804B50FFFEE11DD7: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Fri Dec 03 02:13:44 CET 2021, implemented=true]
02:13:44.977 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch updated to ON
02:13:44.978 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Updating ZigBee channel state zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_3_switch to ON
02:13:44.979 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.980 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:44.981 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7 in 1830 seconds
02:13:45.014 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspSendUnicastResponse [networkId=0, status=EMBER_SUCCESS, sequence=9B]
02:13:45.016 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=180, lastHopRssi=-55, relayList=]
02:13:45.066 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=176, lastHopRssi=-56, relayList=]
02:13:45.067 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=A72C, sourceEui=804B50FFFEE11DD7, lastHopLqi=176, lastHopRssi=-56, relayList=]
02:13:45.068 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=30], lastHopLqi=176, lastHopRssi=-56, sender=A72C, bindingIndex=255, addressIndex=255, messageContents=08 A6 0B 01 00]
02:13:45.069 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A72C/2, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=30, rssi=-56, lqi=B0, payload=08 A6 0B 01 00]
02:13:45.070 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node update. NWK Address=A72C
02:13:45.071 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node A72C is not updated
02:13:45.072 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=166, commandId=11]
02:13:45.073 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: DefaultResponse [On/Off: A72C/2 -> 0000/1, cluster=0006, TID=A6, commandIdentifier=1, statusCode=SUCCESS]
02:13:45.074 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: DefaultResponse [On/Off: A72C/2 -> 0000/1, cluster=0006, TID=A6, commandIdentifier=1, statusCode=SUCCESS]
02:13:45.075 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch received SUCCESS in response to ON
02:13:45.075 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=A72C, apsFrame=EmberApsFrame [profileId=0104, clusterId=0006, sourceEndpoint=1, destinationEndpoint=2, options=[EMBER_APS_OPTION_ENABLE_ADDRESS_DISCOVERY, EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=9B], messageTag=A6, status=EMBER_SUCCESS, messageContents=]
02:13:45.076 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=A6 state=RX_ACK
02:13:45.076 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch updated to ON
02:13:45.076 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=31], lastHopLqi=176, lastHopRssi=-56, sender=A72C, bindingIndex=255, addressIndex=255, messageContents=18 3B 0A 00 00 10 01]
02:13:45.077 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction complete: ZigBeeTransaction [ieeeAddress=804B50FFFEE11DD7 queueTime=403, state=COMPLETE, sendCnt=1, command=OnCommand [On/Off: 0000/0 -> A72C/2, cluster=0006, TID=A6]]
02:13:45.077 [DEBUG] [.transaction.ZigBeeTransactionManager] - transactionListenerRemoved: 0 outstanding
02:13:45.077 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=A6, state=RX_ACK, outstanding=1
02:13:45.077 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Updating ZigBee channel state zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch to ON
02:13:45.078 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=A72C/2, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=31, rssi=-56, lqi=B0, payload=18 3B 0A 00 00 10 01]
02:13:45.079 [DEBUG] [ee.transaction.ZigBeeTransactionQueue] - 804B50FFFEE11DD7: transactionComplete, state=COMPLETE, outstanding=0
02:13:45.079 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:45.080 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node update. NWK Address=A72C
02:13:45.080 [DEBUG] [.transaction.ZigBeeTransactionManager] - Transaction Manager: Send Next transaction. outstandingTransactions=0, outstandingQueues=0, sleepy=0/3
02:13:45.080 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:45.081 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 804B50FFFEE11DD7: Node A72C is not updated
02:13:45.082 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TZ30001obwwnmqTS011F_804B50FFFEE11DD7_2_Switch' changed from OFF to ON
02:13:45.082 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=59, commandId=10]
02:13:45.083 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7 in 1830 seconds
02:13:45.085 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: A72C/2 -> 0000/1, cluster=0006, TID=3B, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:45.086 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: A72C/2 -> 0000/1, cluster=0006, TID=3B, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:45.087 [DEBUG] [.converter.ZigBeeConverterSwitchOnoff] - 804B50FFFEE11DD7: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Fri Dec 03 02:13:45 CET 2021, implemented=true]
02:13:45.088 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 804B50FFFEE11DD7: Channel zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch updated to ON
02:13:45.089 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 804B50FFFEE11DD7: Updating ZigBee channel state zigbee:device:dbb76ab009:804b50fffee11dd7:804B50FFFEE11DD7_2_switch to ON
02:13:45.090 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:45.092 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7
02:13:45.092 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:804b50fffee11dd7 in 1830 seconds
02:13:46.052 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingSenderEui64Handler [networkId=0, senderEui64=842E14FFFE2C2E14]
02:13:46.053 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_BROADCAST, apsFrame=EmberApsFrame [profileId=0000, clusterId=0000, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_SOURCE_EUI64], groupId=0, sequence=59], lastHopLqi=136, lastHopRssi=-66, sender=5F92, bindingIndex=255, addressIndex=255, messageContents=81 B4 C7 4B FE FF 72 02 5C 00 00]
02:13:46.055 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=5F92/0, destinationAddress=0000/0, profile=0000, cluster=0000, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=59, rssi=-66, lqi=88, payload=81 B4 C7 4B FE FF 72 02 5C 00 00]
02:13:46.059 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Localcomputer_Memory_Used' changed from 523 to 524
02:13:46.059 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 842E14FFFE2C2E14: Node update. NWK Address=5F92
02:13:46.061 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 842E14FFFE2C2E14: Node 5F92 is not updated
02:13:46.062 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: NetworkAddressRequest [5F92/0 -> 0000/0, cluster=0000, TID=81, ieeeAddr=5C0272FFFE4BC7B4, requestType=0, startIndex=0]
02:13:46.063 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: NetworkAddressRequest [5F92/0 -> 0000/0, cluster=0000, TID=81, ieeeAddr=5C0272FFFE4BC7B4, requestType=0, startIndex=0]
02:13:46.072 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=5F92, sourceEui=842E14FFFE2C2E14, lastHopLqi=136, lastHopRssi=-66, relayList=]
02:13:46.531 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspMessageSentHandler [networkId=0, type=EMBER_OUTGOING_BROADCAST, indexOrDestination=FFFD, apsFrame=EmberApsFrame [profileId=0000, clusterId=0000, sourceEndpoint=0, destinationEndpoint=0, options=[EMBER_APS_OPTION_SOURCE_EUI64], groupId=0, sequence=59], messageTag=00, status=EMBER_SUCCESS, messageContents=]
02:13:46.532 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX STA: msgTag=00 state=RX_ACK
02:13:46.534 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionProgress: TID=00, state=RX_ACK, outstanding=0
02:13:47.606 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=5F92, sourceEui=842E14FFFE2C2E14, lastHopLqi=132, lastHopRssi=-67, relayList=]
02:13:47.608 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=5F92, sourceEui=842E14FFFE2C2E14, lastHopLqi=136, lastHopRssi=-66, relayList=]
02:13:47.610 [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_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=58], lastHopLqi=132, lastHopRssi=-67, sender=5F92, bindingIndex=255, addressIndex=255, messageContents=18 00 0A 00 00 10 01]
02:13:47.612 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=5F92/1, destinationAddress=0000/1, profile=0104, cluster=0006, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=58, rssi=-67, lqi=84, payload=18 00 0A 00 00 10 01]
02:13:47.613 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 842E14FFFE2C2E14: Node update. NWK Address=5F92
02:13:47.615 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 842E14FFFE2C2E14: Node 5F92 is not updated
02:13:47.617 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=0, commandId=10]
02:13:47.618 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [On/Off: 5F92/1 -> 0000/1, cluster=0006, TID=00, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:47.620 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [On/Off: 5F92/1 -> 0000/1, cluster=0006, TID=00, reports=[AttributeReport [attributeDataType=BOOLEAN, attributeIdentifier=0, attributeValue=true]]]
02:13:47.622 [DEBUG] [l.converter.ZigBeeConverterColorColor] - 842E14FFFE2C2E14: ZigBee attribute reports ZclAttribute [cluster=On/Off, id=0, name=On Off, dataType=BOOLEAN, lastValue=true, lastReportTime=Fri Dec 03 02:13:47 CET 2021, implemented=true]
02:13:47.624 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 842E14FFFE2C2E14: Channel zigbee:device:dbb76ab009:842e14fffe2c2e14:842E14FFFE2C2E14_1_color updated to 0.0,100.0,100
02:13:47.627 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0008, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OPTION_ENABLE_ROUTE_DISCOVERY], groupId=0, sequence=5A], lastHopLqi=136, lastHopRssi=-66, sender=5F92, bindingIndex=255, addressIndex=255, messageContents=18 01 0A 00 00 20 FF]
02:13:47.629 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=5F92/1, destinationAddress=0000/1, profile=0104, cluster=0008, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=5A, rssi=-66, lqi=88, payload=18 01 0A 00 00 20 FF]
02:13:47.629 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 842E14FFFE2C2E14: Updating ZigBee channel state zigbee:device:dbb76ab009:842e14fffe2c2e14:842E14FFFE2C2E14_1_color to 0.0,100.0,100
02:13:47.630 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 842E14FFFE2C2E14: Node update. NWK Address=5F92
02:13:47.630 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:842e14fffe2c2e14
02:13:47.631 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - 842E14FFFE2C2E14: Node 5F92 is not updated
02:13:47.632 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:842e14fffe2c2e14
02:13:47.632 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=1, commandId=10]
02:13:47.633 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:842e14fffe2c2e14 in 14430 seconds
02:13:47.634 [DEBUG] [rtsystems.zigbee.ZigBeeNetworkManager] - RX CMD: ReportAttributesCommand [Level Control: 5F92/1 -> 0000/1, cluster=0008, TID=01, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=255]]]
02:13:47.635 [DEBUG] [.transaction.ZigBeeTransactionManager] - notifyTransactionCommand: ReportAttributesCommand [Level Control: 5F92/1 -> 0000/1, cluster=0008, TID=01, reports=[AttributeReport [attributeDataType=UNSIGNED_8_BIT_INTEGER, attributeIdentifier=0, attributeValue=255]]]
02:13:47.637 [DEBUG] [.zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingRouteRecordHandler [networkId=0, source=5F92, sourceEui=842E14FFFE2C2E14, lastHopLqi=136, lastHopRssi=-66, relayList=]
02:13:47.637 [DEBUG] [l.converter.ZigBeeConverterColorColor] - 842E14FFFE2C2E14: ZigBee attribute reports ZclAttribute [cluster=Level Control, id=0, name=Current Level, dataType=UNSIGNED_8_BIT_INTEGER, lastValue=255, lastReportTime=Fri Dec 03 02:13:47 CET 2021, implemented=true]
02:13:47.638 [DEBUG] [.converter.ZigBeeBaseChannelConverter] - 842E14FFFE2C2E14: Channel zigbee:device:dbb76ab009:842e14fffe2c2e14:842E14FFFE2C2E14_1_color updated to 0.0,100.0,100
02:13:47.639 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - 842E14FFFE2C2E14: Updating ZigBee channel state zigbee:device:dbb76ab009:842e14fffe2c2e14:842E14FFFE2C2E14_1_color to 0.0,100.0,100
02:13:47.640 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker reset for handler with thingUID=zigbee:device:dbb76ab009:842e14fffe2c2e14
02:13:47.641 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker cancelled task for thingUID=zigbee:device:dbb76ab009:842e14fffe2c2e14
02:13:47.642 [DEBUG] [g.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker scheduled task for thingUID=zigbee:device:dbb76ab009:842e14fffe2c2e14 in 14430 seconds
02:13:52.177 [WARN ] [fo.internal.handler.SysteminfoHandler] - No information for channel battery#remainingCapacity with device index 0 :
02:13:52.180 [WARN ] [fo.internal.handler.SysteminfoHandler] - No information for channel battery#remainingTime with device index 0 :
02:13:52.190 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'Localcomputer_UsedHeapPercent' changed from 27 % to 34 %
02:14:01.925 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'airsensor_Ausfuhrung' changed from OFF to ON

chris · December 3, 2021, 1:29am

Thanks.

I think this looks ok from the binding perspective -:

What is interesting is it’s probably not a surprise that this didn’t change with the new binding update since the devices already reported their state. What we see here is the 3 individual commands coming in to the binding (the expansion of the group is done before the binding receives the commands). The binding then sends the 3 commands, and when it receives the DefaulResponse it sets the state to ON (which is the commanded state - this is the new bit I just added).

Immediately after this we also see reports coming in from the device to report its state. This causes a second update of the state for the color bulbs to an HSB of 0,100,100 - this should also be the same as ON since the B part of HSB is 100%.

My guess is that the core, or the UI, then doesn’t allow the OFF command to be sent as something in the system doesn’t like the state. I’m guessing it’s a core problem and it’s not aggregating the group state correctly in this case.

anon71759204 · December 3, 2021, 1:41am

Well, it works from the console (openhab:send ...), but it doesn’t work from the UI. IMHO this points to the UI as the culprit.

chris · December 3, 2021, 1:42am

Sounds reasonable to me