New Zigbee joins successfully, however not funtional with UNSUPPORTED_ATTRIBUTE errors until Zigbe2mqtt and adaptor restarted

[DanielNagy]

What happened?

When I join a new Schneider Electric Wiser 40/300-Series module dimmer 41EPBDWCLMZ/354PBDMBTZ to Z2M, it successfully joins according to the Toast notifications. However, the device is not functional. Unable to manually get state (UNSUPPORTED_ATTRIBUTE error toast), Unable to set light on or off just doesnt do anything.

Previously when i've added this particular model zigbee device, I've resolved this by restarting Zigbee2Mqtt, and the device was fully functional. I've recently added another of this specific device, and noted that a restarted wasnt enough to fix the issue, I had to also restart my zigbee adaptor, and then the newly joined 41EPBDWCLMZ/354PBDMBTZ was fully functional.

This issue is only specific to this exact model schnider electric zigbee device, other schnider zigbee modules (ie 41E2PBSWMZ/356PB2MBTZ) all work as expected.

If i remove this newly joined zigbee device, and re-add it again, it also joins correctly as expected. It seems this issue is present only when a total new 41EPBDWCLMZ/354PBDMBTZ is joined to zigbee2mqtt for the very first time.

What did you expect to happen?

Zigbee device to be fully functional once joined with no errors.

How to reproduce it (minimal and precise)

click Permit join (all), triple press 41EPBDWCLMZ/354PBDMBTZ button 3 times to enter join mode, wait for device to appear, and successfully configure / join z2m, in new device "exposes" tab. press state on / off (nothing happens). press the state "refresh" button, receive UNSUPPORTED_ATTRIBUTE error toast

restart tubes network zigbee adaptor and zigbee2mqtt

device now fully functional.

Zigbee2MQTT version

1.30.1

Adapter firmware version

20220219

Adapter

Tube's Network Zigbee Gateway (CC2652P2 variant) - Network wired

Debug log

z2m logs.txt Device in question - 0x8cf681fffe0eee4e

Noteable events

2023-02-26 11:49:40: Device '0x8cf681fffe0eee4e' joined 2023-02-26 11:50:49: Error: Read 0x8cf681fffe0eee4e/21 genOnOff 'UNSUPPORTED_ATTRIBUTE'

2023-02-26 11:53:39: Restarting Zigbee2MQTT same 'UNSUPPORTED_ATTRIBUTE' issue

2023-02-26 11:55:09: Restarting Zigbee2MQTT same 'UNSUPPORTED_ATTRIBUTE' issue

I then removed device 0x8cf681fffe0eee4e from Z2M, and rejoined it again. PAN Address changed to 0x04DD in wireshark logs

2023-02-26 11:58:35: Device '0x8cf681fffe0eee4e' left the network - wireshark packet #2047 2023-02-26 11:59:36: Device '0x8cf681fffe0eee4e' joined 2023-02-26 12:00:13: Error: Read 0x8cf681fffe0eee4e/21 genOnOff 2023-02-26 12:00:17: Error: Read 0x8cf681fffe0eee4e/21 genOnOff 2023-02-26 12:00:30: Restarting Zigbee2MQTT

I then attempted restarting of Zigbee2MQTT again (this is usually what resolved the issue in the past when i originally joined these zigbee device type)

2023-02-26 12:01:19: Error: Read 0x8cf681fffe0eee4e/21 genOnOff

I then disconnected and reconnected power to Zigbee Adaptor (tubes network adaptor) and restarted zigbee2mqtt

2023-02-26 12:03:21: Adapter disconnected, stopping

Newly added Device is now fully functional.

add dimmer pcap.zip Associated device PAN address (device was joined / removed / joined again as part of troubleshooting before restarting z2m) 0x102A 2023-02-26 11:49:40: Device '0x8cf681fffe0eee4e' joined 0x04DD 2023-02-26 11:59:36: Device '0x8cf681fffe0eee4e' joined

Suggested wireshark filter wpan.dst16 == 0x102a || wpan.src16 == 0x102a || wpan.dst16 == 0x04dd || wpan.src16 == 0x04dd

