pfSense Gold Subscription

Author Topic: IPv6 DHCP-PD -- radvd dies after interface reset - dhcpv6 does not reaquire addr  (Read 52438 times)

0 Members and 1 Guest are viewing this topic.

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile
PROBLEM:  radvd service is stopped after WAN interface bounce.  DHCPv6 can no longer acquire IPv6 addressing .... WAN IP or PD for LAN.

This problem is reproducible.

Note: In the GUI, the radvd service is not showing as 'stopped', it is not there at all.

---

2.1-BETA1 (amd64)
built on Sun Mar 3 08:47:18 EDT 2013
FreeBSD 8.3-RELEASE-p6

---

17:41:04 kernel: re1: link state changed to DOWN

17:41:06 php: : DEVD Ethernet detached event for wan

17:41:14 apinger: ALARM: WAN_DHCP6(fe80::201:5cff:fe24:9301)  *** down ***

17:41:24 php: : The command '/sbin/route change -inet default dynamic6' returned exit code '68', the output was 'route: bad address: dynamic6'

17:41:24 dhcp6c[94030]: client6_init: failed initialize control message authentication

17:41:24 dhcp6c[94030]: client6_init: skip opening control port

17:41:36 php: : The command '/usr/local/sbin/dhcpd -6 -user dhcpd -group _dhcp -chroot /var/dhcpd -cf /etc/dhcpdv6.conf -pf /var/run/dhcpdv6.pid re0' returned exit code '1'

17:41:55 php: : The command '/sbin/route change -inet default dynamic6' returned exit code '68', the output was 'route: bad address: dynamic6'

17:41:56 dhcp6c[49425]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory

17:43:49 php: : Could not find IPv6 gateway for interface(wan).

17:43:58 php: : Shutting down Router Advertisment daemon cleanly

17:44:13 dhcp6c[16033]: client6_recvadvert: XID mismatch

17:44:17 dhcp6c[6748]: client6_init: skip opening control port

17:44:17 dhcp6c[16033]: client6_recvadvert: XID mismatch

-----

After this, the WAN interface is back up, IPv4 only.  IPv6 never recovers.
« Last Edit: March 13, 2013, 05:01:00 pm by priller »

Offline ermal

  • Hero Member
  • *****
  • Posts: 3832
  • Karma: +82/-5
    • View Profile
Re: IPv6 DHCP-PD -- radvd dies after interface reset
« Reply #1 on: March 13, 2013, 08:23:42 am »
You mean it does never try to reconnect with dhcp6?

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile
Re: IPv6 DHCP-PD -- radvd dies after interface reset
« Reply #2 on: March 13, 2013, 04:06:23 pm »
You mean it does never try to reconnect with dhcp6?

It tries, but fails.  It will not reacquire IPv6 addressing after the WAN interface drops and comes back up.  Neither the WAN IPV6 global address or the PD for the LAN.

The "client6_recvadvert: XID mismatch" error just keeps repeating every couple of seconds. 

radvd also stops and "disappears" as noted in this bug:  http://redmine.pfsense.org/issues/2878

I can reproduce this problem on demand, just by restarting the cable modem.

----

Log sequence as follows:

17:41:24 dhcp6c[94030]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
 
17:41:24 dhcp6c[94030]: client6_init: failed initialize control message authentication

17:41:24 dhcp6c[94030]: client6_init: skip opening control port

17:46:34 dhcp6c[16033]: client6_recvadvert: XID mismatch   <<<-- This keeps repeating.



 
« Last Edit: March 13, 2013, 04:10:44 pm by priller »

Offline reslip

  • Newbie
  • *
  • Posts: 14
  • Karma: +0/-0
    • View Profile
I originally submitted the bug 2878, but I may have having a slightly different problem than the one you've described. My WAN ipv6 global address seems to be sticking around, but as you said RADVD disappears. I tried ping through the web interface and ping6 through ssh and they are still working from the firewall on the wan interface.

