Ubisys C4 using configure_device_setup results in timeout

[bdaenen]

What happened?

I just installed a Ubisys C4 and paired it. It seems to have correctly autobound to the coordinator, but I noticed no messages were being published when flipping the switches. Upon reading the docs I assumed I had to reconfigure the input_actions using the toggle_switch template because my switches have an on and off position.

When running
mosquitto_pub -t zigbee2mqtt/KitchenLightControllerC4/set -m '{"configure_device_setup": {"input_action_templates": [{"type": "toggle_switch"}, {"type": "toggle_switch"}, {"type": "toggle_switch"}, {"type": "toggle_switch"}]}}'
I ran into #22610, but apparently that was fixed on dev (props for the amazing speed at which things are fixed here!)

Next I switched to the Z2M edge addon and tried running the same command, which resulted in the following logs:

Warning 2024-05-26 14:49:25ubisys: Using input(s) 0 and endpoint 1 for 'toggle_switch'.
Warning 2024-05-26 14:49:25ubisys: Using input(s) 1 and endpoint 2 for 'toggle_switch'.
Warning 2024-05-26 14:49:25ubisys: Using input(s) 2 and endpoint 3 for 'toggle_switch'.
Warning 2024-05-26 14:49:25ubisys: Using input(s) 3 and endpoint 4 for 'toggle_switch'.
Error 2024-05-26 14:49:48Publish 'set' 'configure_device_setup' to 'KitchenLightControllerC4' failed: 'Error: ZCL command 0x001fee0000008c6b/232 manuSpecificUbisysDeviceSetup.writeStructured([{"attrId":1,"selector":{},"dataType":72,"elementData":{"elementType":"octetStr","elements":[[0,13,1,6,0,2],[0,3,1,6,0,2],[1,13,2,6,0,2],[1,3,2,6,0,2],[2,13,3,6,0,2],[2,3,3,6,0,2],[3,13,4,6,0,2],[3,3,4,6,0,2]]}}], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Timeout - 32163 - 232 - 10 - 64512 - 16 after 10000ms)'

What did you expect to happen?

I expected that the reconfiguration would work, resulting in flipping my light switch connected to the C4 -> L to send out a toggle command.

How to reproduce it (minimal and precise)

1. Use a Ubisys C4 (firmware 2.4.0)
2. Send a message to topic zigbee2mqtt/<friendly_name_of_c4>/set with the following contents:

{
  "configure_device_setup": {
    "input_action_templates": [
      { "type": "toggle" },
      { "type": "toggle" },
      { "type": "toggle" },
      { "type": "toggle" }
    ]
  }
}

3. wait some time for the error to be logged in the z2m logs.

Zigbee2MQTT version

1.37.1-dev commit: 9b3a394

Adapter firmware version

20221226 - tried 20230507 but that caused a myriad of issues

Adapter

SONOFF ZigBee 3.0 USB Dongle Plus, TI CC2652P

Setup

HAOS add-on

Debug log

log.log
I've included everything, but the last 10-ish lines are the most relevant.

[sjorge]

Interesting, I get the same on my SLZB-06P7 (which I switched to yesterday) but I did not have the issue on my older zzhp-lite. (Also effect S1, S2 and J1)

I'll try and look more into this this weekend.

[2024-05-29 08:12:17] debug:    z2m: Error: ZCL command 0x0000000000000000/232 manuSpecificUbisysDeviceSetup.write({"inputActions":{"elementType":"octetStr","elements":[[0,13,2,6,0,2]]}}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Timeout - 40143 - 232 - 223 - 64512 - 4 after 10000ms)
    at Object.start (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/waitress.ts:63:23)
    at ZStackAdapter.sendZclFrameToEndpointInternal (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/adapter/z-stack/adapter/zStackAdapter.ts:498:47)
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
    at Queue.execute (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/utils/queue.ts:35:20)
    at Request.send (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/helpers/request.ts:79:20)
    at Endpoint.zclCommand (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:767:28)
    at Endpoint.write (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/src/controller/model/endpoint.ts:359:9)
    at Object.convertSet (/opt/zigbee2mqtt/node_modules/zigbee-herdsman-converters/src/devices/ubisys.ts:573:25)
    at Publish.onMQTTMessage (/opt/zigbee2mqtt/lib/extension/publish.ts:259:36)
    at EventEmitter.wrappedCallback (/opt/zigbee2mqtt/lib/eventBus.ts:174:17)

