Page MenuHomeVyOS Platform

PPPoE IA-PD doesn't work in VRF
Open, Requires assessmentPublic

Description

  • My ISP provides static IPv4 and /56 IPv6 subnet via DSL/PPPoE
  • I was able to set up PPPoE connection with the provider and it works fine
  • However, if I move the pppoe interface to VRF, I get IPv4 and IPv6 addresses but not /56 subnet.
  • I tried to add only pppoe interface to vrf as well as all underlying interfaces (makes difference on Juniper) with no avail

Here is the configuration without VRF:

r2# show interfaces
 ethernet eth1 {
     description WAN
     duplex auto
     hw-id 00:0d:b9:44:54:31
     speed auto
     vif 35 {
         description DSL-1
     }
 }
 pppoe pppoe0 {
     authentication {
         password <password>
         user <user>
     }
     default-route auto
     description PPPOE-1
     dhcpv6-options {
         pd 0 {
             length 56
         }
         rapid-commit
     }
     ipv6 {
         address {
             autoconf
         }
     }
     source-interface eth1.35
 }
 dummy dum0 {
     address 2606:6d00:19f:a800::2/128
     address 2606:6d00:19f:a800::bbbb/128
 }

and output of dhcp6c:

r2:~# journalctl -u dhcp6c@pppoe0.service
...
Mar 23 02:19:04 r2 systemd[1]: Starting WIDE DHCPv6 client on pppoe0...
Mar 23 02:19:04 r2 dhcp6c[11822]: get_duid: extracted an existing DUID from /var/lib/dhcpv6/dhcp6c_duid: 00:01:00:01:27:ea:d3:18:00:0d:b9:44:54:30
Mar 23 02:19:04 r2 dhcp6c[11822]: dhcp6_ctl_authinit: failed to open /run/dhcp6c/dhcp6c.pppoe0.sock: No such file or directory
Mar 23 02:19:04 r2 dhcp6c[11822]: client6_init: failed initialize control message authentication
Mar 23 02:19:04 r2 dhcp6c[11822]: client6_init: skip opening control port
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>comment [### Autogenerated by interface.py ###] (37)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>comment [# man https://www.unix.com/man-page/debian/5/dhcp6c.conf/] (57)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[interface] (9)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <5>[pppoe0] (6)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>begin of closure [{] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[send] (4)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[ia-pd] (5)
Mar 23 02:19:04 r2 systemd[1]: Started WIDE DHCPv6 client on pppoe0.
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[0] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>comment [# prefix delegation #0] (22)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>end of closure [}] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[id-assoc] (8)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <15>[pd] (2)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <15>[0] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <15>begin of closure [{] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[prefix] (6)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[::] (2)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[/] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[56] (2)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>[infinity] (8)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>end of closure [}] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 02:19:04 r2 dhcp6c[11822]: configure_pool: called
Mar 23 02:19:04 r2 dhcp6c[11822]: clear_poolconf: called
Mar 23 02:19:04 r2 dhcp6c[11823]: dhcp6_reset_timer: reset a timer on pppoe0, state=INIT, timeo=0, retrans=835
Mar 23 02:19:05 r2 dhcp6c[11823]: client6_send: a new XID (6d6c63) is generated
Mar 23 02:19:05 r2 dhcp6c[11823]: copy_option: set client ID (len 14)
Mar 23 02:19:05 r2 dhcp6c[11823]: copy_option: set elapsed time (len 2)
Mar 23 02:19:05 r2 dhcp6c[11823]: copyout_option: set IA_PD prefix
Mar 23 02:19:05 r2 dhcp6c[11823]: copyout_option: set IA_PD
Mar 23 02:19:05 r2 dhcp6c[11823]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 02:19:05 r2 dhcp6c[11823]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=0, retrans=1087
Mar 23 02:19:05 r2 dhcp6c[11823]: client6_recv: receive advertise from fe80::2a0:a510:88:8ea4%pppoe0 on pppoe0
Mar 23 02:19:05 r2 dhcp6c[11823]: dhcp6_get_options: get DHCP option client ID, len 14
Mar 23 02:19:05 r2 dhcp6c[11823]:   DUID: 00:01:00:01:27:ea:d3:18:00:0d:b9:44:54:30
Mar 23 02:19:05 r2 dhcp6c[11823]: dhcp6_get_options: get DHCP option server ID, len 26
Mar 23 02:19:05 r2 dhcp6c[11823]:   DUID: 00:02:00:00:05:83:4a:4e:31:32:35:45:41:39:38:41:46:43:00:00:00:00:00:00:00:00
Mar 23 02:19:05 r2 dhcp6c[11823]: dhcp6_get_options: get DHCP option IA_PD, len 41
Mar 23 02:19:05 r2 dhcp6c[11823]:   IA_PD: ID=0, T1=43200, T2=69120
Mar 23 02:19:05 r2 dhcp6c[11823]: copyin_option: get DHCP option IA_PD prefix, len 25
Mar 23 02:19:05 r2 dhcp6c[11823]: copyin_option:   IA_PD prefix: 2606:6d00:19f:a800::/56 pltime=86400 vltime=86400
Mar 23 02:19:05 r2 dhcp6c[11823]: client6_recvadvert: server ID: 00:02:00:00:05:83:4a:4e:31:32:35:45:41:39:38:41:46:43:00:00:00:00:00:00:00:00, pref=-1
Mar 23 02:19:05 r2 dhcp6c[11823]: client6_recvadvert: reset timer for pppoe0 to 0.784840
Mar 23 02:19:06 r2 dhcp6c[11823]: select_server: picked a server (ID: 00:02:00:00:05:83:4a:4e:31:32:35:45:41:39:38:41:46:43:00:00:00:00:00:00:00:00)
Mar 23 02:19:06 r2 dhcp6c[11823]: client6_send: a new XID (faf874) is generated
Mar 23 02:19:06 r2 dhcp6c[11823]: copy_option: set client ID (len 14)
Mar 23 02:19:06 r2 dhcp6c[11823]: copy_option: set server ID (len 26)
Mar 23 02:19:06 r2 dhcp6c[11823]: copy_option: set elapsed time (len 2)
Mar 23 02:19:06 r2 dhcp6c[11823]: copyout_option: set IA_PD prefix
Mar 23 02:19:06 r2 dhcp6c[11823]: copyout_option: set IA_PD
Mar 23 02:19:06 r2 dhcp6c[11823]: client6_send: send request to ff02::1:2%pppoe0
Mar 23 02:19:06 r2 dhcp6c[11823]: dhcp6_reset_timer: reset a timer on pppoe0, state=REQUEST, timeo=0, retrans=1023
Mar 23 02:19:07 r2 dhcp6c[11823]: client6_recv: receive reply from fe80::2a0:a510:88:8ea4%pppoe0 on pppoe0
Mar 23 02:19:07 r2 dhcp6c[11823]: dhcp6_get_options: get DHCP option client ID, len 14
Mar 23 02:19:07 r2 dhcp6c[11823]:   DUID: 00:01:00:01:27:ea:d3:18:00:0d:b9:44:54:30
Mar 23 02:19:07 r2 dhcp6c[11823]: dhcp6_get_options: get DHCP option server ID, len 26
Mar 23 02:19:07 r2 dhcp6c[11823]:   DUID: 00:02:00:00:05:83:4a:4e:31:32:35:45:41:39:38:41:46:43:00:00:00:00:00:00:00:00
Mar 23 02:19:07 r2 dhcp6c[11823]: dhcp6_get_options: get DHCP option IA_PD, len 41
Mar 23 02:19:07 r2 dhcp6c[11823]:   IA_PD: ID=0, T1=43200, T2=69120
Mar 23 02:19:07 r2 dhcp6c[11823]: copyin_option: get DHCP option IA_PD prefix, len 25
Mar 23 02:19:07 r2 dhcp6c[11823]: copyin_option:   IA_PD prefix: 2606:6d00:19f:a800::/56 pltime=86400 vltime=86400
Mar 23 02:19:07 r2 dhcp6c[11823]: get_ia: make an IA: PD-0
Mar 23 02:19:07 r2 dhcp6c[11823]: update_prefix: create a prefix 2606:6d00:19f:a800::/56 pltime=86400, vltime=86400
Mar 23 02:19:07 r2 dhcp6c[11823]: dhcp6_remove_event: removing an event on pppoe0, state=REQUEST
Mar 23 02:19:07 r2 dhcp6c[11823]: dhcp6_remove_event: removing server (ID: 00:02:00:00:05:83:4a:4e:31:32:35:45:41:39:38:41:46:43:00:00:00:00:00:00:00:00)
Mar 23 02:19:07 r2 dhcp6c[11823]: client6_recvreply: got an expected reply, sleeping.

As you can see from the log, the /56 subnet is allocated and I can confirm that it is working since I have a dummy interface with addresses on this net and I can ping from it.

And here is the same with pppoe interface in VRF:

r2# show vrf
 name red {
     table 200
 }

r2# show interfaces
 ethernet eth1 {
     description WAN
     duplex auto
     hw-id 00:0d:b9:44:54:31
     speed auto
     vif 35 {
         description DSL-1
         vrf red
     }
     vrf red
 }
 pppoe pppoe0 {
     authentication {
         password <password>
         user <user>
     }
     default-route auto
     description PPPOE-1
     dhcpv6-options {
         pd 0 {
             length 56
         }
         rapid-commit
     }
     ipv6 {
         address {
             autoconf
         }
     }
     source-interface eth1.35
     vrf red
 }
 dummy dum0 {
     address 2606:6d00:19f:a800::2/128
     address 2606:6d00:19f:a800::bbbb/128
     vrf red
 }

and the corresponding dhcpv6c log:

Mar 23 12:27:51 r2 systemd[1]: Starting WIDE DHCPv6 client on pppoe0...
Mar 23 12:27:51 r2 dhcp6c[15235]: get_duid: extracted an existing DUID from /var/lib/dhcpv6/dhcp6c_duid: 00:01:00:01:27:ea:d3:18:00:0d:b9:44:54:30
Mar 23 12:27:51 r2 dhcp6c[15235]: dhcp6_ctl_authinit: failed to open /run/dhcp6c/dhcp6c.pppoe0.sock: No such file or directory
Mar 23 12:27:51 r2 dhcp6c[15235]: client6_init: failed initialize control message authentication
Mar 23 12:27:51 r2 dhcp6c[15235]: client6_init: skip opening control port
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>comment [### Autogenerated by interface.py ###] (37)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>comment [# man https://www.unix.com/man-page/debian/5/dhcp6c.conf/] (57)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[interface] (9)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <5>[pppoe0] (6)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>begin of closure [{] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[send] (4)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[ia-pd] (5)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[0] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 12:27:51 r2 systemd[1]: Started WIDE DHCPv6 client on pppoe0.
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>comment [# prefix delegation #0] (22)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>end of closure [}] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[id-assoc] (8)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <15>[pd] (2)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <15>[0] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <15>begin of closure [{] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[prefix] (6)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[::] (2)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[/] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[56] (2)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>[infinity] (8)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>end of closure [}] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: cfdebug_print: <3>end of sentence [;] (1)
Mar 23 12:27:51 r2 dhcp6c[15235]: configure_pool: called
Mar 23 12:27:51 r2 dhcp6c[15235]: clear_poolconf: called
Mar 23 12:27:51 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=INIT, timeo=0, retrans=373
Mar 23 12:27:52 r2 dhcp6c[15239]: client6_send: a new XID (f350c6) is generated
Mar 23 12:27:52 r2 dhcp6c[15239]: copy_option: set client ID (len 14)
Mar 23 12:27:52 r2 dhcp6c[15239]: copy_option: set elapsed time (len 2)
Mar 23 12:27:52 r2 dhcp6c[15239]: copyout_option: set IA_PD prefix
Mar 23 12:27:52 r2 dhcp6c[15239]: copyout_option: set IA_PD
Mar 23 12:27:52 r2 dhcp6c[15239]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 12:27:52 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=0, retrans=1065
Mar 23 12:27:53 r2 dhcp6c[15239]: copy_option: set client ID (len 14)
Mar 23 12:27:53 r2 dhcp6c[15239]: copy_option: set elapsed time (len 2)
Mar 23 12:27:53 r2 dhcp6c[15239]: copyout_option: set IA_PD prefix
Mar 23 12:27:53 r2 dhcp6c[15239]: copyout_option: set IA_PD
Mar 23 12:27:53 r2 dhcp6c[15239]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 12:27:53 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=1, retrans=2115
Mar 23 12:27:55 r2 dhcp6c[15239]: copy_option: set client ID (len 14)
Mar 23 12:27:55 r2 dhcp6c[15239]: copy_option: set elapsed time (len 2)
Mar 23 12:27:55 r2 dhcp6c[15239]: copyout_option: set IA_PD prefix
Mar 23 12:27:55 r2 dhcp6c[15239]: copyout_option: set IA_PD
Mar 23 12:27:55 r2 dhcp6c[15239]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 12:27:55 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=2, retrans=4142
Mar 23 12:27:59 r2 dhcp6c[15239]: copy_option: set client ID (len 14)
Mar 23 12:27:59 r2 dhcp6c[15239]: copy_option: set elapsed time (len 2)
Mar 23 12:27:59 r2 dhcp6c[15239]: copyout_option: set IA_PD prefix
Mar 23 12:27:59 r2 dhcp6c[15239]: copyout_option: set IA_PD
Mar 23 12:27:59 r2 dhcp6c[15239]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 12:27:59 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=3, retrans=8600
Mar 23 12:28:08 r2 dhcp6c[15239]: copy_option: set client ID (len 14)
Mar 23 12:28:08 r2 dhcp6c[15239]: copy_option: set elapsed time (len 2)
Mar 23 12:28:08 r2 dhcp6c[15239]: copyout_option: set IA_PD prefix
Mar 23 12:28:08 r2 dhcp6c[15239]: copyout_option: set IA_PD
Mar 23 12:28:08 r2 dhcp6c[15239]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 12:28:08 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=4, retrans=17924
Mar 23 12:28:25 r2 dhcp6c[15239]: copy_option: set client ID (len 14)
Mar 23 12:28:25 r2 dhcp6c[15239]: copy_option: set elapsed time (len 2)
Mar 23 12:28:25 r2 dhcp6c[15239]: copyout_option: set IA_PD prefix
Mar 23 12:28:25 r2 dhcp6c[15239]: copyout_option: set IA_PD
Mar 23 12:28:25 r2 dhcp6c[15239]: client6_send: send solicit to ff02::1:2%pppoe0
Mar 23 12:28:25 r2 dhcp6c[15239]: dhcp6_reset_timer: reset a timer on pppoe0, state=SOLICIT, timeo=5, retrans=37489
r2:~$ show interfaces
Codes: S - State, L - Link, u - Up, D - Down, A - Admin Down
Interface        IP Address                        S/L  Description
---------        ----------                        ---  -----------
eth1             -                                 u/u  WAN
eth1.35          -                                 u/u  DSL-1
pppoe0           74.116.186.154/32                 u/u  PPPOE-1
                 2606:6d00:15:5cc4:106:12bb:e97d:fc4d/64
r2:~$ ping 8.8.8.8 vrf red
PING 8.8.8.8 (8.8.8.8) 56(84) bytes of data.
64 bytes from 8.8.8.8: icmp_seq=1 ttl=121 time=11.5 ms
64 bytes from 8.8.8.8: icmp_seq=2 ttl=121 time=11.8 ms
64 bytes from 8.8.8.8: icmp_seq=3 ttl=121 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=4 ttl=121 time=11.9 ms
^C
--- 8.8.8.8 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 8ms
rtt min/avg/max/mdev = 11.529/11.710/11.865/0.133 ms
r2:~$ ping 8.8.8.8 interface pppoe0
PING 8.8.8.8 (8.8.8.8) from 74.116.186.154 pppoe0: 56(84) bytes of data.
64 bytes from 8.8.8.8: icmp_seq=1 ttl=121 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=2 ttl=121 time=12.0 ms
^C
--- 8.8.8.8 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 2ms
rtt min/avg/max/mdev = 11.642/11.828/12.015/0.215 ms

So, PPPoE connection works but /56 subnet seems not allocated.

BTW, it would be nice to report any IA-PD allocations in the output of show interfaces... but this is a topic for a separate ticket.

Details

Difficulty level
Unknown (require assessment)
Version
VyOS 1.4-rolling-202103220217
Why the issue appeared?
Will be filled on close
Is it a breaking change?
Unspecified (possibly destroys the router)

Event Timeline

dtoux created this object in space S1 VyOS Public.

This is an interesting use-case and will not work as of now.

Reason is that the PPPoE interface runs in vrf "red" and dhcpc6 which is the userspace helper for PD will run in vrf "default" and thus has no way in reaching the ISP.