Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Group messaging on EFR32 #19624

Closed
dtodor opened this issue Jun 15, 2022 · 12 comments
Closed

Group messaging on EFR32 #19624

dtodor opened this issue Jun 15, 2022 · 12 comments

Comments

@dtodor
Copy link

dtodor commented Jun 15, 2022

Group messages are not delivered to EFR32 devices. According to the logs, the EFR32 device joins the group but does not receive any messages. The problem might be related to the configuration of the OpenThread Border Router.

The initial discussion was started in this thread: #19608.

@dtodor
Copy link
Author

dtodor commented Jun 15, 2022

This is the OTBR configuration we are currently using:

  -DOTBR_DBUS=OFF \
  -DOTBR_DNSSD_DISCOVERY_PROXY=ON \
  -DOTBR_SRP_ADVERTISING_PROXY=ON \
  -DOTBR_INFRA_IF_NAME=eth0 \
  -DOTBR_MDNS=mDNSResponder \
  -DOTBR_BORDER_ROUTING=ON \
  -DOTBR_REST=ON \
  -DBUILD_SHARED_LIBS=OFF \
  -DOT_FIREWALL=OFF \
  -DOT_COAP_OBSERVE=ON \
  -DOT_TREL=OFF \
  -DOT_THREAD_VERSION=1.2 \
  -DOT_BACKBONE_ROUTER=1

We can also see these OTBR logs:

Jun 15 12:23:19 qivicon user.info otbr-agent[3300]: 00:00:21.913 [I] Platform------: MulticastRoutingManager: Enable: OK
Jun 15 12:23:46 qivicon user.info otbr-agent[3300]: 00:00:48.560 [I] Platform------: MulticastRoutingManager: UpdateMldReport: address ff35:40:fd00:0:0:0:100:3e8 Added: OK
Jun 15 12:23:46 qivicon user.info otbr-agent[3300]: 00:00:48.561 [I] Platform------: MulticastRoutingManager: Add: ff35:40:fd00:0:0:0:100:3e8: OK
Jun 15 12:24:52 qivicon user.info otbr-agent[3300]: 00:01:54.745 [I] Platform------: MulticastRoutingManager: AddMulticastForwardingCache: add dynamic route: Backbone fd9a:2b6f:2f66:0:a3:2aff:fe9c:3fe3 => ff35:40:fd00:0:0:0:100:3e8 Thread: OK
Jun 15 12:24:52 qivicon user.info otbr-agent[3300]: 00:01:54.746 [I] Platform------: MulticastRoutingManager: ProcessMulticastRouterMessages: OK
Jun 15 12:35:20 qivicon user.info otbr-agent[3300]: 00:12:22.972 [I] Platform------: MulticastRoutingManager: RemoveMulticastForwardingCache: Backbone fd9a:2b6f:2f66:0:a3:2aff:fe9c:3fe3 => ff35:40:fd00:0:0:0:100:3e8 Thread: OK
Jun 15 13:20:37 qivicon user.info otbr-agent[3300]: 00:57:39.179 [I] Platform------: MulticastRoutingManager: AddMulticastForwardingCache: add dynamic route: Backbone fd9a:2b6f:2f66:0:a3:2aff:fe9c:3fe3 => ff35:40:fd00:0:0:0:100:3e8 Thread: OK
Jun 15 13:20:37 qivicon user.info otbr-agent[3300]: 00:57:39.179 [I] Platform------: MulticastRoutingManager: ProcessMulticastRouterMessages: OK
Jun 15 13:31:21 qivicon user.info otbr-agent[3300]: 01:08:23.421 [I] Platform------: MulticastRoutingManager: RemoveMulticastForwardingCache: Backbone fd9a:2b6f:2f66:0:a3:2aff:fe9c:3fe3 => ff35:40:fd00:0:0:0:100:3e8 Thread: OK

@mkardous-silabs
Copy link
Contributor

@dtodor
Group commands work on efr32 MG12 and MG24.
There might be an issue with the commands you are using or the setup as you mentionned.

Did you send the same commands mentionned in the referenced ticket?

@dtodor
Copy link
Author

dtodor commented Jun 15, 2022

We are using EFR32 MG12. Yes, we are sending the same commands. The OTBR sees the multicasts, but no packets are received by the device.

@mkardous-silabs
Copy link
Contributor

I was able to validate the issue is not with the device but with the commands used to configure the groups.
This issue can be closed. I will add the commands I used in the associated ticket.

