Page MenuHomeVyOS Platform
Create Task
Maniphest T5934

pppoe dhcp6c fails to get prefix
Needs reporter action, NormalPublicBUG
Actions

Description

My ISP (Orange Poland) supports IPv6 through DS-Lite. I don't really care about the v4 part of that, i'm just trying to get a v6 PD working on a separate, second pppoe session. However, it seems that dhcp6c is having some kind of a problem.

Relevant config:

set interfaces pppoe pppoe1 description 'WAN - Fiber v6'
set interfaces pppoe pppoe1 source-interface 'eth0.35'
set interfaces pppoe pppoe1 authentication user "${SECRET_ISP_AUTH_USER}/ipv6"
set interfaces pppoe pppoe1 authentication password "${SECRET_ISP_AUTH_PASSWORD}"
set interfaces pppoe pppoe1 ipv6 address 'autoconf'
set interfaces pppoe pppoe1 dhcpv6-options pd 0 interface br0.5 address '1'
set interfaces pppoe pppoe1 dhcpv6-options pd 0 interface br0.5 sla-id '0'
set interfaces pppoe pppoe1 dhcpv6-options pd 0 length '56'
set interfaces pppoe pppoe1 mtu '1500'
set interfaces pppoe pppoe1 mru '1500'
set interfaces pppoe pppoe1 'no-default-route'

And the log output, pppd seems fine

Jan 13 23:48:02 vyos pppd[157188]: Plugin rp-pppoe.so loaded.
Jan 13 23:48:02 vyos pppd[157188]: Plugin rp-pppoe.so loaded.
Jan 13 23:48:02 vyos pppd[157188]: pppd 2.4.9 started by root, uid 0
Jan 13 23:48:02 vyos pppd[157188]: Send PPPOE Discovery V1T1 PADI session 0x0 length 18
Jan 13 23:48:02 vyos pppd[157188]:  dst ff:ff:ff:ff:ff:ff  src 00:f0:da:ef:0a:d8
Jan 13 23:48:02 vyos pppd[157188]:  [service-name] [host-uniq  04 66 02 00] [PPP-max-payload  05 dc]
Jan 13 23:48:03 vyos pppd[157188]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 56
Jan 13 23:48:03 vyos pppd[157188]:  dst 00:f0:da:ef:0a:d8  src ec:38:73:c8:c7:82
Jan 13 23:48:03 vyos pppd[157188]:  [AC-name war_bng102_re0] [host-uniq  04 66 02 00] [PPP-max-payload  05 dc] [service-name] [AC-cookie  73 fe 2f 81 e1 0f 8e a2 d0 f1 99 09 b9 d2 76 9e]
Jan 13 23:48:03 vyos pppd[157188]: Send PPPOE Discovery V1T1 PADR session 0x0 length 38
Jan 13 23:48:03 vyos pppd[157188]:  dst ec:38:73:c8:c7:82  src 00:f0:da:ef:0a:d8
Jan 13 23:48:03 vyos pppd[157188]:  [service-name] [host-uniq  04 66 02 00] [PPP-max-payload  05 dc] [AC-cookie  73 fe 2f 81 e1 0f 8e a2 d0 f1 99 09 b9 d2 76 9e]
Jan 13 23:48:03 vyos pppd[157188]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 56
Jan 13 23:48:03 vyos pppd[157188]:  dst 00:f0:da:ef:0a:d8  src ec:38:73:c8:c7:83
Jan 13 23:48:03 vyos pppd[157188]:  [AC-name war_bng102_re0] [host-uniq  04 66 02 00] [PPP-max-payload  05 dc] [service-name] [AC-cookie  73 fe 2f 81 e1 0f 8e a2 d0 f1 99 09 b9 d2 76 9e]
Jan 13 23:48:03 vyos pppd[157188]: Recv PPPOE Discovery V1T1 PADS session 0x3058 length 56
Jan 13 23:48:03 vyos pppd[157188]:  dst 00:f0:da:ef:0a:d8  src ec:38:73:c8:c7:82
Jan 13 23:48:03 vyos pppd[157188]:  [service-name] [host-uniq  04 66 02 00] [PPP-max-payload  05 dc] [AC-name war_bng102_re0] [AC-cookie  73 fe 2f 81 e1 0f 8e a2 d0 f1 99 09 b9 d2 76 9e]
Jan 13 23:48:03 vyos pppd[157188]: PADS: Service-Name: ''
Jan 13 23:48:03 vyos pppd[157188]: PPP session is 12376
Jan 13 23:48:03 vyos pppd[157188]: Connected to ec:38:73:c8:c7:82 via interface eth0.35
Jan 13 23:48:03 vyos pppd[157188]: using channel 27
Jan 13 23:48:03 vyos pppd[157188]: Renamed interface ppp1 to pppoe1
Jan 13 23:48:03 vyos pppd[157188]: Using interface pppoe1
Jan 13 23:48:03 vyos pppd[157188]: Connect: pppoe1 <--> eth0.35
Jan 13 23:48:03 vyos pppd[157188]: sent [LCP ConfReq id=0x1 <magic 0x22881956>]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [LCP ConfReq id=0x31 <auth chap MD5> <magic 0x3d45f422>]
Jan 13 23:48:03 vyos pppd[157188]: sent [LCP ConfAck id=0x31 <auth chap MD5> <magic 0x3d45f422>]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [LCP ConfAck id=0x1 <magic 0x22881956>]
Jan 13 23:48:03 vyos pppd[157188]: sent [LCP EchoReq id=0x0 magic=0x22881956]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [LCP EchoRep id=0x0 magic=0x3d45f422]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [CHAP Challenge id=0xb1 <e50bf4b12e8e699a34ebaf4dbb738a47f6aa2edb6f39c9338ed1f0e0f4>, name = "JUNOS"]
Jan 13 23:48:03 vyos pppd[157188]: sent [CHAP Response id=0xb1 <14a3f3b0d67c79696efbc13f7a4b6c70>, name = "XXXXXXX/ipv6"]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [CHAP Success id=0xb1 "session created in USS with key in new format"]
Jan 13 23:48:03 vyos pppd[157188]: CHAP authentication succeeded: session created in USS with key in new format
Jan 13 23:48:03 vyos pppd[157188]: CHAP authentication succeeded
Jan 13 23:48:03 vyos pppd[157188]: peer from calling number EC:38:73:C8:C7:82 authorized
Jan 13 23:48:03 vyos pppd[157188]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jan 13 23:48:03 vyos pppd[157188]: sent [IPV6CP ConfReq id=0x1 <addr fe80::c579:e12e:399b:47dd>]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [LCP ProtRej id=0x32 80 21 01 01 00 16 03 06 00 00 00 00 81 06 00 00 00 00 83 06 00 00 00 00]
Jan 13 23:48:03 vyos pppd[157188]: Protocol-Reject for 'Internet Protocol Control Protocol' (0x8021) received
Jan 13 23:48:03 vyos pppd[157188]: rcvd [IPV6CP ConfReq id=0x51 <addr fe80::ee38:73ff:fec8:c782>]
Jan 13 23:48:03 vyos pppd[157188]: sent [IPV6CP ConfAck id=0x51 <addr fe80::ee38:73ff:fec8:c782>]
Jan 13 23:48:03 vyos pppd[157188]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::c579:e12e:399b:47dd>]
Jan 13 23:48:03 vyos pppd[157188]: local  LL address fe80::c579:e12e:399b:47dd
Jan 13 23:48:03 vyos pppd[157188]: remote LL address fe80::ee38:73ff:fec8:c782
Jan 13 23:48:03 vyos pppd[157188]: Script /etc/ppp/ipv6-up started (pid 157227)
Jan 13 23:48:03 vyos pppd[157188]: Script /etc/ppp/ipv6-up finished (pid 157227), status = 0x0

