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

priller

I've seen the "client6_recvadvert: XID mismatch" problem for a long time now. The only way I have found to clear it is to:

Shutdown pfSense
Power cycle the cable modem
Start pfSense

razzfazz

@qubit:

Every 2 minutes or so, pfsense on the WAN sends a DHCPv6 Solicit to ff02::1:2, and Comcast immediately replies back with two Advertise packets. The first one has all the details pfsense is currently using: a /128 for the WAN, a /64 prefix for the LAN and two IPv6 DNS servers. The second packet contains a completely different /128 and /64 and is from another DHCP server judging from the mac addresses. So apparently two different Comcast DHCPv6 servers are replying back, and since both have the generated XID from the solicit, dhcp6c doesn't like this and throws an error. This same sequence goes on and on.

Whenever that happens, do you by any chance see two instances of dhcp6c running at the same time?

qubit

@razzfazz:

@qubit:

Every 2 minutes or so, pfsense on the WAN sends a DHCPv6 Solicit to ff02::1:2, and Comcast immediately replies back with two Advertise packets. The first one has all the details pfsense is currently using: a /128 for the WAN, a /64 prefix for the LAN and two IPv6 DNS servers. The second packet contains a completely different /128 and /64 and is from another DHCP server judging from the mac addresses. So apparently two different Comcast DHCPv6 servers are replying back, and since both have the generated XID from the solicit, dhcp6c doesn't like this and throws an error. This same sequence goes on and on.

Whenever that happens, do you by any chance see two instances of dhcp6c running at the same time?

Yes, two processes are currently running

ps -ax | grep dhcp6c
45122 ?? INs 0:00.00 /usr/local/sbin/dhcp6c -d -c /var/etc/dhcp6c_wan.conf -p /var/run/dhcp6c_em0.pid em0
55344 ?? INs 0:00.00 /usr/local/sbin/dhcp6c -d -c /var/etc/dhcp6c_wan.conf -p /var/run/dhcp6c_em0.pid em0
80995 1 S+ 0:00.00 grep dhcp6c

PID 55344 is throwing the XID mismatch error. I'm guessing both are trying to bind on the WAN at the same time. Or is one responsible for the LAN IPv6 addressing even though that's on em1?

Some odd things have been happening today upon powering on. Upon boot ipv6 doesn't automatically come up. radvd disappeared from the Status-> Services tab. After disabling DHCP6 and the track interface and enabling again, it seemed to grab a WAN and LAN ipv6 address again, but only pfsense could ping google over ipv6 via the WAN. Other machines on the network received an IPv6 address from pfsense but timed out when trying to ping6 google. System log for routing shows:

Jun 27 21:17:40 radvd[37290]: version 1.9.1 started
Jun 27 21:17:40 radvd[37290]: IPv6 forwarding setting is: 0, should be 1
Jun 27 21:17:40 radvd[37290]: IPv6 forwarding seems to be disabled, but continuing anyway.
Jun 27 21:17:41 radvd[37474]: attempting to reread config file
Jun 27 21:17:41 radvd[37474]: resuming normal operation
Jun 27 21:18:42 radvd[37474]: Exiting, sigterm or sigint received.
Jun 27 21:18:42 radvd[37474]: sending stop adverts
Jun 27 21:18:42 radvd[37474]: removing /var/run/radvd.pid

Not sure how forwarding got disabled. IPv6 is enabled in System -> Advanced -> Networking and there's a default allow all IPv6 traffic out of the LAN. After disabling and enabling the WAN interface once more, I had no IPv6 addressing, although in Status -> Interfaces it says I have a IPv6 gateway and IPv6 DNS servers filled out. dhcp6 still throws XID mismatches. Manually releasing and renewing the WAN doesn't seem to help. From a clean install it seems to just come up, but something in the config (/var/db/ perhaps) seems to be doing something that persists between reboots since yesterday.

Something that looks relevant from the system log:

Jun 27 20:26:27 php: : rc.newwanipv6: Informational is starting em0.
Jun 27 20:26:27 php: : rc.newwanipv6: Failed to update wan IPv6, restarting…
Jun 27 20:26:28 dhcp6c[21670]: client6_recvreply: status code: success
Jun 27 20:26:28 php: : rc.newwanipv6: Informational is starting em0.
Jun 27 20:26:28 php: : rc.newwanipv6: Failed to update wan IPv6, restarting…
Jun 27 20:26:28 dhcp6c[21670]: check_exit: exiting
Jun 27 20:26:29 php: : Restarting/Starting all packages.
Jun 27 20:26:30 kernel: pid 13243 (ntpd), uid 0: exited on signal 11 (core dumped)
Jun 27 20:26:28 php: : rc.newwanipv6: Failed to update wan IPv6, restarting…
Jun 27 20:26:28 dhcp6c[21670]: check_exit: exiting

razzfazz

@qubit:

@razzfazz:

Whenever that happens, do you by any chance see two instances of dhcp6c running at the same time?