@jepenven-silabs
Copy link
Contributor

Closing since working on our side. Verified by @mkardous-silabs . Walk-trough can be seen here : #19608 (comment)

@dtodor
Copy link
Author

dtodor commented Jun 20, 2022

I would assume that when the device joins the multicast group, I would be at least able to see the UDP Message Received packet nb logs. Is this a correct assumption?

@dtodor
Copy link
Author

dtodor commented Jun 22, 2022

Here is some more information regarding our setup:

OTBR:

OTBR
---
# ifconfig
eth0      Link encap:Ethernet  HWaddr 02:A3:2A:9C:3F:E3  
          inet addr:192.168.2.105  Bcast:192.168.2.255  Mask:255.255.255.0
          inet6 addr: fe80::a3:2aff:fe9c:3fe3/64 Scope:Link
          inet6 addr: fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3/64 Scope:Global
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:13392 errors:0 dropped:0 overruns:0 frame:0
          TX packets:4901 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:1175346 (1.1 MiB)  TX bytes:932223 (910.3 KiB)

wpan0     Link encap:UNSPEC  HWaddr 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  
          inet6 addr: fd6a:2dcf:2b13:a3ef:0:ff:fe00:fc00/64 Scope:Global
          inet6 addr: fd6a:2dcf:2b13:a3ef:0:ff:fe00:fc38/64 Scope:Global
          inet6 addr: fe80::c0b0:16b6:fe2a:ad45/64 Scope:Link
          inet6 addr: fd6a:2dcf:2b13:a3ef:0:ff:fe00:fc11/64 Scope:Global
          inet6 addr: fd03:329c:d7fa:1:bc:a93a:44bb:fbff/64 Scope:Global
          inet6 addr: fd6a:2dcf:2b13:a3ef:0:ff:fe00:e400/64 Scope:Global
          inet6 addr: fd6a:2dcf:2b13:a3ef:0:ff:fe00:fc10/64 Scope:Global
          inet6 addr: fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff/64 Scope:Global
          UP POINTOPOINT RUNNING NOARP MULTICAST  MTU:1280  Metric:1
          RX packets:36 errors:0 dropped:1 overruns:0 frame:0
          TX packets:71 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:500 
          RX bytes:4790 (4.6 KiB)  TX bytes:8758 (8.5 KiB)

# ip -6 mroute
(fd03:329c:d7fa:1:bc:a93a:44bb:fbff,ff35:40:fd00::100:3e8) Iif: wpan0      Oifs: eth0  State: resolved
(fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3,ff35:40:fd00::100:3e8) Iif: eth0       Oifs: wpan0  State: resolved

EFR32 Device:

> ipaddr
fd6a:2dcf:2b13:a3ef:0:ff:fe00:dc00
fd03:329c:d7fa:1:3f3e:f201:ffa0:efc8
fd6a:2dcf:2b13:a3ef:38a0:4142:9ec1:9299
fe80:0:0:0:c8dd:9591:e9c2:c038
Done

> ipmaddr
ff35:40:fd00:0:0:0:100:3e8
ff33:40:fd6a:2dcf:2b13:a3ef:0:1
ff32:40:fd6a:2dcf:2b13:a3ef:0:1
ff02:0:0:0:0:0:0:2
ff03:0:0:0:0:0:0:2
ff02:0:0:0:0:0:0:1
ff03:0:0:0:0:0:0:1
ff03:0:0:0:0:0:0:fc
Done

We are able to send PINGs to the device using the multicast address, e.g.

PING on OTBR:

# ping6 ff35:40:fd00::100:3e8
PING ff35:40:fd00::100:3e8 (ff35:40:fd00::100:3e8): 56 data bytes
64 bytes from fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3: seq=0 ttl=64 time=1.321 ms
64 bytes from fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3: seq=1 ttl=64 time=1.421 ms
^C

