Dhcpv6 client doesn't complete negotiation, no delegated prefix

No such luck unfortunately. However the same issue was part of a misconfiguration of mtu, but was supposed to be solved after the mtu was correct.

No, they always had it like this. In general they are very helpful and since it is a small village provider they were quite happy to test ipv6 connectivity with me as the first client.

That is partially correct. The RPi will eventually get the advertise, but after a lot of delay and many unread responses.

Wed Dec 23 21:03:17 2020 daemon.notice odhcp6c[15600]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:03:17 2020 daemon.notice netifd: wan6 (15600): odhcp6c[15600]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:03:33 2020 daemon.notice odhcp6c[15600]: Got a valid ADVERTISE after 15253ms

During my tests yesterday I had one time that everything worked fine, but didn't stay like this.

Wed Dec 23 21:01:38 2020 daemon.notice odhcp6c[4812]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Wed Dec 23 21:01:38 2020 daemon.notice odhcp6c[4812]: Got a valid ADVERTISE after 2ms
Wed Dec 23 21:01:38 2020 daemon.info odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Got a valid ADVERTISE after 2ms
Wed Dec 23 21:01:38 2020 daemon.info odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:38 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Starting REQUEST transaction (timeout 4294967295s, max rc 10)
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Send REQUEST message (elapsed 0ms, rc 0)
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Starting REQUEST transaction (timeout 4294967295s, max rc 10)
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Send REQUEST message (elapsed 0ms, rc 0)
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Got a valid REPLY after 3ms
Wed Dec 23 21:01:39 2020 daemon.info odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Got a valid REPLY after 3ms
Wed Dec 23 21:01:39 2020 daemon.info odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: IAID 0001 T1 450 T2 720
Wed Dec 23 21:01:39 2020 daemon.info odhcp6c[4812]: T1 450s, T2 720s, T3 900s
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: 2222:3333:225:7500::/56 preferred 810 valid 900
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: T1 450s, T2 720s, T3 900s
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: entering stateful-mode on pppoe-wan
Wed Dec 23 21:01:39 2020 daemon.notice odhcp6c[4812]: Starting <POLL> transaction (timeout 450s, max rc 0)
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: entering stateful-mode on pppoe-wan
Wed Dec 23 21:01:39 2020 daemon.notice netifd: wan6 (4812): odhcp6c[4812]: Starting <POLL> transaction (timeout 450s, max rc 0)

I tried once again. For more than 20 minutes they are exchanging solicit-advertise.

root@magiatiko / > tcpdump -i pppoe-wan -evn udp port 547
tcpdump: listening on pppoe-wan, link-type LINUX_SLL (Linux cooked v1), capture size 262144 bytes

