[SOLVED] Patch request - wide-dhcpv6 / dhcp6c

[Greelan]

I was hoping to get a sense of whether a wide-dhcpv6 patch that was introduced in the upstream in 2015 will make it into OPNsense. Hopefully this is the right place to ask, rather than, eg, on GitHub.

The issue is this (as explained to me by my ISP). Whenever dhcp6c on OPNsense sends a release to my ISP, and then (as is usual) tries to send a solicit straight after the release to obtain a new lease, the ISP's BNG responds with a DHCPv6 UnspecFail advertise. Apparently, somewhere between the DHCPv6 proxy and DHCPv6 server running on the BNG, the release process has not been finalised (and so the lease is not considered available to the client again) when dhcp6c sends the new solicit, hence the UnspecFail response.

However, dhcp6c does not interpret this correctly and instead assumes the BNG is trying to advertise the prefix, and so dhcp6c sends a DHCPv6 request for a blank prefix back to the BNG. The BNG of course drops this as invalid. dhcp6c then eventually gives up trying to get a DHCPv6 lease, and accordingly no WAN GUA or IPv6 PD is received, until dhcp6c is reloaded or restarted.

The behaviour can be seen in these logs (anonymised):

Code: [Select]

2020-12-07T09:27:04 dhclient[59442] My address (xxx.xxx.xxx.140) was deleted, dhclient exiting
2020-12-07T09:27:04 dhclient[78405] Starting delete_old_states()
2020-12-07T09:27:04 dhclient[72525] Comparing IPs: Old: xxx.xxx.xxx.xxx New:
2020-12-07T09:27:04 dhclient[44634] Removing states from old IP 'xxx.xxx.xxx.140' (new IP '')
2020-12-07T09:27:04 dhclient[59442] connection closed
2020-12-07T09:27:04 dhclient[59442] exiting.
2020-12-07T09:27:04 dhclient[16850] Starting delete_old_states()
2020-12-07T09:27:04 dhclient[94879] Comparing IPs: Old: xxx.xxx.xxx.140 New:
2020-12-07T09:27:04 dhclient[42526] Removing states from old IP 'xxx.xxx.xxx.140' (new IP '')
2020-12-07T09:27:04 dhclient[72953] DHCPREQUEST on igb0 to 255.255.255.255 port 67
2020-12-07T09:27:04 dhclient[72953] DHCPACK from xxx.xxx.xxx.1
2020-12-07T09:27:04 dhclient[23989] Starting delete_old_states()
2020-12-07T09:27:04 dhclient[72164] Comparing IPs: Old: xxx.xxx.xxx.140 New: xxx.xxx.xxx.140
2020-12-07T09:27:04 dhclient[39437] New IP Address (igb0): xxx.xxx.xxx.140
2020-12-07T09:27:04 dhclient[52716] New Subnet Mask (igb0): 255.255.252.0
2020-12-07T09:27:04 dhclient[95879] New Broadcast Address (igb0): xxx.xxx.xxx.255
2020-12-07T09:27:04 dhclient[31371] New Routers (igb0): xxx.xxx.xxx.1
2020-12-07T09:27:04 dhclient[79817] route add default xxx.xxx.xxx.1
2020-12-07T09:27:04 dhclient[99820] Creating resolv.conf
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: IPv4 renewal is starting on 'igb0'
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: On (IP address: xxx.xxx.xxx.140) (interface: WAN[wan]) (real interface: igb0).
2020-12-07T09:27:04 opnsense[6163] plugins_configure hosts ()
2020-12-07T09:27:04 opnsense[6163] plugins_configure hosts (execute task : dnsmasq_hosts_generate())
2020-12-07T09:27:04 opnsense[6163] plugins_configure hosts (execute task : unbound_hosts_generate())
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: ROUTING: entering configure using 'wan'
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: ROUTING: IPv4 default gateway set to wan
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: ROUTING: setting IPv4 default route to xxx.xxx.xxx.1
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: ROUTING: keeping current default gateway 'xxx.xxx.xxx.1'
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: ROUTING: IPv6 default gateway set to wan
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: ROUTING: skipping IPv6 default route
2020-12-07T09:27:04 opnsense[6163] plugins_configure monitor ()
2020-12-07T09:27:04 opnsense[6163] plugins_configure monitor (execute task : dpinger_configure_do())
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: The WAN_DHCP6 monitor address is empty, skipping.
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: The WAN_DHCP monitor address is empty, skipping.
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: The OpenVPNv6 monitor address is empty, skipping.
2020-12-07T09:27:04 opnsense[6163] /usr/local/etc/rc.newwanip: The OpenVPNv4 monitor address is empty, skipping.
2020-12-07T09:27:05 opnsense[6163] plugins_configure vpn (,wan)
2020-12-07T09:27:05 kernel pflog0: promiscuous mode disabled
2020-12-07T09:27:05 kernel pflog0: promiscuous mode enabled
2020-12-07T09:27:05 opnsense[6163] plugins_configure vpn (execute task : ipsec_configure_do(,wan))
2020-12-07T09:27:05 opnsense[6163] plugins_configure vpn (execute task : openvpn_configure_do(,wan))
2020-12-07T09:27:05 opnsense[6163] /usr/local/etc/rc.newwanip: Resyncing OpenVPN instances for interface WAN.
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (,wan)
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : dyndns_configure_do(,wan))
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : ntpd_configure_defer())
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : opendns_configure_do())
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : openssh_configure_do(,wan))
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : unbound_configure_do(,wan))
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : vxlan_configure_interface())
2020-12-07T09:27:05 opnsense[6163] plugins_configure newwanip (execute task : webgui_configure_do(,wan))
2020-12-07T09:27:05 dhclient[72953] bound to xxx.xxx.xxx.140 -- renewal in 900 seconds.
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: Accept router advertisements on interface igb0
2020-12-07T09:27:05 dhcp6c[7137] RTSOLD script - Sending SIGHUP to dhcp6c
2020-12-07T09:27:05 dhcp6c[41467] restarting
2020-12-07T09:27:05 dhcp6c[41467] Start address release
2020-12-07T09:27:05 dhcp6c[41467] release an IA: NA-0
2020-12-07T09:27:05 dhcp6c[41467] reset a timer on igb0, state=RELEASE, timeo=0, retrans=1033
2020-12-07T09:27:05 dhcp6c[41467] Sending Release
2020-12-07T09:27:05 dhcp6c[41467] a new XID (d304b7) is generated
2020-12-07T09:27:05 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:05 dhcp6c[41467] set server ID (len 14)
2020-12-07T09:27:05 dhcp6c[41467] set IA address
2020-12-07T09:27:05 dhcp6c[41467] set identity association
2020-12-07T09:27:05 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:05 dhcp6c[41467] send release to ff02::1:2%igb0
2020-12-07T09:27:05 dhcp6c[41467] remove an IA: NA-0
2020-12-07T09:27:05 dhcp6c[41467] remove an address xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:8671
2020-12-07T09:27:05 dhcp6c[41467] failed to remove an address on igb0: Can't assign requested address
2020-12-07T09:27:05 dhcp6c[41467] reset a timer on igb0, state=INIT, timeo=0, retrans=174
2020-12-07T09:27:05 dhcp6c[41467] Start address release
2020-12-07T09:27:05 dhcp6c[41467] release an IA: PD-0
2020-12-07T09:27:05 dhcp6c[41467] reset a timer on igb0, state=RELEASE, timeo=0, retrans=930
2020-12-07T09:27:05 dhcp6c[41467] Sending Release
2020-12-07T09:27:05 dhcp6c[41467] a new XID (1527b4) is generated
2020-12-07T09:27:05 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:05 dhcp6c[41467] set server ID (len 14)
2020-12-07T09:27:05 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:05 dhcp6c[41467] set IA_PD prefix
2020-12-07T09:27:05 dhcp6c[41467] set IA_PD
2020-12-07T09:27:05 dhcp6c[41467] send release to ff02::1:2%igb0
2020-12-07T09:27:05 dhcp6c[41467] remove an IA: PD-0
2020-12-07T09:27:05 dhcp6c[41467] remove a site prefix xxxx:xxxx:xxxx:xxxx::/56
2020-12-07T09:27:05 dhcp6c[41467] remove an address xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:3261/64 on igb1_vlan66
2020-12-07T09:27:05 dhcp6c[41467] remove an address xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:3261/64 on igb1
2020-12-07T09:27:05 dhcp6c[41467] remove an address xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:3261/64 on igb1_vlan10
2020-12-07T09:27:05 dhcp6c[41467] remove an address xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:3261/64 on igb1_vlan99
2020-12-07T09:27:05 dhcp6c[41467] remove an address xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:3261/64 on igb1_vlan49
2020-12-07T09:27:05 dhcp6c[41467] reset a timer on igb0, state=INIT, timeo=0, retrans=16
2020-12-07T09:27:05 dhcp6c[41467] removing an event on igb0, state=INIT
2020-12-07T09:27:05 dhcp6c[41467] removing an event on igb0, state=INIT
2020-12-07T09:27:05 dhcp6c[41467] <3>[interface] (9)
2020-12-07T09:27:05 dhcp6c[41467] <5>[igb0] (4)
2020-12-07T09:27:05 dhcp6c[41467] <3>begin of closure [{] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>[send] (4)
2020-12-07T09:27:05 dhcp6c[41467] <3>[ia-na] (5)
2020-12-07T09:27:05 dhcp6c[41467] <3>[0] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of sentence [;] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>comment [# request stateful address] (26)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of sentence [;] (1)
2020-12-07T09:27:05 dhcp6c[41467] <5>[igb1_vlan10] (11)
2020-12-07T09:27:05 dhcp6c[41467] <3>begin of closure [{] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>[sla-id] (6)
2020-12-07T09:27:05 dhcp6c[41467] <3>[16] (2)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of sentence [;] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>[sla-len] (7)
2020-12-07T09:27:05 dhcp6c[41467] <3>[8] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of sentence [;] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of closure [}] (1)
2020-12-07T09:27:05 dhcp6c[41467] called
2020-12-07T09:27:05 dhcp6c[41467] called
2020-12-07T09:27:05 dhcp6c[41467] duplicated interface: igb0
2020-12-07T09:27:05 dhcp6c[41467] <3>[interface] (9)
2020-12-07T09:27:05 dhcp6c[41467] <5>[igb0] (4)
2020-12-07T09:27:05 dhcp6c[41467] <3>begin of closure [{] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>[send] (4)
2020-12-07T09:27:05 dhcp6c[41467] <3>[ia-na] (5)
2020-12-07T09:27:05 dhcp6c[41467] <3>[0] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of sentence [;] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>comment [# we'd like some nameservers please] (35)
2020-12-07T09:27:05 dhcp6c[41467] <3>[id-assoc] (8)
2020-12-07T09:27:05 dhcp6c[41467] <13>[na] (2)
2020-12-07T09:27:05 dhcp6c[41467] <13>[0] (1)
2020-12-07T09:27:05 dhcp6c[41467] <13>begin of closure [{] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of closure [}] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>end of sentence [;] (1)
2020-12-07T09:27:05 dhcp6c[41467] <3>[id-assoc] (8)
2020-12-07T09:27:05 dhcp6c[41467] <13>[pd] (2)
2020-12-07T09:27:05 dhcp6c[41467] <13>[0] (1)
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: ROUTING: entering configure using 'wan'
2020-12-07T09:27:05 dhcp6c[41467] receive reply from fe80::2a2:ff:feb2:c2%igb0 on igb0
2020-12-07T09:27:05 dhcp6c[41467] get DHCP option client ID, len 14
2020-12-07T09:27:05 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:60
2020-12-07T09:27:05 dhcp6c[41467] get DHCP option server ID, len 14
2020-12-07T09:27:05 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:d0
2020-12-07T09:27:05 dhcp6c[41467] get DHCP option identity association, len 63
2020-12-07T09:27:05 dhcp6c[41467] IA_NA: ID=0, T1=0, T2=0
2020-12-07T09:27:05 dhcp6c[41467] get DHCP option status code, len 47
2020-12-07T09:27:05 dhcp6c[41467] status code: success
2020-12-07T09:27:05 dhcp6c[41467] get DHCP option status code, len 41
2020-12-07T09:27:05 dhcp6c[41467] status code: success
2020-12-07T09:27:05 dhcp6c[41467] Received REPLY for RELEASE
2020-12-07T09:27:05 dhcp6c[41467] status code: success
2020-12-07T09:27:05 dhcp6c[33283] dhcp6c RELEASE on igb0
2020-12-07T09:27:05 dhcp6c[80681] dhcp6c RELEASE on igb0 - running newipv6
2020-12-07T09:27:05 opnsense[99831] /usr/local/etc/rc.newwanipv6: IPv6 renewal is starting on 'igb0'
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: ROUTING: IPv4 default gateway set to wan
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: ROUTING: setting IPv4 default route to xxx.xxx.xxx.1
2020-12-07T09:27:05 opnsense[99831] /usr/local/etc/rc.newwanipv6: On (IP address: ) (interface: WAN[wan]) (real interface: igb0).
2020-12-07T09:27:05 opnsense[99831] /usr/local/etc/rc.newwanipv6: Failed to detect IP for WAN[wan]
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: ROUTING: keeping current default gateway 'xxx.xxx.xxx.1'
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: ROUTING: IPv6 default gateway set to wan
2020-12-07T09:27:05 opnsense[17528] /usr/local/etc/rc.configure_interface: ROUTING: skipping IPv6 default route
2020-12-07T09:27:05 dhcp6c[41467] script "/var/etc/dhcp6c_wan_script.sh" terminated
2020-12-07T09:27:05 dhcp6c[41467] removing an event on igb0, state=RELEASE
2020-12-07T09:27:05 dhcp6c[41467] got an expected reply, sleeping.
2020-12-07T09:27:05 opnsense[17528] plugins_configure ipsec (1,wan)
2020-12-07T09:27:05 opnsense[17528] plugins_configure ipsec (execute task : ipsec_configure_do(1,wan))
2020-12-07T09:27:05 opnsense[17528] plugins_configure dhcp (1)
2020-12-07T09:27:05 opnsense[17528] plugins_configure dhcp (execute task : dhcpd_dhcp_configure(1))
2020-12-07T09:27:06 dhcp6c[41467] Sending Solicit
2020-12-07T09:27:06 dhcp6c[41467] a new XID (2efce5) is generated
2020-12-07T09:27:06 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:06 dhcp6c[41467] set identity association
2020-12-07T09:27:06 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:06 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:06 dhcp6c[41467] set IA_PD prefix
2020-12-07T09:27:06 dhcp6c[41467] set IA_PD
2020-12-07T09:27:06 dhcp6c[41467] send solicit to ff02::1:2%igb0
2020-12-07T09:27:06 dhcp6c[41467] reset a timer on igb0, state=SOLICIT, timeo=0, retrans=1085
2020-12-07T09:27:06 dhcp6c[41467] receive advertise from fe80::2a2:ff:feb2:c2%igb0 on igb0
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option server ID, len 10
2020-12-07T09:27:06 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option client ID, len 14
2020-12-07T09:27:06 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:60
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option status code, len 2
2020-12-07T09:27:06 dhcp6c[41467] status code: unspec failure
2020-12-07T09:27:06 dhcp6c[41467] server ID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28, pref=-1
2020-12-07T09:27:06 dhcp6c[41467] reset timer for igb0 to 0.992740
2020-12-07T09:27:06 dhcp6c[41467] receive advertise from fe80::2a2:ff:feb2:c2%igb0 on igb0
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option server ID, len 10
2020-12-07T09:27:06 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option client ID, len 14
2020-12-07T09:27:06 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:60
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option status code, len 2
2020-12-07T09:27:06 dhcp6c[41467] status code: unspec failure
2020-12-07T09:27:06 dhcp6c[41467] server ID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28, pref=-1
2020-12-07T09:27:06 dhcp6c[41467] duplicated server (ID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28)
2020-12-07T09:27:06 opnsense[17528] plugins_configure dns (1)
2020-12-07T09:27:06 opnsense[17528] plugins_configure dns (execute task : dnsmasq_configure_do(1))
2020-12-07T09:27:06 opnsense[17528] plugins_configure dns (execute task : unbound_configure_do(1))
2020-12-07T09:27:06 dhcp6c[41467] Sending Release
2020-12-07T09:27:06 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:06 dhcp6c[41467] set server ID (len 14)
2020-12-07T09:27:06 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:06 dhcp6c[41467] set IA_PD prefix
2020-12-07T09:27:06 dhcp6c[41467] set IA_PD
2020-12-07T09:27:06 dhcp6c[41467] send release to ff02::1:2%igb0
2020-12-07T09:27:06 dhcp6c[41467] reset a timer on igb0, state=RELEASE, timeo=1, retrans=1770
2020-12-07T09:27:06 dhcp6c[41467] receive reply from fe80::2a2:ff:feb2:c2%igb0 on igb0
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option client ID, len 14
2020-12-07T09:27:06 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:60
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option server ID, len 14
2020-12-07T09:27:06 dhcp6c[41467] DUID: xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:d0
2020-12-07T09:27:06 dhcp6c[41467] get DHCP option status code, len 2
2020-12-07T09:27:06 dhcp6c[41467] status code: no binding
2020-12-07T09:27:06 dhcp6c[41467] Received REPLY for RELEASE
2020-12-07T09:27:06 dhcp6c[41467] status code: no binding
2020-12-07T09:27:06 dhcp6c[41467] executes /var/etc/dhcp6c_wan_script.sh
2020-12-07T09:27:06 dhcp6c[44127] dhcp6c RELEASE on igb0
2020-12-07T09:27:06 dhcp6c[60627] dhcp6c RELEASE on igb0 - running newipv6
2020-12-07T09:27:06 opnsense[56651] /usr/local/etc/rc.newwanipv6: IPv6 renewal is starting on 'igb0'
2020-12-07T09:27:06 opnsense[56651] /usr/local/etc/rc.newwanipv6: On (IP address: ) (interface: WAN[wan]) (real interface: igb0).
2020-12-07T09:27:06 opnsense[56651] /usr/local/etc/rc.newwanipv6: Failed to detect IP for WAN[wan]
2020-12-07T09:27:06 dhcp6c[41467] script "/var/etc/dhcp6c_wan_script.sh" terminated
2020-12-07T09:27:06 dhcp6c[41467] removing an event on igb0, state=RELEASE
2020-12-07T09:27:06 dhcp6c[41467] got an expected reply, sleeping.
2020-12-07T09:27:07 dhcp6c[41467] picked a server (ID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28)
2020-12-07T09:27:07 dhcp6c[41467] Sending Request
2020-12-07T09:27:07 dhcp6c[41467] a new XID (2f1201) is generated
2020-12-07T09:27:07 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:07 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:27:07 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:07 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:07 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:27:07 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=0, retrans=907
2020-12-07T09:27:07 dhcp6c[41467] Sending Request
2020-12-07T09:27:07 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:07 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:27:07 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:07 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:07 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:27:07 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=1, retrans=1895
2020-12-07T09:27:09 dhcp6c[41467] Sending Request
2020-12-07T09:27:09 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:09 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:27:09 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:09 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:09 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:27:09 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=2, retrans=3731
2020-12-07T09:27:13 dhcp6c[41467] Sending Request
2020-12-07T09:27:13 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:13 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:27:13 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:13 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:13 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:27:13 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=3, retrans=7516
2020-12-07T09:27:21 dhcp6c[41467] Sending Request
2020-12-07T09:27:21 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:21 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:27:21 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:21 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:21 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:27:21 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=4, retrans=14760
2020-12-07T09:27:35 dhcp6c[41467] Sending Request
2020-12-07T09:27:35 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:27:35 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:27:35 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:27:35 dhcp6c[41467] set option request (len 4)
2020-12-07T09:27:35 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:27:35 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=5, retrans=28144
2020-12-07T09:28:03 dhcp6c[41467] Sending Request
2020-12-07T09:28:03 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:28:03 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:28:03 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:28:03 dhcp6c[41467] set option request (len 4)
2020-12-07T09:28:03 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:28:03 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=6, retrans=31284
2020-12-07T09:28:35 dhcp6c[41467] Sending Request
2020-12-07T09:28:35 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:28:35 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:28:35 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:28:35 dhcp6c[41467] set option request (len 4)
2020-12-07T09:28:35 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:28:35 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=7, retrans=32607
2020-12-07T09:29:07 dhcp6c[41467] Sending Request
2020-12-07T09:29:07 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:29:07 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:29:07 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:29:07 dhcp6c[41467] set option request (len 4)
2020-12-07T09:29:07 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:29:07 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=8, retrans=31383
2020-12-07T09:29:39 dhcp6c[41467] Sending Request
2020-12-07T09:29:39 dhcp6c[41467] set client ID (len 14)
2020-12-07T09:29:39 dhcp6c[41467] set server ID (len 10)
2020-12-07T09:29:39 dhcp6c[41467] set elapsed time (len 2)
2020-12-07T09:29:39 dhcp6c[41467] set option request (len 4)
2020-12-07T09:29:39 dhcp6c[41467] send request to ff02::1:2%igb0
2020-12-07T09:29:39 dhcp6c[41467] reset a timer on igb0, state=REQUEST, timeo=9, retrans=30951
2020-12-07T09:30:10 dhcp6c[41467] no responses were received
2020-12-07T09:30:10 dhcp6c[41467] removing an event on igb0, state=REQUEST
2020-12-07T09:30:10 dhcp6c[41467] removing server (ID: xx:xx:xx:xx:xx:xx:xx:xx:xx:28)

The BNG's behaviour (my ISP uses Cisco routers) is actually RFC compliant, according to my ISP. Per RFC 3315 (https://tools.ietf.org/html/rfc3315#section-15):

If a server receives a message that contains options it should not contain (such as an Information-request message with an IA option), is missing options that it should contain, or is otherwise not valid, it MAY send a Reply (or Advertise as appropriate) with a Server Identifier option, a Client Identifier option if one was included in the message and a Status Code option with status UnSpecFail.

Same for the updated RFC 8415 (https://tools.ietf.org/html/rfc8415#section-16):

If a server receives a message that it considers invalid, it MAY send a Reply message (or Advertise message, as appropriate) with a Server Identifier option (see Section 21.3), a Client Identifier option (see Section 21.2) (if one was included in the message), and a Status Code option (see Section 21.13) with status UnspecFail.

The issue of wide-dhcpv6 / dhcp6c not responding correctly to UnspecFail advertises was, I am told, addressed in the upstream. My research suggests that occurred in 2015: https://sourceforge.net/p/wide-dhcpv6/bugs/34/. Specifically, item 4:

4) dhcpv6: ignore advertise messages with none of requested data and missed status codes.

This patch was implemented in Debian in March 2018: https://metadata.ftp-master.debian.org/changelogs//main/w/wide-dhcpv6/wide-dhcpv6_20080615-23_changelog. Specifically, patch 0018:

- Add patch 0018 to ignore advertise messages with none of requested data and missed status codes.
  Thanks to Roman Mamedov for the report and Evgeniy Manachkin for the patch (Closes: #765453).

What I understand to be the content of the patch is attached.

But this patch does not appear to have made it into FreeBSD or OPNsense.

Curiously, some of the items addressed by the upstream patch in 2015 have been implemented - in FreeBSD in Jan 2016 (based on the descriptions in https://www.freshports.org/net/dhcp6 for version 20080615_4) and in OPNsense in December 2016 (based on the commit descriptions in https://github.com/opnsense/dhcp6c/commits/master). But not item 4.

Is there any prospect of this patch being implemented in OPNsense?

[mimugmail]

This should more go into GitHub rather than here

[Greelan]

No problem, will post it there

[Greelan]

For reference, here it is: https://github.com/opnsense/dhcp6c/issues/25

[franco]

We're taking care of this now, thanks!

Testers welcome, package tomorrow.


Cheers,
Franco

[franco]

As per Greelan it looks promising and I have no objections to pull this into 20.7.7. Running fine from here as well.

To test:

# pkg add -f https://pkg.opnsense.org/FreeBSD:12:amd64/20.7/misc/dhcp6c-20200512_1.txz

To revert:

# opnsense-revert dhcp6c


Cheers,
Franco