IPv6 DHCP-PD – radvd dies after interface reset - dhcpv6 does not reaquire addr
-
Today I tried to do some debugging.
What I found is that the DHCP process itself looks ok and also the PD is working.
But during the process the route command isn't foundDuring renewal an XID mismatch is generated.
[2.1-RC0][xxxx]/var/run(66): /usr/local/sbin/dhcp6c -d -D -f -c /var/etc/dhcp6c_wan.conf -p /var/run/dhcp6c_pppoe0.pid pppoe0
Jun/16/2013 17:18:15: get_duid: extracted an existing DUID from /var/db/dhcp6c_duid: 00:01:00:01:19:50:8e:29:48:5d:60:cb:50:36
Jun/16/2013 17:18:15: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Jun/16/2013 17:18:15: client6_init: failed initialize control message authentication
Jun/16/2013 17:18:15: client6_init: skip opening control port
Jun/16/2013 17:18:15: cfdebug_print: <3>[interface] (9)
Jun/16/2013 17:18:15: cfdebug_print: <5>[pppoe0] (6)
Jun/16/2013 17:18:15: cfdebug_print: <3>begin of closure [{] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[send] (4)
Jun/16/2013 17:18:15: cfdebug_print: <3>[ia-na] (5)
Jun/16/2013 17:18:15: cfdebug_print: <3>[0] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>comment [# request stateful address] (26)
Jun/16/2013 17:18:15: cfdebug_print: <3>[send] (4)
Jun/16/2013 17:18:15: cfdebug_print: <3>[ia-pd] (5)
Jun/16/2013 17:18:15: cfdebug_print: <3>[0] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>comment [# request prefix delegation] (27)
Jun/16/2013 17:18:15: cfdebug_print: <3>[request] (7)
Jun/16/2013 17:18:15: cfdebug_print: <3>[domain-name-servers] (19)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[request] (7)
Jun/16/2013 17:18:15: cfdebug_print: <3>[domain-name] (11)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[script] (6)
Jun/16/2013 17:18:15: cfdebug_print: <3>["/var/etc/dhcp6c_wan_script.sh"] (31)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>comment [# we'd like some nameservers please] (35)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of closure [}] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[id-assoc] (8)
Jun/16/2013 17:18:15: cfdebug_print: <13>[na] (2)
Jun/16/2013 17:18:15: cfdebug_print: <13>[0] (1)
Jun/16/2013 17:18:15: cfdebug_print: <13>begin of closure [{] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of closure [}] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[id-assoc] (8)
Jun/16/2013 17:18:15: cfdebug_print: <13>[pd] (2)
Jun/16/2013 17:18:15: cfdebug_print: <13>[0] (1)
Jun/16/2013 17:18:15: cfdebug_print: <13>begin of closure [{] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[prefix-interface] (16)
Jun/16/2013 17:18:15: cfdebug_print: <5>[bridge0] (7)
Jun/16/2013 17:18:15: cfdebug_print: <3>begin of closure [{] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[sla-id] (6)
Jun/16/2013 17:18:15: cfdebug_print: <3>[32] (2)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>[sla-len] (7)
Jun/16/2013 17:18:15: cfdebug_print: <3>[16] (2)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of closure [}] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of closure [}] (1)
Jun/16/2013 17:18:15: cfdebug_print: <3>end of sentence [;] (1)
Jun/16/2013 17:18:15: configure_pool: called
Jun/16/2013 17:18:15: clear_poolconf: called
Jun/16/2013 17:18:15: dhcp6_reset_timer: reset a timer on pppoe0, state=INIT, timeo=0, retrans=383
Jun/16/2013 17:18:16: client6_send: a new XID (37f7f7) is generated
Jun/16/2013 17:18:16: copy_option: set client ID (len 14)
Jun/16/2013 17:18:16: copyout_option: set identity association
Jun/16/2013 17:18:16: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:16: copy_option: set option request (len 4)
Jun/16/2013 17:18:16: copyout_option: set IA_PD
Jun/16/2013 17:18:16: client6_send: send solicit to ff02::1:2%pppoe0
Jun/16/2013 17:18:16: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=0, retrans=1088
Jun/16/2013 17:18:16: client6_recv: receive advertise from fe80::2a0:a50f:fc78:5530%pppoe0 on pppoe0
Jun/16/2013 17:18:16: dhcp6_get_options: get DHCP option client ID, len 14
Jun/16/2013 17:18:16: DUID: 00:01:00:01:19:50:8e:29:48:5d:60:cb:50:36
Jun/16/2013 17:18:16: dhcp6_get_options: get DHCP option server ID, len 26
Jun/16/2013 17:18:16: DUID: 00:02:00:00:05:83:4a:4e:31:31:45:41:33:30:42:41:46:41:00:00:00:00:00:00:00:00
Jun/16/2013 17:18:16: dhcp6_get_options: get DHCP option IA_PD, len 41
Jun/16/2013 17:18:16: IA_PD: ID=0, T1=3600, T2=5760
Jun/16/2013 17:18:16: copyin_option: get DHCP option IA_PD prefix, len 25
Jun/16/2013 17:18:16: copyin_option: IA_PD prefix: 2001:980:93ab::/48 pltime=7200 vltime=7200
Jun/16/2013 17:18:16: dhcp6_get_options: get DHCP option identity association, len 18
Jun/16/2013 17:18:16: IA_NA: ID=0, T1=0, T2=0
Jun/16/2013 17:18:16: copyin_option: get DHCP option status code, len 2
Jun/16/2013 17:18:16: status code: no addresses
Jun/16/2013 17:18:16: dhcp6_get_options: get DHCP option DNS, len 32
Jun/16/2013 17:18:16: client6_recvadvert: server ID: 00:02:00:00:05:83:4a:4e:31:31:45:41:33:30:42:41:46:41:00:00:00:00:00:00:00:00, pref=-1
Jun/16/2013 17:18:16: client6_recvadvert: reset timer for pppoe0 to 0.771510
Jun/16/2013 17:18:17: select_server: picked a server (ID: 00:02:00:00:05:83:4a:4e:31:31:45:41:33:30:42:41:46:41:00:00:00:00:00:00:00:00)
Jun/16/2013 17:18:17: client6_send: a new XID (982ee) is generated
Jun/16/2013 17:18:17: copy_option: set client ID (len 14)
Jun/16/2013 17:18:17: copy_option: set server ID (len 26)
Jun/16/2013 17:18:17: copyout_option: set status code
Jun/16/2013 17:18:17: copyout_option: set identity association
Jun/16/2013 17:18:17: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:17: copy_option: set option request (len 4)
Jun/16/2013 17:18:17: copyout_option: set IA_PD prefix
Jun/16/2013 17:18:17: copyout_option: set IA_PD
Jun/16/2013 17:18:17: client6_send: send request to ff02::1:2%pppoe0
Jun/16/2013 17:18:17: dhcp6_reset_timer: reset a timer on pppoe0, state=REQUEST, timeo=0, retrans=977
Jun/16/2013 17:18:17: client6_recv: receive reply from fe80::2a0:a50f:fc78:5530%pppoe0 on pppoe0
Jun/16/2013 17:18:17: dhcp6_get_options: get DHCP option client ID, len 14
Jun/16/2013 17:18:17: DUID: 00:01:00:01:19:50:8e:29:48:5d:60:cb:50:36
Jun/16/2013 17:18:17: dhcp6_get_options: get DHCP option server ID, len 26
Jun/16/2013 17:18:17: DUID: 00:02:00:00:05:83:4a:4e:31:31:45:41:33:30:42:41:46:41:00:00:00:00:00:00:00:00
Jun/16/2013 17:18:17: dhcp6_get_options: get DHCP option IA_PD, len 41
Jun/16/2013 17:18:17: IA_PD: ID=0, T1=3600, T2=5760
Jun/16/2013 17:18:17: copyin_option: get DHCP option IA_PD prefix, len 25
Jun/16/2013 17:18:17: copyin_option: IA_PD prefix: 2001:980:93ab::/48 pltime=7200 vltime=7200
Jun/16/2013 17:18:17: dhcp6_get_options: get DHCP option identity association, len 18
Jun/16/2013 17:18:17: IA_NA: ID=0, T1=0, T2=0
Jun/16/2013 17:18:17: copyin_option: get DHCP option status code, len 2
Jun/16/2013 17:18:17: status code: no addresses
Jun/16/2013 17:18:17: dhcp6_get_options: get DHCP option DNS, len 32
Jun/16/2013 17:18:17: info_printf: nameserver[0] 2001:888:0:6::66
Jun/16/2013 17:18:17: info_printf: nameserver[1] 2001:888:0:9::99
Jun/16/2013 17:18:17: get_ia: make an IA: PD-0
Jun/16/2013 17:18:17: update_prefix: create a prefix 2001:980:93ab::/48 pltime=7200, vltime=7200
Jun/16/2013 17:18:17: ifaddrconf: add an address 2001:980:93ab:20:fe:4aff:fec8:9c00/64 on bridge0
Jun/16/2013 17:18:17: get_ia: make an IA: NA-0
Jun/16/2013 17:18:17: update_ia: status code for NA-0: no addresses
Jun/16/2013 17:18:17: update_ia: IA NA-0 is invalidated
Jun/16/2013 17:18:17: remove_ia: remove an IA: NA-0
Jun/16/2013 17:18:17: dhcp6_reset_timer: reset a timer on pppoe0, state=INIT, timeo=0, retrans=915
Jun/16/2013 17:18:17: client6_recvreply: executes /var/etc/dhcp6c_wan_script.sh
route: not found
route: not found
Jun/16/2013 17:18:24: client6_script: script "/var/etc/dhcp6c_wan_script.sh" terminated
Jun/16/2013 17:18:24: dhcp6_remove_event: removing an event on pppoe0, state=REQUEST
Jun/16/2013 17:18:24: dhcp6_remove_event: removing server (ID: 00:02:00:00:05:83:4a:4e:31:31:45:41:33:30:42:41:46:41:00:00:00:00:00:00:00:00)
Jun/16/2013 17:18:24: client6_recvreply: got an expected reply, sleeping.
Jun/16/2013 17:18:24: client6_send: a new XID (e4dbbb) is generated
Jun/16/2013 17:18:24: copy_option: set client ID (len 14)
Jun/16/2013 17:18:24: copyout_option: set identity association
Jun/16/2013 17:18:24: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:24: copy_option: set option request (len 4)
Jun/16/2013 17:18:24: client6_send: send solicit to ff02::1:2%pppoe0
Jun/16/2013 17:18:24: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=0, retrans=1079
Jun/16/2013 17:18:25: copy_option: set client ID (len 14)
Jun/16/2013 17:18:25: copyout_option: set identity association
Jun/16/2013 17:18:25: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:25: copy_option: set option request (len 4)
Jun/16/2013 17:18:25: client6_send: send solicit to ff02::1:2%pppoe0
Jun/16/2013 17:18:25: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=1, retrans=2086
Jun/16/2013 17:18:27: copy_option: set client ID (len 14)
Jun/16/2013 17:18:27: copyout_option: set identity association
Jun/16/2013 17:18:27: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:27: copy_option: set option request (len 4)
Jun/16/2013 17:18:27: client6_send: send solicit to ff02::1:2%pppoe0
Jun/16/2013 17:18:27: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=2, retrans=4252
Jun/16/2013 17:18:31: copy_option: set client ID (len 14)
Jun/16/2013 17:18:31: copyout_option: set identity association
Jun/16/2013 17:18:31: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:31: copy_option: set option request (len 4)
Jun/16/2013 17:18:31: client6_send: send solicit to ff02::1:2%pppoe0
Jun/16/2013 17:18:31: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=3, retrans=8287
Jun/16/2013 17:18:40: copy_option: set client ID (len 14)
Jun/16/2013 17:18:40: copyout_option: set identity association
Jun/16/2013 17:18:40: copy_option: set elapsed time (len 2)
Jun/16/2013 17:18:40: copy_option: set option request (len 4)
Jun/16/2013 17:18:40: client6_send: send solicit to ff02::1:2%pppoe0
Jun/16/2013 17:18:40: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=4, retrans=16283 -
@ermal:
Can anybody confirm that when a renewal is not done either 2 dhcp6c processes are running or there is no default gw for v6?
At the time the 4 day lease expired, all IPv6 addressing went away.
There is no dhcp6c process running:
$ ps -aux | grep dhcp6c root 56506 0.0 0.0 9068 1512 ?? S 12:14PM 0:00.00 grep dhcp6cJun 17 05:58:32 dhcp6c[34138]: client6_timo: all information to be updated was canceled Jun 17 05:55:08 dhcp6c[34138]: client6_timo: all information to be updated was canceledradvd is no longer running:
Jun 13 05:50:51 radvd[41186]: removing /var/run/radvd.pid Jun 13 05:50:51 radvd[41186]: sending stop adverts Jun 13 05:50:51 radvd[41186]: Exiting, sigterm or sigint received. Jun 13 05:50:30 radvd[40640]: IPv6 forwarding seems to be disabled, but continuing anyway. Jun 13 05:50:30 radvd[40640]: IPv6 forwarding setting is: 0, should be 1 Jun 13 05:50:30 radvd[40640]: version 1.9.1 started Jun 13 05:42:24 radvd[53132]: resuming normal operation Jun 13 05:42:24 radvd[53132]: attempting to reread config file Jun 13 05:42:05 radvd[50732]: IPv6 forwarding seems to be disabled, but continuing anyway. Jun 13 05:42:05 radvd[50732]: IPv6 forwarding setting is: 0, should be 1 Jun 13 05:42:05 radvd[50732]: version 1.9.1 started Jun 13 05:34:06 radvd[52561]: resuming normal operation Jun 13 05:34:06 radvd[52561]: attempting to reread config file Jun 13 05:33:47 radvd[52249]: IPv6 forwarding seems to be disabled, but continuing anyway. Jun 13 05:33:47 radvd[52249]: IPv6 forwarding setting is: 0, should be 1 Jun 13 05:33:47 radvd[52249]: version 1.9.1 startedGateway is there (same as when it was working):
Internet6: Destination Gateway Flags Netif Expire default fe80::201:5cff:fe24:9301%em1 UG em1 ::1 ::1 UH lo0 fe80::%em0/64 link#1 U em0 fe80::1:1%em0 link#1 UHS lo0 fe80::%em1/64 link#2 U em1 fe80::230:18ff:fea5:bdb8%em1 link#2 UHS lo0 -
I haven't stayed on a version long enough to see what happens after 4 days.
But after every update I loose IPv6 connectivity.
I found that by going to "LAN interface" and disabling "IPv6" and clicking "save" then going to the "WAN interface" and disabling "IPv6" then clicking on Save then clicking "Apply changes" then turning "Ipv6" back on for the "WAN interface" as "DHCP6" and set "Prefix to 64" and clicking "save" then switching to the "LAN interface" and setting "IPv6 to Track Interface" and setting "interface to WAN" and clicking "save" then hitting "Apply changes" I can get IPv6 back without rebooting. It's worked ever time since last Wednesday. If I reboot then I loose connectivity and have to repeat the above procedure to get it back.
-
Ok just did that on version
2.1-RC0 (i386)
built on Wed Jun 19 06:11:14 EDT 2013
FreeBSD 8.3-RELEASE-p8And no ipv6 – I will give it a bit, and then try to reboot.. But I had a ipv6 while I was away for work.. Figured sweet, but when I got back looking today no ipv6.. So tried updating to the above, as of yet have not been able to get a ipv6
Just going to have to go back to a tunnel from HE.. Since this is clearly NOT ready for primetime, I would just use m0n0wall but no openvpn support is not there..
Can we please work on getting stable ipv6 where it comes up on its own and best yet maintain the IP range..
-
The problem has gotten progressively worse. If it helps at all ….
Prior to the May 9 build, at least you were able to get IPv6 addressing. It would disappear when the lease expired (RENEW problem on bug #2919), but you could reboot and be back in service.
Now, I can't get it to renew by rebooting .. as johnpoz noted. I have to build fresh to get IPv6 working again.
At this point, I need to move on until this gets resolved.
-
I have just moved back to HE tunnel – this is just not working out..
Guess will try the native stuff again when 2.1 is final with a new clean build, etc. But for now I have also just moved on and went back to my stable HE tunnel.. Its got a bit of latency.. But it works!
C:\Windows\System32>ping ipv6.google.com Pinging ipv6.l.google.com [2607:f8b0:4006:802::1012] with 32 bytes of data: Reply from 2607:f8b0:4006:802::1012: time=60ms Reply from 2607:f8b0:4006:802::1012: time=56ms Reply from 2607:f8b0:4006:802::1012: time=58ms Reply from 2607:f8b0:4006:802::1012: time=55ms Ping statistics for 2607:f8b0:4006:802::1012: Packets: Sent = 4, Received = 4, Lost = 0 (0% loss), Approximate round trip times in milli-seconds: Minimum = 55ms, Maximum = 60ms, Average = 57ms -
I just upgraded to the built on Fri Jun 21 15:17:41 EDT 2013 and for the first time it rebooted and IPv6 was working without any problems on Comcast. I'll do some more testing in the morning.
Seems to be heading in the right direction.
Thanks
-
I think I don't see anything in the git commits that is related to this problem, but I will upgrade and test it too.
-
I just upgraded to the built on Fri Jun 21 15:17:41 EDT 2013 and for the first time it rebooted and IPv6 was working without any problems on Comcast. I'll do some more testing in the morning.
After future testing IPv6 kept connectivity after multiple reboots and after pulling plug on WAN 1 and letting router failover to backup U-Verse then returning to Wan1 Comcast connection.
I haven't checked out get comments about changes but I haven't been able to get any of the previous versions to work after a reboot or failover test and the last 2 versions work as expected.
I also installed the latest update built on Sat Jun 22 14:54:39 EDT 2013 and it came up after the reboots and after a failover test.
I don't know if it will work for others but it's working well for me.
-
Comcast home, pfSense snapshot built on Sat Jun 15 05:06:50 EDT 2013, nanobsd if that makes a difference. After over 7 days of uptime I still have working IPv6 connectivity on both the WAN and the LAN side.
-
Well, looks like its time for me to download another build, and test things out for myself.
I'm going to go with the one that user "razzfazz" used (pfSense snapshot built on Sat Jun 15 05:06:50 EDT 2013) and see how that works for me.
EDIT: Well, looks like I cannot go back that far on the snapshot server. btw, the link I'm using is
http://snapshots.pfsense.org/FreeBSD_RELENG_8_3/i386/pfSense_RELENG_2_1/livecd_installer/?C=M;O=D
user "netkeys" seems to have similar luck with pfsense snapshot built on Sat Jun 22 14:54:39 EDT 2013, so I will download that one, and do my testing with it.
–Brian
-
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