[DanielNagy]

Just realised there was additional hersman debug logs i could have enabled... Let me know if the pcap file is enough here, I do have another Clipsal device to connect. Its also worth noting that others have had this same specific issue https://gist.github.com/phindmarsh/84085fd0f13a79969c51e71d53197d0b?permalink_comment_id=4419909#gistcomment-4419909

[Koenkk]

It looks like the device does not support reading the on/off state (UNSUPPORTED_ATTRIBUTE)

[DanielNagy]

After I restart zigbee2mqtt and my tube adaptor, the device then works as expected.

To me it seems that the coordinator adaptor or zigbee2mqtt is in a strange state upon this device completed joining the zigbee network.

This behaviour only happens on this specific Schneider dimmer device. Other Schneider switch devices behave as expected.

[DanielNagy]

As you can see, after restarting of Zigbee2mqtt / tubes zigbee adaptor, the device successfully works responds as expected to the same on/off state request.

Zigbee2MQTT:debug 2023-02-27 09:18:07: Received MQTT message on 'zigbee2mqtt/Games Light Dimmer/get' with data '{"state":""}'
Zigbee2MQTT:debug 2023-02-27 09:18:07: Publishing get 'get' 'state' to 'Games Light Dimmer'
2023-02-26T22:18:07.201Z zigbee-herdsman:controller:endpoint Read 0x8cf681fffe0eee4e/3 genOnOff(["onOff"], {"sendWhen":"immediate","timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})
2023-02-26T22:18:07.201Z zigbee-herdsman:adapter:zStack:adapter sendZclFrameToEndpointInternal 0x8cf681fffe0eee4e:1245/3 (0,0,1)
2023-02-26T22:18:07.201Z zigbee-herdsman:adapter:zStack:znp:SREQ --> AF - dataRequest - {"dstaddr":1245,"destendpoint":3,"srcendpoint":1,"clusterid":6,"transid":106,"options":0,"radius":30,"len":5,"data":{"type":"Buffer","data":[16,107,0,0,0]}}
2023-02-26T22:18:07.201Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,15,36,1,221,4,3,1,6,0,106,0,30,5,16,107,0,0,0,253]
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,1,100,1,0,100,254,3,68,128,0,1,106,172]
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,1,100,1,0,100,254,3,68,128,0,1,106,172]
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 1 - 3 - 4 - 1 - [0] - 100
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- AF - dataRequest - {"status":0}
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,68,128,0,1,106,172]
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 4 - 128 - [0,1,106] - 172
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - dataConfirm - {"status":0,"endpoint":1,"transid":106}
2023-02-26T22:18:07.226Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2023-02-26T22:18:07.243Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,69,196,221,4,0,91]
2023-02-26T22:18:07.243Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,3,69,196,221,4,0,91]
2023-02-26T22:18:07.243Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 3 - 2 - 5 - 196 - [221,4,0] - 91
2023-02-26T22:18:07.243Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - srcRtgInd - {"dstaddr":1245,"relaycount":0,"relaylist":[]}
2023-02-26T22:18:07.243Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2023-02-26T22:18:07.293Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,28,68,129,0,0,6,0,221,4,3,1,0,47,0,109,80,229,0,0,8,24,107,1,0,0,0,16,0,221,4,29,93]
2023-02-26T22:18:07.293Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,28,68,129,0,0,6,0,221,4,3,1,0,47,0,109,80,229,0,0,8,24,107,1,0,0,0,16,0,221,4,29,93]
2023-02-26T22:18:07.293Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 28 - 2 - 4 - 129 - [0,0,6,0,221,4,3,1,0,47,0,109,80,229,0,0,8,24,107,1,0,0,0,16,0,221,4,29] - 93
2023-02-26T22:18:07.293Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":1245,"srcendpoint":3,"dstendpoint":1,"wasbroadcast":0,"linkquality":47,"securityuse":0,"timestamp":15028333,"transseqnumber":0,"len":8,"data":{"type":"Buffer","data":[24,107,1,0,0,0,16,0]}}
2023-02-26T22:18:07.295Z zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":107,"manufacturerCode":null,"commandIdentifier":1},"Payload":[{"attrId":0,"status":0,"dataType":16,"attrData":0}],"Command":{"ID":1,"name":"readRsp","parameters":[{"name":"attrId","type":33},{"name":"status","type":32},{"name":"dataType","type":32,"conditions":[{"type":"statusEquals","value":0}]},{"name":"attrData","type":1000,"conditions":[{"type":"statusEquals","value":0}]}]}},"address":1245,"endpoint":3,"linkquality":47,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'
Zigbee2MQTT:debug 2023-02-27 09:18:07: Received Zigbee message from 'Games Light Dimmer', type 'readResponse', cluster 'genOnOff', data '{"onOff":0}' from endpoint 3 with groupID 0
2023-02-26T22:18:07.296Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
Zigbee2MQTT:info  2023-02-27 09:18:07: MQTT publish: topic 'zigbee2mqtt/Games Light Dimmer', payload '{"ballast_lamp_alarm_lamp_burn_hours":false,"ballast_maximum_level":254,"ballast_minimum_level":93,"ballast_status_lamp_failure":false,"ballast_status_non_operational":false,"brightness":254,"linkquality":47,"onLevel":"previous","state":"OFF","switchindication":"reversewithload","update":{"installed_version":33753087,"latest_version":33753087,"state":"idle"},"update_available":false}'
2023-02-26T22:18:12.070Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,5,69,196,59,160,1,21,11,0]
2023-02-26T22:18:12.070Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,5,69,196,59,160,1,21,11,0]
2023-02-26T22:18:12.070Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 5 - 2 - 5 - 196 - [59,160,1,21,11] - 0
2023-02-26T22:18:12.070Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- ZDO - srcRtgInd - {"dstaddr":41019,"relaycount":1,"relaylist":[2837]}
2023-02-26T22:18:12.070Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2023-02-26T22:18:12.152Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,28,68,129,0,0,0,4,59,160,1,1,0,112,0,36,244,233,0,0,8,24,183,10,0,0,33,19,0,21,11,28,146]
2023-02-26T22:18:12.152Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,28,68,129,0,0,0,4,59,160,1,1,0,112,0,36,244,233,0,0,8,24,183,10,0,0,33,19,0,21,11,28,146]
2023-02-26T22:18:12.152Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 28 - 2 - 4 - 129 - [0,0,0,4,59,160,1,1,0,112,0,36,244,233,0,0,8,24,183,10,0,0,33,19,0,21,11,28] - 146
2023-02-26T22:18:12.153Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":1024,"srcaddr":41019,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":112,"securityuse":0,"timestamp":15332388,"transseqnumber":0,"len":8,"data":{"type":"Buffer","data":[24,183,10,0,0,33,19,0]}}
2023-02-26T22:18:12.153Z zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":183,"manufacturerCode":null,"commandIdentifier":10},"Payload":[{"attrId":0,"dataType":33,"attrData":19}],"Command":{"ID":10,"name":"report","parameters":[{"name":"attrId","type":33},{"name":"dataType","type":32},{"name":"attrData","type":1000}]}},"address":41019,"endpoint":1,"linkquality":112,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'

