Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.15k stars 1.68k forks source link

IKEA Symfonisk Gen2 remotes E2123 not pairing after in 1.36.1-dev commit: 3e91349 #22084

Closed aurelmarius closed 7 months ago

aurelmarius commented 7 months ago

What happened?

After upgrading to latest dev build 1.36.1-dev commit: 3e91349 the IKEA Symfonisk Gen2 remotes stoped publishing play/puase (toggle) state to mqtt. I tried to re-pair the remote but clusters doesn't bind to coordinator anymore. Downgrading to 1.36.1 commit: ffc2ff1 solves the problem.

[2024-04-04 18:30:42] info:     z2m: Configuring '0x540f57fffe449664'
[2024-04-04 18:30:42] debug:    z2m: Received Zigbee message from '0x540f57fffe449664', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":16777269,"imageType":4366,"manufacturerCode":4476}' from endpoint 1 with groupID 0
[2024-04-04 18:30:42] debug:    z2m: Device '0x540f57fffe449664' requested OTA
[2024-04-04 18:30:42] debug:    zh:controller:endpoint: CommandResponse 0x540f57fffe449664/1 genOta.queryNextImageResponse({"status":152}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})
[2024-04-04 18:30:42] debug:    zh:controller:endpoint: Request Queue (0x540f57fffe449664/1): send request
[2024-04-04 18:30:42] debug:    zh:ember:queue: Status queue=0 priorityQueue=0.
[2024-04-04 18:30:42] error:    z2m: Failed to configure '0x540f57fffe449664', attempt 3 (Error: Device 0x540f57fffe449664 has no output cluster genPollCtrl
    at getEndpointsWithCluster (/app/node_modules/zigbee-herdsman-converters/src/lib/modernExtend.ts:28:15)
    at configure (/app/node_modules/zigbee-herdsman-converters/src/lib/modernExtend.ts:126:31)
    at Object.configure (/app/node_modules/zigbee-herdsman-converters/src/index.ts:164:27)
    at Configure.configure (/app/lib/extension/configure.ts:122:37)
    at /app/lib/extension/configure.ts:87:62
    at EventEmitter.wrappedCallback (/app/lib/eventBus.ts:174:23)
    at EventEmitter.emit (node:events:529:35)
    at EventBus.emitLastSeenChanged (/app/lib/eventBus.ts:51:22)
    at Controller.<anonymous> (/app/lib/zigbee.ts:74:27)
    at Controller.emit (node:events:517:28))

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.36.1-dev commit: 3e91349

Adapter firmware version

7.4.1 [GA]

Adapter

SLZB-06M

Setup

Docker on x86-64 Intel CPU

Debug log

log.log

aurelmarius commented 7 months ago

@mrskycriper This doesn't fix the bindings. Also commandToggle doesn't publish to mqtt. I attached logs.

Debug 2024-04-06 13:47:30AREQ: <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":33109,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":94,"securityuse":0,"timestamp":752456,"transseqnumber":0,"len":3,"data":{"type":"Buffer","data":[17,25,2]}}
Debug 2024-04-06 13:47:30Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":25,"manufacturerCode":null,"commandIdentifier":2},"Payload":{},"Command":{"ID":2,"parameters":[],"name":"toggle"}},"address":33109,"endpoint":1,"linkquality":94,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'
Debug 2024-04-06 13:47:30--- parseNext []
Debug 2024-04-06 13:47:30Received Zigbee message from '0x540f57fffe449664', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
ikea-bindings

log.log

mrskycriper commented 7 months ago

@mrskycriper This doesn't fix the bindings. Also commandToggle doesn't publish to mqtt. I attached logs.

ikea-bindings

log.log

Can you try manually re-configuring it? Automatic re-configuration should have been disabled recently. Toggle will probably start working after genOnOff bind is restored.

aurelmarius commented 7 months ago

@mrskycriper This doesn't fix the bindings. Also commandToggle doesn't publish to mqtt. I attached logs.

ikea-bindings

log.log

Can you try manually re-configuring it? Automatic re-configuration should have been disabled recently. Toggle will probably start working after genOnOff bind is restored.

Error 2024-04-06 14:01:20Failed to configure '0x540f57fffe449664', attempt 4 (Error: Device 0x540f57fffe449664 has no input cluster genLevelCtrl at getEndpointsWithCluster (/app/node_modules/zigbee-herdsman-converters/src/lib/modernExtend.ts:28:15) at configure (/app/node_modules/zigbee-herdsman-converters/src/lib/modernExtend.ts:126:31) at Object.configure (/app/node_modules/zigbee-herdsman-converters/src/index.ts:164:27) at processTicksAndRejections (node:internal/process/task_queues:95:5) at Configure.configure (/app/lib/extension/configure.ts:121:13) at Configure.onMQTTMessage (/app/lib/extension/configure.ts:55:21) at EventEmitter.wrappedCallback (/app/lib/eventBus.ts:174:17))
Debug 2024-04-06 14:01:20MQTT publish: topic 'zigbee2mqtt/bridge/response/device/configure', payload '{"data":{"id":"0x540f57fffe449664"},"error":"Failed to configure (Device 0x540f57fffe449664 has no input cluster genLevelCtrl)","status":"error","transaction":"t13kq-1"}'
mrskycriper commented 7 months ago

