search

zigpy / bellows

A Python 3 project to implement EZSP for EmberZNet devices
GNU General Public License v3.0
177 stars 87 forks source link

Group messagen sent to group 0x0000 #536

Closed pipiche38 closed 1 year ago

pipiche38 commented 1 year ago

We are using zigpy library and it looks like when a Ikea remote is sending an On or Off message to group 0x0000, the message is not seen in the upper layer.

Here after is what I have been able to capture from the logs

2023-03-19 19:03:52,303 DEBUG   :Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_MULTICAST: 3>, 65533, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=155), 255, <EmberStatus.SUCCESS: 0>, b'']
2023-03-19 19:03:52,305 DEBUG   :Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_MULTICAST: 3>, 65533, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=155), 255, <EmberStatus.SUCCESS: 0>, b'']
2023-03-19 19:03:52,307 DEBUG   :Unexpected message send notification tag: 255

Screenshot 2023-03-19 at 19 04 24

puddly commented 1 year ago

Add the coordinator to group 0x0000, this is what quirks do: https://github.com/zigpy/zha-device-handlers/blob/fa60b9d23a3e94b5a164e6aad1f24f4134544daa/zhaquirks/ikea/__init__.py#L19-L43

pipiche38 commented 1 year ago

As you know we are using only the low level here is what I did, and from the respond, the coordinator is added to Group 0x0000, however still the messages are not coming through

2023-03-19 20:20:42,066 INFO    : [ MainThread 18316] Start Group Management
2023-03-19 20:20:42,072 DEBUG   : [ MainThread 18316] add_group_member_ship GrpId: 0000, NwkId: 0000, Ep: 01
2023-03-19 20:20:42,073 DEBUG   : [ MainThread 18316] zcl_add_group_membership 0000 01 0000
2023-03-19 20:20:42,075 DEBUG   : [ MainThread 18316] zcl_raw_add_group_membership 0000 01 01 0000
2023-03-19 20:20:42,083 DEBUG   :Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=8, profile_id=260, cluster_id=4, data=Serialized[b'\x11\x00\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2023-03-19 20:20:42,085 DEBUG   : [ MainThread 18316] Dumping: /var/lib/domoticz/plugins/Domoticz-Zigbee/Data//GroupsList-07.json
2023-03-19 20:20:42,092 DEBUG   :Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x0000, EmberApsFrame(profileId=260, clusterId=4, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=8), 9, b'\x11\x00\x00\x00\x00\x00')
2023-03-19 20:20:42,104 DEBUG   :Sending: b'651721a9602a15b259904b21aa5493099c4e27a3e4c8768bfdc66389dde07e'
2023-03-19 20:20:42,115 DEBUG   :Data frame: b'5717a1a9602a15ddcb6e7e'
2023-03-19 20:20:42,117 DEBUG   :Sending: b'8610be7e'
2023-03-19 20:20:42,120 DEBUG   :Application frame received sendUnicast: [<EmberStatus.SUCCESS: 0>, 111]
2023-03-19 20:20:42,124 DEBUG   :Data frame: b'6717b1a9112a15b658904a24ab1592499c21d8abedce9874fbd76389fc7e3f56257e'
2023-03-19 20:20:42,125 DEBUG   :Sending: b'87009f7e'
2023-03-19 20:20:42,128 DEBUG   :Data frame: b'7717b1a96b2a15b259904b21aa5493099c4e27c4e4ce6749a67e'
2023-03-19 20:20:42,131 DEBUG   :Application frame received incomingMessageHandler: [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=4, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=111), 255, 0, 0x0000, 255, 255, b'\x11\x00\x00\x00\x00\x00']
2023-03-19 20:20:42,132 DEBUG   :Sending: b'8070787e'
2023-03-19 20:20:42,134 DEBUG   :Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=4, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=111), 255, 0, 0x0000, 255, 255, b'\x11\x00\x00\x00\x00\x00']
2023-03-19 20:20:42,138 DEBUG   :Received a packet: ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=111, profile_id=260, cluster_id=4, data=Serialized[b'\x11\x00\x00\x00\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=255, rssi=0)
2023-03-19 20:20:42,143 DEBUG   :[0x0000:1:0x0004] Received ZCL frame: b'\x11\x00\x00\x00\x00\x00'
2023-03-19 20:20:42,149 DEBUG   :[0x0000:1:0x0004] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=0, command_id=0, *direction=<Direction.Server_to_Client: 0>)
2023-03-19 20:20:42,154 DEBUG   :[0x0000:1:0x0004] Decoded ZCL frame: Groups:add(group_id=0x0000, group_name='')
2023-03-19 20:20:42,156 DEBUG   :[0x0000:1:0x0004] Received command 0x00 (TSN 0): add(group_id=0x0000, group_name='')
2023-03-19 20:20:42,158 DEBUG   :[0x0000:1:0x0004] No explicit handler for cluster command 0x00: add(group_id=0x0000, group_name='')
2023-03-19 20:20:42,169 DEBUG   :Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0, EmberApsFrame(profileId=260, clusterId=4, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=111), 9, <EmberStatus.SUCCESS: 0>, b'']
2023-03-19 20:20:42,173 DEBUG   : [ZigpyForwarder_7 18343] zcl_decoders Zcl.ddr: 1 GlobalCommand: False Sqn: 00 ManufCode: None Command: 00 Data: 000000 Payload: 110000000000
2023-03-19 20:20:42,174 DEBUG   :Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0, EmberApsFrame(profileId=260, clusterId=4, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY: 64>, groupId=0, sequence=111), 9, <EmberStatus.SUCCESS: 0>, b'']
2023-03-19 20:20:42,175 DEBUG   : [ZigpyForwarder_7 18343] buildframe_8060_add_group_member_ship_response - Data: 000000
2023-03-19 20:20:42,181 DEBUG   : [ZigpyForwarder_7 18343] add_group_member_ship_response - MsgData: 000100040000000000 (18)
2023-03-19 20:20:42,184 DEBUG   : [ZigpyForwarder_7 18343] add_group_member_ship_response - [00] GroupID: 0000 adding: 0000 with Status: 00

