DHCPv6 on WAN not working (TOS 5, PPPoE)

Hi everyone,

I do observe issues with DHCPv6 not working on WAN, namely it is most of the time unable to acquire prefix via DHCPv6-PD and/or renew the acquired prefix (there are occasions when the prefix gets acquired shortly after Turris OS boot, but never renewed).

This in turns result in no IPv6 connectivity on LAN (as no prefix is available) or expiring IPv6 connectivity (if odhcp6c ever manages to receive the DHCPv6 packets, it is not able to renew the acquired prefixes later).

Environment:

  • Turris 1.0 (blue)
  • Turris OS 5 (TurrisOS 5.0.0 286c407c3d8877e51fa90cbd830f2fedb3ad1f26, hbt)
  • VDSL by CETIN(.cz)
    • VDSL modem Nokia F-010G-B in bridge mode, connected to a VLAN-enabled switch
    • DSL internet interface is on VLAN 848
    • VLAN 848 distributed to the VLAN-enabled switch with a VLAN tag (848)
    • the other end of PPPoE is terminated by CETIN on a Nokia BRAS
  • PPPoE dialled on top of lan2.848 interface (these virtual DSA interfaces we see since TOS4; not a bridge)
  • Turris interface lan2 is connected to the VLAN-enabled switch, VLAN tags are used to differentiate between networks (VDSL 848, LAN, NAT64, ā€¦)

/etc/config/network:

config interface 'wan'
	option proto 'pppoe'
	option username 'o2'
	option password 'o2'
	option ipv6 '1'
	option ifname 'lan2.848'

config interface 'wan6'
	option ifname '@wan'
	option proto 'dhcpv6'
	option reqaddress 'try'
	option reqprefix 'auto'

After a quite long debugging session, I have identified that if /proc/sys/net/netfilter/nf_conntrack_checksum is set to 1, the odhcp6c process never receives a DHCPv6 response from the DHCPv6 server (I do see the response in tcpdump, but it is missing when running strace -f -p <pid-of-odhcp6c> - the recvmsg syscall is not seen at the moment the packet arrives on the PPPoE interface).

As soon as I change nf_conntrack_checksum to 0, the odhcp6c process suddenly receives the response, acquires/renews the prefix and all is fine from that moment onwards.

When I set the nf_conntrack_checksum to 1 and dial the PPPoE session manually, this is what I see on the interface:

15:23:04.642572 PPPoE PADT [ses 0x1] [Host-Uniq 0x00007A37] [AC-Cookie 0x0C3AD2C79B7EF1B01C02B8C519B59FBA]
15:23:05.010461 PPPoE PADI [Service-Name] [Host-Uniq 0x00000A93]
15:23:05.020340 PPPoE PADO [Service-Name] [AC-Name "PA77B02USTIMA02"] [Host-Uniq 0x00000A93] [AC-Cookie 0x0C3AD2C79B7EF1B01C02B8C519B59FBA]
15:23:05.020448 PPPoE PADR [Service-Name] [Host-Uniq 0x00000A93] [AC-Cookie 0x0C3AD2C79B7EF1B01C02B8C519B59FBA]
15:23:05.030047 PPPoE PADS [ses 0x1] [Service-Name] [Host-Uniq 0x00000A93]
15:23:09.450840 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:09.460392 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:09.740677 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > ff02::1: ICMP6, router advertisement, length 16
15:23:10.492276 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:10.501418 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:12.541008 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:12.550454 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:16.700142 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:16.709297 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:19.900106 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > ff02::1: ICMP6, router advertisement, length 16
15:23:20.273758 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:20.282922 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:21.305458 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:21.314891 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:22.009771 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 solicit
15:23:22.018949 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 advertise
15:23:23.210615 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 request
15:23:23.221425 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:23:24.217463 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 request
15:23:24.227197 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:23:26.105702 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 request
15:23:26.115491 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:23:26.319986 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > fe80::c8ae:e3fa:a005:71ca: ICMP6, router advertisement, length 16
15:23:30.015285 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 request
15:23:30.025355 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply

until around 15:23:35, odhcp6c was issuing sendmsg, but reading from the socket using recvmsg ended up with -EAGAIN:

strace: Process 3948 attached
15:23:27 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:23:29 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28,
 msg_iov=[{iov_base="\3^\323\250\0\10\0\2\2\250\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {i
ov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="\0\24\0\0", iov_len=4}, {iov_base="\0'\0\26\0\10.\1.\5.\2cz\0", iov_len=26}, {iov_base="", iov_len=0}
, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\16\n\0\1Qz8*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 139
15:23:30 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)

around 15:23:35 I have set nf_conntrack_checksum to 0. This is what followed:

15:23:37.691975 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 request
15:23:37.701884 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:23:37 clock_gettime(CLOCK_MONOTONIC, {tv_sec=96055, tv_nsec=520705602}) = 0
15:23:37 read(3, "\366*\377\250", 4)    = 4
15:23:37 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28,
 msg_iov=[{iov_base="\3^\323\250\0\10\0\2\5\247\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {i
ov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="\0\24\0\0", iov_len=4}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}
, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\16\n\0\1Qz8*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 139
15:23:37 setsockopt(4, SOL_SOCKET, SO_RCVTIMEO_OLD, "\0\0\0\17\0\0\v\270", 8) = 0
15:23:37 recvmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")},
 msg_namelen=28, msg_iov=[{iov_base="\7^\323\250\0\2\0\n\0\3\0\1@|}\346S\3\0\1\0\n\0\3\0\1\330X\327\0\n\6\0\31\0)\0\0\0\1\0\0\7\10\0\0\v@\0\32\0\31\0\0\16\20\0\1Q\2008*\0e\0(\31\374\0\0\0\0\0\0\0\0\0",
iov_len=1536}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_IPV6, cmsg_type=0x32}], msg_controllen=32, msg_flags=0}, 0) = 77
15:23:37 clock_gettime(CLOCK_MONOTONIC, {tv_sec=96055, tv_nsec=571387524}) = 0
15:23:37 clock_gettime(CLOCK_MONOTONIC, {tv_sec=96055, tv_nsec=571991725}) = 0
15:23:37 clock_gettime(CLOCK_MONOTONIC, {tv_sec=96055, tv_nsec=572428513}) = 0
15:23:37 clock_gettime(CLOCK_MONOTONIC, {tv_sec=96055, tv_nsec=572781767}) = 0
15:23:37 rt_sigprocmask(SIG_BLOCK, ~[], [], 8) = 0
15:23:37 fork(strace: Process 6321 attached
 <unfinished ...>
(...)
[pid  6321] 15:23:47 execve("/lib/netifd/dhcpv6.script", ["/lib/netifd/dhcpv6.script", "pppoe-wan", "bound"], 0x623e80 /* 28 vars */) = 0
(...)
  • at 15:23:47 an external script was called: /lib/netifd/dhcpv6.script pppoe-wan bound
  • at 15:23:41 CEST 2020, the wan interface still didnā€™t have any IPv6 prefix assigned.
  • at 15:23:56 CEST 2020, the wan interface was assigned a delegated IPv6 prefix and sub-assigned prefixes from the delegated /56 to local interfaces:
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 3582,
    "valid": 86382,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 4471,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]

Right after that, I have set nf_conntrack_checksum to 1 again. In tcpdump, the activity of odhcp6c was clear:

15:40:04.323800 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > fe80::c8ae:e3fa:a005:71ca: ICMP6, router advertisement, length 16
15:53:38.652087 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
15:53:38.662549 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:53:48.891935 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
15:53:48.902252 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:54:09.372127 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
15:54:09.382674 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:54:48.283912 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
15:54:48.293938 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:56:08.160132 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
15:56:08.170616 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
15:59:00.187933 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
15:59:00.198264 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:04:44.256468 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
16:04:44.266930 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:08:07.328439 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > fe80::c8ae:e3fa:a005:71ca: ICMP6, router advertisement, length 16
16:11:50.239474 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
16:11:50.261846 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:11:50.261769 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:11:50.272469 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:12:01.243913 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:12:01.254417 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:12:25.051613 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:12:25.061873 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:13:08.060260 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:13:08.070879 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:14:32.027615 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:14:32.037959 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:17:34.299110 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:17:34.309913 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:23:01.980942 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:23:01.991136 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply

however there was no other call to /lib/netifd/dhcpv6.script to rebind the prefix. As confirmed by strace, with the exception of router advertisements from the BRAS (which are also processed by odhcp6c), no other packet has been received by the odhcp6c process:

15:40:04 recvmsg(5, {msg_name={sa_family=AF_INET6, sin6_port=htons(0), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\206\0Z?@\0\21\224\0\0\0\0\0\0\0\0", iov_len=1500}], msg_iovlen=1, msg_control=[{cmsg_len=16, cmsg_level=SOL_IPV6, cmsg_type=0x34}], msg_controllen=16, msg_flags=0}, MSG_DONTWAIT) = 16
15:40:04 recvmsg(5, {msg_namelen=28}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
15:40:06 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:40:30 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:42:20 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:44:11 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:46:16 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:48:19 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:50:26 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:52:16 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:53:38 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2\0\0\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
15:53:38 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:53:48 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2\3\377\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
15:53:48 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:54:09 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2\v\377\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
15:54:09 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:54:48 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2\0333\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
15:54:48 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:56:08 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2:f\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
15:56:08 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
15:59:00 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2}\231\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
15:59:00 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:04:44 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2\377\377\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
16:08:07 recvmsg(5, {msg_name={sa_family=AF_INET6, sin6_port=htons(0), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\206\0Z?@\0\21\224\0\0\0\0\0\0\0\0", iov_len=1500}], msg_iovlen=1, msg_control=[{cmsg_len=16, cmsg_level=SOL_IPV6, cmsg_type=0x34}], msg_controllen=16, msg_flags=0}, MSG_DONTWAIT) = 16
16:08:07 recvmsg(5, {msg_namelen=28}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
16:08:09 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:11:50 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5/\224\311\0\10\0\2\377\377\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
16:11:50 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\0\0\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:11:50 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:12:01 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\4J\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:12:01 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:12:25 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\r\227\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:12:25 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:13:08 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\36c\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:13:08 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:14:32 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2?0\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:14:32 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:17:34 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\206c\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:17:34 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)
16:23:01 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\377\377\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:24:43 recvmsg(5, {msg_namelen=28}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
16:24:45 recvmsg(5, {msg_namelen=28}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
16:30:24 recvmsg(5, {msg_namelen=28}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
16:30:29 recvmsg(5, {msg_namelen=28}, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
16:30:29 recvmsg(4, {msg_namelen=28}, 0) = -1 EAGAIN (Resource temporarily unavailable)

The wan6 prefix preferred time dropped to 0, which in turn was presented in LAN router advertisements and the prefix was depreferred (the end hosts in LAN stopped using IPv6 completely).

Thu Apr 23 16:23:33 CEST 2020
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 4,
    "valid": 82804,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 3574,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]
Thu Apr 23 16:23:49 CEST 2020
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 0,
    "valid": 82788,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 3558,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]
(...)
Thu Apr 23 16:33:04 CEST 2020
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 0,
    "valid": 82233,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 3003,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]

I have changed the nf_conntrack_checksum to 0 at 16:24. Thereā€™s an internal exponential backoff in odhcp6c, so the request to renew/rebind was not immediate. It was sent at 16:33:08:

16:33:08.188264 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 rebind
16:33:08.198639 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
16:34:28.330977 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > fe80::c8ae:e3fa:a005:71ca: ICMP6, router advertisement, length 16

from odhcp6c strace log:

16:33:08 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\6\304\27\211\0\10\0\2\377\377\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="", iov_len=0}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 121
16:33:08 recvmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\7\304\27\211\0\2\0\n\0\3\0\1@|}\346S\3\0\1\0\n\0\3\0\1\330X\327\0\n\6\0\31\0)\0\0\0\1\0\0\7\10\0\0\v@\0\32\0\31\0\0\16\20\0\1Q\2008*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=1536}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_IPV6, cmsg_type=0x32}], msg_controllen=32, msg_flags=0}, 0) = 77
(...)
[pid  3299] 16:33:08 execve("/lib/netifd/dhcpv6.script", ["/lib/netifd/dhcpv6.script", "pppoe-wan", "rebound"], 0x623e80 /* 28 vars */ <unfinished ...>
(...)
16:34:28 recvmsg(5, {msg_name={sa_family=AF_INET6, sin6_port=htons(0), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\206\0Z?@\0\21\224\0\0\0\0\0\0\0\0", iov_len=1500}], msg_iovlen=1, msg_control=[{cmsg_len=16, cmsg_level=SOL_IPV6, cmsg_type=0x34}], msg_controllen=16, msg_flags=0}, MSG_DONTWAIT) = 16

at 16:33:08 the prefix was successfully rebound and finally the wan6 prefix had correct preferred time (3600 seconds, as sent by the BRAS):

Thu Apr 23 16:33:20 CEST 2020
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 3588,
    "valid": 86388,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 2987,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]

Next I have kept nf_conntrack_checksum to 0 and waited 30 minutes for the prefix to rebind:

17:01:19.331296 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303 > fe80::c8ae:e3fa:a005:71ca: ICMP6, router advertisement, length 16
17:03:08.379990 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
17:03:08.390904 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
17:01:19 recvmsg(5, {msg_name={sa_family=AF_INET6, sin6_port=htons(0), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\206\0Z?@\0\21\224\0\0\0\0\0\0\0\0", iov_len=1500}], msg_iovlen=1, msg_control=[{cmsg_len=16, cmsg_level=SOL_IPV6, cmsg_type=0x34}], msg_controllen=16, msg_flags=0}, MSG_DONTWAIT) = 16
(...)
17:03:08 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5\253\347W\0\10\0\2\0\0\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
17:03:08 recvmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\7\253\347W\0\2\0\n\0\3\0\1@|}\346S\3\0\1\0\n\0\3\0\1\330X\327\0\n\6\0\31\0)\0\0\0\1\0\0\7\10\0\0\v@\0\32\0\31\0\0\16\20\0\1Q\2008*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=1536}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_IPV6, cmsg_type=0x32}], msg_controllen=32, msg_flags=0}, 0) = 77
Thu Apr 23 17:02:53 CEST 2020
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 1815,
    "valid": 84615,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 4406,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]
