Group Communication - Unable to verify if the multicast command is working correctly

[sethunk]

Problem - We are sending multicast command to DUT for onoff cluster to change the on-off attribute value to "on". We are trying to read the same attribute value in unicast mode to check if the multicast command actually worked but we are not able to see the value changed in the attribute.
Before sending multicast command we are setting the appropriate ACL entry and Group settings command to initialise the test condition.

Sequence of the Commands sent:
1.Initial Commands

1. ./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": [{"cluster": null, "endpoint": 0, "deviceType": null}]}, {"fabricIndex": 1, "privilege": 3, "authMode": 3, "subjects": null, "targets": [{"cluster": null, "endpoint": 1, "deviceType": null}]}]' 1 0
2. ./chip-tool groupkeymanagement key-set-write '{"groupKeySetID": 42,"groupKeySecurityPolicy": 0, "epochKey0":"d0d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime0": 2220000,"epochKey1":"d1d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime1": 2220001,"epochKey2":"d2d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime2": 2220002 }' 1 0
3. ./chip-tool groups add-group 0x0001 grp1 1 0
4. ./chip-tool groupkeymanagement write group-key-map '[{"groupId": 1, "groupKeySetID": 42, "fabricIndex": 1}]' 1 0
5. ./chip-tool groups view-group 0x0001 1 0
6. ./chip-tool groupkeymanagement key-set-read 42 1 0
7. ./chip-tool groupkeymanagement read group-table 1 0
8. ./chip-tool groupsettings add-group grp1 0x0001
9. ./chip-tool groupsettings add-keysets 0x42 0 0x000000000021dfe hex:d0d1d2d3d4d5d6d7d8d9dadbdcdddedf
10. ./chip-tool groupsettings bind-keyset 0x0001 0x42
11. ./chip-tool groupsettings show-groups

---

2.Sending Multicast commands
12../chip-tool onoff on 0xffffffffffff0001 1

---

3.Reading on-off attribute
13../chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": [{"cluster": null, "endpoint": 0, "deviceType": null}]}, {"fabricIndex": 1, "privilege": 3, "authMode": 2, "subjects": null, "targets": [{"cluster": null, "endpoint": 1, "deviceType": null}]}]' 1 0
14../chip-tool onoff read on-off 1 1

Note: Response from DUT
[1655278244.271372][3893:3893] CHIP:DMG: ReadRequestMessage =
[1655278244.271400][3893:3893] CHIP:DMG: {
[1655278244.271422][3893:3893] CHIP:DMG: AttributePathIBs =
[1655278244.271448][3893:3893] CHIP:DMG: [
[1655278244.271472][3893:3893] CHIP:DMG: AttributePathIB =
[1655278244.271500][3893:3893] CHIP:DMG: {
[1655278244.271527][3893:3893] CHIP:DMG: Endpoint = 0x1,
[1655278244.271561][3893:3893] CHIP:DMG: Cluster = 0x6,
[1655278244.271589][3893:3893] CHIP:DMG: Attribute = 0x0000_0000,
[1655278244.271619][3893:3893] CHIP:DMG: }
[1655278244.271646][3893:3893] CHIP:DMG:
[1655278244.271671][3893:3893] CHIP:DMG: ],
[1655278244.271699][3893:3893] CHIP:DMG:
[1655278244.271726][3893:3893] CHIP:DMG: isFabricFiltered = true,
[1655278244.271750][3893:3893] CHIP:DMG: InteractionModelRevision = 1
[1655278244.271773][3893:3893] CHIP:DMG: },
[1655278244.271853][3893:3893] CHIP:DMG: IM RH moving to [GeneratingReports]
[1655278244.271945][3893:3893] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0
[1655278244.271975][3893:3893] CHIP:DMG: RE:Run Cluster 6, Attribute 0 is dirty
[1655278244.271996][3893:3893] CHIP:DMG: Reading attribute: Cluster=0x0000_0006 Endpoint=1 AttributeId=0x0000_0000 (expanded=0)
[1655278244.272024][3893:3893] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0006 e=1 p=v
[1655278244.272059][3893:3893] CHIP:DMG: AccessControl: allowed

---

4.Test Environment

App used - allclusters app
Platform - Chip-tool - RPI-4, 8GB RAM
DUT - RPI - RPI-4, 8GB RAM
Network - Ble-wifi
Commit - 9493d7b