Corresponding OTBR Logs:

Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.292 [I] MeshForwarder-: Sent IPv6 HopOpts msg, len:152, chksum:0000, ecn:no, to:0xffff, sec:yes, prio:low
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.292 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.292 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.307 [I] MeshForwarder-: Received IPv6 ICMP6 msg, len:104, chksum:0000, ecn:no, from:0xdc00, sec:yes, prio:normal, rss:-48.0
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.307 [I] MeshForwarder-:     src:[fd03:329c:d7fa:1:3f3e:f201:ffa0:efc8]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.307 [I] MeshForwarder-:     dst:[fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.332 [I] MeshForwarder-: Received IPv6 HopOpts msg, len:152, chksum:0000, ecn:no, from:0xdc00, sec:yes, prio:normal, rss:-48.0
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.332 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.333 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.362 [I] MeshForwarder-: Sent IPv6 HopOpts msg, len:152, chksum:0000, ecn:no, to:0xffff, sec:yes, prio:low
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.362 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.362 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.442 [I] MeshForwarder-: Received IPv6 HopOpts msg, len:152, chksum:0000, ecn:no, from:0xdc00, sec:yes, prio:normal, rss:-48.0
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.442 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:50:02 qivicon user.info otbr-agent[94]: 01:12:55.442 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]

Further, it is possible to send PINGs from a macOS computer, .e.g.

PING on macOS:

# ping6 ff35:40:fd00::100:3e8 
ping6: UDP connect: No route to host

# ping6 -I en0 ff35:40:fd00::100:3e8
PING6(56=40+8+8 bytes) fdf0:203f:8b90:10fc:8b0:dfd5:4e5f:3f59 --> ff35:40:fd00::100:3e8
16 bytes from fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3, icmp_seq=0 hlim=255 time=7.350 ms
16 bytes from fd03:329c:d7fa:1:3f3e:f201:ffa0:efc8, icmp_seq=0 hlim=63 time=54.447 ms
16 bytes from fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3, icmp_seq=1 hlim=255 time=4.901 ms
16 bytes from fd03:329c:d7fa:1:3f3e:f201:ffa0:efc8, icmp_seq=1 hlim=63 time=48.357 ms
16 bytes from fdf0:203f:8b90:10fc:a3:2aff:fe9c:3fe3, icmp_seq=2 hlim=255 time=7.582 ms
16 bytes from fd03:329c:d7fa:1:3f3e:f201:ffa0:efc8, icmp_seq=2 hlim=63 time=52.416 ms
^C

Corresponding OTBR Logs:

Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.602 [I] MeshForwarder-: Sent IPv6 HopOpts msg, len:104, chksum:0000, ecn:no, to:0xffff, sec:yes, prio:low
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.602 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.603 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.617 [I] MeshForwarder-: Received IPv6 ICMP6 msg, len:56, chksum:0000, ecn:no, from:0xdc00, sec:yes, prio:normal, rss:-48.0
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.617 [I] MeshForwarder-:     src:[fd03:329c:d7fa:1:3f3e:f201:ffa0:efc8]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.617 [I] MeshForwarder-:     dst:[fdf0:203f:8b90:10fc:8b0:dfd5:4e5f:3f59]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.657 [I] MeshForwarder-: Received IPv6 HopOpts msg, len:104, chksum:0000, ecn:no, from:0xdc00, sec:yes, prio:normal, rss:-49.0
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.657 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.657 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.662 [I] MeshForwarder-: Sent IPv6 HopOpts msg, len:104, chksum:0000, ecn:no, to:0xffff, sec:yes, prio:low
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.662 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:51:28 qivicon user.info otbr-agent[94]: 01:14:21.662 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]
Jun 22 10:51:29 qivicon user.info otbr-agent[94]: 01:14:21.712 [I] MeshForwarder-: Received IPv6 HopOpts msg, len:104, chksum:0000, ecn:no, from:0xdc00, sec:yes, prio:normal, rss:-49.0
Jun 22 10:51:29 qivicon user.info otbr-agent[94]: 01:14:21.712 [I] MeshForwarder-:     src:[fd6a:2dcf:2b13:a3ef:a88b:7415:cb4:61ff]
Jun 22 10:51:29 qivicon user.info otbr-agent[94]: 01:14:21.713 [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:fc]

So multicast forwarding seems to be working fine. Unfortunately we are still unable to send group messages to the device, i.e. no packets are received as far as we can tell.

@jepenven-silabs Do you have any ideas what might be going wrong? We've also tried the commands from the other ticket using the chip-tool - same result.

@dtodor
Copy link
Author

dtodor commented Jun 22, 2022

We are testing using the lighting-app example built using the following commands:

# Full device
gn gen out/normal '--args=efr32_board="BRD4161A"'
ninja -C out/normal

We've also added the following OpenThread configs to args.gni, although not sure whether these are needed at all:

openthread_enable_core_config_args = true
openthread_config_thread_version = "1.2"

@jepenven-silabs
Copy link
Contributor