I tried with both write and writeStructure

[sjorge]

@Koenkk seems this broke somewhere recently, again ...

My dev setup was still on 1.36.1-dev commit: 37551265, using my zzh on 20230507. And I was able to configure an S1 just fine.

I did a package capture (I think you still have my dev key, if not ask me again on discord)
z2m-37551265-zzh-dev.pcapng.zip

I did the following:

• start z2m
• read state via the frontend
• toggled the state via the frontend (ensuring the device was responding)
• use the wired up switch (momentum) and watch it toggle the state
• executed mosquitto_pub -t zigbee2mqtt/0x001fee0000006e19/set -m '{"configure_device_setup":{"input_action_templates":[{"type":"on_off_switch"}]}}' -- bad config my my wired switch bu that is fine
• used the wired up switch and see it go off when depressed and back on when release (expected)
• executed mosquitto_pub -t zigbee2mqtt/0x001fee0000006e19/set -m '{"configure_device_setup":{"input_action_templates":[{"type":"dimmer_single", "no_onoff": true}]}}'
• used the wired up switch and see it toggle as expected

After upgrading to my dev setup to 1.37.1-dev commit: a02fd3ce, I also am experiencing the timeouts:

Attached is another capture:

• start z2m
• read state
• toggle state using frontend
• use the wired up switch (toggle)
• executed mosquitto_pub -t zigbee2mqtt/0x001fee0000006e19/set -m '{"configure_device_setup":{"input_action_templates":[{"type":"on_off_switch"}]}}'
• ... timeout
• use the wired switch ... stops respodning
• read state
• toggle state via frontend

The device still seems to respond at least.

z2m-a02fd3ce-zzh-dev.pcapng.zip

Going over the commit history, I would guess it would be either the move of the cluster definition from zh -> zhc or the zspec rewrite in zh that might be the cause. I looked at the packet capture but I am not seeing any immediate clues but i might have missed something.

Edit: on the positive note, switching my dev back to the older build does allow me to configure the S1 so it looks like trying on the newer build does not somehow damage the device 😌

Edit 2: the working dev I had was actually 1.36.1-dev plus zhc at Koenkk/zigbee-herdsman-converters@010319f with Koenkk/zigbee-herdsman-converters@5f82043, applied on top which is after Koenkk/zigbee-herdsman-converters@162f3cd ... so that would rule out the zspec revamp

Edit 3:
To try and narrow it down:
e9b7a84 broken (timeout)
907591c + zhc fix = broken
e03013c + zhc fix = working
4b291bf + zhc fix = working
3755126 + zhc fix = working
3755126 broken (Error: Cluster with name 'manuSpecificUbisysDeviceSetup' does not exist)

[sjorge]

It goes from working to broken between these commits in z2m (I did apply the one fix from Koenkk/zigbee-herdsman-converters@5f82043 to both):

e03013c...907591c

I redid the pcaps but just capturing the writeStruct between both to have a more clear picture of what is going on, I probably should have done this sooner:

Wireshark can't decode the writeStruct when we get a timeout vs it can when we get a response. It would be a fair assumption that, the actually device would be in the same boat.

[sjorge]

I'm leaning towards Koenkk/zigbee-herdsman@f88b4d6 somehow being an issue there.

Edit: this seems to be partially true, writeStruct was never fully implemented before so calls in devices/ubisys.ts needed some changes after that did not happen.

[tomasbedrich]

Hello, unfortunately this is still not working on my side. With 1.38.0-dev commit: [a371347] I am getting the same error. Please see the log (filter for device 0x001fee0000009ae3).

zigbee2mqtt-ubisys-input-actions-fail.log

[bdaenen]

I can second that, I've tested it last night and I'm still seeing identical behaviour on the latest dev add-on, which is using a version of zigbee-herdsman-converters that includes Koenkk/zigbee-herdsman-converters#7587

I haven't had the time to dump the log yet, but I'll get to it this weekend.

[sjorge]

Is either of you able to capture the traffic with wireshark? If the payload is still corrupt it should show up as red, like in my screenshots.

Edit, what firmware are you on? 2.4.0 ?

Since I currently only have a S1 in my test network, can someone try with just:

mosquitto_pub -t zigbee2mqtt/xxx/set -m '{"configure_device_setup":{"input_action_templates":[{"type":"toggle"}]}}