Checking /var/etc/radvd.conf just has #Automatically generated, do not edit.

I have on track WAN interface for my internal interface with ipv6 prefix id of 0.

I should also note that in the dashboard, WAN_DHCP6 in the gateways section shows an fe80 loopback address, while WAN (DHCP) in the interfaces section show a 2001: external address
« Last Edit: March 15, 2013, 08:05:09 pm by reslip »

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile
I originally submitted the bug 2878, but I may have having a slightly different problem than the one you've described. My WAN ipv6 global address seems to be sticking around, but as you said RADVD disappears. I tried ping through the web interface and ping6 through ssh and they are still working from the firewall on the wan interface.

I had that happen yesterday.  WAN DHCPv6 did a renew, the WAN IPv6 address was still there.  But, RADVD disappeared and there was no IPv6 address on the LAN.

In that instance, I was not receiving the "XID mismatch" errors.  RADVD just died after renewal.  So, I'd call it another sighting of your bug 2878.
« Last Edit: March 15, 2013, 09:25:31 pm by priller »

Offline reslip

  • Newbie
  • *
  • Posts: 14
  • Karma: +0/-0
    • View Profile
This is the same thing that happens to me. On a reboot the WAN (fxp1) IPV6 ip stays constant for about 30 minutes, then gets a change and doesn't seem to refresh the local interface. This was in my system log.

Mar 15 23:31:12   php: : rc.newwanipv6: Informational is starting fxp1.
Mar 15 23:31:17   php: : rc.newwanipv6: on (IP address: 2001:558:xxxxxxxx) (interface: wan) (real interface: fxp1).
Mar 15 23:31:18   php: : The command '/usr/local/sbin/dhcpd -6 -user dhcpd -group _dhcp -chroot /var/dhcpd -cf /etc/dhcpdv6.conf -pf /var/run/dhcpdv6.pid sk0' returned exit code '1', the output was 'Internet Systems Consortium DHCP Server 4.2.4-P2 Copyright 2004-2012 Internet Systems Consortium. All rights reserved. For info, please visit https://www.isc.org/software/dhcp/ Wrote 0 leases to leases file. No subnet6 declaration for sk0 (fe80:2::xxxxxxx). ** Ignoring requests on sk0. If this is not what you want, please write a subnet6 declaration in your dhcpd.conf file for the network segment to which interface sk0 is attached. ** Not configured to listen on any interfaces! If you did not get this software from ftp.isc.org, please get the latest from ftp.isc.org and install that before requesting help. If you did get this software from ftp.isc.org and have not yet read the README, please read it before requesting help. If you intend to request help from the dhcp-server@isc.org maili

FYI, the /etc/dhcpdv6.conf file is empty.

Not sure if this means I should be adding something in dhcpd.conf. I can't access the dhcp6 configuration for a local lan (sk0) because I am using track interface for my ipv6 configuration.

My guess would be a change to /etc/rc.newwanipv6 10 days ago.
« Last Edit: March 15, 2013, 10:54:41 pm by reslip »

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile

I had that happen yesterday.  WAN DHCPv6 did a renew, the WAN IPv6 address was still there.  But, RADVD disappeared and there was no IPv6 address on the LAN.

OK, this problem is pretty serious and very real.

Right on cue, 48 hours later, the WAN dhcpv6 did a renew and BAM!   IPv6 addressing assigned to the LAN (DHCP-PD) is gone and radvd has disappeared.  

Is there anything I can provide to help resolve this issue?

** Edit **

Just saw something.  Both times this has happened, there was this syslog message just before everything went to crap.

"pfSense package system has detected an ip change 2001:558:6020:xxxx:35ac:547f:afad:d3f ->  2001:558:6020:xxxx:4cff:12d7:4aa5:fc41 ... Restarting packages."

When in reality, there was NO change.  Before the 'event', the address was  2001:558:6020:xxxx:4cff:12d7:4aa5:fc41 and it still is.  