Yes, two processes are currently running

ps -ax | grep dhcp6c
45122 ?? INs 0:00.00 /usr/local/sbin/dhcp6c -d -c /var/etc/dhcp6c_wan.conf -p /var/run/dhcp6c_em0.pid em0
55344 ?? INs 0:00.00 /usr/local/sbin/dhcp6c -d -c /var/etc/dhcp6c_wan.conf -p /var/run/dhcp6c_em0.pid em0
80995 1 S+ 0:00.00 grep dhcp6c

PID 55344 is throwing the XID mismatch error. I'm guessing both are trying to bind on the WAN at the same time. Or is one responsible for the LAN IPv6 addressing even though that's on em1?

I very much doubt this is intentional; given the fairly large difference in PIDs, this looks to me like something, somewhere is not checking to see if the DHCP6 client is already running before starting it (again).

reslip

I'm also still running into the same issue. I was running 2.1 beta 1 for a while and was getting ipv6 ok, but would lose it on a dhcp6 refresh. Now with the latest build, I am running into the same issue where it looks like radvd is never even started. It doesn't show up in the services screen. The logs for routing shows the following:

Jun 28 14:08:06 radvd[36933]: IPv6 forwarding setting is: 0, should be 1
Jun 28 14:08:06 radvd[36933]: IPv6 forwarding seems to be disabled, but continuing anyway.
Jun 28 14:08:08 radvd[38290]: attempting to reread config file
Jun 28 14:08:08 radvd[38290]: resuming normal operation

wallabybob

@reslip:

I am running into the same issue where it looks like radvd is never even started. It doesn't show up in the services screen.

