Dhcp6c: prefix renewal fails - does pfsense create pd's with wrong pl/vl times?



  • Hello,

    I am currently struggling with my IPv6 PD. On reboot, this seems to work as intended. When however, the prefix is not renewed and the prefix is just dropped after 4hrs, see below.

    What bugs me: I get a delegation for 4h:

    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option IA_PD prefix, len 25
    Jul 25 02:19:52 firewall dhcp6c[38402]:   IA_PD prefix: 2003:a:XXXX::/56 pltime=14400 vltime=14400
    

    However:

    Jul 25 02:19:52 firewall dhcp6c[38402]: update a prefix 2003:a:XXXXXX::/56 pltime=140733193402432, vltime=34359752768
    

    Sure enough, the prefix is dropped after 4h:

    Jul 25 06:19:52 firewall dhcp6c[38402]: prefix timeout for 2003:a:XXXX:/56
    

    Full logs
    Startup:

    
    Jul 25 02:19:52 firewall dhcp6c[38402]: IA timeout for PD-0, state=ACTIVE
    Jul 25 02:19:52 firewall dhcp6c[38402]: reset a timer on pppoe1, state=RENEW, timeo=0, retrans=9915
    Jul 25 02:19:52 firewall dhcp6c[38402]: Sending Renew
    Jul 25 02:19:52 firewall dhcp6c[38402]: a new XID (dff8a9) is generated
    Jul 25 02:19:52 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 02:19:52 firewall dhcp6c[38402]: set server ID (len 23)
    Jul 25 02:19:52 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 02:19:52 firewall dhcp6c[38402]: set IA_PD prefix
    Jul 25 02:19:52 firewall dhcp6c[38402]: set IA_PD
    Jul 25 02:19:52 firewall dhcp6c[38402]: send renew to ff02::1:2%pppoe1
    Jul 25 02:19:52 firewall dhcp6c[38402]: receive reply from fe80::90:1a00:1a4:6715%pppoe1 on pppoe1
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option server ID, len 23
    Jul 25 02:19:52 firewall dhcp6c[38402]:   DUID: 00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43:33:33:45:58:32:2f:01
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option client ID, len 14
    Jul 25 02:19:52 firewall dhcp6c[38402]:   DUID: 00:01:00:01:1d:a9:5f:51:00:15:17:21:12:e4
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option IA_PD, len 41
    Jul 25 02:19:52 firewall dhcp6c[38402]:   IA_PD: ID=0, T1=7200, T2=11520
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option IA_PD prefix, len 25
    Jul 25 02:19:52 firewall dhcp6c[38402]:   IA_PD prefix: 2003:a:XXXX::/56 pltime=14400 vltime=14400
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option opt_20, len 0
    Jul 25 02:19:52 firewall dhcp6c[38402]: unknown or unexpected DHCP6 option opt_20, len 0
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option DNS, len 32
    Jul 25 02:19:52 firewall dhcp6c[38402]: get DHCP option status code, len 2
    Jul 25 02:19:52 firewall dhcp6c[38402]:   status code: success
    Jul 25 02:19:52 firewall dhcp6c[38402]: dhcp6c Received INFO
    Jul 25 02:19:52 firewall dhcp6c[38402]: status code: success
    Jul 25 02:19:52 firewall dhcp6c[38402]: nameserver[0] 2003:180:2:6000:0:1:0:53
    Jul 25 02:19:52 firewall dhcp6c[38402]: nameserver[1] 2003:180:2::1:0:53
    Jul 25 02:19:52 firewall dhcp6c[38402]: update an IA: PD-0
    Jul 25 02:19:52 firewall dhcp6c[38402]: update a prefix 2003:a:XXXXXX::/56 pltime=140733193402432, vltime=34359752768
    Jul 25 02:19:52 firewall dhcp6c[38402]: executes /var/etc/dhcp6c_opt2_script.sh
    Jul 25 02:19:57 firewall dhcp6c[38402]: script "/var/etc/dhcp6c_opt2_script.sh" terminated
    Jul 25 02:19:57 firewall dhcp6c[38402]: removing an event on pppoe1, state=RENEW
    Jul 25 02:19:57 firewall dhcp6c[38402]: got an expected reply, sleeping.
    
    

    Prefix timeout

    
    Jul 25 06:19:52 firewall dhcp6c[38402]: prefix timeout for 2003:a:XXXX:/56
    Jul 25 06:19:52 firewall dhcp6c[38402]: remove a site prefix 2003:a:XXXX::/56
    Jul 25 06:19:52 firewall dhcp6c[38402]: IA PD-0 is invalidated
    Jul 25 06:19:52 firewall dhcp6c[38402]: remove an IA: PD-0
    Jul 25 06:19:52 firewall dhcp6c[38402]: reset a timer on pppoe1, state=INIT, timeo=0, retrans=123
    Jul 25 06:19:53 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:19:53 firewall dhcp6c[38402]: a new XID (148b78) is generated
    Jul 25 06:19:53 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:19:53 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:19:53 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:19:53 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:19:53 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=0, retrans=1006
    Jul 25 06:19:54 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:19:54 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:19:54 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:19:54 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:19:54 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:19:54 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=1, retrans=2025
    Jul 25 06:19:56 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:19:56 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:19:56 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:19:56 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:19:56 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:19:56 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=2, retrans=4238
    Jul 25 06:20:00 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:20:00 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:20:00 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:20:00 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:20:00 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:20:00 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=3, retrans=8815
    Jul 25 06:20:09 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:20:09 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:20:09 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:20:09 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:20:09 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:20:09 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=4, retrans=16767
    Jul 25 06:20:25 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:20:25 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:20:25 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:20:25 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:20:25 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:20:25 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=5, retrans=33631
    Jul 25 06:20:59 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:20:59 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:20:59 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:20:59 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:20:59 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:20:59 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=6, retrans=67494
    Jul 25 06:22:07 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:22:07 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:22:07 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:22:07 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:22:07 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:22:07 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=7, retrans=110004
    Jul 25 06:23:57 firewall dhcp6c[38402]: Sending Solicit
    Jul 25 06:23:57 firewall dhcp6c[38402]: set client ID (len 14)
    Jul 25 06:23:57 firewall dhcp6c[38402]: set elapsed time (len 2)
    Jul 25 06:23:57 firewall dhcp6c[38402]: set IA_PD
    Jul 25 06:23:57 firewall dhcp6c[38402]: send solicit to ff02::1:2%pppoe1
    Jul 25 06:23:57 firewall dhcp6c[38402]: reset a timer on pppoe1, state=SOLICIT, timeo=8, retrans=124716
    Jul 25 06:24:03 firewall dhcp6c[38402]: all information to be updated was canceled
    Jul 25 06:24:03 firewall dhcp6c[38402]: removing an event on pppoe1, state=REBIND
    
    

    my dhcp6c conf for the interface:

    
                            <if>pppoe1</if>
                            <spoofmac></spoofmac>
    
                            <enable></enable>
                            <ipaddr>pppoe</ipaddr>
                            <ipaddrv6>dhcp6</ipaddrv6>
    
                            <dhcp6-ia-pd-len>8</dhcp6-ia-pd-len>
                            <dhcp6-ia-pd-send-hint></dhcp6-ia-pd-send-hint>
    
                            <dhcp6usev4iface></dhcp6usev4iface>
    
                            <adv_dhcp6_interface_statement_send_options>ia-pd 0</adv_dhcp6_interface_statement_send_options>
                            <adv_dhcp6_id_assoc_statement_prefix_enable>Selected</adv_dhcp6_id_assoc_statement_prefix_enable>
                            <adv_dhcp6_config_advanced>yes</adv_dhcp6_config_advanced>
    
    


  • What version of pfSense are you runnning?



  • Sorry, forgot to mention:

    2.3.4-RELEASE-p1 (amd64)
    built on Fri Jul 14 14:52:43 CDT 2017
    FreeBSD 10.3-RELEASE-p19

    I also had the issue with all 2.3.x versions. I activated  ia-pd 0 only a few moths back. Currently, I am testing  pltime => 14400. Seems to hold atm.

    
                            <adv_dhcp6_interface_statement_send_options>ia-pd 0</adv_dhcp6_interface_statement_send_options>
                            <adv_dhcp6_id_assoc_statement_prefix_enable>Selected</adv_dhcp6_id_assoc_statement_prefix_enable>
                            <adv_dhcp6_id_assoc_statement_prefix_pltime>14400</adv_dhcp6_id_assoc_statement_prefix_pltime>
    
    

    Live - status can be seen here: https://status.m-box.de/ - if the interface (GatewayB) is up and all the IPv6 stuff is down,  the prefix is lost.



  • OK, there are a lot of changes around dhcp6c in version 2.4b, some of them are back ported but there have also been changes to dhcp6c itself which have not been backported.

    If you can, you might wish to try 2.4b,  it is very stable.



  • Ok, thanks for the info! I'll give it a try if my current setup fails again. I'll keep this thread updated!



  • As a note, most ISP's will ignore your lease time request. :)



  • As a note, most ISP's will ignore your lease time request.

    Figured that much as I would do the same. My hope is dhcpv6c might get to know the lease time that way. So far, it works as the prefix is renewed correctly (knock on wood).



  • A noob question, how do I get 2.4b? When I switch over to devel snapshots, I would update to 2.3.5.a.20170726.1256



  • It's so long since I changed to 2.4b  I cannot remember… Sad or what :D

    Have a look under advanced config, I think there may be something there. I only remember doing what you have done when I was on 2.3, but that's over a year ago now.



  • Hi!

    Export config, install 2.4 with ZFS and then simple restore config. It will restore everything.
    Did it this way and it took me exactly 7.87 minutes :)



  • And THAT is the best way to do it!

    No junk left around either.



  • Export config, install 2.4 with ZFS and then simple restore config

    Thanks, I read about ZFS and was also thinking doing it this way.

    BTW, you can directly upgrade to 2.4b when selecting NEXT MAJOR in update settings.



  • I'll remember that, or try to. :)



  • @helge000:

    Export config, install 2.4 with ZFS and then simple restore config

    Thanks, I read about ZFS and was also thinking doing it this way.

    BTW, you can directly upgrade to 2.4b when selecting NEXT MAJOR in update settings.

    You can, but then you het NO ZFS :)



  • Don't use ZFS as I run pfSense on an APU2 with a 32Gb SSD. There would not much benefit as I also use a RAM disk and set low levels of logging.



  • There would not much benefit as I also use a RAM disk and set low levels of logging.

    Truth is you could also benefit from ZFS:

    • It is a copy on write FS witch greatly reduces the chance of failures due to power cuts etc.
    • By using ZIL/log you basically get the benefits from aync IO with the reliability of synced I/O operations (though this does not need to make a big performance dent with SSD's nowadays, it is very true for HDD's in RAIDZ).
    • Upgrading to new releases will benefit as can basically create a snapshot from your root volume and boot from that if something goes wrong greatly reducing upgrade downtime in case of issues (this is indeed the main reason for me to switch)


  • Indeed, but as was pointed out, it tales 10 or minutes or less to install pfSense from scratch and reload the config - which is backed up in a couple of locations just in case, Plus I have a spare APU which I do my testing and developing on, so if needed that swings into action.

    I might use ZFS on my FreeBSD PC, but at present the stuff on it that needs to be backed up goes to a NAS Raid device.

    Maybe one day….



  • For what it's worth, I opened a redmine ticket for it: https://redmine.pfsense.org/issues/7734

    @marjohn56,

    OK, there are a lot of changes around dhcp6c in version 2.4b

    I think you where referring to your https://github.com/pfsense/pfsense/pull/3515; and this got merged in 2.4b?