[2024-06-14 14:04:08] debug: 	zh:controller:endpoint: ZCL command 0x001fee0000006e19/232 manuSpecificUbisysDeviceSetup.writeStructured([{"attrId":1,"selector":{},"dataType":72,"elementData":{"elementType":65,"elements":[[0,13,2,6,0,2]]}}], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})

That should make comparing the payload a bit easier. This one applied and works for me. (I had it on on_off_switch before so I know it took the payload as the behavior changed as expected)

Edit 2: I modified my database to swap the model number:

[2024-06-14 14:12:21] debug: 	zh:controller:endpoint: ZCL command 0x001fee0000006e19/232 manuSpecificUbisysDeviceSetup.writeStructured([{"attrId":1,"selector":{},"dataType":72,"elementData":{"elementType":65,"elements":[[0,13,1,6,0,1],[0,3,1,6,0,0],[1,13,2,6,0,2],[2,13,3,6,0,2],[3,13,4,6,0,2]]}}], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})

But the generated payload is what it should be (although the device is offline as I don't want to send the wrong payload to the S1 as that will brick it) and that seems to match the logs provided here 🤔

[bdaenen]

My ubisys c4 I tried is on 2.4.0

I'm assuming I need a second ZigBee stick to wireshark the network, or can one both capture and operate as a coordinator simultaneously?

I'm not opposed to getting one, if only to debug or even contribute in the future, but it's going to be a at least a couple of weeks considering my availability :)

[sjorge]

I'm not opposed to getting one, if only to debug or even contribute in the future, but it's going to be a at least a couple of weeks considering my availability :)

Yeah, you would need a 2nd stick and run the correct firmware on that. https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html#_1-flashing-the-cc2531-stick

It's OK if you can't, I already verified the payload I saw (which the device never saw of course as I unplugged it) from my test just now matches what it should on the mesh at least. So the main question remains why are your C4's not accepting it.

[sjorge]

@bdaenen you were using a zstack based adaptor right? I noticed @tomasbedrich is using ember. writeStructure is not used much yet, basically just this devices and one TRV.

So It could also be bugs lurking in the adaptor side. All I have are zstack devices for both my prd and dev network.

Both are on 20240316, but I don't think the zstrack firmware build should matter for writeStructure support. CC @Koenkk just in case.

[bdaenen]

Indeed, I have a SONOFF ZigBee 3.0 USB Dongle Plus, TI CC2652P which I believe is zstack. It is on a rather old build though (20221226).

I tried flashing newer ones a while back but that resulted in lots of issues with devices not responding, network blackouts, ...

I'll try and update to 20240316 over the weekend and get back to you!

[bdaenen]

Hi,

I've updated to 20240316, and the majority of my devices dropped to an LQI of 0. The Ubisys C4, however, was not affected. There doesn't seem to be any rhyme or reason to the LQI dropping; I have 3 exactly the same brand and model of lamps on the same firmware version in the same room. One works, the other two do not. The one that works is the furthest away from the coordinator 😆

Needless to say, I'm downgrading back to 20221226 for now.

I ran mosquitto_pub -t 'zigbee2mqtt/KitchenLightControllerC4/set' -m '{"configure_device_setup": {"input_action_templates": [{"type": "toggle_switch"}, {"type": "toggle_switch"}, {"type": "toggle_switch"}, {"type": "toggle_switch"}]}}' but the same timeout still occurs.

I still have an unopened Ubisys S2, would there be any value in testing the same things with that device?
At this point I'm willing to switch coordinator adaptors if it gets the Ubisys devices to work, which would also allow me to use the sonoff for sniffing in case any other issues crop up.

Thanks a lot for your time and effort!

[sjorge]

If you could If you have a spare S2, it would be a good data point to check if you also get a timeout trying to configure that one. If that one works fine, we can rule out your adaptor and z-stack fw.

[bdaenen]

Just tested the S2, it also came with firmware 2.4 and behaves identically.

[sjorge]

So it happens on multiple devices for multiple people with different coordinator types.

I'm not really sure what could be the cause of the timeouts, I only ever had timeouts with a corrupt payload.

Before that there were issues with configure_device_setup on newer firmware, but that was because we were using write and not writeStructure on them. For me locally currently everything is working fine and the new configurations send are also applied.