So, the question is ... What is triggering this?  Why did pfsense erroneously think it had changed? Is the WAN address stored in a file somewhere and is compared when dhcpv6 renews?  I'm thinking that file is not being updated and every time there is a renewal, it thinks it has changed.  

Thoughts?




« Last Edit: March 16, 2013, 08:53:11 pm by priller »

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile

Just saw something.  Both times this has happened, there was this syslog message just before everything went to crap.

"pfSense package system has detected an ip change 2001:558:6020:xxxx:35ac:547f:afad:d3f ->  2001:558:6020:xxxx:4cff:12d7:4aa5:fc41 ... Restarting packages."

When in reality, there was NO change.  Before the 'event', the address was  2001:558:6020:xxxx:4cff:12d7:4aa5:fc41 and it still is.  

So, the question is ... What is triggering this?  Why did pfsense erroneously think it had changed? Is the WAN address stored in a file somewhere and is compared when dhcpv6 renews?  I'm thinking that file is not being updated and every time there is a renewal, it thinks it has changed.  


I've noticed something that doesn't look right that may explain the above.  


The current WAN address from ifconfig:

inet6 2001:558:6020:14a:3117:6e4b:xxxx:b6bf prefixlen 128


The contents of /var/db/wan_ipv6:

2001:558:6020:14a:4cff:12d7:4aa5:fc41       <<<---- OLD ... the previous address

The contents of /var/db/wan_cacheipv6:

2001:558:6020:14a:4cff:12d7:4aa5:fc41        <<<---- OLD ... the previous address


So, the next time it renews (and gets the same address renewed), one of those files will be checked and pfsense will erroneously think the address changed.  But, that is stale information.  

Can somebody confirm that the expectation is that the /var/db file(s) should be the current address and not the last, no longer valid address?

Is my logic wrong?

Thanks








« Last Edit: March 17, 2013, 07:57:17 pm by priller »

Offline ermal

  • Hero Member
  • *****
  • Posts: 3832
  • Karma: +82/-5
    • View Profile
Do you have on the logs any line similar to:
rc.newwanipv6: on (IP address: {$curwanipv6}) (interface: {$interface}) (real interface: {$interface_real}).

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile
Do you have on the logs any line similar to:
rc.newwanipv6: on (IP address: {$curwanipv6}) (interface: {$interface}) (real interface: {$interface_real}).

There is:

Mar 16 18:57:19 php: : rc.newwanipv6: Informational is starting re1.
Mar 16 18:57:24 php: : rc.newwanipv6: on (IP address: 2001:558:6020:14a:4cff:12d7:4aa5:fc41) (interface: wan) (real interface: re1).

This ran during a scheduled dhcpv6 renewal.  Since the time stamp on that one, the WAN IP had changed after reboot and there is no syslog to reflect that it ran. And the /var/db files were not updated.

For now, I've manually edited those 2 /var/db files to reflect the current address.  Will see if it survives the next renewal without issue.

---

A secondary issue is that almost every time I reboot, the WAN IPv6 address and the PD for LAN change.  It's like the DUID is changing with each restart.  This should be constant.

I've found some older discussions about the DUID changing here:
http://www.dslreports.com/forum/r27854661-IPv6-Seeing-two-different-LAN-side-ranges
http://forum.pfsense.org/index.php/topic,55161.msg306484.html#msg306484


« Last Edit: March 18, 2013, 06:50:33 am by priller »

Offline reslip

  • Newbie
  • *
  • Posts: 14
  • Karma: +0/-0
    • View Profile
Do you have on the logs any line similar to:
rc.newwanipv6: on (IP address: {$curwanipv6}) (interface: {$interface}) (real interface: {$interface_real}).

Previously I had
 rc.newwanipv6: on (IP address: 2001:558:xxxxxxxx) (interface: wan) (real interface: fxp1).

Not sure if you need any more info.

