L2TP/IPSec broken in latest rolling release
Closed, ResolvedPublicBUG
Actions

Assigned To

Authored By

	c-po
	Sep 2 2018, 2:31 PM

Description

Sep  2 16:28:20 AC1 systemd[1]: Startup finished in 10.843s (kernel) + 36.601s (userspace) = 47.445s.
Sep  2 16:28:44 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:28:44 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:28:45 AC1 charon: 16[NET] received packet: from 188.193.xxx.xxx[500] to 46.38.xxx.xxx[500] (788 bytes)
Sep  2 16:28:45 AC1 charon: 16[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V V V ]
Sep  2 16:28:45 AC1 charon: 16[IKE] received NAT-T (RFC 3947) vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-08 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-07 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-06 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-05 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-04 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received FRAGMENTATION vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] received DPD vendor ID
Sep  2 16:28:45 AC1 charon: 16[IKE] 188.193.xxx.xxx is initiating a Main Mode IKE_SA
Sep  2 16:28:45 AC1 charon: 16[ENC] generating ID_PROT response 0 [ SA V V V V ]
Sep  2 16:28:45 AC1 charon: 16[NET] sending packet: from 46.38.xxx.xxx[500] to 188.193.xxx.xxx[500] (160 bytes)
Sep  2 16:28:45 AC1 charon: 10[NET] received packet: from 188.193.xxx.xxx[500] to 46.38.xxx.xxx[500] (228 bytes)
Sep  2 16:28:45 AC1 charon: 10[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Sep  2 16:28:45 AC1 charon: 10[IKE] remote host is behind NAT
Sep  2 16:28:45 AC1 charon: 10[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Sep  2 16:28:45 AC1 charon: 10[NET] sending packet: from 46.38.xxx.xxx[500] to 188.193.xxx.xxx[500] (244 bytes)
Sep  2 16:28:46 AC1 charon: 12[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (108 bytes)
Sep  2 16:28:46 AC1 charon: 12[ENC] parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Sep  2 16:28:46 AC1 charon: 12[CFG] looking for pre-shared key peer configs matching 46.38.xxx.xxx...188.193.xxx.xxx[172.16.30.115]
Sep  2 16:28:46 AC1 charon: 12[CFG] selected peer config "vpnprof-dmvpn-tun100"
Sep  2 16:28:46 AC1 charon: 12[IKE] IKE_SA vpnprof-dmvpn-tun100[1] established between 46.38.xxx.xxx[46.38.xxx.xxx]...188.193.xxx.xxx[172.16.30.115]
Sep  2 16:28:46 AC1 charon: 12[IKE] scheduling rekeying in 3435s
Sep  2 16:28:46 AC1 charon: 12[IKE] maximum IKE_SA lifetime 3795s
Sep  2 16:28:46 AC1 charon: 12[ENC] generating ID_PROT response 0 [ ID HASH ]
Sep  2 16:28:46 AC1 charon: 12[NET] sending packet: from 46.38.xxx.xxx[4500] to 188.193.xxx.xxx[4500] (76 bytes)
Sep  2 16:28:46 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:28:46 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:28:46 AC1 charon: 15[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:28:46 AC1 charon: 15[ENC] parsed QUICK_MODE request 4028766595 [ HASH SA No ID ID NAT-OA NAT-OA ]
Sep  2 16:28:46 AC1 charon: 15[IKE] no matching CHILD_SA config found
Sep  2 16:28:46 AC1 charon: 15[ENC] generating INFORMATIONAL_V1 request 3927061117 [ HASH N(INVAL_ID) ]
Sep  2 16:28:46 AC1 charon: 15[NET] sending packet: from 46.38.xxx.xxx[4500] to 188.193.xxx.xxx[4500] (76 bytes)
Sep  2 16:28:50 AC1 charon: 07[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:28:50 AC1 charon: 07[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:28:50 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:28:50 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:28:53 AC1 charon: 05[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:28:53 AC1 charon: 05[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:28:54 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:28:54 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:28:56 AC1 charon: 12[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:28:56 AC1 charon: 12[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:28:58 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:28:58 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:29:00 AC1 charon: 09[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:29:00 AC1 charon: 09[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:29:02 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:29:02 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:29:03 AC1 charon: 05[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:29:03 AC1 charon: 05[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:29:06 AC1 charon: 06[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:29:06 AC1 charon: 06[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:29:06 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:29:06 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:29:09 AC1 charon: 10[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:29:09 AC1 charon: 10[IKE] received retransmit of request with ID 4028766595, but no response to retransmit
Sep  2 16:29:10 AC1 xl2tpd[2814]: Can not find tunnel 23646 (refhim=0)
Sep  2 16:29:10 AC1 xl2tpd[2814]: network_thread: unable to find call or tunnel to handle packet.  call = 21162, tunnel = 23646 Dumping.
Sep  2 16:29:13 AC1 charon: 16[NET] received packet: from 188.193.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (316 bytes)
Sep  2 16:29:13 AC1 charon: 16[IKE] received retransmit of request with ID 4028766595, but no response to retransmit

It is working in:

cpo@AC1:~$ show version
Version:          VyOS 1.2.0-rolling+201808212334

Kernel

cpo@AC1:~$ uname -a
Linux AC1.x 4.18.0-amd64-vyos #1 SMP Tue Aug 21 22:43:29 CEST 2018 x86_64 GNU/Linux

Details

Difficulty level: Hard (possibly days)
Version: 1.2.0-rolling+201809020337
Why the issue appeared?: Other

Event Timeline

c-po created this task.Sep 2 2018, 2:31 PM

c-po updated the task description. (Show Details)Sep 2 2018, 2:34 PM

c-po updated the task description. (Show Details)Sep 2 2018, 2:50 PM

c-po triaged this task as High priority.Sep 2 2018, 2:52 PM

c-po edited projects, added VyOS 1.2 Crux (VyOS 1.2.0-rc1); removed VyOS 1.2 Crux.

c-po changed Difficulty level from Unknown (require assessment) to Normal (likely a few hours).

c-po edited projects, added VyOS 1.2 Crux; removed VyOS 1.2 Crux (VyOS 1.2.0-rc1).

Issue was introduced between those two images:

1.2.0-rolling+201809021626 (bad)
1.2.0-rolling+201808310337 (bad)
1.2.0-rolling+201808271913 (good)

masterit added a subscriber: masterit.Sep 7 2018, 6:38 AM

Okay, I narrowed it down even further:

not working 1.2.0-rolling+201808271019
    working 1.2.0-rolling+201808230337

I even have a images based on 1.2.0-rolling+201808230337 codebase but already with Linux 4.18 so the Kernel change seems not to be an issue.

After a successfull connection I see the spawned process:

root      2595  0.0  0.0   4332   124 pts/1    Ss+  22:58   0:00 /usr/sbin/xl2tpd
root      2868  0.5  0.2  26108  2484 pts/1    S+   22:59   0:00  \_ /usr/sbin/pppd passive nodetach 10.255.255.0:172.16.222.1 refuse-pap auth name VyattaL2TPServer debug file /etc/ppp/options.xl2tpd /dev/pts/1

and shows this log:

Sep  7 22:59:24 AC1 charon: 12[NET] received packet: from 46.84.xxx.xxx[500] to 46.38.xxx.xxx[500] (788 bytes)
Sep  7 22:59:24 AC1 charon: 12[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V V V ]
Sep  7 22:59:24 AC1 charon: 12[IKE] received NAT-T (RFC 3947) vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-08 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-07 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-06 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-05 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-04 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received FRAGMENTATION vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] received DPD vendor ID
Sep  7 22:59:24 AC1 charon: 12[IKE] 46.84.xxx.xxx is initiating a Main Mode IKE_SA
Sep  7 22:59:24 AC1 charon: 12[ENC] generating ID_PROT response 0 [ SA V V V V ]
Sep  7 22:59:24 AC1 charon: 12[NET] sending packet: from 46.38.xxx.xxx[500] to 46.84.xxx.xxx[500] (156 bytes)
Sep  7 22:59:24 AC1 charon: 05[NET] received packet: from 46.84.xxx.xxx[500] to 46.38.xxx.xxx[500] (228 bytes)
Sep  7 22:59:24 AC1 charon: 05[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Sep  7 22:59:24 AC1 charon: 05[IKE] remote host is behind NAT
Sep  7 22:59:24 AC1 charon: 05[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Sep  7 22:59:24 AC1 charon: 05[NET] sending packet: from 46.38.xxx.xxx[500] to 46.84.xxx.xxx[500] (244 bytes)
Sep  7 22:59:24 AC1 charon: 15[NET] received packet: from 46.84.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (100 bytes)
Sep  7 22:59:24 AC1 charon: 15[ENC] parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Sep  7 22:59:24 AC1 charon: 15[CFG] looking for pre-shared key peer configs matching 46.38.xxx.xxx...46.84.xxx.xxx[192.168.100.53]
Sep  7 22:59:24 AC1 charon: 15[CFG] selected peer config "remote-access-win-aaa"
Sep  7 22:59:24 AC1 charon: 15[IKE] IKE_SA remote-access-win-aaa[1] established between 46.38.xxx.xxx[46.38.xxx.xxx]...46.84.xxx.xxx[192.168.100.53]
Sep  7 22:59:24 AC1 charon: 15[ENC] generating ID_PROT response 0 [ ID HASH ]
Sep  7 22:59:24 AC1 charon: 15[NET] sending packet: from 46.38.xxx.xxx[4500] to 46.84.xxx.xxx[4500] (68 bytes)
Sep  7 22:59:25 AC1 charon: 10[NET] received packet: from 46.84.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (308 bytes)
Sep  7 22:59:25 AC1 charon: 10[ENC] parsed QUICK_MODE request 3497402913 [ HASH SA No ID ID NAT-OA NAT-OA ]
Sep  7 22:59:25 AC1 charon: 10[IKE] received 3600s lifetime, configured 0s
Sep  7 22:59:25 AC1 charon: 10[ENC] generating QUICK_MODE response 3497402913 [ HASH SA No ID ID NAT-OA NAT-OA ]
Sep  7 22:59:25 AC1 charon: 10[NET] sending packet: from 46.38.xxx.xxx[4500] to 46.84.xxx.xxx[4500] (196 bytes)
Sep  7 22:59:25 AC1 charon: 16[NET] received packet: from 46.84.xxx.xxx[4500] to 46.38.xxx.xxx[4500] (60 bytes)
Sep  7 22:59:25 AC1 charon: 16[ENC] parsed QUICK_MODE request 3497402913 [ HASH ]
Sep  7 22:59:25 AC1 charon: 16[IKE] CHILD_SA remote-access-mac-zzz{1} established with SPIs c3de5ac0_i 08a0781d_o and TS 46.38.xxx.xxx/32[udp/l2f] === 46.84.xxx.xxx/32[udp/51760]
Sep  7 22:59:26 AC1 xl2tpd[2595]: Connection established to 46.84.xxx.xxx, 51760.  Local: 8133, Remote: 42 (ref=0/0).  LNS session is 'default'
Sep  7 22:59:26 AC1 xl2tpd[2595]: start_pppd: I'm running:
Sep  7 22:59:26 AC1 xl2tpd[2595]: "/usr/sbin/pppd"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "passive"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "nodetach"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "10.255.255.0:172.16.222.1"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "refuse-pap"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "auth"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "name"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "VyattaL2TPServer"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "debug"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "file"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "/etc/ppp/options.xl2tpd"
Sep  7 22:59:26 AC1 xl2tpd[2595]: "/dev/pts/1"
Sep  7 22:59:26 AC1 xl2tpd[2595]: Call established with 46.84.xxx.xxx, Local: 36442, Remote: 11729, Serial: 1
Sep  7 22:59:26 AC1 pppd[2868]: Plugin radius.so loaded.
Sep  7 22:59:26 AC1 pppd[2868]: RADIUS plugin initialized.
Sep  7 22:59:26 AC1 pppd[2868]: Plugin radattr.so loaded.
Sep  7 22:59:26 AC1 pppd[2868]: RADATTR plugin initialized.
Sep  7 22:59:26 AC1 pppd[2868]: pppd 2.4.7 started by root, uid 0
Sep  7 22:59:26 AC1 pppd[2868]: using channel 1
Sep  7 22:59:26 AC1 pppd[2868]: Using interface ppp0
Sep  7 22:59:26 AC1 pppd[2868]: Connect: ppp0 <--> /dev/pts/1
Sep  7 22:59:26 AC1 pppd[2868]: sent [LCP ConfReq id=0x1 <mru 1400> <asyncmap 0x0> <auth eap> <magic 0x47ac96a2> <pcomp> <accomp>]
Sep  7 22:59:26 AC1 systemd-sysctl[2875]: Overwriting earlier assignment of net/core/rmem_max in file '/etc/sysctl.d/99-sysctl.conf'.
Sep  7 22:59:26 AC1 pppd[2868]: rcvd [LCP ConfNak id=0x1 <auth chap MS-v2>]
Sep  7 22:59:26 AC1 pppd[2868]: sent [LCP ConfReq id=0x2 <mru 1400> <asyncmap 0x0> <auth chap MS-v2> <magic 0x47ac96a2> <pcomp> <accomp>]
Sep  7 22:59:26 AC1 pppd[2868]: rcvd [LCP ConfAck id=0x2 <mru 1400> <asyncmap 0x0> <auth chap MS-v2> <magic 0x47ac96a2> <pcomp> <accomp>]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x2bba4d61> <pcomp> <accomp>]
Sep  7 22:59:29 AC1 pppd[2868]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x2bba4d61> <pcomp> <accomp>]
Sep  7 22:59:29 AC1 pppd[2868]: sent [CHAP Challenge id=0x36 <>, name = "xl2tpd"]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [LCP EchoReq id=0x0 magic=0x2bba4d61]
Sep  7 22:59:29 AC1 pppd[2868]: sent [LCP EchoRep id=0x0 magic=0x47ac96a2]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [CHAP Response id=0x36 <>, name = "xxx"]
Sep  7 22:59:29 AC1 pppd[2868]: RADATTR plugin wrote 9 line(s) to file /var/run/radattr.ppp0.
Sep  7 22:59:29 AC1 pppd[2868]: sent [CHAP Success id=0x36 "S=xxxxxxxxxx"]
Sep  7 22:59:29 AC1 pppd[2868]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 10.255.255.0>]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Sep  7 22:59:29 AC1 pppd[2868]: sent [IPCP ConfNak id=0x1 <addr 172.16.222.1> <ms-dns1 172.16.254.31> <ms-dns2 172.16.254.32>]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [IPV6CP ConfReq id=0x1 <addr fe80::0ceb:e023:f9a4:c341>]
Sep  7 22:59:29 AC1 pppd[2868]: Unsupported protocol 'IPv6 Control Protocol' (0x8057) received
Sep  7 22:59:29 AC1 pppd[2868]: sent [LCP ProtRej id=0x3 80 57 01 01 00 0e 01 0a 0c eb e0 23 f9 a4 c3 41]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
Sep  7 22:59:29 AC1 pppd[2868]: sent [IPCP ConfReq id=0x2 <addr 10.255.255.0>]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [IPCP ConfReq id=0x2 <addr 172.16.222.1> <ms-dns1 172.16.254.31> <ms-dns2 172.16.254.32>]
Sep  7 22:59:29 AC1 pppd[2868]: sent [IPCP ConfAck id=0x2 <addr 172.16.222.1> <ms-dns1 172.16.254.31> <ms-dns2 172.16.254.32>]
Sep  7 22:59:29 AC1 pppd[2868]: rcvd [IPCP ConfAck id=0x2 <addr 10.255.255.0>]
Sep  7 22:59:29 AC1 pppd[2868]: Script /etc/ppp/ip-pre-up started (pid 2876)
Sep  7 22:59:29 AC1 pppd[2868]: Script /etc/ppp/ip-pre-up finished (pid 2876), status = 0x0
Sep  7 22:59:29 AC1 pppd[2868]: Cannot determine ethernet address for proxy ARP
Sep  7 22:59:29 AC1 pppd[2868]: local  IP address 10.255.255.0
Sep  7 22:59:29 AC1 pppd[2868]: remote IP address 172.16.222.1
Sep  7 22:59:29 AC1 pppd[2868]: Script /etc/ppp/ip-up started (pid 2916)

Do you have a copy of 1.2.0-rolling+201808230337 to share? I'd like to get wireguard working, but need L2TP working as well. It's no longer on the download page.

There you go: http://www.mybll.net/vyos-1.2.0-rolling+201808230337-amd64.iso

This is whats happening when we add L2TP/vpn configurtion and do a commit:

Sep 11 18:26:30 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/usr/libexec/vyos/conf_mode/ipsec-settings.py
Sep 11 18:26:30 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:30 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:30 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/opt/vyatta/sbin/vyatta-vti-config.pl
Sep 11 18:26:30 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:30 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:30 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/opt/vyatta/sbin/vpn-config.pl --config_file=/etc/ipsec.conf --secrets_file=/etc/ipsec.secrets --init_script=/etc/init.d/ipsec
Sep 11 18:26:30 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:31 LR1 charon: 00[DMN] signal of type SIGINT received. Shutting down
Sep 11 18:26:31 LR1 ipsec_starter[5750]: charon stopped after 200 ms
Sep 11 18:26:31 LR1 ipsec_starter[5750]: ipsec starter stopped
Sep 11 18:26:33 LR1 ipsec_starter[6095]: Starting strongSwan 5.6.2 IPsec [starter]...
Sep 11 18:26:33 LR1 ipsec_starter[6095]: # deprecated keyword 'nat_traversal' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6095]: # deprecated keyword 'virtual_private' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6095]: ### 2 parsing errors (0 fatal) ###
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:33 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/opt/vyatta/sbin/dmvpn-config.pl --config_file=/etc/swanctl/swanctl.conf --init_script=/etc/init.d/ipsec
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:33 LR1 charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.6.2, Linux 4.18.4-amd64-vyos, x86_64)
Sep 11 18:26:33 LR1 charon: 00[CFG] PKCS11 module '<name>' lacks library path
Sep 11 18:26:33 LR1 charon: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Sep 11 18:26:33 LR1 charon: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Sep 11 18:26:33 LR1 charon: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Sep 11 18:26:33 LR1 charon: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Sep 11 18:26:33 LR1 charon: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Sep 11 18:26:33 LR1 charon: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Sep 11 18:26:33 LR1 charon: 00[CFG] loaded 0 RADIUS server configurations
Sep 11 18:26:33 LR1 charon: 00[CFG] HA config misses local/remote address
Sep 11 18:26:33 LR1 charon: 00[LIB] loaded plugins: charon test-vectors ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md5 mgf1 rdrand random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent xcbc cmac hmac ctr ccm gcm curl attr kernel-netlink resolve socket-default connmark farp stroke vici updown eap-identity eap-aka eap-md5 eap-gtc eap-mschapv2 eap-radius eap-tls eap-ttls eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs dhcp lookip error-notify certexpire led addrblock counters
Sep 11 18:26:33 LR1 charon: 00[LIB] dropped capabilities, running as uid 0, gid 0
Sep 11 18:26:33 LR1 charon: 00[JOB] spawning 16 worker threads
Sep 11 18:26:33 LR1 ipsec_starter[6113]: charon (6115) started after 60 ms
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading secrets
Sep 11 18:26:33 LR1 charon: 05[CFG] loading secrets from '/etc/ipsec.secrets'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading ca certificates from '/etc/ipsec.d/cacerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading aa certificates from '/etc/ipsec.d/aacerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading attribute certificates from '/etc/ipsec.d/acerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading crls from '/etc/ipsec.d/crls'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'nat_traversal' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'virtual_private' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6113]: ### 2 parsing errors (0 fatal) ###
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:33 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/opt/vyatta/sbin/vyos-update-nhrp.pl --set_ipsec
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:33 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/opt/vyatta/sbin/vyatta-update-l2tp.pl
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:33 LR1 charon: 10[CFG] rereading secrets
Sep 11 18:26:33 LR1 charon: 10[CFG] loading secrets from '/etc/ipsec.secrets'
Sep 11 18:26:33 LR1 charon: 10[CFG]   loaded IKE secret for 172.16.34.1 %any
Sep 11 18:26:33 LR1 charon: 10[CFG] rereading ca certificates from '/etc/ipsec.d/cacerts'
Sep 11 18:26:33 LR1 charon: 10[CFG] rereading aa certificates from '/etc/ipsec.d/aacerts'
Sep 11 18:26:33 LR1 charon: 10[CFG] rereading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Sep 11 18:26:33 LR1 charon: 10[CFG] rereading attribute certificates from '/etc/ipsec.d/acerts'
Sep 11 18:26:33 LR1 charon: 10[CFG] rereading crls from '/etc/ipsec.d/crls'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'nat_traversal' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'virtual_private' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'leftnexthop' in conn 'remote-access-win-aaa'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'pfs' in conn 'remote-access-win-aaa'
Sep 11 18:26:33 LR1 ipsec_starter[6113]:   PFS is enabled by specifying a DH group in the 'esp' cipher suite
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'leftnexthop' in conn 'remote-access-mac-zzz'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'pfs' in conn 'remote-access-mac-zzz'
Sep 11 18:26:33 LR1 ipsec_starter[6113]:   PFS is enabled by specifying a DH group in the 'esp' cipher suite
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'leftnexthop' in conn 'remote-access'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'pfs' in conn 'remote-access'
Sep 11 18:26:33 LR1 ipsec_starter[6113]:   PFS is enabled by specifying a DH group in the 'esp' cipher suite
Sep 11 18:26:33 LR1 ipsec_starter[6113]: ### 8 parsing errors (0 fatal) ###
Sep 11 18:26:33 LR1 charon: 12[CFG] received stroke: add connection 'remote-access-win-aaa'
Sep 11 18:26:33 LR1 charon: 12[CFG] a DH group is mandatory in IKE proposals
Sep 11 18:26:33 LR1 charon: 12[CFG] skipped invalid proposal string: aes256-sha1
Sep 11 18:26:33 LR1 charon: 14[CFG] received stroke: add connection 'remote-access-mac-zzz'
Sep 11 18:26:33 LR1 charon: 14[CFG] a DH group is mandatory in IKE proposals
Sep 11 18:26:33 LR1 charon: 14[CFG] skipped invalid proposal string: aes256-sha1
Sep 11 18:26:33 LR1 charon: 16[CFG] received stroke: add connection 'remote-access'
Sep 11 18:26:33 LR1 charon: 16[CFG] a DH group is mandatory in IKE proposals
Sep 11 18:26:33 LR1 charon: 16[CFG] skipped invalid proposal string: aes256-sha1
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading secrets
Sep 11 18:26:33 LR1 charon: 05[CFG] loading secrets from '/etc/ipsec.secrets'
Sep 11 18:26:33 LR1 charon: 05[CFG]   loaded IKE secret for 172.16.34.1 %any
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading ca certificates from '/etc/ipsec.d/cacerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading aa certificates from '/etc/ipsec.d/aacerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading attribute certificates from '/etc/ipsec.d/acerts'
Sep 11 18:26:33 LR1 charon: 05[CFG] rereading crls from '/etc/ipsec.d/crls'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'nat_traversal' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'virtual_private' in config setup
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'leftnexthop' in conn 'remote-access-win-aaa'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'pfs' in conn 'remote-access-win-aaa'
Sep 11 18:26:33 LR1 ipsec_starter[6113]:   PFS is enabled by specifying a DH group in the 'esp' cipher suite
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'leftnexthop' in conn 'remote-access-mac-zzz'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'pfs' in conn 'remote-access-mac-zzz'
Sep 11 18:26:33 LR1 ipsec_starter[6113]:   PFS is enabled by specifying a DH group in the 'esp' cipher suite
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'leftnexthop' in conn 'remote-access'
Sep 11 18:26:33 LR1 ipsec_starter[6113]: # deprecated keyword 'pfs' in conn 'remote-access'
Sep 11 18:26:33 LR1 ipsec_starter[6113]:   PFS is enabled by specifying a DH group in the 'esp' cipher suite
Sep 11 18:26:33 LR1 ipsec_starter[6113]: ### 8 parsing errors (0 fatal) ###
Sep 11 18:26:33 LR1 systemd[1]: Stopped LSB: layer 2 tunelling protocol daemon.
Sep 11 18:26:33 LR1 systemd[1]: Starting LSB: layer 2 tunelling protocol daemon...
Sep 11 18:26:33 LR1 xl2tpd[6220]: Not looking for kernel SAref support.
Sep 11 18:26:33 LR1 xl2tpd[6220]: This binary does not support kernel L2TP.
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:33 LR1 systemd[1]: Started LSB: layer 2 tunelling protocol daemon.
Sep 11 18:26:33 LR1 xl2tpd[6216]: Starting xl2tpd: xl2tpd.
Sep 11 18:26:33 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/opt/vyatta/sbin/vyatta-update-pptp.pl
Sep 11 18:26:33 LR1 xl2tpd[6221]: xl2tpd version xl2tpd-1.3.6 started on LR1.mucI.mybll.net PID:6221
Sep 11 18:26:33 LR1 xl2tpd[6221]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
Sep 11 18:26:33 LR1 xl2tpd[6221]: Forked by Scott Balmos and David Stipp, (C) 2001
Sep 11 18:26:33 LR1 xl2tpd[6221]: Inherited by Jeff McAdams, (C) 2002
Sep 11 18:26:33 LR1 xl2tpd[6221]: Forked again by Xelerance (www.xelerance.com) (C) 2006
Sep 11 18:26:33 LR1 xl2tpd[6221]: Listening on IP address 172.16.34.1, port 1701
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:33 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:34 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/bin/mv /tmp/config.boot.6245 /opt/vyatta/etc/config/archive/config.boot
Sep 11 18:26:34 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:34 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:34 LR1 sudo:      foo : TTY=pts/0 ; PWD=/home/foo ; USER=root ; COMMAND=/usr/sbin/logrotate -f -s /opt/vyatta/etc/config/archive/lr.state /opt/vyatta/etc/config/archive/lr.conf
Sep 11 18:26:34 LR1 sudo: pam_unix(sudo:session): session opened for user root by foo(uid=0)
Sep 11 18:26:34 LR1 sudo: pam_unix(sudo:session): session closed for user root
Sep 11 18:26:34 LR1 commit: Successful change to active configuration by user foo on /dev/pts/0

I've fixed it by adjusting the syntax for new StrongSWAN. The new way to do it is arguably better than it used to be, but I still wonder why the old syntax had to break. The fix is in 0.12.45+vyos2+current2 and should be in tomorrow's nightly build.

I verified it by creating a basic setup with PSK and local auth and connecting to it from a Windows VM. I'll also test it with NM plugin for Linux, but for testing with other scenarios (x.509, RADIUS) and different clients (e.g. OS X) I'll need your help.

I can confirm L2TP/IPSec working with Windows 10 (1803) and Apple iOS 11.4.1 together with RADIUS auth backend.

Thanks!

c-po closed this task as Resolved.Sep 15 2018, 7:52 AM

c-po assigned this task to dmbaturin.

c-po moved this task from Need Triage to In Progress on the VyOS 1.2 Crux board.

c-po edited projects, added VyOS 1.2 Crux (VyOS 1.2.0-rc1); removed VyOS 1.2 Crux.

c-po changed Difficulty level from Normal (likely a few hours) to Hard (possibly days).

c-po changed Why the issue appeared? from Will be filled on close to Other.

syncer added a project: VyOS-1.2.0-GA.Oct 15 2018, 10:42 PM

syncer moved this task from Needs Triage to Finished on the VyOS 1.2 Crux (VyOS 1.2.0-rc1) board.Oct 15 2018, 10:42 PM

L2TP/IPSec broken in latest rolling releaseClosed, ResolvedPublicBUGActions

Description

Details

Event Timeline

L2TP/IPSec broken in latest rolling release
Closed, ResolvedPublicBUG
Actions