IPv6 DHCP-PD – radvd dies after interface reset - dhcpv6 does not reaquire addr
-
Yesterday I tried a clean install from June 22 with an imported 2.0.3 config. No packages, just some static DHCP leases and such. I have Comcast and set up DHCP6 appropriately. I'm able to get WAN and LAN IPv6 addresses and ping6 works from both pfsense itself and clients. Rebooted pfsense a few times and IPv6 started up fine. I had some issues in previous snapshots before where radvd would disappear but so far I haven't seen that, however the NTP service starts and immediately stops (core dump) and I have to select listen on WAN and start it a few times for it to come up.
However once things settle down after boot my system log is flooded with the following:
Jun 26 19:18:27 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:18:27 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:18:44 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:18:44 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:19:20 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:19:20 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:20:28 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:20:28 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:22:24 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:22:24 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:24:29 dhcp6c[29245]: client6_recvadvert: XID mismatch
Jun 26 19:24:29 dhcp6c[29245]: client6_recvadvert: XID mismatchThis just goes on about every two minutes or so. I should note that despite this I still have stable IPv6 during this time. I ran a packet capture (I don't have the saved one at the moment) and what seems to trigger this is the following:
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.
I'm not that familiar with IPv6 at the moment, but why is this happening? Why is pfsense sending out a solicit every 2+ minutes when it has stable IPv6 addressing? Is it some kind of keepalive? I'm assuming it went through the solicit-advertise-request-reply sequence upon boot because IPv6 is working fine. I'm just wondering if pfsense is supposed to be sending solicits every couple of minutes or if dhcpc6 just needs to ignore all other DHCPv6 packets once bound unless it's renewing after 4 days.
Has anyone with working IPv6 on Comcast seen this on recent snapshots? Thanks.
-
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
-
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?
-
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 dhcp6cPID 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.pidNot 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 -
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 dhcp6cPID 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).
-
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 -
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 -
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 -
:(
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 -
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 directoryAs far as I understand, these are just warnings, and completely unrelated to your problem.
-
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 directoryAs 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.
-
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.
-
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…
-
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.
-
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.
-
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 {
}; -
I just pushed some fixes related to this.
Can you please either gitsync or try with tomorrow snapshots. -
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 -
You seem to have other issues than dhcp.
Can you share your config(/var/etc/dhcp6c_wan.conf))? -
[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 { };