5Logs
DUT_Logs_15.06.2022.txt
TH_Logs_15.06.2022.txt

[dtodor]

We are also unable to control the devices using group messaging. We are testing on EFR32 and ESP32, it seems that the multicasts are not received. According to the logs, the ESP32 device cannot join the multicast group whereas the EFR32 device joins the group but does not receive any messages.

ESP32 output:

I (2402) chip[SVR]: Joining Multicast groups
I (2402) chip[IN]: Joining Multicast Group with address UDP:[FF35:40:FD00::100:3E8]:5540
E (2412) chip[SVR]: Error when trying to join Group 1000 of fabric index 1 : 10e

EFR32 output:

<detail> [DL] OpenThread State Changed (Flags: 0x00001084)
<detail> [DL]    Device Role: CHILD
<detail> [DL]    Partition Id: 0x4D5DA14C
<info  > [DL] _OnPlatformEvent default:  event->Type = 32769
<info  > [DL] SRP Client was started, detected server: fd6a:2dcf:2b13:a3ef:a88b:7415:0cb4:61ff
<info  > [DL] _OnPlatformEvent default:  event->Type = 32780
<detail> [DL] OpenThread State Changed (Flags: 0x00000200)
<info  > [DL] _OnPlatformEvent default:  event->Type = 32780
<detail> [DL] Thread Attached updating Multicast address
<info  > [SVR] Joining Multicast groups
<info  > [IN] Joining Multicast Group with address UDP:[ff35:40:fd00:0:0:0:100:3e8]:5540
<detail> [DL] OpenThread State Changed (Flags: 0x00000001)
<detail> [DL]    Thread Unicast Addresses:
<detail> [DL]         fd03:329c:d7fa:1:6f26:89c7:e576:bca7/64 valid preferred
<detail> [DL]         fd6a:2dcf:2b13:a3ef:0:ff:fe00:9c01/64 valid rloc
<detail> [DL]         fd6a:2dcf:2b13:a3ef:bab0:a3bc:cd47:ffa8/64 valid
<detail> [DL]         fe80:0:0:0:888b:3a6e:3ebe:e6eb/64 valid preferred

Controller output:

[1655291066.498019][18480:18483] CHIP:CTL: Getting value for key 'g/gdc' with size 4
[1655291066.498287][18480:18483] CHIP:CTL: Getting value for key 'f/1/g' with size 128
[1655291066.498407][18480:18483] CHIP:CTL: Getting value for key 'f/1/gk/1' with size 128
[1655291066.498492][18480:18483] CHIP:CTL: Getting value for key 'f/1/gk/2' with size 128
[1655291066.498625][18480:18483] CHIP:CTL: Getting value for key 'f/1/gk/3' with size 128
[1655291066.498712][18480:18483] CHIP:CTL: Getting value for key 'f/1/k/3e8' with size 128
[1655291066.506803][18480:18483] CHIP:IN: Prepared outgoing group message 0x75dfdab8 to 0x0000000000000000 (1)  of type 0x8 and protocolId (0, 1) on exchange 23189i with MessageCounter:76000.
[1655291066.507255][18480:18483] CHIP:IN: Sending encrypted group msg 0x75dfdab8 with MessageCounter:76000 to 1000 at monotonic time: 0000000000C0974B msec to Multicast IPV6 address : UDP:[ff35:40:fd00::100:3e8]:5540 with GroupID of 1000 and fabric index of 1

[bzbarsky-apple]

@dtodor For ESP32, the issue is known and tracked in #18984

@dtodor For EFR32, groups are expected to work. Please file a separate issue with exact steps to reproduce and logs.

For the original issue here, @sethunk thank you for the detailed steps and the complete (and even annotated!) logs.

This command in the sequence of commands executed:

./chip-tool groups add-group 0x0001 grp1 1 0

adds endpoint 0 of all-clusters-app to the group. That endpoint does not have an On/Off cluster on it. And later when the on command is sent the server logs:

[1655278098.965247][3893:3893] CHIP:DMG: Received group command for Group=1 Cluster=0x0000_0006 Command=0x0000_0001
[1655278098.965876][3893:3893] CHIP:DMG: Processing group command for Endpoint=0 Cluster=0x0000_0006 Command=0x0000_0001
[1655278098.965951][3893:3893] CHIP:DMG: No command 0x0000_0000 in Cluster 0x0000_0006 on Endpoint 0x0