@aurelmarius My bad, I see that bug with cluster type. Second hot-fix is coming.

aurelmarius commented 7 months ago

@mrskycriper

I tried to manually bind the OnOff and LevelCtrl clusters, the command was succcesfull. Now I can see volume_up and volume_down actions published to mqtt but still no toggle.

Toggle:

Debug 2024-04-06 14:20:12AREQ: <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":33109,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":83,"securityuse":0,"timestamp":13275545,"transseqnumber":0,"len":3,"data":{"type":"Buffer","data":[17,46,2]}}
Debug 2024-04-06 14:20:12Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":46,"manufacturerCode":null,"commandIdentifier":2},"Payload":{},"Command":{"ID":2,"parameters":[],"name":"toggle"}},"address":33109,"endpoint":1,"linkquality":83,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'
Debug 2024-04-06 14:20:12--- parseNext []
Debug 2024-04-06 14:20:12Received Zigbee message from '0x540f57fffe449664', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0

Volume UP:

Debug 2024-04-06 14:20:46Received Zigbee message from '0x540f57fffe449664', type 'commandMoveWithOnOff', cluster 'genLevelCtrl', data '{"movemode":0,"rate":255}' from endpoint 1 with groupID 0
Debug 2024-04-06 14:20:46MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664', payload '{"action":"volume_up","battery":null,"linkquality":47,"update":{"installed_version":16777269,"latest_version":16777269,"state":"idle"},"update_available":null,"voltage":null}'
Debug 2024-04-06 14:20:46MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664', payload '{"action":"","battery":null,"linkquality":47,"update":{"installed_version":16777269,"latest_version":16777269,"state":"idle"},"update_available":null,"voltage":null}'
Debug 2024-04-06 14:20:46MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664/action', payload 'volume_up'

Testing more things and setting device into Legacy, I got play_pause action sent to mqtt:

Debug 2024-04-06 14:25:42MQTT publish: topic 'homeassistant/device_automation/0x540f57fffe449664/action_play_pause/config', payload '{"automation_type":"trigger","device":{"identifiers":["zigbee2mqtt_0x540f57fffe449664"],"manufacturer":"IKEA","model":"SYMFONISK sound remote, gen 2 (E2123)","name":"0x540f57fffe449664","sw_version":"1.0.35","via_device":"zigbee2mqtt_bridge_0x00124b002578dd23"},"origin":{"name":"Zigbee2MQTT","sw":"1.36.1-dev","url":"https://www.zigbee2mqtt.io"},"payload":"play_pause","subtype":"play_pause","topic":"zigbee2mqtt/0x540f57fffe449664/action","type":"action"}'
Debug 2024-04-06 14:25:42Received MQTT message on 'homeassistant/device_automation/0x540f57fffe449664/action_play_pause/config' with data '{"automation_type":"trigger","device":{"identifiers":["zigbee2mqtt_0x540f57fffe449664"],"manufacturer":"IKEA","model":"SYMFONISK sound remote, gen 2 (E2123)","name":"0x540f57fffe449664","sw_version":"1.0.35","via_device":"zigbee2mqtt_bridge_0x00124b002578dd23"},"origin":{"name":"Zigbee2MQTT","sw":"1.36.1-dev","url":"https://www.zigbee2mqtt.io"},"payload":"play_pause","subtype":"play_pause","topic":"zigbee2mqtt/0x540f57fffe449664/action","type":"action"}'
Debug 2024-04-06 14:25:42MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664/action', payload 'play_pause'
Screenshot 2024-04-06 at 14 22 01
aurelmarius commented 7 months ago

@mrskycriper Thanks for the fix. It is almost ok now. Toggle button still doesn't work when Legacy is off. (Should I open a new issue for this ?). When pairing the remote, Endpoint 3 doesn't bind as tradfriButton and dots_2 button doesn't work.

Screenshot 2024-04-07 at 18 31 32

It should be like in this picture.

Screenshot 2024-04-07 at 18 39 17

log.log

mrskycriper commented 7 months ago

Should I open a new issue for this

Just re-open this one. It wasn't fixed yet, so I'd say that's fair.

Toggle button still doesn't work when Legacy is off.

That is super strange, I'll triple check my code.

When pairing the remote, Endpoint 3 doesn't bind as tradfriButton and dots_2 button doesn't work.

Can you please share the contents of Clusters tab for this device?

aurelmarius commented 7 months ago

