Project

General

Profile

Actions
Copy link

Bug #7734

open

Using opton ia pd0 does not renew prefix and prefix get dropped

Added by Daniel Helgenberger over 7 years ago. Updated over 7 years ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
DHCP (IPv6)
Target version:
-
Start date:
07/28/2017
Due date:
% Done:

0%

Estimated time:
Plus Target Version:
Release Notes:
Affected Version:
2.3.x
Affected Architecture:

Description

From my ISP i am getting a vl/rl of 14400 seconds

The prefix is not renewed and is dropped after 4hrs, see below.

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

Workaound

I think a workaround exists by explicitly setting at least the vltime option. When I set it to 14400, the prefix is renewed every 2hrs as intended.

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:

                        <descr><![CDATA[WAN_B]]></descr>
                        <if>pppoe1</if>
                        <spoofmac></spoofmac>
                        <blockpriv></blockpriv>
                        <blockbogons></blockbogons>
                        <enable></enable>
                        <ipaddr>pppoe</ipaddr>
                        <ipaddrv6>dhcp6</ipaddrv6>
                        <dhcp6-duid></dhcp6-duid>
                        <dhcp6-ia-pd-len>8</dhcp6-ia-pd-len>
                        <dhcp6-ia-pd-send-hint></dhcp6-ia-pd-send-hint>
                        <dhcp6prefixonly></dhcp6prefixonly>
                        <dhcp6usev4iface></dhcp6usev4iface>
                        <dhcp6debug></dhcp6debug>
                        <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>
Actions
Copy link
 #1

Updated by Daniel Helgenberger over 7 years ago

This might be related to #7330

Actions
Copy link
 #2

Updated by Martin Wasley over 7 years ago

If you are still running 2.3 then it's not related at all, 7330 was a 2.4 issues and was fixed and is closed. The issue there was caused by a previous patch not restarting dhcp6c when using pppoe, I know this because it was one of my 2.4 patches that caused the problem! I fixed it. :)

Also, you are posting a part of your pfsense config file, not dhcp6c_*.conf which is found in /var/etc/

Actions
Copy link
 #3

Updated by Daniel Helgenberger over 7 years ago

Sorry - was looking for it but forgot about /var/etc:

interface pppoe1 {
    send ia-pd 0;
    script "/var/etc/dhcp6c_opt2_script.sh";
};
id-assoc pd { };

Interestingly, I configured pltime=14400, this does not seem to end up in the options file.
See also, https://forum.pfsense.org/index.php?topic=134192.0

Actions
Copy link

Also available in: Atom PDF