Looks like you have made some changes to dual stack (rc.linkup) and radvd, but the latest build I see is from yesterday March 17th. I will wait for a new build later today, then do the update to let you know how it goes. Ironically, I have not lost my ipv6 lan address in the past 12 hours. 

Offline ermal

  • Hero Member
  • *****
  • Posts: 3832
  • Karma: +82/-5
    • View Profile
Yeah made some changes which should improve the situation.
Test with newer snapshots.

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile
Yeah made some changes which should improve the situation.
Test with newer snapshots.

It gotten worse with the 20130318-1652 build.  I can get the WAN interface IPv6 address, but cannot get the PD for LAN.

RADVD doesn't even start at all.

After upgrade, getting this on the dashboard:
[ There were error(s) loading the rules: pfctl: DIOCADDALTQ: Device busy - The line in question reads
  • : ]


This message is constant:   dhcp6c[16530]: client6_recvadvert: XID mismatch


-------

Reverted back to:

2.1-BETA1 (amd64)
built on Sun Mar 17 12:19:16 EDT 2013
FreeBSD 8.3-RELEASE-p6

... and everything came back.


« Last Edit: March 18, 2013, 09:08:03 pm by priller »

Offline ermal

  • Hero Member
  • *****
  • Posts: 3832
  • Karma: +82/-5
    • View Profile
It would have been helpful having the system logs rather than just it does not work!

Quote
This message is constant:   dhcp6c[16530]: client6_recvadvert: XID mismatch
This might be not important since you might be seeing other clients reply/advertisments.
« Last Edit: March 19, 2013, 04:47:04 am by ermal »

Offline priller

  • Full Member
  • ***
  • Posts: 211
  • Karma: +5/-0
    • View Profile

Here's what I saw after applying the 20130318-1652 build.

+ IPv4 was working fine.
+ IPv6 - The WAN obtained an address.  There was never PD assigned to the LAN.
+ There are dozens of "client6_recvadvert: XID mismatch" messages.
+ I never saw RADVD start.  Never saw it in a 'stopped' state, it just never appeared. There is not a single syslog message about it.  Possibly it doesn't get called until there is IPV6 address on the LAN?

+ The dashboard kept flashing the following:
There were error(s) loading the rules: pfctl: DIOCADDALTQ: Device busy - The line in question reads 0

+ I attempted to revert back to previous configuration from GUI.  Firmware --> Restore Full Backup.
This failed twice (as in didn't do anything, no syslog message)
+ I then downloaded and installed the  Sun Mar 17 12:19:16 build.   When it came back up, system was normal.

Here's syslogs that appear to be anywhere relevant to the issue.

No indication that  rc.newwanipv6 ever ran.


21:15:40 syslogd: kernel boot file is /boot/kernel/kernel
21:15:41 php: : Restarting/Starting all packages.

21:15:54 dhcp6c[15951]: client6_recvadvert: XID mismatch

21:15:57 php: : Checking for and disabling any rules dependent upon disabled preprocessors for WAN...
21:17:46 dhcp6c[15951]: client6_recvadvert: XID mismatch

21:35:41 php: : rc.newwanip: Informational is starting ovpns1.
21:35:42 apinger: Starting Alarm Pinger, apinger(23340)
21:35:42 apinger: bind socket: Can't assign requested address
21:35:45 dhcp6c[16042]: client6_recvadvert: XID mismatch

21:35:48 php: : The command '/sbin/route change -inet6 default fe80::201:5cff:fe24:9301' returned exit code '1', the output was 'route: writing to routing socket: Network is unreachable route: writing to routing socket: Network is unreachable change net default: gateway fe80::201:5cff:fe24:9301: Network is unreachable'

21:35:58 php: : Checking for and disabling any rules dependent upon disabled preprocessors for WAN...

21:36:27 kernel: re1: promiscuous mode enabled

21:36:37 dhcp6c[16042]: client6_recvadvert: XID mismatch