[Koenkk]

Can you provide a sniff of both the working and non working read? (a very short sniff with just the read in it)

[DanielNagy]

The pcap contains the entire process of joining a new dimmer device to z2m. If you filter on both PAN ID's you'll see that none of the "get state" for the first ID worked. Right near the end of the PCAP you should see the new PAN ID of the rejoined dimmer device, then at some point post z2m / tubes restart, you can see the "get state" working successfully.

[Koenkk]

It seems to read from endpoint 21, while it should read from 3.

• Can you try with topic zigbee2mqtt/DEVICE_ID/get/3 and see if that works?
• Can you provide the herdsman debug log when pairing the device? First force remove it and restart z2m.
• Can you provide the data/database.db entry of this device after pairing?

[DanielNagy]

Hi @Koenkk,

Unsure what you mean by the first step "try with topic". (I'm using z2m in hassio supervisor) Will force remove, and capture logs again to pair. note, this will not reproduce the issue based on past experience.

[DanielNagy]

Here are the logs. Note, when i force removed it from zigbee2mqtt, according to pcap, it was still connected, and reporting (as 0x04DD), i had to reset the device as well for it to show the "device left network" toast messages in zigbee2mqtt. Once device rejoined, it was 0x517B PAN ID.

NOTE - This did not reproduce the issue. The issue only happens when the Dimmer module is brand new out of box.

log today.txt database.db.txt force remove, reset unit, rejoined 0x517B pcap.zip

[Koenkk]

Does the issue appear when you force remove the device, restart z2m and pair it?

[DanielNagy]

No, the only way I can reproduce the issue is to buy a new dimmer and join it to my zigbee network.

However, I do have another device I haven't installed yet.

Question is, am I providing the correct level of logs now before I attempt that?

[Koenkk]

log today.txt is the correct log (includes zigbee-herdsman logging)

[DanielNagy]

I've had another Dimmer module installed, straight out of the box, But for some reason, I am unable to pair/join this device to the zigbee network.

Restarted zigbee2mqtt / adaptor Enable Permit Join (All) Put dimmer device into join mode (3 button so orange led flashing). Nothing happens.

Here is log and pcap log3.txt wont join.zip

Can see a heap of Association Request FFD and Association Response's in the PCAP, but it doesnt appear to pair, and go through the interview process. Zigbee2MQTT web gui does not have any Pop up Toasts.

[DanielNagy]

From what I understand in the Pcap, it looks like it was attempting to join the network via 0xC854 device, but it was failing (interested to understand why?). I did try via "Enable Permit Join (Co-ordinator)" as well, but that failed. But I successfully "Enable Permit Join" with the 0x4454 zigbee device, and it joined successfully.

And It obviously now has the issue where i cannot get state, where i cannot control the device.

Here is the log file joined.txt Timestamp of where to look - Zigbee2MQTT:info 2023-03-03 13:40:03: Zigbee: allowing new devices to join. The new device is 0x8cf681fffe0eee2e (Sewing Light Dimmer)

But based on the log file i attached above, I can see it is trying to read endpoint 21 with the resulting UNSUPPORTED_ATTRIBUTE as you previously identified.

From Dev console, i can successfully read endpoint 3

I haven't rebooted zigbee2mqtt / tubes zigbee adaptor yet just incase you have further tests you want me to do whilst it is in the current broken state. (Again, this issue can only be reproduced with a new zigbee device purchase)

[DanielNagy]

from database.db before reboot

{"id":25,"type":"Router","ieeeAddr":"0x8cf681fffe0eee2e","nwkAddr":39421,"manufId":4190,"manufName":"Schneider Electric","powerSource":"Mains (single phase)","modelId":"CH/DIMMER/1","epList":[21,242,3],"endpoints":{"3":{"profId":260,"epId":3,"devId":257,"inClusterList":[0,3,4,5,6,8,769,2821],"outClusterList":[25],"clusters":{"genBasic":{"attributes":{"dateCode":""}},"genOnOff":{"attributes":{"onOff":0}}},"binds":[{"cluster":6,"type":"endpoint","deviceIeeeAddress":"0x00124b002590823d","endpointID":1},{"cluster":8,"type":"endpoint","deviceIeeeAddress":"0x00124b002590823d","endpointID":1},{"cluster":769,"type":"endpoint","deviceIeeeAddress":"0x00124b002590823d","endpointID":1}],"configuredReportings":[{"cluster":6,"attrId":0,"minRepIntval":0,"maxRepIntval":3600,"repChange":0},{"cluster":8,"attrId":0,"minRepIntval":0,"maxRepIntval":3600,"repChange":1}],"meta":{}},"21":{"profId":260,"epId":21,"devId":260,"inClusterList":[0,3,2821,65303],"outClusterList":[3,4,5,6,8,258],"clusters":{"genBasic":{"attributes":{"modelId":"CH/DIMMER/1","manufacturerName":"Schneider Electric","powerSource":1,"zclVersion":3,"appVersion":2,"stackVersion":6,"hwVersion":1,"dateCode":"","swBuildId":"002.003.007 R"}},"genOnOff":{"attributes":{}},"genLevelCtrl":{"attributes":{}}},"binds":[],"configuredReportings":[],"meta":{}},"242":{"profId":41440,"epId":242,"devId":97,"inClusterList":[],"outClusterList":[33],"clusters":{},"binds":[],"configuredReportings":[],"meta":{}}},"appVersion":2,"stackVersion":6,"hwVersion":1,"dateCode":"","swBuildId":"002.003.007 R","zclVersion":3,"interviewCompleted":true,"meta":{"configured":-220419804},"lastSeen":1677812186626,"defaultSendRequestWhen":"immediate"}

[Koenkk]

Found the issue!

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/advanced/more/switch-to-dev-branch.html)