(Ignore the wrong command id in that third log line; I'll put up a PR to fix that in a sec.)

@sethunk Does fixing that add-group command to be ./chip-tool groups add-group 0x0001 grp1 1 1 to add endpoint 1 to the group (since that's where the later read is going to look for the state change) make things work?

[jepenven-silabs]

Well the problem is right in the logs : Group registered on the EFR32 has an ipv6 address of
UDP:[ff35:40:fd00:0:0:0:100:3e8]:5540
While the command sent with chip-tool goes to
UDP:[ff35:40:fd00::100:3e8]:5540

Since the logs from the ESP32 doesn't have this problem, it might be specific to the implementation

[dtodor]

I don't get it, it is the same IP address actually, right?

[jepenven-silabs]

Joining Multicast Group with address

My bad, I did not see the :: in the destination address

[jepenven-silabs]

@dtodor the complete log for the EFR32 in a different issue would be appreciated since there is a huge amount of reasons why a multicast packet might be discarded. On the EFR32 platform you should be able to see a log that is printed on reception of ANY IPV6 messages with the destinations Addr it starts with UDP Message Received packet nb : If you're able to see this logs with the multicast address in it, the the problem is that the group configuration or ACL isn't set properly either on the client or server side. If you don't see it then it's because the packet never reached the device.

[dtodor]

@jepenven-silabs Yes, I don't see the log. I'm starting to think that the OpenThread Border Router is not configured properly. Is there any documentation on how to compile OTBR to support multicasts?

[dtodor]

@jepenven-silabs I'll move the discussion to this thread: #19624.
@sethunk Sorry for hijacking the ticket!

[woody-apple]

Cert Blocker Review: Please note this comment:

./chip-tool groups add-group 0x0001 grp1 1 0

adds endpoint 0 of all-clusters-app to the group. That endpoint does not have an On/Off cluster on it. And later when the on command is sent the server logs:

[1655278098.965247][3893:3893] CHIP:DMG: Received group command for Group=1 Cluster=0x0000_0006 Command=0x0000_0001
[1655278098.965876][3893:3893] CHIP:DMG: Processing group command for Endpoint=0 Cluster=0x0000_0006 Command=0x0000_0001
[1655278098.965951][3893:3893] CHIP:DMG: No command 0x0000_0000 in Cluster 0x0000_0006 on Endpoint 0x0

(Ignore the wrong command id in that third log line; I'll put up a PR to fix that in a sec.)

@sethunk Does fixing that add-group command to be ./chip-tool groups add-group 0x0001 grp1 1 1 to add endpoint 1 to the group (since that's where the later read is going to look for the state change) make things work?

[mkardous-silabs]

I was able to confirm there is no issue device side for efr32 devices.
@bzbarsky-apple @sethunk I ran the test again on an efr32 MG12 device and everything works as expected.
Here are the commands I ran.

• Device side

./chip-tool groups add-group 0x0001 grp1 <node-id> 1
./chip-tool groupkeymanagement key-set-write '{"groupKeySetID": "0x42","groupKeySecurityPolicy": 0, "epochKey0":"d0d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime0": 2220000,"epochKey1":"d1d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime1": 2220001,"epochKey2":"d2d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime2": 2220002 }' <nodeId>
./chip-tool groupkeymanagement write group-key-map '[{"groupId": 1, "groupKeySetID": "0x42", "fabricIndex": 1}]' <nodeId> 0
./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": null },{"fabricIndex": 1, "privilege": 3, "authMode": 3, "subjects": [1], "targets": null }]' <nodeId> 0

• Controller

./chip-tool groupsettings add-group grp1 0x0001
./chip-tool groupsettings add-keysets 0x42 0 0x000000000021dfe hex:d0d1d2d3d4d5d6d7d8d9dadbdcdddedf
./chip-tool groupsettings bind-keyset 0x0001 0x42

• Send Command

./chip-tool onoff on 0xffffffffffff0001 1

• Validate Command

./chip-tool onoff read on-off <nodeId> 1

[sethunk]

I have been able to get this working. Thank you for the support.