Thu Apr 23 17:03:08 CEST 2020
[
  {
    "address": "2a00:6500:xxxx:fc00::",
    "mask": 56,
    "preferred": 3600,
    "valid": 86400,
    "class": "wan6",
    "assigned": {
      "lan": {
        "address": "2a00:6500:xxxx:fc00::",
        "mask": 60
      },
      "nat64": {
        "address": "2a00:6500:xxxx:fc10::",
        "mask": 64
      }
    }
  }
]
[
  {
    "target": "::",
    "mask": 0,
    "nexthop": "fe80::427c:7dff:fee6:5303",
    "metric": 512,
    "valid": 4391,
    "source": "2a00:6500:xxxx:fc00::/56"
  }
]

And again at 17:33:08:

17:33:08.571897 PPPoE  [ses 0x1] IP6 fe80::c8ae:e3fa:a005:71ca.546 > ff02::1:2.547: dhcp6 renew
17:33:08.582335 PPPoE  [ses 0x1] IP6 fe80::427c:7dff:fee6:5303.547 > fe80::c8ae:e3fa:a005:71ca.546: dhcp6 reply
17:33:08 sendmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "ff02::1:2", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\5\320\21\362\0\10\0\2\0\0\0\6\0\26", iov_len=14}, {iov_base="\0\25\0\26\0\27\0\30\0\37\08\0@\0C\0^\0_\0`", iov_len=22}, {iov_base="\0\1\0\n\0\3\0\1\330X\327\0\n\6", iov_len=14}, {iov_base="\0\2\0\n\0\3\0\1@|}\346S\3", iov_len=14}, {iov_base=NULL, iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0'\0\26\0\10.\1.\5.\2.\0", iov_len=26}, {iov_base="", iov_len=0}, {iov_base="", iov_len=0}, {iov_base="\0\31\0)\0\0\0\1\0\0\0\0\0\0\0\0\0\32\0\31\0\0\0\0\0\0\0\08*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=45}], msg_iovlen=10, msg_controllen=0, msg_flags=0}, 0) = 135
17:33:08 recvmsg(4, {msg_name={sa_family=AF_INET6, sin6_port=htons(547), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fe80::427c:7dff:fee6:5303", &sin6_addr), sin6_scope_id=if_nametoindex("pppoe-wan")}, msg_namelen=28, msg_iov=[{iov_base="\7\320\21\362\0\2\0\n\0\3\0\1@|}\346S\3\0\1\0\n\0\3\0\1\330X\327\0\n\6\0\31\0)\0\0\0\1\0\0\7\10\0\0\v@\0\32\0\31\0\0\16\20\0\1Q\2008*\0e\0(\31\374\0\0\0\0\0\0\0\0\0", iov_len=1536}], msg_iovlen=1, msg_control=[{cmsg_len=32, cmsg_level=SOL_IPV6, cmsg_type=0x32}], msg_controllen=32, msg_flags=0}, 0) = 77

Note that this all was issued with an extra ip6tables rules:
-I INPUT 1 -p udp --dport 546 -j ACCEPT
-I INPUT 1 -p udp --dport 547 -j ACCEPT
thereā€™s also no ip6tables rule to drop the conntrack INVALID packets.

Until now I have not found the root cause why are the packets not delivered to odhcp6c, even though the packets and UDP checksums seem to be OK:

I forgot to mention how do I work around this issue. I have created /etc/sysctl.d/12-nf-conntrack-checksum-override.conf with the following:

net.netfilter.nf_conntrack_checksum=0

Thanks to the order of evaluation (/etc/sysctl.d/11-nf-conntrack.conf sets net.netfilter.nf_conntrack_checksum=1), sysctl fixes up my configuration after each and every reboot. This workaround should also persist across upgrades, should any overwrite 11-nf-conntrack.conf.

Seems a similar report of Bad udp cksum on packets from odhcp6c - #8 by vcunat - Turris OS 4.x - Turris forum


capture on ingress happens prior the kernel processes a frame, i.e. WSā€™s checksum computation may not align with the kernelā€™s.

conntrack might be helpful, also the ndptool app.


marginal notes:

547 is the source port in the context. What about other potentially relevant firewall rules, e.g. RA (icmpv6 type 134) | NA (icmpv6 type 136)?


As per Linux documentation on VLAN tag management of DSA ports there is no mention of adding virtual interface on top of the DSA port.

thanks, I am capturing conntrack -E and ndptool as of now (I havenā€™t observed any NDP issue so far); will update this thread as soon as there are some relevant events.

I was just lazy to only pick the relevant port, youā€™re right itā€™s not relevant here.

Enabled. I donā€™t generally filter out ICMPv6. The rules are default from a clean TOS 5 installation.

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
 pkts bytes target     prot opt in     out     source               destination
(...)
  128 12667 zone_wan_input  all      pppoe-wan *       ::/0                 ::/0                 /* !fw3 */
(...)
Chain zone_wan_input (1 references)
 pkts bytes target     prot opt in     out     source               destination
  128 12667 input_wan_rule  all      *      *       ::/0                 ::/0                 /* !fw3: Custom wan input rule chain */
   15  1875 ACCEPT     udp      *      *       fc00::/6             fc00::/6             udp dpt:546 /* !fw3: Allow-DHCPv6 */
    0     0 ACCEPT     icmpv6    *      *       fe80::/10            ::/0                 ipv6-icmptype 130 code 0 /* !fw3: Allow-MLD */
    0     0 ACCEPT     icmpv6    *      *       fe80::/10            ::/0                 ipv6-icmptype 131 code 0 /* !fw3: Allow-MLD */
    0     0 ACCEPT     icmpv6    *      *       fe80::/10            ::/0                 ipv6-icmptype 132 code 0 /* !fw3: Allow-MLD */
    0     0 ACCEPT     icmpv6    *      *       fe80::/10            ::/0                 ipv6-icmptype 143 code 0 /* !fw3: Allow-MLD */
   93  9672 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 128 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 129 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 1 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 2 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 3 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 4 code 0 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 4 code 1 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 133 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 135 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
   20  1120 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 134 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     icmpv6    *      *       ::/0                 ::/0                 ipv6-icmptype 136 limit: avg 1000/sec burst 5 /* !fw3: Allow-ICMPv6-Input */
    0     0 ACCEPT     tcp      *      *       ::/0                 ::/0                 tcp dpt:80 /* !fw3: webserver/80/tcp */
    0     0 ACCEPT     tcp      *      *       ::/0                 ::/0                 tcp dpt:443 /* !fw3: webserver/443/tcp */
    0     0 zone_wan_src_REJECT  all      *      *       ::/0                 ::/0                 /* !fw3 */
(...)
Chain zone_wan_src_REJECT (1 references)
 pkts bytes target     prot opt in     out     source               destination
    0     0 reject     all      pppoe-wan *       ::/0                 ::/0                 /* !fw3 */

I am quite new to DSA, what is the recommended config here? Bridge of lan1 to lan5 plus eth0 (?) and then create a VLAN device on top of that bridge? (I have already tried bridge of lan1.848 to lan5.848 plus eth0.848 and dial PPPoE via this bridge. No change, same behaviour.)

# conntrack -E  | grep udp | egrep '=(546|547) '
    [NEW] udp      17 60 src=fe80::d47d:ad70:7cd9:3d08 dst=ff02::1:2 sport=546 dport=547 [UNREPLIED] src=ff02::1:2 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546
    [NEW] udp      17 60 src=fe80::427c:7dff:fee6:5303 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 [UNREPLIED] src=fe80::d47d:ad70:7cd9:3d08 dst=fe80::427c:7dff:fee6:5303 sport=546 dport=547

(... a while later ...)
[DESTROY] udp      17 src=fe80::427c:7dff:fee6:5303 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 packets=4 bytes=500 [UNREPLIED] src=fe80::d47d:ad70:7cd9:3d08 dst=fe80::427c:7dff:fee6:5303 sport=546 dport=547 packets=0 bytes=0
[DESTROY] udp      17 src=fe80::d47d:ad70:7cd9:3d08 dst=ff02::1:2 sport=546 dport=547 packets=4 bytes=732 [UNREPLIED] src=ff02::1:2 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 packets=0 bytes=0
    [NEW] udp      17 60 src=fe80::d47d:ad70:7cd9:3d08 dst=ff02::1:2 sport=546 dport=547 [UNREPLIED] src=ff02::1:2 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546
    [NEW] udp      17 60 src=fe80::427c:7dff:fee6:5303 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 [UNREPLIED] src=fe80::d47d:ad70:7cd9:3d08 dst=fe80::427c:7dff:fee6:5303 sport=546 dport=547

(... a while later ...)
[DESTROY] udp      17 src=fe80::d47d:ad70:7cd9:3d08 dst=ff02::1:2 sport=546 dport=547 packets=1 bytes=183 [UNREPLIED] src=ff02::1:2 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 packets=0 bytes=0
[DESTROY] udp      17 src=fe80::427c:7dff:fee6:5303 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 packets=1 bytes=125 [UNREPLIED] src=fe80::d47d:ad70:7cd9:3d08 dst=fe80::427c:7dff:fee6:5303 sport=546 dport=547 packets=0 bytes=0
# conntrack -L | egrep '=(546|547) '
udp      17 40 src=fe80::427c:7dff:fee6:5303 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 packets=4 bytes=500 [UNREPLIED] src=fe80::d47d:ad70:7cd9:3d08 dst=fe80::427c:7dff:fee6:5303 sport=546 dport=547 packets=0 bytes=0 mark=0 use=1
udp      17 40 src=fe80::d47d:ad70:7cd9:3d08 dst=ff02::1:2 sport=546 dport=547 packets=4 bytes=732 [UNREPLIED] src=ff02::1:2 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 packets=0 bytes=0 mark=0 use=1

on each DHCPv6 reply (from the BRAS), the counter (first column) in ip6tables -L zone_wan_input -n -v -x increases by one:

# ip6tables -L zone_wan_input -n -v -x
Chain zone_wan_input (1 references)
    pkts      bytes target     prot opt in     out     source               destination
(...)
      21     2625 ACCEPT     udp      *      *       fc00::/6             fc00::/6             udp dpt:546 /* !fw3: Allow-DHCPv6 */

conntrack -S (there was a rebind event at 16:15:21):

Wed Apr 29 16:15:19 CEST 2020
cpu=0   	found=72 invalid=41 ignore=1079363 insert=0 insert_failed=0 drop=0 early_drop=0 error=0 search_restart=861
cpu=1   	found=45 invalid=940164 ignore=1243494 insert=0 insert_failed=0 drop=0 early_drop=0 error=246 search_restart=4129
Wed Apr 29 16:15:20 CEST 2020
cpu=0   	found=72 invalid=41 ignore=1079365 insert=0 insert_failed=0 drop=0 early_drop=0 error=0 search_restart=861
cpu=1   	found=45 invalid=940165 ignore=1243503 insert=0 insert_failed=0 drop=0 early_drop=0 error=246 search_restart=4129
Wed Apr 29 16:15:21 CEST 2020
cpu=0   	found=72 invalid=41 ignore=1079372 insert=0 insert_failed=0 drop=0 early_drop=0 error=0 search_restart=861
cpu=1   	found=45 invalid=940165 ignore=1243511 insert=0 insert_failed=0 drop=0 early_drop=0 error=246 search_restart=4129
Wed Apr 29 16:15:22 CEST 2020
cpu=0   	found=72 invalid=41 ignore=1079385 insert=0 insert_failed=0 drop=0 early_drop=0 error=0 search_restart=861
cpu=1   	found=45 invalid=940166 ignore=1243514 insert=0 insert_failed=0 drop=0 early_drop=0 error=246 search_restart=4129
Wed Apr 29 16:15:23 CEST 2020
cpu=0   	found=72 invalid=41 ignore=1079387 insert=0 insert_failed=0 drop=0 early_drop=0 error=0 search_restart=861
cpu=1   	found=45 invalid=940166 ignore=1243522 insert=0 insert_failed=0 drop=0 early_drop=0 error=246 search_restart=4129

then I have disabled the nf_conntrack_checksum again

# echo 0 > /proc/sys/net/netfilter/nf_conntrack_checksum
# date
Wed Apr 29 16:17:08 CEST 2020

and at the moment of successful rebind, these events were seen in the conntrack -L view:

    [NEW] udp      17 60 src=fe80::d47d:ad70:7cd9:3d08 dst=ff02::1:2 sport=546 dport=547 [UNREPLIED] src=ff02::1:2 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546
    [NEW] udp      17 60 src=fe80::427c:7dff:fee6:5303 dst=fe80::d47d:ad70:7cd9:3d08 sport=547 dport=546 [UNREPLIED] src=fe80::d47d:ad70:7cd9:3d08 dst=fe80::427c:7dff:fee6:5303 sport=546 dport=547

(not really different from the case when it doesnā€™t work)

Could be (one potential explanation) that the switch chip is performing some assessment on the frameā€™s checksum on its own which may, or not, manipulate/delete the frameā€™s checksum and thus kernel not accepting the frame (with net.netfilter.nf_conntrack_checksum=1)?

DHCPv6 already hasnā€™t worked for me in 3.x since day 1. Initially I get an address, but after a few hours, it is lost. This might finally be the explanation.

Yes, this could be the explanation. I have tried to disable checksum offloads via ethtool, however so far nothing changed.

Yes, it might. Check the output of

ifstatus wan6

or

ifstatus wan

and verify the values of preferred and valid attributes of the ipv6-prefix section - the values are in seconds and should be decreasing; every successful prefix renewal (by odhcp6c, the DHCPv6 client) should re-set the counters to whatever is sent by the DHCPv6 server.

Spoke too soon - seems Iā€™ve now had an IPv6 address since 97 days; I just hadnā€™t bothered looking at it anymore.

I do not have a T but only an O and there tx-checksum-ipv6 cannot be turned off (aka [fixed]) on Lan ports

ethtool -k lan0 | grep check

rx-checksumming: off [fixed]
tx-checksumming: on
tx-checksum-ipv4: on [fixed]
tx-checksum-ip-generic: off [fixed]
tx-checksum-ipv6: on [fixed]
tx-checksum-fcoe-crc: off [fixed]
tx-checksum-sctp: off [fixed]

contrary to the WAN port where it would possible to turn tx-checksum-ipv6 off

ethtool -k eth2 | grep check

rx-checksumming: off [fixed]
tx-checksumming: on
tx-checksum-ipv4: on
tx-checksum-ip-generic: off [fixed]
tx-checksum-ipv6: on
tx-checksum-fcoe-crc: off [fixed]
tx-checksum-sctp: off [fixed]

As temporary workaround, we decided to turn off nf_conntrack_checksum in default and it is disabled since Turris OS 5.0 RC2, which was released yesterday.

2 Likes

This ā€œfixedā€ my IPv6, apparently.

EDIT: my ISP setup seems quite different ā€“ Starnet.CZ, fiber to building, ethernet to Omnia.

1 Like