Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    IPv6 DHCP-PD – radvd dies after interface reset - dhcpv6 does not reaquire addr

    Scheduled Pinned Locked Moved 2.1 Snapshot Feedback and Problems - RETIRED
    166 Posts 21 Posters 75.8k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • R
      razzfazz
      last edited by

      My box (running the Jul 15 snapshot) also just lost all IPv6 connectivity after 9 days of uptime (Comcast Residential).

      Here is the relevant system log output:

      
Jul 24 17:20:21 router check_reload_status: updating dyndns WAN_DHCP6,WAN_DHCP
Jul 24 17:20:21 router check_reload_status: Restarting ipsec tunnels
Jul 24 17:20:21 router check_reload_status: Restarting OpenVPN tunnels/interfaces
Jul 24 17:20:21 router check_reload_status: Reloading filter
Jul 24 17:20:33 router check_reload_status: Linkup starting re0
Jul 24 10:20:33 router kernel: re0: link state changed to DOWN
Jul 24 17:20:35 router check_reload_status: Linkup starting re0
Jul 24 10:20:35 router kernel: re0: link state changed to UP
Jul 24 10:20:35 router php: rc.linkup: DEVD Ethernet detached event for wan
Jul 24 17:20:36 router check_reload_status: Linkup starting re0
Jul 24 10:20:36 router kernel: re0: link state changed to DOWN
Jul 24 10:20:37 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:20:37 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:20:37 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:20:37 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:20:37 router php: rc.linkup: DEVD Ethernet attached event for wan
Jul 24 10:20:37 router php: rc.linkup: HOTPLUG: Configuring interface wan
Jul 24 10:20:38 router php: rc.linkup: DEVD Ethernet detached event for wan
Jul 24 10:20:39 router php: rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jul 24 10:20:39 router php: rc.linkup: Clearing states to old gateway 76.102.40.1.
Jul 24 10:20:44 router php: rc.newipsecdns: Could not determine VPN endpoint for ''
Jul 24 17:20:49 router check_reload_status: Linkup starting re0
Jul 24 10:20:49 router kernel: re0: link state changed to UP
Jul 24 10:20:49 router php: rc.newipsecdns: Could not determine VPN endpoint for ''
Jul 24 10:20:51 router php: rc.linkup: DEVD Ethernet attached event for wan
Jul 24 10:20:51 router php: rc.linkup: HOTPLUG: Configuring interface wan
Jul 24 10:20:52 router php: rc.linkup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf re0 > /tmp/re0_output 2> /tmp/re0_error_output' returned exit code '1', the output was '' 
Jul 24 10:20:52 router php: rc.linkup: Accept router advertisements on interface re0 
Jul 24 10:20:53 router kernel: re0: link state changed to DOWN
Jul 24 17:20:53 router check_reload_status: Linkup starting re0
Jul 24 10:20:53 router dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process.
Jul 24 10:20:55 router php: rc.newipsecdns: Could not determine VPN endpoint for ''
Jul 24 10:20:55 router php: rc.linkup: DEVD Ethernet detached event for wan
Jul 24 10:20:55 router php: rc.linkup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf re0 > /tmp/re0_output 2> /tmp/re0_error_output' returned exit code '15', the output was '' 
Jul 24 10:20:55 router php: rc.linkup: Accept router advertisements on interface re0 
Jul 24 17:20:55 router check_reload_status: Linkup starting re0
Jul 24 10:20:55 router kernel: re0: link state changed to UP
Jul 24 10:20:56 router php: rc.linkup: Shutting down Router Advertisment daemon cleanly
Jul 24 17:20:56 router check_reload_status: updating dyndns wan
Jul 24 10:20:58 router php: rc.linkup: DEVD Ethernet attached event for wan
Jul 24 10:20:58 router php: rc.linkup: HOTPLUG: Configuring interface wan
Jul 24 10:20:59 router php: rc.dyndns.update: DynDNS ([hostname removed]) There was an error trying to determine the public IP for interface - wan(re0). Probably interface is not a WAN interface.
Jul 24 10:21:00 router php: rc.newipsecdns: Could not determine VPN endpoint for ''
Jul 24 10:21:00 router php: rc.dyndns.update: DynDNS ([hostname removed]) There was an error trying to determine the public IP for interface - wan(re0). Probably interface is not a WAN interface.
Jul 24 17:21:03 router check_reload_status: rc.newwanip starting re0
Jul 24 10:21:03 router php: rc.linkup: Accept router advertisements on interface re0 
Jul 24 10:21:03 router php: rc.linkup: ROUTING: setting default route to 192.168.100.1
Jul 24 10:21:04 router dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such process.
Jul 24 10:21:05 router php: rc.newipsecdns: Could not determine VPN endpoint for ''
Jul 24 10:21:06 router php: rc.newwanip: rc.newwanip: Informational is starting re0.
Jul 24 10:21:06 router php: rc.newwanip: rc.newwanip: on (IP address: 192.168.100.10) (interface: wan) (real interface: re0).
Jul 24 10:21:06 router php: rc.newwanip: ROUTING: setting default route to 192.168.100.1
Jul 24 17:21:07 router check_reload_status: updating dyndns wan
Jul 24 10:21:07 router dhcp6c[25808]: client6_timo: no responses were received
Jul 24 10:21:10 router php: rc.newipsecdns: Could not determine VPN endpoint for ''
Jul 24 10:21:11 router dhcp6c[25808]: client6_timo: no responses were received
Jul 24 10:21:11 router dhcp6c[25808]: check_exit: exiting
Jul 24 10:21:16 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:16 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:16 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:17 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:17 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:17 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:18 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:18 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:18 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:19 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:19 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:19 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:20 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:20 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:20 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:21 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:21 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:21 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:23 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:23 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:23 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:27 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:27 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:27 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:35 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:35 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:35 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:51 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:51 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 10:21:51 router kernel: arpresolve: can't allocate llinfo for 76.102.40.1
Jul 24 17:22:07 router check_reload_status: rc.newwanip starting re0
Jul 24 10:22:10 router php: rc.newwanip: rc.newwanip: Informational is starting re0.
Jul 24 10:22:10 router php: rc.newwanip: rc.newwanip: on (IP address: 76.102.40.77) (interface: wan) (real interface: re0).
Jul 24 10:22:10 router php: rc.newwanip: ROUTING: setting default route to 76.102.40.1
Jul 24 10:22:14 router php: rc.newwanip: Dyndns debug information ([hostname removed]): Could not resolve checkip.dyndns.org to ip using interface ip 192.168.100.10.
Jul 24 10:22:14 router php: rc.newwanip: DynDNS ([hostname removed]) There was an error trying to determine the public IP for interface - wan(re0). Probably interface is not a WAN interface.
Jul 24 10:22:14 router php: rc.dyndns.update: phpDynDNS ([hostname removed]): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Jul 24 10:22:14 router php: rc.newwanip: phpDynDNS ([hostname removed]): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Jul 24 10:22:15 router php: rc.newwanip: DynDNS ([hostname removed]) There was an error trying to determine the public IP for interface - wan(re0). Probably interface is not a WAN interface.
Jul 24 10:22:15 router php: rc.newwanip: DynDNS ([hostname removed]) There was an error trying to determine the public IP for interface - wan(re0). Probably interface is not a WAN interface.
Jul 24 10:22:15 router php: rc.dyndns.update: DynDNS ([hostname removed]) There was an error trying to determine the public IP for interface - wan(re0). Probably interface is not a WAN interface.
Jul 24 10:22:21 router php: rc.newwanip: Forcefully reloading IPsec racoon daemon
Jul 24 10:22:21 router php: rc.newwanip: Forcefully reloading IPsec racoon daemon
Jul 24 10:22:21 router php: rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Jul 24 10:22:21 router php: rc.newwanip: Creating rrd update script
Jul 24 10:22:21 router php: rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Jul 24 10:22:21 router php: rc.newwanip: Creating rrd update script
Jul 24 10:22:23 router php: rc.newwanip: pfSense package system has detected an ip change 76.102.40.77 ->  192.168.100.10 ... Restarting packages.
Jul 24 17:22:23 router check_reload_status: Starting packages
Jul 24 10:22:23 router snmpd[4636]: disk_OS_get_disks: device 'da0' not in device list
Jul 24 10:22:23 router snmpd[5638]: bind: 0.0.0.0:161 Address already in use
Jul 24 10:22:23 router snmpd[5638]: NgMkSockNode: Address already in use
Jul 24 10:22:23 router php: rc.newwanip: pfSense package system has detected an ip change 192.168.100.10 ->  76.102.40.77 ... Restarting packages.
Jul 24 10:22:23 router snmpd[5638]: assignment to begemotNgControlNodeName.0 returns 5
Jul 24 17:22:23 router check_reload_status: Reloading filter
Jul 24 10:22:23 router snmpd[5638]:   in file /var/etc/snmpd.conf line 25
Jul 24 10:22:23 router snmpd[5638]: error in config file
Jul 24 10:22:26 router php: rc.start_packages: Restarting/Starting all packages.
Jul 24 10:22:27 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:28 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:29 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:29 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:29 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:29 router php: rc.filter_configure_sync: Could not find IPv6 gateway for interface(wan).
Jul 24 10:22:31 router php: rc.start_packages: XML error: SYSTEM or PUBLIC, the URI is missing at line 1 in /usr/local/pkg/iftop.xml
Jul 24 10:22:31 router php: rc.start_packages: XML error: SYSTEM or PUBLIC, the URI is missing at line 1 in /usr/local/pkg/iftop.xml
Jul 24 10:22:33 router php: rc.start_packages: XML error: SYSTEM or PUBLIC, the URI is missing at line 1 in /usr/local/pkg/ipmitool.xml
Jul 24 10:22:33 router php: rc.start_packages: XML error: SYSTEM or PUBLIC, the URI is missing at line 1 in /usr/local/pkg/ipmitool.xml
Jul 24 10:22:35 router upsmon[55314]: Signal 15: exiting

      At the beginning, the cable modem appears to lose upstream connectivity. This causes the WAN interface (re0) on the pfSense box to bounce, which in turn prompts pfSense to try to reconfigure it. The problem is that when the interface comes back up, the cable modem hasn't re-established its uplink. As a result, it replies to the DHCPv4 requests from the pfSense box with an ACK for a private IP from the 192.168.100.0/24 range (at 10:21:06); however, it does not respond to DHCPv6 requests at all during this time, which causes dhcp6c on the pfSense box to exit (at 10:21:11). After the cable modem's upstream recovers, pfSense correctly picks up the new public IPv4 address (at 10:22:10); however, dhcp6c is not restarted, and so pfSense never attempt to re-acquire an IPv6 address.

      So it looks like the problem is that pfSense does not deal well with IPv6 connectivity going away and then coming back.

      (As a side note, what's up with some of the time stamps being time zone adjusted but others not?)

      1 Reply Last reply Reply Quote 0
      • R
        razzfazz
        last edited by

        Looks like there are relevant entries in dhcpd.log as well:

        
Jul 22 16:54:58 router dhclient: RENEW
Jul 22 16:54:58 router dhclient: Creating resolv.conf
Jul 24 10:20:35 router dhclient[11039]: connection closed
Jul 24 10:20:35 router dhclient[11039]: exiting.
Jul 24 10:20:49 router dhclient: PREINIT
Jul 24 10:20:49 router dhclient: Starting delete_old_states()
Jul 24 10:20:49 router dhclient: Comparing IPs: Old:  New: 
Jul 24 10:20:49 router dhclient[81638]: DHCPREQUEST on re0 to 255.255.255.255 port 67
Jul 24 10:20:49 router dhclient[81638]: DHCPDISCOVER on re0 to 255.255.255.255 port 67 interval 2
Jul 24 10:20:51 router dhclient[81638]: DHCPDISCOVER on re0 to 255.255.255.255 port 67 interval 2
Jul 24 10:20:52 router dhclient[86320]: dhclient already running, pid: 81638.
Jul 24 10:20:52 router dhclient[86320]: exiting.
Jul 24 10:20:53 router dhclient[81638]: DHCPDISCOVER on re0 to 255.255.255.255 port 67 interval 4
Jul 24 10:20:55 router dhclient[83516]: connection closed
Jul 24 10:20:55 router dhclient[83516]: exiting.
Jul 24 10:20:59 router dhclient: PREINIT
Jul 24 10:20:59 router dhclient: Starting delete_old_states()
Jul 24 10:20:59 router dhclient: Comparing IPs: Old:  New: 
Jul 24 10:20:59 router dhclient[9924]: DHCPREQUEST on re0 to 255.255.255.255 port 67
Jul 24 10:20:59 router dhclient[9924]: DHCPNAK from 192.168.100.1
Jul 24 10:20:59 router dhclient[9924]: DHCPDISCOVER on re0 to 255.255.255.255 port 67 interval 2
Jul 24 10:21:01 router dhclient[9924]: DHCPDISCOVER on re0 to 255.255.255.255 port 67 interval 2
Jul 24 10:21:01 router dhclient[9924]: DHCPOFFER from 192.168.100.1
Jul 24 10:21:01 router dhclient: ARPSEND
Jul 24 10:21:01 router dhclient[9924]: DHCPOFFER from 192.168.100.1
Jul 24 10:21:01 router dhclient[9924]: DHCPOFFER already seen.
Jul 24 10:21:03 router dhclient: ARPCHECK
Jul 24 10:21:03 router dhclient[9924]: DHCPREQUEST on re0 to 255.255.255.255 port 67
Jul 24 10:21:03 router dhclient[9924]: DHCPACK from 192.168.100.1
Jul 24 10:21:03 router dhclient: BOUND
Jul 24 10:21:03 router dhclient: Starting delete_old_states()
Jul 24 10:21:03 router dhclient: Comparing IPs: Old:  New: 192.168.100.10
Jul 24 10:21:03 router dhclient: Starting add_new_address()
Jul 24 10:21:03 router dhclient: ifconfig re0 inet 192.168.100.10 netmask 255.255.255.0 broadcast 192.168.100.255 
Jul 24 10:21:03 router dhclient: New IP Address (re0): 192.168.100.10
Jul 24 10:21:03 router dhclient: New Subnet Mask (re0): 255.255.255.0
Jul 24 10:21:03 router dhclient: New Broadcast Address (re0): 192.168.100.255
Jul 24 10:21:03 router dhclient: New Routers (re0): 192.168.100.1
Jul 24 10:21:03 router dhclient: Adding new routes to interface: re0
Jul 24 10:21:03 router dhclient: /sbin/route add default 192.168.100.1
Jul 24 10:21:03 router dhclient: Creating resolv.conf
Jul 24 10:21:03 router dhclient[9924]: bound to 192.168.100.10 -- renewal in 30 seconds.
Jul 24 10:21:33 router dhclient[17330]: DHCPREQUEST on re0 to 192.168.100.1 port 67
Jul 24 10:21:34 router dhclient[17330]: DHCPREQUEST on re0 to 192.168.100.1 port 67
Jul 24 10:21:36 router dhclient[17330]: DHCPREQUEST on re0 to 192.168.100.1 port 67
Jul 24 10:21:41 router dhclient[17330]: DHCPREQUEST on re0 to 192.168.100.1 port 67
Jul 24 10:21:50 router dhclient[17330]: DHCPREQUEST on re0 to 192.168.100.1 port 67
Jul 24 10:22:04 router dhclient: EXPIRE
Jul 24 10:22:04 router dhclient: Starting delete_old_states()
Jul 24 10:22:04 router dhclient: Comparing IPs: Old:  New: 
Jul 24 10:22:04 router dhclient: Deleting old routes
Jul 24 10:22:05 router dhclient: PREINIT
Jul 24 10:22:05 router dhclient: Starting delete_old_states()
Jul 24 10:22:05 router dhclient[17330]: DHCPDISCOVER on re0 to 255.255.255.255 port 67 interval 2
Jul 24 10:22:05 router dhclient[17330]: DHCPOFFER from 96.156.92.1
Jul 24 10:22:05 router dhclient: ARPSEND
Jul 24 10:22:07 router dhclient: ARPCHECK
Jul 24 10:22:07 router dhclient[17330]: DHCPREQUEST on re0 to 255.255.255.255 port 67
Jul 24 10:22:07 router dhclient[17330]: DHCPACK from 96.156.92.1
Jul 24 10:22:07 router dhclient: BOUND
Jul 24 10:22:07 router dhclient: Starting delete_old_states()
Jul 24 10:22:07 router dhclient: Deleting old routes
Jul 24 10:22:07 router dhclient: Starting add_new_address()
Jul 24 10:22:07 router dhclient: ifconfig re0 inet 76.102.40.77 netmask 255.255.252.0 broadcast 255.255.255.255 
Jul 24 10:22:07 router dhclient: New IP Address (re0): 76.102.40.77
Jul 24 10:22:07 router dhclient: New Subnet Mask (re0): 255.255.252.0
Jul 24 10:22:07 router dhclient: New Broadcast Address (re0): 255.255.255.255
Jul 24 10:22:07 router dhclient: New Routers (re0): 76.102.40.1
Jul 24 10:22:07 router dhclient: Adding new routes to interface: re0
Jul 24 10:22:07 router dhclient: /sbin/route add default 76.102.40.1

        Why does dhclient log to dhcpd.log, not to system.log (like dhcp6c does)?

        1 Reply Last reply Reply Quote 0
        • P
          priller
          last edited by

          @jimp:

          It should have logged the blocked traffic, did you see anything in the firewall logs at the time?

          If we can locate the conflicting addresses we can filter them out during the bogon update routine if we have to.

          For reference, see this for the bad bogonsv6 address:  http://forum.pfsense.org/index.php/topic,64980.0.html

          Thanks, qubit!!!

          1 Reply Last reply Reply Quote 0
          • N
            netkeys
            last edited by

            Here's an update I'm running build from 2.1-RC0 (i386) built on Tue Jul 23 21:56:24 EDT 2013 FreeBSD 8.3-RELEASE-p8 and it's not been up for 10 Days 10 Hours 12 Minutes 47 Seconds without lose of IPv6.

            Update: 1 1/2 days latter with uptime of 11 Days 20 Hours 51 Minutes 55 Seconds and have lost all IPv6 connectivity.

            1 Reply Last reply Reply Quote 0
            • R
              razzfazz
              last edited by

              Just lost all v6 connectivity on my box again, after around 4 days of uptime. As before, this appears to happen when the interface bounces and v6 connectivity goes away temporarily; radvd exits and is never restarted.

              1 Reply Last reply Reply Quote 0
              • N
                netkeys
                last edited by

                Update 8/21/2013:

                I've now had a connection for 16 Days 07 Hours 52 Minutes 17 Seconds using build 2.1-RC1 (i386) built on Thu Aug 1 19:03:40 EDT 2013.

                This is the longest I've maintained a connection with no reboots or any other action.

                1 Reply Last reply Reply Quote 0
                • First post
                  Last post
                Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.