13:28:18.817648 Out ethertype IPv6 (0x86dd), length 168: (flowlabel 0x72d87, hlim 1, next-header UDP (17) payload length: 112) fe80::d832:bada:97ad:e74b.546 > ff02::1:2.547: [udp sum ok] dhcp6 solicit (xid=70612e (elapsed-time 0) (option-request SIP-servers-domain SIP-servers-address DNS-server DNS-search-list SNTP-servers NTP-server AFTR-Name opt_67 opt_94 opt_95 opt_96 opt_82) (client-ID hwaddr type 1 001e101f0000) (reconfigure-accept) (Client-FQDN) (IA_NA IAID:1 T1:0 T2:0) (IA_PD IAID:1 T1:0 T2:0))
13:28:18.821227  In ethertype IPv6 (0x86dd), length 182: (hlim 64, next-header UDP (17) payload length: 126) fe80::10c.547 > fe80::d832:bada:97ad:e74b.546: [udp sum ok] dhcp6 advertise (xid=70612e (client-ID hwaddr type 1 001e101f0000) (server-ID hwaddr type 1 6c3b6bee0d46) (preference 255) (DNS-server 2001:4860:4860::8888 2001:4860:4860::8844) (IA_PD IAID:1 T1:450 T2:720 (IA_PD-prefix 2222:3333:225:7500::/56 pltime:810 vltime:900)))
...
13:50:09.867416 Out ethertype IPv6 (0x86dd), length 168: (flowlabel 0x72d87, hlim 1, next-header UDP (17) payload length: 112) fe80::d832:bada:97ad:e74b.546 > ff02::1:2.547: [udp sum ok] dhcp6 solicit (xid=70612e (elapsed-time 65535) (option-request SIP-servers-domain SIP-servers-address DNS-server DNS-search-list SNTP-servers NTP-server AFTR-Name opt_67 opt_94 opt_95 opt_96 opt_82) (client-ID hwaddr type 1 001e101f0000) (reconfigure-accept) (Client-FQDN) (IA_NA IAID:1 T1:0 T2:0) (IA_PD IAID:1 T1:0 T2:0))
13:50:09.870379  In ethertype IPv6 (0x86dd), length 182: (hlim 64, next-header UDP (17) payload length: 126) fe80::10c.547 > fe80::d832:bada:97ad:e74b.546: [udp sum ok] dhcp6 advertise (xid=70612e (client-ID hwaddr type 1 001e101f0000) (server-ID hwaddr type 1 6c3b6bee0d46) (preference 255) (DNS-server 2001:4860:4860::8888 2001:4860:4860::8844) (IA_PD IAID:1 T1:450 T2:720 (IA_PD-prefix 2222:3333:225:7500::/56 pltime:810 vltime:900)))

In the logs odhcp6c has not detected any response:

Thu Dec 24 13:28:18 2020 daemon.notice odhcp6c[5506]: (re)starting transaction on pppoe-wan
Thu Dec 24 13:28:18 2020 daemon.notice netifd: wan6 (5506): odhcp6c[5506]: (re)starting transaction on pppoe-wan
Thu Dec 24 13:28:18 2020 daemon.notice odhcp6c[5506]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)
Thu Dec 24 13:28:18 2020 daemon.notice netifd: wan6 (5506): odhcp6c[5506]: Starting SOLICIT transaction (timeout 4294967295s, max rc 0)

root@magiatiko / > date
Thu Dec 24 13:52:47 CET 2020

Regarding ubus, I managed to capture both scenarios. The working one:

<- 9569fa05 #43084bd1         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{"passthru":"001700202001486048600000000000000000888820014860486000000000000000008844"},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604796,"valid":2591996,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:225:7500::/56"},{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591996}],"ip6prefix":["2222:3333:225:7500::/56,810,900"],"dns":["2001:4860:4860::8888","2001:4860:4860::8844"],"interface":"wan6"}}
-> 9d8725df #9569fa05         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{"passthru":"001700202001486048600000000000000000888820014860486000000000000000008844"},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604796,"valid":2591996,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:225:7500::/56"},{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1796,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591996}],"ip6prefix":["2222:3333:225:7500::/56,810,900"],"dns":["2001:4860:4860::8888","2001:4860:4860::8844"],"interface":"wan6"},"user":"root","group":"root"}

and the failed one:

<- c2ea4cec #43084bd1         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604790,"valid":2591990,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1790,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591990}],"dns":["2001:4860:4860::8844","2001:4860:4860::8888"],"interface":"wan6"}}
-> 9d8725df #c2ea4cec         invoke: {"objid":1124617169,"method":"notify_proto","data":{"action":0,"link-up":true,"data":{},"keep":false,"ip6addr":[{"ipaddr":"2222:3333:227:75d3:d832:bada:97ad:e74b","mask":"64","preferred":604790,"valid":2591990,"offlink":true}],"routes6":[{"target":"::","netmask":"0","gateway":"fe80::10c","metric":512,"valid":1790,"source":"2222:3333:227:75d3:d832:bada:97ad:e74b/64"},{"target":"2222:3333:227:75d3::","netmask":"64","metric":256,"valid":2591990}],"dns":["2001:4860:4860::8844","2001:4860:4860::8888"],"interface":"wan6"},"user":"root","group":"root"}

I hope it can provide some insight what is going on.

1 Like