But dhcp6c does not

Jan 13 23:48:37 vyos dhcp6c[157601]: get_duid: extracted an existing DUID from /var/lib/dhcpv6/dhcp6c_duid: 00:04:03:00:02:00:04:00:05:00:00:06:00:07:00:08:00:09
Jan 13 23:48:37 vyos dhcp6c[157601]: dhcp6_ctl_authinit: failed to open /run/dhcp6c/dhcp6c.pppoe1.sock: No such file or directory
Jan 13 23:48:37 vyos dhcp6c[157601]: client6_init: failed initialize control message authentication
Jan 13 23:48:37 vyos dhcp6c[157601]: client6_init: skip opening control port
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>comment [### Autogenerated by interface.py ###] (37)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>comment [# man https://www.unix.com/man-page/debian/5/dhcp6c.conf/] (57)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[interface] (9)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <5>[pppoe1] (6)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>begin of closure [{] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[send] (4)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[ia-pd] (5)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[0] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>comment [# prefix delegation #0] (22)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of closure [}] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[id-assoc] (8)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <15>[pd] (2)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <15>[0] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <15>begin of closure [{] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[prefix] (6)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[::] (2)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[/] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[64] (2)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[infinity] (8)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[prefix-interface] (16)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <5>[br0.5] (5)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>begin of closure [{] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[sla-len] (7)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[0] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[sla-id] (6)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[0] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[ifid] (4)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>[2] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of closure [}] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of closure [}] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: cfdebug_print: <3>end of sentence [;] (1)
Jan 13 23:48:37 vyos dhcp6c[157601]: configure_pool: called
Jan 13 23:48:37 vyos dhcp6c[157601]: clear_poolconf: called
Jan 13 23:48:37 vyos dhcp6c[157603]: dhcp6_reset_timer: reset a timer on pppoe1, state=INIT, timeo=0, retrans=383
Jan 13 23:48:37 vyos dhcp6c[157603]: client6_send: a new XID (a5326e) is generated
Jan 13 23:48:37 vyos dhcp6c[157603]: copy_option: set client ID (len 18)
Jan 13 23:48:37 vyos dhcp6c[157603]: copy_option: set elapsed time (len 2)
Jan 13 23:48:37 vyos dhcp6c[157603]: copyout_option: set IA_PD prefix
Jan 13 23:48:37 vyos dhcp6c[157603]: copyout_option: set IA_PD
Jan 13 23:48:37 vyos dhcp6c[157603]: client6_send: transmit failed: Operation not permitted
Jan 13 23:48:37 vyos dhcp6c[157603]: dhcp6_reset_timer: reset a timer on pppoe1, state=SOLICIT, timeo=0, retrans=1088
Jan 13 23:48:38 vyos dhcp6c[157603]: copy_option: set client ID (len 18)
Jan 13 23:48:38 vyos dhcp6c[157603]: copy_option: set elapsed time (len 2)
Jan 13 23:48:38 vyos dhcp6c[157603]: copyout_option: set IA_PD prefix
Jan 13 23:48:38 vyos dhcp6c[157603]: copyout_option: set IA_PD
Jan 13 23:48:38 vyos dhcp6c[157603]: client6_send: transmit failed: Operation not permitted
Jan 13 23:48:38 vyos dhcp6c[157603]: dhcp6_reset_timer: reset a timer on pppoe1, state=SOLICIT, timeo=1, retrans=2151
Jan 13 23:48:40 vyos dhcp6c[157603]: copy_option: set client ID (len 18)
Jan 13 23:48:40 vyos dhcp6c[157603]: copy_option: set elapsed time (len 2)
Jan 13 23:48:40 vyos dhcp6c[157603]: copyout_option: set IA_PD prefix
Jan 13 23:48:40 vyos dhcp6c[157603]: copyout_option: set IA_PD
Jan 13 23:48:40 vyos dhcp6c[157603]: client6_send: transmit failed: Operation not permitted
Jan 13 23:48:40 vyos dhcp6c[157603]: dhcp6_reset_timer: reset a timer on pppoe1, state=SOLICIT, timeo=2, retrans=4283
Jan 13 23:48:45 vyos dhcp6c[157603]: copy_option: set client ID (len 18)
Jan 13 23:48:45 vyos dhcp6c[157603]: copy_option: set elapsed time (len 2)
Jan 13 23:48:45 vyos dhcp6c[157603]: copyout_option: set IA_PD prefix
Jan 13 23:48:45 vyos dhcp6c[157603]: copyout_option: set IA_PD
Jan 13 23:48:45 vyos dhcp6c[157603]: client6_send: transmit failed: Operation not permitted
Jan 13 23:48:45 vyos dhcp6c[157603]: dhcp6_reset_timer: reset a timer on pppoe1, state=SOLICIT, timeo=3, retrans=8905
Jan 13 23:48:48 vyos dhcp6c[157603]: dhcp6_remove_event: removing an event on pppoe1, state=SOLICIT

In addition, dhcp6c does NOT want to run automatically once pppd does it's thing. I always have to nudge it manually by changing any v6 option to actually make it run. This is possibly because the /etc/ppp/ip-up.d99-vyos-pppoe-callback hook does not run in this case, this being a pure v6 connection. Naively copying it to ipv6-up.d fixes that problem

Details

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

Event Timeline

anonuser35hww45 created this task.Jan 13 2024, 10:59 PM
anonuser35hww45 renamed this task from pppoe dhcp6c fails to get prefix to pppoe dhcp6c fails to get prefix and kills of wan connection.Jan 13 2024, 11:05 PM
anonuser35hww45 renamed this task from pppoe dhcp6c fails to get prefix and kills of wan connection to pppoe dhcp6c fails to get prefix.
anonuser35hww45 updated the task description. (Show Details)
anonuser35hww45 updated the task description. (Show Details)
anonuser35hww45 updated the task description. (Show Details)Jan 13 2024, 11:08 PM
Viacheslav triaged this task as Normal priority.Jan 14 2024, 10:12 AM
anonuser35hww45 updated the task description. (Show Details)Jan 14 2024, 10:54 AM
Viacheslav added a subscriber: Viacheslav.Jan 14 2024, 11:11 AM

Always use "set commands" to make it easier for developers to reproduce it.

anonuser35hww45 updated the task description. (Show Details)Jan 14 2024, 11:30 AM

@Viacheslav sure, updated the OP

dmbaturin edited projects, added VyOS 1.4 Sagitta (1.4.0-epa1); removed VyOS 1.4 Sagitta.Feb 15 2024, 5:37 PM
c-po added a subscriber: c-po.Feb 16 2024, 11:45 AM

client6_send: transmit failed: Operation not permitted

Do you run a firewall in the system? You should allow all necessary ICMPv6 options, please try without the firewall if it is still an issue

c-po changed the task status from Open to Needs reporter action.Feb 16 2024, 11:45 AM
c-po claimed this task.
anonuser35hww45 added a comment.Feb 16 2024, 1:54 PM

@c-po As it relates to v6, no, i have no nothing

vyos@gateway# show firewall ipv6 
Configuration under specified path is empty
[edit]
Viacheslav added a comment.Feb 16 2024, 2:19 PM

I'd delete the whole firewall configuration, at least for test.

anonuser35hww45 added a comment.Feb 16 2024, 2:38 PM

Including v4?

c-po added a comment.Feb 17 2024, 9:00 AM

Yes please - just to rule this out