6LowPAN ipsp: ping host -> µc failes, ping µc -> host works. after that: ping host -> µc works

[thelittlebug]

Describe the bug
the µc is pingable only after the µc pinged the host in advance

To Reproduce

# build the sample code and flash
> west build -b nrf52840dk_nrf52840 samples/bluetooth/ipsp && west flash

# create a 6lowpan connection
> echo "connect ee:ea:64:fb:cf:40 2" > /sys/kernel/debug/bluetooth/6lowpan_control

# ping with a multicast, works as expected
> ping -I bt0 ff02::1
ping6: Warning: source address might be selected on device other than: bt0
PING ff02::1(ff02::1) from :: bt0: 56 data bytes
64 bytes from fe80::eeea:64ff:fefb:cf40%bt0: icmp_seq=1 ttl=64 time=50.9 ms
64 bytes from fe80::eeea:64ff:fefb:cf40%bt0: icmp_seq=2 ttl=64 time=127 ms
64 bytes from fe80::eeea:64ff:fefb:cf40%bt0: icmp_seq=3 ttl=64 time=116 ms

# create ip on the host 2001:db8::2, µc has address 2001:db8::1
> ip address add 2001:db8::2/64 dev bt0

# ping the µc from the host with the new address, does not work
> ping 2001:db8::1
PING 2001:db8::1(2001:db8::1) 56 data bytes
From 2001:db8::2 icmp_seq=1 Destination unreachable: Address unreachable
From 2001:db8::2 icmp_seq=2 Destination unreachable: Address unreachable
From 2001:db8::2 icmp_seq=3 Destination unreachable: Address unreachable
From 2001:db8::2 icmp_seq=4 Destination unreachable: Address unreachable

but now from the µc shell

# ping the host, does work
> net ping 2001:db8::2
PING 2001:db8::2
8 bytes from 2001:db8::2 to 2001:db8::1: icmp_seq=0 ttl=64 time=214 ms
8 bytes from 2001:db8::2 to 2001:db8::1: icmp_seq=1 ttl=64 time=68 ms
8 bytes from 2001:db8::2 to 2001:db8::1: icmp_seq=2 ttl=64 time=58 ms

after that the ping from the host to the µc works

ping 2001:db8::1
PING 2001:db8::1(2001:db8::1) 56 data bytes
64 bytes from 2001:db8::1: icmp_seq=1 ttl=64 time=219 ms
64 bytes from 2001:db8::1: icmp_seq=2 ttl=64 time=117 ms
64 bytes from 2001:db8::1: icmp_seq=3 ttl=64 time=106 ms

Expected behavior
the µc should be pingable

Impact
showstopper

Sidenote
the other examples like connecting via tcp or udp to port 4242 on the µc also doesn't work

Environment (please complete the following information):
pop os 20.04
zephyr 2.3.0
nrf52840-dk

Additional context
im no ipv6 specialist. for me it looks like zephyr is dropping the packets. i tried to analyze that with wireshark and debugging messages on the µc.

[00:00:42.914,642] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:00:42.914,703] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 57
[00:00:42.914,855] <dbg> net_bt.net_bt_recv: (<log_strdup alloc failed>): iface 0x200014ac pkt 0x2000b2a0 len 57
[00:00:42.914,916] <dbg> net_ipv6.net_ipv6_input: (<log_strdup alloc failed>): IPv6 packet len 72 received from <log_strdu>
[00:00:42.914,947] <dbg> net_ipv6.net_ipv6_input: (<log_strdup alloc failed>): DROP: packet for unjoined multicast address
[00:00:43.904,602] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:00:43.904,663] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 57
[00:00:43.904,785] <dbg> net_bt.net_bt_recv: (<log_strdup alloc failed>): iface 0x200014ac pkt 0x2000b2a0 len 57
[00:00:43.904,846] <dbg> net_ipv6.net_ipv6_input: (<log_strdup alloc failed>): IPv6 packet len 72 received from <log_strdu>
[00:00:43.904,876] <dbg> net_ipv6.net_ipv6_input: (<log_strdup alloc failed>): DROP: packet for unjoined multicast address
[00:00:44.939,605] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:00:44.939,666] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 57
[00:00:44.939,758] <dbg> net_bt.net_bt_recv: (rx_workq): iface 0x200014ac pkt 0x2000b2a0 len 57
[00:00:44.939,849] <dbg> net_ipv6.net_ipv6_input: (rx_workq): IPv6 packet len 72 received from <log_strdup alloc failed> t>
[00:00:44.939,849] <dbg> net_ipv6.net_ipv6_input: (<log_strdup alloc failed>): DROP: packet for unjoined multicast address
[00:00:56.864,562] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:00:56.865,142] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 74