The log extract you posted suggests it has started. Perhaps it has quietly died. The pfSense shell command```
ps ax | grep radvd

catfish99

radvd seems to be running - however IPv6 address isn't acquired. If I connect my computer to my cable modem directly, I get an IPv6 address from Comcast ..


[2.1-RC0][root@pfsense.pvt]/root(1): ps ax | grep radvd
  657  ??  S      0:00.02 /usr/local/sbin/radvd -p /var/run/radvd.pid -C /var/etc/radvd.conf -m syslog
72676   0  S+     0:00.00 grep radvd
[2.1-RC0][root@pfsense.pvt]/root(2): ifconfig
em0: flags=8943 <up,broadcast,running,promisc,simplex,multicast>metric 0 mtu 1500
	options=4209b <rxcsum,txcsum,vlan_mtu,vlan_hwtagging,vlan_hwcsum,wol_magic,vlan_hwtso>ether 00:00:24:ce:6a:24
	inet6 fe80::200:24ff:fece:6a24%em0 prefixlen 64 scopeid 0x1 
	inet XX.XX.XXX.XXX netmask 0xfffffe00 broadcast 255.255.255.255
	nd6 options=3 <performnud,accept_rtadv>media: Ethernet autoselect (1000baseT <full-duplex>)
	status: active

(Rest snipped..)</full-duplex></performnud,accept_rtadv></rxcsum,txcsum,vlan_mtu,vlan_hwtagging,vlan_hwcsum,wol_magic,vlan_hwtso></up,broadcast,running,promisc,simplex,multicast>

Updated to the latest firmware today. Here's the date/time stamp of the firmware I am using:


Version	2.1-RC0 (i386) 
built on Thu Jun 27 21:49:32 EDT 2013 
FreeBSD 8.3-RELEASE-p8

priller

:(

Well, my install just crashed completely and now it is impossible to get IPv6 back.


dhcp6c[29508]: client6_init: skip opening control port
dhcp6c[29508]: client6_init: failed initialize control message authentication
dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory

razzfazz

@priller:


dhcp6c[29508]: client6_init: skip opening control port
dhcp6c[29508]: client6_init: failed initialize control message authentication
dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory

As far as I understand, these are just warnings, and completely unrelated to your problem.

priller

@razzfazz:

@priller:


dhcp6c[29508]: client6_init: skip opening control port
dhcp6c[29508]: client6_init: failed initialize control message authentication
dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory

As far as I understand, these are just warnings, and completely unrelated to your problem.

May not be the root cause, but it should be noted that the only time they appear is when pfSense is not pulling IPv6 addressing. That is the only 'error' in the logs.

johnpoz

Like I said before, lets see how it works when 2.1 is released - its currently so unstable that its not viable for anyone wanting to actually use ipv6 even for testing.. Since you may or may not be even to pull a address, let alone maintain one for any length of time.

That being said, my HE tunnel has been rock solid since I went back to it ;) Even upgraded snaps a couple of times - and upon reboot there is is solid.. Now its got a bit more latency then native - but hey it works!! ;)

I am just going to wait til 2.1 is released, will then do a clean install and see if it works.

razzfazz

@priller:

May not be the root cause, but it should be noted that the only time they appear is when pfSense is not pulling IPv6 addressing. That is the only 'error' in the logs.

Hm, I guess I do wonder if these may somehow be related to a second instance of the DHCP6 client being started…

razzfazz

@johnpoz:

Like I said before, lets see how it works when 2.1 is released - its currently so unstable that its not viable for anyone wanting to actually use ipv6 even for testing..

I think that's a bit of an over-generalization. It's been working fine for me on Comcast Home for the past several snapshots now, so it certainly looks like the problem isn't universal.

jimp

I encourage people to not stop trying, too. If you wait for a release, and it works for everyone except you and nobody else can reproduce a problem, then it would never get fixed properly.

reslip

I've sense switched off ipv6 on the lan side as I was having too many issues with clients and radvd. It was as though the wan interface was never properly brought up so ipv6 was not routing properly. Now for ipv6 on the WAN I am showing some errors acquiring an address. From system.log…

Jun 29 03:34:42 fw dhcp6c[23649]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Jun 29 03:34:42 fw dhcp6c[23649]: client6_init: failed initialize control message authentication
Jun 29 03:34:42 fw dhcp6c[23649]: client6_init: skip opening control port
Jun 29 03:34:42 fw dhcp6c[23649]: cfparse: cfparse: fopen(/var/etc/dhcp6c_wan.conf): No such file or directory
….
Jun 29 03:34:43 fw php: : The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf fxp1 > /tmp/fxp1_output 2> /tmp/fxp1_error_output' returned exit code '1', the output was ''
Jun 29 03:34:43 fw php: : Accept router advertisements on interface fxp1
Jun 29 03:34:44 fw php: : rc.newwanip: Informational is starting fxp1.
Jun 29 03:34:44 fw php: : rc.newwanip: on (IP address: ) (interface: wan) (real interface: fxp1).
Jun 29 03:34:44 fw php: : rc.newwanip: Failed to update wan IP, restarting...
....
[2.1-RC0][admin@fw.xxxx.com]/var/etc(29): cat dhclient_wan.conf
interface "fxp1" {
timeout 60;
retry 15;
select-timeout 0;
initial-interval 1;

script "/sbin/dhclient-script";
}

[2.1-RC0][admin@fw.xxxx.com]/var/etc(30): cat dhcp6c_wan.conf
interface fxp1 {
send ia-na 0; # request stateful address
send ia-na 0; # request stateful address
send ia-pd 0; # request prefix delegation
request domain-name-servers;
request domain-name;
script "/var/etc/dhcp6c_wan_script.sh"; # we'd like some nameservers please
};
id-assoc na 0 { };
id-assoc pd 0 {
};

eri--

I just pushed some fixes related to this.
Can you please either gitsync or try with tomorrow snapshots.

reslip

From the developer shell I did playback gitsync RELENG_2_1. I am still getting errors for dhcp6 on the WAN side.

Jul 3 10:58:55 php: rc.bootup: ROUTING: setting IPv6 default route to fe80::201:5cff:xxxx:xxxx%fxp1
Jul 3 10:58:55 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
Jul 3 10:58:55 dhcp6c[42896]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Jul 3 10:58:55 dhcp6c[42896]: client6_init: failed initialize control message authentication
Jul 3 10:58:55 dhcp6c[42896]: client6_init: skip opening control port
Jul 3 10:58:55 dhcp6c[42896]: add_options: /var/etc/dhcp6c_wan.conf:3 IA_NA (0) is not defined
Jul 3 10:58:55 dhcp6c[42896]: main: failed to parse configuration file

eri--

You seem to have other issues than dhcp.
Can you share your config(/var/etc/dhcp6c_wan.conf))?

reslip


[2.1-RC0][admin@fw.subnothing.com]/var/etc(8): cat dhcp6c_wan.conf
interface fxp1 {
        send ia-na 0;   # request stateful address
 	send ia-na 0;	# request stateful address
	send ia-pd 0;	# request prefix delegation
	request domain-name-servers;
	request domain-name;
	script "/var/etc/dhcp6c_wan_script.sh"; # we'd like some nameservers please
};
id-assoc na 0 { };
id-assoc pd 0 {
};

qubit

@reslip:

From the developer shell I did playback gitsync RELENG_2_1. I am still getting errors for dhcp6 on the WAN side.

Jul 3 10:58:55 php: rc.bootup: ROUTING: setting IPv6 default route to fe80::201:5cff:xxxx:xxxx%fxp1
Jul 3 10:58:55 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
Jul 3 10:58:55 dhcp6c[42896]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Jul 3 10:58:55 dhcp6c[42896]: client6_init: failed initialize control message authentication
Jul 3 10:58:55 dhcp6c[42896]: client6_init: skip opening control port
Jul 3 10:58:55 dhcp6c[42896]: add_options: /var/etc/dhcp6c_wan.conf:3 IA_NA (0) is not defined
Jul 3 10:58:55 dhcp6c[42896]: main: failed to parse configuration file

As of this post I think the three commits relating to rc.newwanip are in master and not RELENG_2_1 yet