dhcpd6 problem after interface reset

Started by RadicalEd, September 28, 2020, 10:00:12 PM

Previous topic - Next topic
Hi,

I'm using OPNSense for a V-DSL connection which authenticates itself via pppoe. So far everything seems to be working and OPNSense is also receiving a IPv6 subnet which it provides to the clients. Due to a forced 24h disconnect on the side of the provider, I'm trying to control it with a cronjob and the type "Periodic interface reset". The reset itself works fine but after it the dhcpd6 is in a non working state and can't be started again. Also the clients don't receive an IP address anymore. As the dhcpd6 seems to be a part of dhcpd (please correct me if I'm wrong), I also tried to restart it without a change.

The problem can be fixed by rebooting the whole system or trigger a Disconnect and Connect over the webinterface on the WAN interface. Afterwards the service is running again and everything is working fine.

My question is how I can solve this problem? An Idea would be to switch to a Disconnect/Connect procedure instead of the Reset of the Interface. But how can I do this within a cronjob? Or is there an option that could cause this Behaviour?

Within the dhcpd.log I wasn't able to spot any problem:
Sep 26 05:13:00 home dhcpd[93351]: Internet Systems Consortium DHCP Server 4.4.2
Sep 26 05:13:00 home dhcpd[93351]: Copyright 2004-2020 Internet Systems Consortium.
Sep 26 05:13:00 home dhcpd[93351]: All rights reserved.
Sep 26 05:13:00 home dhcpd[93351]: For info, please visit https://www.isc.org/software/dhcp/
Sep 26 05:13:00 home dhcpd[93351]: Config file: /etc/dhcpd.conf
Sep 26 05:13:00 home dhcpd[93351]: Database file: /var/db/dhcpd.leases
Sep 26 05:13:00 home dhcpd[93351]: PID file: /var/run/dhcpd.pid
Sep 26 05:13:00 home dhcpd[93351]: Internet Systems Consortium DHCP Server 4.4.2
Sep 26 05:13:00 home dhcpd[93351]: Copyright 2004-2020 Internet Systems Consortium.
Sep 26 05:13:00 home dhcpd[93351]: All rights reserved.
Sep 26 05:13:00 home dhcpd[93351]: For info, please visit https://www.isc.org/software/dhcp/
Sep 26 05:13:00 home dhcpd[93351]: Wrote 0 deleted host decls to leases file.
Sep 26 05:13:00 home dhcpd[93351]: Wrote 0 new dynamic host decls to leases file.
Sep 26 05:13:00 home dhcpd[93351]: Wrote 22 leases to leases file.
Sep 26 05:13:00 home dhcpd[93351]: Listening on BPF/re0/00:01:2e:95:fe:56/192.168.128.0/24
Sep 26 05:13:00 home dhcpd[93351]: Sending on   BPF/re0/00:01:2e:95:fe:56/192.168.128.0/24
Sep 26 05:13:00 home dhcpd[93351]: Sending on   Socket/fallback/fallback-net
Sep 26 05:13:00 home dhcpd[93351]: Server starting service.
Sep 26 05:13:00 home dhcpd[20355]: Internet Systems Consortium DHCP Server 4.4.2
Sep 26 05:13:00 home dhcpd[20355]: Copyright 2004-2020 Internet Systems Consortium.
Sep 26 05:13:00 home dhcpd[20355]: All rights reserved.
Sep 26 05:13:00 home dhcpd[20355]: For info, please visit https://www.isc.org/software/dhcp/
Sep 26 05:13:00 home dhcpd[20355]: Config file: /etc/dhcpdv6.conf
Sep 26 05:13:00 home dhcpd[20355]: Database file: /var/db/dhcpd6.leases
Sep 26 05:13:00 home dhcpd[20355]: PID file: /var/run/dhcpdv6.pid
Sep 26 05:13:00 home dhcpd[20355]: Internet Systems Consortium DHCP Server 4.4.2
Sep 26 05:13:00 home dhcpd[20355]: Copyright 2004-2020 Internet Systems Consortium.
Sep 26 05:13:00 home dhcpd[20355]: All rights reserved.
Sep 26 05:13:00 home dhcpd[20355]: For info, please visit https://www.isc.org/software/dhcp/
Sep 26 05:13:00 home dhcpd[20355]: Wrote 2 NA, 0 TA, 0 PD leases to lease file.
Sep 26 05:13:00 home dhcpd[20355]: Bound to *:547
Sep 26 05:13:00 home dhcpd[20355]: Listening on Socket/7/re0/2003:d3:5f1d:e900::/56
Sep 26 05:13:00 home dhcpd[20355]: Sending on   Socket/7/re0/2003:d3:5f1d:e900::/56
Sep 26 05:13:00 home dhcpd[20355]: Server starting service.
Sep 26 05:13:04 home dhcpd[53622]: Internet Systems Consortium DHCP Server 4.4.2
Sep 26 05:13:04 home dhcpd[53622]: Copyright 2004-2020 Internet Systems Consortium.
Sep 26 05:13:04 home dhcpd[53622]: All rights reserved.
Sep 26 05:13:04 home dhcpd[53622]: For info, please visit https://www.isc.org/software/dhcp/
Sep 26 05:13:04 home dhcpd[53622]: Config file: /etc/dhcpdv6.conf
Sep 26 05:13:04 home dhcpd[53622]: Database file: /var/db/dhcpd6.leases
Sep 26 05:13:04 home dhcpd[53622]: PID file: /var/run/dhcpdv6.pid
Sep 26 05:13:04 home dhcpd[53622]: Internet Systems Consortium DHCP Server 4.4.2
Sep 26 05:13:04 home dhcpd[53622]: Copyright 2004-2020 Internet Systems Consortium.
Sep 26 05:13:04 home dhcpd[53622]: All rights reserved.
Sep 26 05:13:04 home dhcpd[53622]: For info, please visit https://www.isc.org/software/dhcp/
Sep 26 05:13:04 home dhcpd[53622]: Wrote 2 NA, 0 TA, 0 PD leases to lease file.
Sep 26 05:13:04 home dhcpd[53622]: Bound to *:547
Sep 26 05:13:04 home dhcpd[53622]: Listening on Socket/7/re0/2003:d3:5f1d:e900::/56
Sep 26 05:13:04 home dhcpd[53622]: Sending on   Socket/7/re0/2003:d3:5f1d:e900::/56
Sep 26 05:13:04 home dhcpd[53622]: Server starting service.


Also the system.log doesn't show any cause for a problem:
Sep 26 05:13:00 home ppp-linkdown[68373]: Removing stale PPPoE gateway fe80::6664:9bff:fe61:3aed%pppoe1 on inet6
Sep 26 05:13:00 home opnsense[4718]: /usr/local/etc/rc.configure_interface: ROUTING: entering configure using 'opt1'
Sep 26 05:13:00 home opnsense[4718]: /usr/local/etc/rc.configure_interface: ROUTING: IPv6 default gateway set to opt1
Sep 26 05:13:00 home opnsense[4718]: /usr/local/etc/rc.configure_interface: ROUTING: skipping IPv6 default route
Sep 26 05:13:00 home opnsense[4718]: plugins_configure ipsec (1,opt1)
Sep 26 05:13:00 home opnsense[4718]: plugins_configure ipsec (execute task : ipsec_configure_do(1,opt1))
Sep 26 05:13:00 home opnsense[4718]: plugins_configure dhcp (1)
Sep 26 05:13:00 home opnsense[4718]: plugins_configure dhcp (execute task : dhcpd_dhcp_configure(1))
Sep 26 05:13:00 home opnsense[4718]: plugins_configure dns (1)
Sep 26 05:13:00 home opnsense[4718]: plugins_configure dns (execute task : dnsmasq_configure_do(1))
Sep 26 05:13:00 home opnsense[4718]: plugins_configure dns (execute task : unbound_configure_do(1))
Sep 26 05:13:03 home kernel: ng0: changing name to 'pppoe1'
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: IPv4 renewal is starting on 'pppoe1'
Sep 26 05:13:04 home kernel: nd6_dad_timer: called with non-tentative address fe80:7::201:2eff:fe95:fe56(pppoe1)
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: On (IP address: 217.251.199.XX) (interface: WAN[opt1]) (real interface: pppoe1).
Sep 26 05:13:04 home opnsense[22178]: /usr/local/etc/rc.newwanipv6: IPv6 renewal is starting on 'pppoe1'
Sep 26 05:13:04 home opnsense[11157]: plugins_configure hosts ()
Sep 26 05:13:04 home opnsense[11157]: plugins_configure hosts (execute task : dnsmasq_hosts_generate())
Sep 26 05:13:04 home opnsense[22178]: /usr/local/etc/rc.newwanipv6: On (IP address: fe80::201:2eff:fe95:fe56) (interface: WAN[opt1]) (real interface: pppoe1).
Sep 26 05:13:04 home opnsense[22178]: plugins_configure dhcp (,inet6)
Sep 26 05:13:04 home opnsense[22178]: plugins_configure dhcp (execute task : dhcpd_dhcp_configure(,inet6))
Sep 26 05:13:04 home opnsense[11157]: plugins_configure hosts (execute task : unbound_hosts_generate())
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: Accept router advertisements on interface pppoe1
Sep 26 05:13:04 home dhcp6c[9369]: RTSOLD script - Sending SIGHUP to dhcp6c
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: entering configure using 'opt1'
Sep 26 05:13:04 home opnsense[22178]: plugins_configure hosts ()
Sep 26 05:13:04 home opnsense[22178]: plugins_configure hosts (execute task : dnsmasq_hosts_generate())
Sep 26 05:13:04 home opnsense[22178]: plugins_configure hosts (execute task : unbound_hosts_generate())
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: IPv4 default gateway set to opt1
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: setting IPv4 default route to 62.155.243.64
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: keeping current default gateway '62.155.243.64'
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: IPv6 default gateway set to opt1
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: setting IPv6 default route to fe80::6664:9bff:fe61:3aed
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: ROUTING: keeping current default gateway 'fe80::6664:9bff:fe61:3aed%pppoe1'
Sep 26 05:13:04 home opnsense[11157]: plugins_configure monitor ()
Sep 26 05:13:04 home opnsense[11157]: plugins_configure monitor (execute task : dpinger_configure_do())
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: The WAN_DHCP6 monitor address is empty, skipping.
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: The WAN_PPPOE monitor address is empty, skipping.
Sep 26 05:13:04 home opnsense[11157]: plugins_configure vpn (,opt1)
Sep 26 05:13:04 home kernel: pflog0: promiscuous mode disabled
Sep 26 05:13:04 home kernel: pflog0: promiscuous mode enabled
Sep 26 05:13:04 home opnsense[11157]: plugins_configure vpn (execute task : ipsec_configure_do(,opt1))
Sep 26 05:13:04 home opnsense[11157]: plugins_configure vpn (execute task : openvpn_configure_do(,opt1))
Sep 26 05:13:04 home opnsense[11157]: /usr/local/etc/rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Sep 26 05:13:04 home kernel: ovpns1: link state changed to DOWN
Sep 26 05:13:05 home kernel: pflog0: promiscuous mode disabled
Sep 26 05:13:05 home kernel: pflog0: promiscuous mode enabled
Sep 26 05:13:05 home kernel: ovpns1: link state changed to UP
Sep 26 05:13:05 home opnsense[11157]: /usr/local/etc/rc.newwanip: OpenVPN server 1 instance started on PID 26332.
Sep 26 05:13:05 home opnsense[82934]: /usr/local/etc/rc.newwanip: IPv4 renewal is starting on 'ovpns1'
Sep 26 05:13:05 home opnsense[82934]: /usr/local/etc/rc.newwanip: Interface '' is disabled or empty, nothing to do.
Sep 26 05:13:05 home kernel: pflog0: promiscuous mode disabled
Sep 26 05:13:05 home opnsense[11157]: plugins_configure newwanip (,opt1)
Sep 26 05:13:05 home kernel: pflog0: promiscuous mode enabled
Sep 26 05:13:05 home opnsense[11157]: plugins_configure newwanip (execute task : dyndns_configure_do(,opt1))
Sep 26 05:13:07 home dhcp6c[43546]: dhcp6c RELEASE on pppoe1 - running newipv6
Sep 26 05:13:07 home opnsense[59755]: /usr/local/etc/rc.newwanipv6: IPv6 renewal is starting on 'pppoe1'
Sep 26 05:13:07 home opnsense[59755]: /usr/local/etc/rc.newwanipv6: On (IP address: fe80::201:2eff:fe95:fe56) (interface: WAN[opt1]) (real interface: pppoe1).
Sep 26 05:13:07 home opnsense[59755]: plugins_configure dhcp (,inet6)
Sep 26 05:13:07 home opnsense[59755]: plugins_configure dhcp (execute task : dhcpd_dhcp_configure(,inet6))
Sep 26 05:13:07 home opnsense[59755]: /usr/local/etc/rc.newwanipv6: Warning! dhcpd_radvd_configure(auto) found no suitable IPv6 address on re0
Sep 26 05:13:08 home opnsense[59755]: plugins_configure hosts ()
Sep 26 05:13:08 home opnsense[59755]: plugins_configure hosts (execute task : dnsmasq_hosts_generate())
Sep 26 05:13:08 home opnsense[59755]: plugins_configure hosts (execute task : unbound_hosts_generate())
Sep 26 05:13:10 home opnsense[30665]: /usr/local/etc/rc.dyndns: Dynamic DNS: updating cache file /var/cache/dyndns_opt1_XXX.duckdns.org_0.cache: 217.251.199.XX
Sep 26 05:13:10 home opnsense[30665]: /usr/local/etc/rc.dyndns: Dynamic DNS: (Success) IP Address Updated Successfully!
Sep 26 05:13:11 home opnsense[11157]: /usr/local/etc/rc.newwanip: Dynamic DNS: updating cache file /var/cache/dyndns_opt1_XXXX.duckdns.org_0.cache: 217.251.199.XX
Sep 26 05:13:11 home opnsense[11157]: /usr/local/etc/rc.newwanip: Dynamic DNS: (Success) IP Address Updated Successfully!
Sep 26 05:13:12 home opnsense[11157]: plugins_configure newwanip (execute task : ntpd_configure_defer())
Sep 26 05:13:12 home opnsense[11157]: plugins_configure newwanip (execute task : opendns_configure_do())
Sep 26 05:13:12 home opnsense[11157]: plugins_configure newwanip (execute task : openssh_configure_do(,opt1))
Sep 26 05:13:12 home opnsense[11157]: plugins_configure newwanip (execute task : unbound_configure_do(,opt1))
Sep 26 05:13:12 home opnsense[11157]: plugins_configure newwanip (execute task : vxlan_configure_interface())
Sep 26 05:13:12 home opnsense[11157]: plugins_configure newwanip (execute task : webgui_configure_do(,opt1))

Hi there

This isn't exactly an answer to your situation, but unless you want static assignment or knowledge of how many benign nodes in your network, it will likely make the life easier by going SLAAC ("unmanaged" in your LAN interface setting) or stateless DHCP6, especially when your LAN prefix is forced to change every 24 hours.

My household network is set up similarly, only that I only use DHCP6 to supplement DNS which nodes can also get from Router Advertisement. So far so good until radvd stops responding

radvd is right now a bigger issue in that it mysteriously stops responding to solicitation. There is another thread on this in GitHub

Cheers
Ivan

Heya,

thanks for your feedback. Sadly I wasn't able to get it to working by choosing "unmanaged" for the routing advertisements. Also I tried to disable the pppoe interface via cli (ifconfig pppoe1 down & up) but the result is the same. It seems that OPNsense do some additional steps if I hit the "disconnect" & "connect" button via the WebUI.

Currently I'm thinking about to switch to a private IPv6 subnet with NAT.