2023-03-19 20:24:54,666 DEBUG :Data frame: b'13d3b1a96b2a164fa6904b23aa546d499d4e277412ce6730327e' 2023-03-19 20:24:54,667 DEBUG :Sending: b'82503a7e' 2023-03-19 20:24:54,671 DEBUG :Application frame received messageSentHandler: [<EmberOutgoingMessageType.OUTGOING_MULTICAST: 3>, 65533, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=223), 255, <EmberStatus.SUCCESS: 0>, b''] 2023-03-19 20:24:54,674 DEBUG :Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_MULTICAST: 3>, 65533, EmberApsFrame(profileId=260, clusterId=6, sourceEndpoint=1, destinationEndpoint=255, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=223), 255, <EmberStatus.SUCCESS: 0>, b''] 2023-03-19 20:24:54,676 DEBUG :Unexpected message send notification tag: 255

puddly commented 1 year ago

It has to be done exactly in the way I linked to above. Loopback ZCL requests are usually ignored by EmberZNet, add_to_group on the coordinator is rewritten to use an EZSP command.

pipiche38 commented 1 year ago

It has to be done exactly in the way I linked to above. Loopback ZCL requests are usually ignored by EmberZNet, add_to_group on the coordinator is rewritten to use an EZSP command.

Not sure I understand what you mean. In fact we rely on handle_message() which has been overwrite.

puddly commented 1 year ago

I'm referring to this:

2023-03-19 20:20:42,066 INFO    : [ MainThread 18316] Start Group Management
2023-03-19 20:20:42,072 DEBUG   : [ MainThread 18316] add_group_member_ship GrpId: 0000, NwkId: 0000, Ep: 01
2023-03-19 20:20:42,073 DEBUG   : [ MainThread 18316] zcl_add_group_membership 0000 01 0000
2023-03-19 20:20:42,075 DEBUG   : [ MainThread 18316] zcl_raw_add_group_membership 0000 01 01 0000
2023-03-19 20:20:42,083 DEBUG   :Sending packet ZigbeePacket(src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=8, profile_id=260, cluster_id=4, data=Serialized[b'\x11\x00\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)

You can't send a Groups.add ZCL command from 0x0000 to 0x0000 because EmberZNet doesn't process it. You have to use coordinator_app.add_to_group(0x0000, name="Group name"), which is internally translated into an EmberZNet setMulticastTableEntry command.

pipiche38 commented 1 year ago

@puddly as usall, thanks for your support. It works like a charm. I'll migh investigate more to probably use the zigpy group API