[DanielNagy]

Fantastic. I need to work out how to roll my additional switch indication functionality from my local herdsman convertors, into the main git repo to benefit more than just myself :).

[joaquinvacas]

14749 I think it's related to this.

[DanielNagy]

14749 I think it's related to this.

FYI, The fix for this issue has only made it to stable release 1.30.3 in the last few days.

[warwickschroeder]

I've updated to the latest but I'm still experiencing the same issue. Has this been resolved for everyone else?

[Koenkk]

@warwickschroeder please provide the debug log

See https://www.zigbee2mqtt.io/guide/usage/debug.html on how to enable debug logging.

[DanielNagy]

@warwickschroeder Just to clarify, is your issue specifically related to the Clipsal Dimmer join problem? or @joaquinvacas's issue #14749

I haven't tested this yet as i haven't installed a new Dimmer device since this is only reproduceable on a totally new device. Given this fix was added to stable (and subsequently, easier for me to test in Homeassistant), I'll take some new logs again when I add a new dimmer. I've got maybe 1 more dimmer I can install, until i need to buy more.

[warwickschroeder]

Seems to be working fine now. Fix was to power cycle the switches. I am having issues joining these switches to the network now though. Is this an existing issue?

[DanielNagy]

@warwickschroeder your issue sounds different. The dimmer should join z2m successfully, but isn't controllable from z2m without restarting z2m. This only applies to the Clipsal iconic dimmer, not to any other Clipsal iconic device.