Just re-open this one. It wasn't fixed yet, so I'd say that's fair.

Can't reopen it, but i think it doesn't matter.

That is super strange, I'll triple check my code.

You can see in the log:

Legacy disabled: No MQTT Publish

[2024-04-07 18:33:00] debug:    zh:zstack:znp: AREQ: <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":65418,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":58,"securityuse":0,"timestamp":6891418,"transseqnumber":0,"len":3,"data":{"type":"Buffer","data":[17,32,2]}}
[2024-04-07 18:33:00] debug:    zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":32,"manufacturerCode":null,"commandIdentifier":2},"Payload":{},"Command":{"ID":2,"parameters":[],"name":"toggle"}},"address":65418,"endpoint":1,"linkquality":58,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'
[2024-04-07 18:33:00] debug:    zh:zstack:unpi:parser: --- parseNext []
[2024-04-07 18:33:00] debug:    z2m: Received Zigbee message from '0x540f57fffe449664', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0

Legacy enabled:

[2024-04-07 18:32:59] debug:    zh:zstack:znp: AREQ: <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":65418,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":47,"securityuse":0,"timestamp":6827204,"transseqnumber":0,"len":3,"data":{"type":"Buffer","data":[17,31,2]}}
[2024-04-07 18:32:59] debug:    zh:controller: Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":1,"manufacturerSpecific":false,"direction":0,"disableDefaultResponse":true,"reservedBits":0},"transactionSequenceNumber":31,"manufacturerCode":null,"commandIdentifier":2},"Payload":{},"Command":{"ID":2,"parameters":[],"name":"toggle"}},"address":65418,"endpoint":1,"linkquality":47,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'
[2024-04-07 18:32:59] debug:    zh:zstack:unpi:parser: --- parseNext []
[2024-04-07 18:32:59] debug:    z2m: Received Zigbee message from '0x540f57fffe449664', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
[2024-04-07 18:32:59] debug:    z2m: MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664', payload '{"action":"play_pause","battery":100,"linkquality":47,"update":{"installed_version":-1,"latest_version":-1,"state":null},"update_available":null,"voltage":null}'
[2024-04-07 18:32:59] debug:    z2m: MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664', payload '{"action":"","battery":100,"linkquality":47,"update":{"installed_version":-1,"latest_version":-1,"state":null},"update_available":null,"voltage":null}'
[2024-04-07 18:32:59] debug:    z2m: MQTT publish: topic 'zigbee2mqtt/0x540f57fffe449664/action', payload 'play_pause'

On the 1.36.1 stable is like this:

Info 2024-04-07 19:22:22MQTT publish: topic 'zigbee2mqttefr32/Music Remote Buc/action', payload 'toggle'
Debug 2024-04-07 19:22:24Received Zigbee message from 'Music Remote Buc', type 'commandToggle', cluster 'genOnOff', data '{}' from endpoint 1 with groupID 0
Info 2024-04-07 19:22:24MQTT publish: topic 'zigbee2mqttefr32/Music Remote Buc', payload '{"action":"toggle","battery":100,"linkquality":248,"update":{"installed_version":-1,"latest_version":-1,"state":null},"update_available":null,"voltage":3100}'
Info 2024-04-07 19:22:24MQTT publish: topic 'zigbee2mqttefr32/Music Remote Buc', payload '{"action":"","battery":100,"linkquality":248,"update":{"installed_version":-1,"latest_version":-1,"state":null},"update_available":null,"voltage":3100}'
Info 2024-04-07 19:22:24MQTT publish: topic 'zigbee2mqttefr32/Music Remote Buc/action', payload 'toggle'

Can you please share the contents of Clusters tab for this device?

Sure:

Screenshot 2024-04-07 at 19 15 46
aurelmarius commented 7 months ago

@mrskycriper Maybe this info will help you with the debug. When pairing, z2m will bind tradfriButton as InputCluster on Endpoint 1, but the remote doesn't have tradfriButton on that endpoint.

Screenshot 2024-04-08 at 19 43 59
mrskycriper commented 7 months ago

Welp, I found a bug and it's fundamental. Filtering for reportings and binging is only accepting endpoints by name but treats them like endpoint ids (which are numeric).

As for the toggle, I suspect that legacy converter is catching those messages and prevents them from being handled by modern extends.

aurelmarius commented 7 months ago

As for the toggle, I suspect that legacy converter is catching those messages and prevents them from being handled by modern extends.

Thanks. I can confirm that it was fixed by https://github.com/Koenkk/zigbee-herdsman-converters/pull/7376

mrskycriper commented 7 months ago

@aurelmarius binding should also be fixed after the 4th PR. Can you please confirm that?

aurelmarius commented 7 months ago

@aurelmarius binding should also be fixed after the 4th PR. Can you please confirm that?

Yes, it works as expected. Thanks a lot.