[jukkar]

There was some changes related to multicast groups, perhaps this is related to that. Note that as the log says, the application needs to join the multicast group in order to receive the multicast packets. Is this a sample app found in zephyr?
Could you increase the CONFIG_LOG_STRDUP_BUF_COUNT so that we see what the IP address is in the log, now it just shows <log_strdup alloc failed>

[thelittlebug]

yes, i use the official sample located sample/bluetooth/ipsp. so my idea was: it should work out of the box :)

i changed the config you mentioned. now there are no log_strdup errors anymore but for me it doesn't get more meaningful as before.

[00:02:52.298,645] <dbg> net_bt.net_bt_recv: (rx_workq): iface 0x200014ac pkt 0x2000bed0 len 57
[00:02:52.298,736] <dbg> net_ipv6.net_ipv6_input: (rx_workq): IPv6 packet len 72 received from 2001:db8::2 to ff02::1:ff00:1
[00:02:52.298,767] <dbg> net_ipv6.net_ipv6_input: (rx_workq): DROP: packet for unjoined multicast address
[00:02:53.333,435] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:02:53.333,526] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 57
[00:02:53.333,648] <dbg> net_bt.net_bt_recv: (rx_workq): iface 0x200014ac pkt 0x2000bed0 len 57
[00:02:53.333,740] <dbg> net_ipv6.net_ipv6_input: (rx_workq): IPv6 packet len 72 received from 2001:db8::2 to ff02::1:ff00:1
[00:02:53.333,740] <dbg> net_ipv6.net_ipv6_input: (rx_workq): DROP: packet for unjoined multicast address
[00:03:36.578,186] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:03:36.578,765] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 74
[00:03:36.578,857] <dbg> net_bt.net_bt_recv: (rx_workq): iface 0x200014ac pkt 0x2000bed0 len 74
[00:03:36.578,948] <dbg> net_ipv6.net_ipv6_input: (rx_workq): IPv6 packet len 93 received from 2001:db8::2 to ff02::fb
[00:03:36.578,979] <dbg> net_ipv6.net_ipv6_input: (rx_workq): DROP: packet for unjoined multicast address
[00:03:51.786,804] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:03:51.786,834] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 20
[00:03:51.786,956] <dbg> net_bt.net_bt_recv: (rx_workq): iface 0x200014ac pkt 0x2000bed0 len 20
[00:03:51.787,048] <dbg> net_ipv6.net_ipv6_input: (rx_workq): IPv6 packet len 56 received from fe80::983b:8fff:fe72:e966 to ff02::2
[00:03:51.787,048] <dbg> net_ipv6.net_ipv6_input: (rx_workq): DROP: packet for unjoined multicast address
[00:05:44.602,264] <dbg> net_bt.ipsp_alloc_buf: (BT RX): Channel 0x20000230 requires buffer
[00:05:44.602,844] <dbg> net_bt.ipsp_recv: (BT RX): Incoming data channel 0x20000230 len 74
[00:05:44.602,935] <dbg> net_bt.net_bt_recv: (rx_workq): iface 0x200014ac pkt 0x2000bed0 len 74
[00:05:44.603,088] <dbg> net_ipv6.net_ipv6_input: (rx_workq): IPv6 packet len 93 received from 2001:db8::2 to ff02::fb
[00:05:44.603,088] <dbg> net_ipv6.net_ipv6_input: (rx_workq): DROP: packet for unjoined multicast address

[jukkar]

@Vudentz, was there some issue with ipsp connectivity requiring some extra activity from the user?

[github-actions]

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.

[thelittlebug]

bump!

[fabiojmendes]

Having the same issue here! Thanks @thelittlebug for the info, I went through some hoops to enable the shell because I didn't know how to. But after a was able to ping the host (raspberry pi 4) from the test board (nrf52840 DK) a reached the same point as described in this bug.

Environment (please complete the following information):

Raspbian GNU/Linux 10 (buster) Linux pi4 5.4.79-v8+ #1373 SMP PREEMPT Mon Nov 23 13:32:41 GMT 2020 aarch64 GNU/Linux
zephyr-v2.4.0-2599-g03a1d04c8492
nrf52840-dk

[fabiobaltieri]

Hey I've hit this problem as well and managed to bisect it to:

b7b73d0 net: ipv6: added interface multicast group filtering

Filed #31075 with a fix.

[fabiobaltieri]

Hey #31075 got merged, this should be fixed now.