[github-actions[bot]]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[DanielNagy]

Hi @Koenkk,

It appears there is joining issues with this device type again. However, it isnt fixable by restarting mqtt as it did before. living-b.log

(I upgraded my Coordinator to version 20230507, and went around to confirm all zigbee switches)

Attached is a log of my various attemps to join the zigbee network, leave zigbee network, etc. the issue is, it JOINS successfully, I am however unable to control it from the Exposes tab.

the ID in question is 0x8cf681fffe046b62 Living Light Dimmer

The existing joined devices of the same type operate correctly (and i was able to rejoin another one successfully earlier today after some trouble.. restarting z2m/coordinator, etc)

Of interested based on the error message, it is attempting Endpoint 1?? this device isn't supposed to have a Endpoint 1

This is how a working device looks under clusters.

[DanielNagy]

Hi @Koenkk,

I managed to rejoin this device. (and it doesnt have the Endpoint 1)

I unjoined the device from the zigbee network

I powered off my tubez Zigbee co-ordinator for 10 seconds. This forced zigbee2mqtt to restart

I then joined the device (via the Pandry device, not sure if this made a difference or not, but it failed the previous times. "All" and "Coordinator" join methods had previously failed as well).

I then joined the device.

There is no 1 Endpoint anymore.

Here is the log file. living-c.log

I think the trick was to make sure the device had left the network first, then restart zigbee2mqtt/ tubez coordinator.

[DanielNagy]

I've managed to get the 3 dimmer devices resolved and rejoined. the Coordinator might have been in a "funny state" in regards to those devices post firmware upgrade of my tubez coordinator to version 20230507. Either way - there are logs there to determine if that is the case.