xelerance / xl2tpd

Official Xelerance fork of L2TPd
GNU General Public License v2.0
519 stars 203 forks source link

L2TP over IPSec fails on xl2tpd #219

Closed rwb196884 closed 2 years ago

rwb196884 commented 3 years ago

I appreciate that this may be a configuration problem, but I've been unable to find any help anywhere else so here we are...

Trying to connect an L2TP/IPSec VPN from Win10 and from MacOS X 10.7 to Debian 10. Both clients have the same problem: IPSec connection is made but then xl2tpd doesn't work. Here is syslog:

Dec 29 20:34:12 mini31 charon: 16[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (408 bytes)
Dec 29 20:34:12 mini31 charon: 16[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V ]
Dec 29 20:34:12 mini31 ipsec[676]: 00[DMN] Starting IKE charon daemon (strongSwan 5.7.2, Linux 4.19.0-11-amd64, x86_64)
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] opening directory '/etc/ipsec.d/cacerts' failed: No such file or directory
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG]   reading directory failed
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] opening directory '/etc/ipsec.d/aacerts' failed: No such file or directory
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG]   reading directory failed
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] opening directory '/etc/ipsec.d/ocspcerts' failed: No such file or directory
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG]   reading directory failed
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] opening directory '/etc/ipsec.d/acerts' failed: No such file or directory
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG]   reading directory failed
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] opening directory '/etc/ipsec.d/crls' failed: No such file or directory
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG]   reading directory failed
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG]   loaded IKE secret for %any %any
Dec 29 20:34:12 mini31 ipsec[676]: 00[CFG] expanding file expression '/var/lib/strongswan/ipsec.secrets.inc' failed
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] loaded plugins: charon aes rc2 sha2 sha1 md5 mgf1 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl fips-prf gmp agent xcbc hmac gcm attr kernel-netlink resolve socket-default bypass-lan connmark stroke updown counters
Dec 29 20:34:12 mini31 ipsec[676]: 00[LIB] dropped capabilities, running as uid 0, gid 0
Dec 29 20:34:12 mini31 ipsec[676]: 00[JOB] spawning 16 worker threads
Dec 29 20:34:12 mini31 ipsec[676]: 05[IKE] installed bypass policy for 192.168.1.0/24
Dec 29 20:34:12 mini31 ipsec[676]: 05[IKE] installed bypass policy for 192.168.2.0/24
Dec 29 20:34:12 mini31 ipsec[676]: 05[KNL] received netlink error: Invalid argument (22)
Dec 29 20:34:12 mini31 ipsec[676]: 05[KNL] unable to install source route for %any6
Dec 29 20:34:12 mini31 ipsec[676]: 05[IKE] installed bypass policy for ::1/128
Dec 29 20:34:12 mini31 ipsec[676]: 05[IKE] installed bypass policy for fe80::/64
Dec 29 20:34:12 mini31 ipsec[676]: 07[CFG] received stroke: add connection 'wep-ap'
Dec 29 20:34:12 mini31 ipsec[676]: 07[CFG] added configuration 'wep-ap'
Dec 29 20:34:12 mini31 ipsec[676]: 05[KNL] interface ifb0 activated
Dec 29 20:34:12 mini31 ipsec[676]: 09[KNL] fe80::e8c9:27ff:fe79:f309 appeared on ifb0
Dec 29 20:34:12 mini31 charon: 16[ENC] received unknown vendor ID: 01:52:8b:bb:c0:06:96:12:18:49:ab:9a:1c:5b:2a:51:00:00:00:01
Dec 29 20:34:12 mini31 ipsec[676]: 12[IKE] interface change for bypass policy for fe80::/64 (from br0 to ifb0)
Dec 29 20:34:12 mini31 ipsec[676]: 13[KNL] fe80::abe:acff:fe0a:6c1d appeared on wlx08beac0a6c1d
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] interface change for bypass policy for fe80::/64 (from ifb0 to wlx08beac0a6c1d)
Dec 29 20:34:12 mini31 ipsec[676]: 15[KNL] 192.168.43.7 appeared on wlan0
Dec 29 20:34:12 mini31 ipsec[676]: 09[IKE] installed bypass policy for 192.168.43.0/24
Dec 29 20:34:12 mini31 ipsec[676]: 09[IKE] interface change for bypass policy for fe80::/64 (from wlx08beac0a6c1d to wlan0)
Dec 29 20:34:12 mini31 ipsec[676]: 14[KNL] fe80::9284:dff:fef3:7a2f appeared on wlan0
Dec 29 20:34:12 mini31 ipsec[676]: 14[KNL] interface enp0s6f1u2 activated
Dec 29 20:34:12 mini31 ipsec[676]: 05[IKE] interface change for bypass policy for fe80::/64 (from wlan0 to enp0s6f1u2)
Dec 29 20:34:12 mini31 ipsec[676]: 11[KNL] fe80::a01e:f9ff:fe09:1bdd appeared on enp0s6f1u2
Dec 29 20:34:12 mini31 ipsec[676]: 06[KNL] 192.168.42.221 appeared on enp0s6f1u2
Dec 29 20:34:12 mini31 ipsec[676]: 13[IKE] installed bypass policy for 192.168.42.0/24
Dec 29 20:34:12 mini31 ipsec[676]: 06[KNL] interface wlx00e032800384 deleted
Dec 29 20:34:12 mini31 ipsec[676]: 07[KNL] interface wlx00e032800384 activated
Dec 29 20:34:12 mini31 ipsec[676]: 05[KNL] interface wlx00e032800384 deactivated
Dec 29 20:34:12 mini31 ipsec[676]: 15[KNL] 192.168.43.7 disappeared from wlan0
Dec 29 20:34:12 mini31 ipsec[676]: 13[KNL] interface wlan0 deactivated
Dec 29 20:34:12 mini31 ipsec[676]: 05[IKE] uninstalling bypass policy for 192.168.43.0/24
Dec 29 20:34:12 mini31 ipsec[676]: 09[KNL] fe80::9284:dff:fef3:7a2f disappeared from wlan0
Dec 29 20:34:12 mini31 ipsec[676]: 05[KNL] error uninstalling route installed with policy 192.168.43.0/24 === 192.168.43.0/24 out
Dec 29 20:34:12 mini31 ipsec[676]: 16[KNL] interface wlan0 activated
Dec 29 20:34:12 mini31 ipsec[676]: 13[KNL] 192.168.43.7 appeared on wlan0
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] installed bypass policy for 192.168.43.0/24
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] interface change for bypass policy for fe80::/64 (from enp0s6f1u2 to wlan0)
Dec 29 20:34:12 mini31 ipsec[676]: 13[KNL] interface wlx00e032800384 activated
Dec 29 20:34:12 mini31 ipsec[676]: 12[KNL] fe80::9284:dff:fef3:7a2f appeared on wlan0
Dec 29 20:34:12 mini31 ipsec[676]: 16[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (408 bytes)
Dec 29 20:34:12 mini31 ipsec[676]: 16[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V ]
Dec 29 20:34:12 mini31 ipsec[676]: 16[ENC] received unknown vendor ID: 01:52:8b:bb:c0:06:96:12:18:49:ab:9a:1c:5b:2a:51:00:00:00:01
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] received MS NT5 ISAKMPOAKLEY vendor ID
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] received NAT-T (RFC 3947) vendor ID
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 29 20:34:12 mini31 ipsec[676]: 16[IKE] received FRAGMENTATION vendor ID
Dec 29 20:34:12 mini31 ipsec[676]: 16[ENC] received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 29 20:34:12 mini31 ipsec[676]: 16[ENC] received unknown vendor ID: 26:24:4d:38:ed:db:61:b3:17:2a:36:e3:d0:cf:b8:19
Dec 29 20:34:12 mini31 charon: 16[IKE] received MS NT5 ISAKMPOAKLEY vendor ID
Dec 29 20:34:12 mini31 charon: 16[IKE] received NAT-T (RFC 3947) vendor ID
Dec 29 20:34:12 mini31 charon: 16[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 29 20:34:12 mini31 charon: 16[IKE] received FRAGMENTATION vendor ID
Dec 29 20:34:12 mini31 charon: 16[ENC] received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 29 20:34:12 mini31 charon: 16[ENC] received unknown vendor ID: 26:24:4d:38:ed:db:61:b3:17:2a:36:e3:d0:cf:b8:19
Dec 29 20:34:12 mini31 charon: 16[ENC] received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 29 20:34:12 mini31 charon: 16[IKE] 192.168.1.11 is initiating a Main Mode IKE_SA
Dec 29 20:34:12 mini31 charon: 16[CFG] selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
Dec 29 20:34:12 mini31 charon: 16[ENC] generating ID_PROT response 0 [ SA V V V V ]
Dec 29 20:34:12 mini31 charon: 16[NET] sending packet: from 192.168.1.31[500] to 192.168.1.11[500] (156 bytes)
Dec 29 20:34:12 mini31 charon: 08[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (260 bytes)
Dec 29 20:34:12 mini31 charon: 08[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 29 20:34:12 mini31 charon: 08[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 29 20:34:12 mini31 charon: 08[NET] sending packet: from 192.168.1.31[500] to 192.168.1.11[500] (244 bytes)
Dec 29 20:34:12 mini31 charon: 12[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (68 bytes)
Dec 29 20:34:12 mini31 charon: 12[ENC] parsed ID_PROT request 0 [ ID HASH ]
Dec 29 20:34:12 mini31 charon: 12[CFG] looking for pre-shared key peer configs matching 192.168.1.31...192.168.1.11[192.168.1.11]
Dec 29 20:34:12 mini31 charon: 12[CFG] selected peer config "wep-ap"
Dec 29 20:34:12 mini31 charon: 12[IKE] IKE_SA wep-ap[1] established between 192.168.1.31[192.168.1.31]...192.168.1.11[192.168.1.11]
Dec 29 20:34:12 mini31 charon: 12[ENC] generating ID_PROT response 0 [ ID HASH ]
Dec 29 20:34:12 mini31 charon: 12[NET] sending packet: from 192.168.1.31[500] to 192.168.1.11[500] (68 bytes)
Dec 29 20:34:12 mini31 charon: 11[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (468 bytes)
Dec 29 20:34:12 mini31 charon: 11[ENC] parsed QUICK_MODE request 1 [ HASH SA No ID ID ]
Dec 29 20:34:12 mini31 charon: 11[CFG] selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ
Dec 29 20:34:12 mini31 charon: 11[IKE] received 3600s lifetime, configured 0s
Dec 29 20:34:12 mini31 charon: 11[IKE] received 250000000 lifebytes, configured 0
Dec 29 20:34:12 mini31 charon: 11[ENC] generating QUICK_MODE response 1 [ HASH SA No ID ID ]
Dec 29 20:34:12 mini31 charon: 11[NET] sending packet: from 192.168.1.31[500] to 192.168.1.11[500] (180 bytes)
Dec 29 20:34:12 mini31 charon: 15[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (60 bytes)
Dec 29 20:34:12 mini31 charon: 15[ENC] parsed QUICK_MODE request 1 [ HASH ]
Dec 29 20:34:12 mini31 kernel: [32346.713201] alg: No test for echainiv(authenc(hmac(sha1),cbc(aes))) (echainiv(authenc(hmac(sha1-generic),cbc(aes-asm))))
Dec 29 20:34:12 mini31 charon: 15[IKE] CHILD_SA wep-ap{1} established with SPIs c221cbc4_i b7d62612_o and TS 192.168.1.31/32[udp/l2f] === 192.168.1.11/32[udp/l2f]
Dec 29 20:34:12 mini31 kernel: [32346.720604] kauditd_printk_skb: 3 callbacks suppressed
Dec 29 20:34:12 mini31 kernel: [32346.720606] audit: type=1400 audit(1609274052.810:14): apparmor="DENIED" operation="open" profile="/usr/lib/ipsec/charon" name="/proc/11712/fd/" pid=11712 comm="charon" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Dec 29 20:34:12 mini31 vpn: + 192.168.1.11 192.168.1.11 -- 192.168.1.31
Dec 29 20:34:13 mini31 xl2tpd[755]: network_thread: recv packet from 192.168.1.11, size = 108, tunnel = 0, call = 0 ref=0 refhim=0
Dec 29 20:34:13 mini31 xl2tpd[755]: get_call: allocating new tunnel for host 192.168.1.11, port 1701.
Dec 29 20:34:13 mini31 xl2tpd[755]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Dec 29 20:34:13 mini31 xl2tpd[755]: protocol_version_avp: peer is using version 1, revision 0.
Dec 29 20:34:13 mini31 xl2tpd[755]: framing_caps_avp: supported peer frames: sync
Dec 29 20:34:13 mini31 xl2tpd[755]: bearer_caps_avp: supported peer bearers:
Dec 29 20:34:13 mini31 xl2tpd[755]: firmware_rev_avp: peer reports firmware version 2560 (0x0a00)
Dec 29 20:34:13 mini31 xl2tpd[755]: hostname_avp: peer reports hostname 'RWB-LAPTOP-DELL'
Dec 29 20:34:13 mini31 xl2tpd[755]: vendor_avp: peer reports vendor 'Microsoft'
Dec 29 20:34:13 mini31 xl2tpd[755]: assigned_tunnel_avp: using peer's tunnel 1
Dec 29 20:34:13 mini31 xl2tpd[755]: receive_window_size_avp: peer wants RWS of 8.  Will use flow control.
Dec 29 20:34:13 mini31 xl2tpd[755]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 1, call is 0.
Dec 29 20:34:13 mini31 xl2tpd[755]: control_finish: sending SCCRP
Dec 29 20:34:14 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177
Dec 29 20:34:15 mini31 xl2tpd[755]: network_thread: recv packet from 192.168.1.11, size = 108, tunnel = 0, call = 0 ref=0 refhim=0
Dec 29 20:34:15 mini31 xl2tpd[755]: get_call: allocating new tunnel for host 192.168.1.11, port 1701.
Dec 29 20:34:15 mini31 xl2tpd[755]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Dec 29 20:34:15 mini31 xl2tpd[755]: protocol_version_avp: peer is using version 1, revision 0.
Dec 29 20:34:15 mini31 xl2tpd[755]: framing_caps_avp: supported peer frames: sync
Dec 29 20:34:15 mini31 xl2tpd[755]: bearer_caps_avp: supported peer bearers:
Dec 29 20:34:15 mini31 xl2tpd[755]: firmware_rev_avp: peer reports firmware version 2560 (0x0a00)
Dec 29 20:34:15 mini31 xl2tpd[755]: hostname_avp: peer reports hostname 'RWB-LAPTOP-DELL'
Dec 29 20:34:15 mini31 xl2tpd[755]: vendor_avp: peer reports vendor 'Microsoft'
Dec 29 20:34:15 mini31 xl2tpd[755]: assigned_tunnel_avp: using peer's tunnel 1
Dec 29 20:34:15 mini31 xl2tpd[755]: receive_window_size_avp: peer wants RWS of 8.  Will use flow control.
Dec 29 20:34:15 mini31 xl2tpd[755]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 1, call is 0.
Dec 29 20:34:15 mini31 xl2tpd[755]: control_finish: Peer requested tunnel 1 twice, ignoring second one.
Dec 29 20:34:15 mini31 xl2tpd[755]: build_fdset: closing down tunnel 14464
Dec 29 20:34:16 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177
Dec 29 20:34:19 mini31 xl2tpd[755]: network_thread: recv packet from 192.168.1.11, size = 108, tunnel = 0, call = 0 ref=0 refhim=0
Dec 29 20:34:19 mini31 xl2tpd[755]: get_call: allocating new tunnel for host 192.168.1.11, port 1701.
Dec 29 20:34:19 mini31 xl2tpd[755]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Dec 29 20:34:19 mini31 xl2tpd[755]: protocol_version_avp: peer is using version 1, revision 0.
Dec 29 20:34:19 mini31 xl2tpd[755]: framing_caps_avp: supported peer frames: sync
Dec 29 20:34:19 mini31 xl2tpd[755]: bearer_caps_avp: supported peer bearers:
Dec 29 20:34:19 mini31 xl2tpd[755]: firmware_rev_avp: peer reports firmware version 2560 (0x0a00)
Dec 29 20:34:19 mini31 xl2tpd[755]: hostname_avp: peer reports hostname 'RWB-LAPTOP-DELL'
Dec 29 20:34:19 mini31 xl2tpd[755]: vendor_avp: peer reports vendor 'Microsoft'
Dec 29 20:34:19 mini31 xl2tpd[755]: assigned_tunnel_avp: using peer's tunnel 1
Dec 29 20:34:19 mini31 xl2tpd[755]: receive_window_size_avp: peer wants RWS of 8.  Will use flow control.
Dec 29 20:34:19 mini31 xl2tpd[755]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 1, call is 0.
Dec 29 20:34:19 mini31 xl2tpd[755]: control_finish: Peer requested tunnel 1 twice, ignoring second one.
Dec 29 20:34:19 mini31 xl2tpd[755]: build_fdset: closing down tunnel 26480
Dec 29 20:34:20 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177
Dec 29 20:34:27 mini31 xl2tpd[755]: network_thread: recv packet from 192.168.1.11, size = 108, tunnel = 0, call = 0 ref=0 refhim=0
Dec 29 20:34:27 mini31 xl2tpd[755]: get_call: allocating new tunnel for host 192.168.1.11, port 1701.
Dec 29 20:34:27 mini31 xl2tpd[755]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Dec 29 20:34:27 mini31 xl2tpd[755]: protocol_version_avp: peer is using version 1, revision 0.
Dec 29 20:34:27 mini31 xl2tpd[755]: framing_caps_avp: supported peer frames: sync
Dec 29 20:34:27 mini31 xl2tpd[755]: bearer_caps_avp: supported peer bearers:
Dec 29 20:34:27 mini31 xl2tpd[755]: firmware_rev_avp: peer reports firmware version 2560 (0x0a00)
Dec 29 20:34:27 mini31 xl2tpd[755]: hostname_avp: peer reports hostname 'RWB-LAPTOP-DELL'
Dec 29 20:34:27 mini31 xl2tpd[755]: vendor_avp: peer reports vendor 'Microsoft'
Dec 29 20:34:27 mini31 xl2tpd[755]: assigned_tunnel_avp: using peer's tunnel 1
Dec 29 20:34:27 mini31 xl2tpd[755]: receive_window_size_avp: peer wants RWS of 8.  Will use flow control.
Dec 29 20:34:27 mini31 xl2tpd[755]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 1, call is 0.
Dec 29 20:34:27 mini31 xl2tpd[755]: control_finish: Peer requested tunnel 1 twice, ignoring second one.
Dec 29 20:34:27 mini31 xl2tpd[755]: build_fdset: closing down tunnel 30430
Dec 29 20:34:28 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177
Dec 29 20:34:37 mini31 xl2tpd[755]: network_thread: recv packet from 192.168.1.11, size = 108, tunnel = 0, call = 0 ref=0 refhim=0
Dec 29 20:34:37 mini31 xl2tpd[755]: get_call: allocating new tunnel for host 192.168.1.11, port 1701.
Dec 29 20:34:37 mini31 xl2tpd[755]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Dec 29 20:34:37 mini31 xl2tpd[755]: protocol_version_avp: peer is using version 1, revision 0.
Dec 29 20:34:37 mini31 xl2tpd[755]: framing_caps_avp: supported peer frames: sync
Dec 29 20:34:37 mini31 xl2tpd[755]: bearer_caps_avp: supported peer bearers:
Dec 29 20:34:37 mini31 xl2tpd[755]: firmware_rev_avp: peer reports firmware version 2560 (0x0a00)
Dec 29 20:34:37 mini31 xl2tpd[755]: hostname_avp: peer reports hostname 'RWB-LAPTOP-DELL'
Dec 29 20:34:37 mini31 xl2tpd[755]: vendor_avp: peer reports vendor 'Microsoft'
Dec 29 20:34:37 mini31 xl2tpd[755]: assigned_tunnel_avp: using peer's tunnel 1
Dec 29 20:34:37 mini31 xl2tpd[755]: receive_window_size_avp: peer wants RWS of 8.  Will use flow control.
Dec 29 20:34:37 mini31 xl2tpd[755]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 1, call is 0.
Dec 29 20:34:37 mini31 xl2tpd[755]: control_finish: Peer requested tunnel 1 twice, ignoring second one.
Dec 29 20:34:37 mini31 xl2tpd[755]: build_fdset: closing down tunnel 23884
Dec 29 20:34:44 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177
Dec 29 20:34:47 mini31 charon: 14[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (76 bytes)
Dec 29 20:34:47 mini31 charon: 14[ENC] parsed INFORMATIONAL_V1 request 2223299078 [ HASH D ]
Dec 29 20:34:47 mini31 charon: 14[IKE] received DELETE for ESP CHILD_SA with SPI b7d62612
Dec 29 20:34:47 mini31 charon: 14[IKE] closing CHILD_SA wep-ap{1} with SPIs c221cbc4_i (580 bytes) b7d62612_o (0 bytes) and TS 192.168.1.31/32[udp/l2f] === 192.168.1.11/32[udp/l2f]
Dec 29 20:34:47 mini31 kernel: [32381.734660] audit: type=1400 audit(1609274087.825:15): apparmor="DENIED" operation="open" profile="/usr/lib/ipsec/charon" name="/proc/11733/fd/" pid=11733 comm="charon" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Dec 29 20:34:47 mini31 vpn: - 192.168.1.11 192.168.1.11 -- 192.168.1.31
Dec 29 20:34:47 mini31 charon: 10[NET] received packet: from 192.168.1.11[500] to 192.168.1.31[500] (84 bytes)
Dec 29 20:34:47 mini31 charon: 10[ENC] parsed INFORMATIONAL_V1 request 3589023779 [ HASH D ]
Dec 29 20:34:47 mini31 charon: 10[IKE] received DELETE for IKE_SA wep-ap[1]
Dec 29 20:34:47 mini31 charon: 10[IKE] deleting IKE_SA wep-ap[1] between 192.168.1.31[192.168.1.31]...192.168.1.11[192.168.1.11]
Dec 29 20:35:16 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177
Dec 29 20:36:20 mini31 xl2tpd[755]: network_thread: select timeout with max retries: 300 for tunnel: 50177

I'm reading this as IPSec starts and authenticates but then there is some problem with xl2tpd? But I don't understand what that problem is or what to do about it. Any ideas?!

dkosovic commented 3 years ago

If I'm reading things correctly, both the client and server seem to be on the same 192.168.1.0/24 subnet, consequently the routing for the VPN connection is most likely totally screwed up.

rwb196884 commented 3 years ago

They are: it's the home wifi. And over that network I want to make an IPSec/L2TP tunnel between a client (Win10) and the router (Debian 10) and send all traffic between then through the tunnel instead of over the normal network.

rwb196884 commented 2 years ago

Both machines are connected via ethernet. The server is 192.168.1.31 and the client is 192.16.1.11.

# cat /etc/ipsec.conf
# ipsec.conf - strongSwan IPsec configuration file
# basic configuration
config setup
        charondebug="all"

# Connections
conn wep-ap
        type=transport
        authby=secret
        pfs=no
        rekey=no
        keyingtries=1
        left=192.168.0.31
        leftid=%any
        leftprotoport=17/1701
        right=%any
        rightprotoport=17/%any
        rightsubnet=vhost:%priv,%no
        auto=add
        ike=aes128-sha1-sha1-modp1024,3des-sha1-sha1-modp1024
        leftnexthop=%defaultroute
        rightnexthop=%defaultroute

# grep "^[^;]" /etc/xl2tpd/xl2tpd.conf
[global]                                                                ; Global parameters:
port = 1701                                                     ; * Bind to port 1701
listen-addr = 192.168.1.31
debug avp = yes
debug network = yes
debug packet = yes
debug state = yes
debug tunnel = yes
auth file = /etc/xl2tpd/l2tp-secrets
max retries = 5
access control = no
[lns default]                                                   ; Our fallthrough LNS definition
ip range = 192.168.4.100-192.168.4.254  ; * Allocate from this IP range
local ip = 192.168.4.31                         ; * Our local IP to use
length bit = yes                                                ; * Use length bit in payload?
name = mini31                                           ; * Report this as our hostname
pppoptfile = /etc/ppp/options.xl2tpd
ppp debug = yes
require authentication = yes
require chap = yes
refuse pap = yes
rwb196884 commented 2 years ago

I now have an identical configuration working on a Rasberry Pi.

Debian:

# uname -a
Linux mini31 4.19.0-18-amd64 #1 SMP Debian 4.19.208-1 (2021-09-29) x86_64 GNU/Linux
# dpkg -l | grep xl2tpd
ii  xl2tpd                               1.3.12-1.1                          amd64        layer 2 tunneling protocol implementation

Raspberry:

$ uname -a
Linux raspberrypi 5.15.32+ #1538 Thu Mar 31 19:37:58 BST 2022 armv6l GNU/Linux
$ sudo dpkg -l | grep xl2tpd
ii  xl2tpd                               1.3.12-1.1                       armhf        layer 2 tunneling protocol implementation
rwb196884 commented 2 years ago

The syslogs are different when charon completes and xl2tpd starts:

Debian:

...
Aug  8 11:02:05 mini31 charon: 10[IKE] CHILD_SA wep-ap{9} established with SPIs ccb74d8c_i 0705192f_o and TS 192.168.0.31/32[udp/l2f] === 192.168.0.7/32[udp/59134]
Aug  8 11:02:05 mini31 xl2tpd[20596]: network_thread: recv packet from 192.168.0.7, size = 68, tunnel = 0, call = 0 ref=0 refhim=0
Aug  8 11:02:05 mini31 xl2tpd[20596]: get_call: allocating new tunnel for host 192.168.0.7, port 59134.
Aug  8 11:02:05 mini31 xl2tpd[20596]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Aug  8 11:02:05 mini31 xl2tpd[20596]: protocol_version_avp: peer is using version 1, revision 0.
Aug  8 11:02:05 mini31 xl2tpd[20596]: framing_caps_avp: supported peer frames: async sync
Aug  8 11:02:05 mini31 xl2tpd[20596]: hostname_avp: peer reports hostname 'macbook'
Aug  8 11:02:05 mini31 xl2tpd[20596]: assigned_tunnel_avp: using peer's tunnel 49
Aug  8 11:02:05 mini31 xl2tpd[20596]: receive_window_size_avp: peer wants RWS of 4.  Will use flow control.
Aug  8 11:02:05 mini31 xl2tpd[20596]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 49, call is 0.
Aug  8 11:02:05 mini31 xl2tpd[20596]: control_finish: sending SCCRP
Aug  8 11:02:05 mini31 xl2tpd[20596]: network_thread: recv packet from 192.168.0.7, size = 68, tunnel = 0, call = 0 ref=0 refhim=0
Aug  8 11:02:05 mini31 xl2tpd[20596]: get_call: allocating new tunnel for host 192.168.0.7, port 59134.
...

Raspberry:

...
Aug  8 11:02:11 raspberrypi charon: 10[IKE] CHILD_SA wep-ap{3} established with SPIs c2896df1_i 0a636fb2_o and TS 192.168.0.141/32[udp/l2f] === 192.168.0.7/32[udp/61036]
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: network_thread: recv packet from 192.168.0.7, size = 68, tunnel = 0, call = 0 ref=0 refhim=0
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: get_call: allocating new tunnel for host 192.168.0.7, port 61036.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: protocol_version_avp: peer is using version 1, revision 0.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: framing_caps_avp: supported peer frames: async sync
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: hostname_avp: peer reports hostname 'macbook'
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: assigned_tunnel_avp: using peer's tunnel 48
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: receive_window_size_avp: peer wants RWS of 4.  Will use flow control.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: control_finish: message type is Start-Control-Connection-Request(1).  Tunnel is 48, call is 0.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: control_finish: sending SCCRP
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: network_thread: recv packet from 192.168.0.7, size = 20, tunnel = 19058, call = 0 ref=0 refhim=0
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: message_type_avp: message type 3 (Start-Control-Connection-Connected)
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: control_finish: message type is Start-Control-Connection-Connected(3).  Tunnel is 48, call is 0.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: Connection established to 192.168.0.7, 61036.  Local: 19058, Remote: 48 (ref=0/0).  LNS session is 'default'
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: network_thread: recv packet from 192.168.0.7, size = 38, tunnel = 19058, call = 0 ref=0 refhim=0
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: message_type_avp: message type 10 (Incoming-Call-Request)
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: message_type_avp: new incoming call
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: assigned_call_avp: using peer's call 4451
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: call_serno_avp: serial number is 1
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: control_finish: message type is Incoming-Call-Request(10).  Tunnel is 48, call is 0.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: control_finish: Sending ICRP
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: network_thread: recv packet from 192.168.0.7, size = 40, tunnel = 19058, call = 32279 ref=0 refhim=0
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: message_type_avp: message type 12 (Incoming-Call-Connected)
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: tx_speed_avp: transmit baud rate is 1000000
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: frame_type_avp: peer uses: async frames
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: control_finish: message type is Incoming-Call-Connected(12).  Tunnel is 48, call is 4451.
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: start_pppd: I'm running:
Aug  8 11:02:12 raspberrypi xl2tpd[8176]: "/usr/sbin/pppd"
...

So it looks like Debian isn't starting PPP.

rwb196884 commented 2 years ago

On debian /etc/strongswan.d/charon was empty. I coped the files form the Raspberry

dkosovic commented 2 years ago

Are you using kernel mode L2TP for both Debian and Raspberry PI? As you are using completely different kernel versions with major version number difference, the L2TP kernel modules would be different.

I can't see from the log snippets if they have something like xl2tpd[456]: This binary does not support kernel L2TP or xl2tpd[789]: Using l2tp kernel support

Not sure if the apparmor="DENIED" errors for strongswan in your original post on Debian are an issue.