@dtodor So the way the OTBR works with an end device for multicast is subscription based. The device needs to be part of the thread network and then you need to add a group to it. Make sure both the chip-tool and the end-device are on the same commit as the building of the Multicast address changed recently and mismatch between chip-tool and the end-device in commit hash might result in the issue you've just described. The OTBR won't forward any multicast address to any devices unless at least one device is subscribed to it.

Now For debugging all of this, you'll need Wireshark or some way to actually sniff IPV6 packets.

Easiest setup would be to run these two commands with wireshark running
chip-tool groups add-group 0x0101 Light <nodeId> 1
chip-tool onoff on 0xffffffffffff0101 1

These commands will fails for multiples reasons on the device side. Among them are :

  • Wrong Key sync policy
  • No key set on the end device
  • No ACL set on the end device.

What you should see however is the UDP log on the EFR32 device, on top of seeing the IPV6 packet in Wireshark.
The on-off command can be send from any device connected to the same network as the OTBR.
However if you're face with this log after executing the command with chip-tool

[1655997317210] [17669:2893819] CHIP: [TOO] Run command failure: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417:

That's is a networking issue with your network. You'll need to investigate why the IPV6 routing isn't working on it .

@dtodor
Copy link
Author

dtodor commented Jun 23, 2022

But I would assume that pinging the device through the multicast address is a good indicator that the group subscription (MLR, etc.) has taken place and that the OTBR, especially the BBR part of it, are properly working. Right?

@dtodor
Copy link
Author

dtodor commented Jul 14, 2022

So after some more debugging, the UDP packets do get actually delivered to the EFR32 board, but the checksum verification fails, i.e.:

#ifndef FUZZING_BUILD_MODE_UNSAFE_FOR_PRODUCTION
    SuccessOrExit(error = Checksum::VerifyMessageChecksum(aMessage, aMessageInfo, kProtoUdp));
#endif

I've tried to read and compare the contents of the message with the message as captured by the sniffer:

    uint8_t buffer[2028];
    auto    read = aMessage.ReadBytes(0, buffer, 2048);
    printf("*********** OT Udp::HandleMessage - message (bytes %d):\n", read);
    for (int i = 0; i < read; i++)
    {
        printf("%02X", buffer[i]);
    }
    printf("\n");

Received message:

???: 60 0F 86 97 00 4A 11 3F

Source: FD 11 BF 7D D9 94 79 63 00 A3 2A FF FE 9C 3F E3 

Destination: FF 35 00 40 FD 00 00 00 00 00 00 00 01 00 03 E8 

Source port: DA 78 

Destination port: 15 A4

???: 004A

Checksum: 7B 64

Application: 06 E7 B6 81 2B 23 00 00 01 00 00 00 00 00 00 00 E8 03 5D 9C 0B AF 9B 5B 43 1F 4B 71 F7 7F 91 0C C3 FE EF 53 54 F8 BE D0 6D 3A D8 F2 EE 7B DB 21 60 C9 F8 7A 3C 96 64 A3 5E 41 E3 59 3F AE 53 7F 7E BA

Captured message using sniffer:

???: F8 7D 59 98 EC 8E 6D FF FF 00 30 0D FB 11 00 00 01 C0 A2 16 07 7E 5A 3C 90 EA 33 88 4A 88 17 03 00 00 FC E1 06 6D 04 40 2D 30 00 EE 6C 08 0F 86 97 3F 

Source: FD 11 BF 7D D9 94 79 63 00 A3 2A FF FE 9C 3F E3 

Destination: FF 35 00 40 FD 00 00 00 00 00 00 00 01 00 03 E8 

???: F0 

Source port: DA 78 

Destination port: 15 A4 

Checksum: 7B 64

Application: 06 E7 B6 81 2B 23 00 00 01 00 00 00 00 00 00 00 E8 03 5D 9C 0B AF 9B 5B 43 1F 4B 71 F7 7F 91 0C C3 FE EF 53 54 F8 BE D0 6D 3A D8 F2 EE 7B DB 21 60 C9 F8 7A 3C 96 64 A3 5E 41 E3 59 3F AE 53 7F 7E BA

@jepenven-silabs Any ideas what might cause the checksum verification to fail?

@dtodor
Copy link
Author

dtodor commented Jul 14, 2022

After disabling the checksum verification and some fixes in our code, group messaging works!!! Could it be that everyone is building with FUZZING_BUILD_MODE_UNSAFE_FOR_PRODUCTION defined?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants