search

nm-l2tp / NetworkManager-l2tp

L2TP and L2TP/IPsec support for NetworkManager
GNU General Public License v2.0
488 stars 84 forks source link

Connection is down shortly after it is established #40

Closed shawnLeeZX closed 7 years ago

shawnLeeZX commented 7 years ago

Hi, I compiled 6a8ed3f from source (seems ike and esp dialogue does not work, so I fall back to the version that does not use the dialogue), and also xl2tp from source. The connection is able to establish, however, after some seconds, the xl2tp tunnel just die. 

Apr 11 18:52:27 shawn-world NetworkManager[1012]: xl2tpd[6885]: Maximum retries exceeded for tunnel 45495.  Closing.

I am using ubuntu 16.04. network-manager is of 1.2.6. The full log is attached, so is configuration files for xl2tp, ipsec.

ipsec.conf

conn %default
    ikelifetime=8h
    lifetime=8h
    rekeymargin=3m
    keyingtries=1
    keyexchange=ikev1
    authby=secret
    rightid=""
    auto=add
    ike=aes128-sha1-modp1024,3des-sha1-modp1024
    # esp=aes128-sha1-modp1024,3des-sha1-modp1024
    esp=aes256-sha1,3des-sha1
    # ike=aes128-md5!
    # esp=aes128-md5!

conn IE
    keyexchange=ikev1
    left=%defaultroute
    auto=add
    authby=secret
    type=transport
    leftprotoport=17/1701
    rightprotoport=17/1701
    # set this to the ip address of your vpn server
    right=VPN_SERVER_IP

xl2tp.conf

[lac IE]
lns = VPN_SERVER_IP
ppp debug = yes
pppoptfile = /etc/ppp/options.l2tpd.client
length bit = no

options.l2tp.client

ipcp-accept-local
ipcp-accept-remote
refuse-eap
require-mschap-v2
noccp
noauth
idle 1800
mtu 1410
mru 1410
defaultroute
usepeerdns
debug
lock
connect-delay 5000
name xxxx
password xxx

Syslog

Apr 11 18:51:19 shawn-world NetworkManager[1012]: nm-l2tp[6810] <info>  ipsec enable flag: yes
Apr 11 18:51:19 shawn-world NetworkManager[1012]: ** Message: Check port 1701
Apr 11 18:51:19 shawn-world NetworkManager[1012]: nm-l2tp[6810] <info>  starting ipsec
Apr 11 18:51:19 shawn-world NetworkManager[1012]: Stopping strongSwan IPsec failed: starter is not running
Apr 11 18:51:21 shawn-world NetworkManager[1012]: Starting strongSwan 5.3.5 IPsec [starter]...
Apr 11 18:51:21 shawn-world NetworkManager[1012]: Loading config setup
Apr 11 18:51:21 shawn-world NetworkManager[1012]: Loading conn 'nm-ipsec-l2tp-6810'
Apr 11 18:51:21 shawn-world NetworkManager[1012]: found netkey IPsec stack
Apr 11 18:51:21 shawn-world charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.3.5, Linux 4.4.0-72-generic, x86_64)
Apr 11 18:51:21 shawn-world charon: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Apr 11 18:51:21 shawn-world charon: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Apr 11 18:51:21 shawn-world charon: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Apr 11 18:51:21 shawn-world charon: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Apr 11 18:51:21 shawn-world charon: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Apr 11 18:51:21 shawn-world charon: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Apr 11 18:51:21 shawn-world charon: 00[CFG]   loaded IKE secret for %any
Apr 11 18:51:21 shawn-world charon: 00[LIB] loaded plugins: charon test-vectors aes rc2 sha1 sha2 md4 md5 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 connmark stroke updown
Apr 11 18:51:21 shawn-world charon: 00[LIB] dropped capabilities, running as uid 0, gid 0
Apr 11 18:51:21 shawn-world charon: 00[JOB] spawning 16 worker threads
Apr 11 18:51:21 shawn-world charon: 06[CFG] received stroke: add connection 'nm-ipsec-l2tp-6810'
Apr 11 18:51:21 shawn-world charon: 06[CFG] added configuration 'nm-ipsec-l2tp-6810'
Apr 11 18:51:22 shawn-world charon: 07[CFG] rereading secrets
Apr 11 18:51:22 shawn-world charon: 07[CFG] loading secrets from '/etc/ipsec.secrets'
Apr 11 18:51:22 shawn-world charon: 07[CFG]   loaded IKE secret for %any
Apr 11 18:51:22 shawn-world NetworkManager[1012]: nm-l2tp[6810] <info>  Spawned ipsec up script with PID 6871.
Apr 11 18:51:22 shawn-world charon: 10[CFG] received stroke: initiate 'nm-ipsec-l2tp-6810'
Apr 11 18:51:22 shawn-world charon: 12[IKE] initiating Main Mode IKE_SA nm-ipsec-l2tp-6810[1] to 137.189.99.189
Apr 11 18:51:22 shawn-world charon: 12[ENC] generating ID_PROT request 0 [ SA V V V V ]
Apr 11 18:51:22 shawn-world charon: 12[NET] sending packet: from 10.6.5.202[500] to 137.189.99.189[500] (280 bytes)
Apr 11 18:51:22 shawn-world charon: 13[NET] received packet: from 137.189.99.189[500] to 10.6.5.202[500] (124 bytes)
Apr 11 18:51:22 shawn-world charon: 13[ENC] parsed ID_PROT response 0 [ SA V V ]
Apr 11 18:51:22 shawn-world charon: 13[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Apr 11 18:51:22 shawn-world charon: 13[IKE] received FRAGMENTATION vendor ID
Apr 11 18:51:22 shawn-world charon: 13[ENC] generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Apr 11 18:51:22 shawn-world charon: 13[NET] sending packet: from 10.6.5.202[500] to 137.189.99.189[500] (244 bytes)
Apr 11 18:51:22 shawn-world charon: 11[NET] received packet: from 137.189.99.189[500] to 10.6.5.202[500] (304 bytes)
Apr 11 18:51:22 shawn-world charon: 11[ENC] parsed ID_PROT response 0 [ KE No V V V V NAT-D NAT-D ]
Apr 11 18:51:22 shawn-world charon: 11[IKE] received Cisco Unity vendor ID
Apr 11 18:51:22 shawn-world charon: 11[IKE] received XAuth vendor ID
Apr 11 18:51:22 shawn-world charon: 11[ENC] received unknown vendor ID: ec:a6:f7:20:f3:4c:f4:e0:52:bb:2b:ae:e4:3a:b0:6b
Apr 11 18:51:22 shawn-world charon: 11[ENC] received unknown vendor ID: 1f:07:f7:0e:aa:65:14:d3:b0:fa:96:54:2a:50:01:00
Apr 11 18:51:22 shawn-world charon: 11[IKE] local host is behind NAT, sending keep alives
Apr 11 18:51:22 shawn-world charon: 11[ENC] generating ID_PROT request 0 [ ID HASH ]
Apr 11 18:51:22 shawn-world charon: 11[NET] sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (68 bytes)
Apr 11 18:51:22 shawn-world charon: 14[NET] received packet: from 137.189.99.189[4500] to 10.6.5.202[4500] (84 bytes)
Apr 11 18:51:22 shawn-world charon: 14[ENC] parsed ID_PROT response 0 [ ID HASH V ]
Apr 11 18:51:22 shawn-world charon: 14[IKE] received DPD vendor ID
Apr 11 18:51:22 shawn-world charon: 14[IKE] IKE_SA nm-ipsec-l2tp-6810[1] established between 10.6.5.202[10.6.5.202]...137.189.99.189[137.189.99.189]
Apr 11 18:51:22 shawn-world charon: 14[IKE] scheduling reauthentication in 10168s
Apr 11 18:51:22 shawn-world charon: 14[IKE] maximum IKE_SA lifetime 10708s
Apr 11 18:51:22 shawn-world charon: 14[ENC] generating QUICK_MODE request 2799167388 [ HASH SA No ID ID NAT-OA NAT-OA ]
Apr 11 18:51:22 shawn-world charon: 14[NET] sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (244 bytes)
Apr 11 18:51:22 shawn-world charon: 15[NET] received packet: from 137.189.99.189[4500] to 10.6.5.202[4500] (164 bytes)
Apr 11 18:51:22 shawn-world charon: 15[ENC] parsed QUICK_MODE response 2799167388 [ HASH SA No ID ID NAT-OA ]
Apr 11 18:51:22 shawn-world charon: 15[IKE] CHILD_SA nm-ipsec-l2tp-6810{1} established with SPIs c28c60c1_i 30f103c4_o and TS 10.6.5.202/32[udp/l2f] === 137.189.99.189/32[udp/l2f]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: initiating Main Mode IKE_SA nm-ipsec-l2tp-6810[1] to 137.189.99.189
Apr 11 18:51:22 shawn-world NetworkManager[1012]: generating ID_PROT request 0 [ SA V V V V ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: sending packet: from 10.6.5.202[500] to 137.189.99.189[500] (280 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received packet: from 137.189.99.189[500] to 10.6.5.202[500] (124 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: parsed ID_PROT response 0 [ SA V V ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received FRAGMENTATION vendor ID
Apr 11 18:51:22 shawn-world NetworkManager[1012]: generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: sending packet: from 10.6.5.202[500] to 137.189.99.189[500] (244 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received packet: from 137.189.99.189[500] to 10.6.5.202[500] (304 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: parsed ID_PROT response 0 [ KE No V V V V NAT-D NAT-D ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received Cisco Unity vendor ID
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received XAuth vendor ID
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received unknown vendor ID: ec:a6:f7:20:f3:4c:f4:e0:52:bb:2b:ae:e4:3a:b0:6b
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received unknown vendor ID: 1f:07:f7:0e:aa:65:14:d3:b0:fa:96:54:2a:50:01:00
Apr 11 18:51:22 shawn-world NetworkManager[1012]: local host is behind NAT, sending keep alives
Apr 11 18:51:22 shawn-world NetworkManager[1012]: generating ID_PROT request 0 [ ID HASH ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (68 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received packet: from 137.189.99.189[4500] to 10.6.5.202[4500] (84 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: parsed ID_PROT response 0 [ ID HASH V ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received DPD vendor ID
Apr 11 18:51:22 shawn-world NetworkManager[1012]: IKE_SA nm-ipsec-l2tp-6810[1] established between 10.6.5.202[10.6.5.202]...137.189.99.189[137.189.99.189]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: scheduling reauthentication in 10168s
Apr 11 18:51:22 shawn-world NetworkManager[1012]: maximum IKE_SA lifetime 10708s
Apr 11 18:51:22 shawn-world NetworkManager[1012]: generating QUICK_MODE request 2799167388 [ HASH SA No ID ID NAT-OA NAT-OA ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (244 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: received packet: from 137.189.99.189[4500] to 10.6.5.202[4500] (164 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: parsed QUICK_MODE response 2799167388 [ HASH SA No ID ID NAT-OA ]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: CHILD_SA nm-ipsec-l2tp-6810{1} established with SPIs c28c60c1_i 30f103c4_o and TS 10.6.5.202/32[udp/l2f] === 137.189.99.189/32[udp/l2f]
Apr 11 18:51:22 shawn-world NetworkManager[1012]: connection 'nm-ipsec-l2tp-6810' established successfully
Apr 11 18:51:22 shawn-world charon: 15[ENC] generating QUICK_MODE request 2799167388 [ HASH ]
Apr 11 18:51:22 shawn-world charon: 15[NET] sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (60 bytes)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: nm-l2tp[6810] <info>  strongSwan is ready.
Apr 11 18:51:22 shawn-world charon: 08[CFG] rereading secrets
Apr 11 18:51:22 shawn-world charon: 08[CFG] loading secrets from '/etc/ipsec.secrets'
Apr 11 18:51:22 shawn-world charon: 08[CFG]   loaded IKE secret for %any
Apr 11 18:51:22 shawn-world NetworkManager[1012]: ** Message: xl2tpd started with pid 6885
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: setsockopt recvref[30]: Protocol not available
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Using l2tp kernel support.
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: xl2tpd version xl2tpd-1.3.6 started on shawn-world PID:6885
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Forked by Scott Balmos and David Stipp, (C) 2001
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Inherited by Jeff McAdams, (C) 2002
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Forked again by Xelerance (www.xelerance.com) (C) 2006
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Listening on IP address 0.0.0.0, port 1701
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Connecting to host 137.189.99.189, port 1701
Apr 11 18:51:22 shawn-world NetworkManager[1012]: <info>  [1491907882.7225] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",0]: VPN plugin: state changed: starting (3)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Connection established to 137.189.99.189, 1701.  Local: 45495, Remote: 900 (ref=0/0).
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Calling on tunnel 45495
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: Call established with 137.189.99.189, Local: 30, Remote: 899, Serial: 1 (ref=0/0)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: start_pppd: I'm running:
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "/usr/sbin/pppd"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "passive"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "nodetach"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: ":"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "file"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "/var/run/nm-ppp-options.xl2tpd.6810"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "plugin"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "pppol2tp.so"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "pppol2tp"
Apr 11 18:51:22 shawn-world NetworkManager[1012]: xl2tpd[6885]: "7"
Apr 11 18:51:22 shawn-world pppd[6886]: Plugin /usr/lib/pppd/2.4.7/nm-l2tp-pppd-plugin.so loaded.
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] initializing
Apr 11 18:51:22 shawn-world pppd[6886]: Plugin pppol2tp.so loaded.
Apr 11 18:51:22 shawn-world pppd[6886]: pppd 2.4.7 started by root, uid 0
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 3 / phase 'serial connection'
Apr 11 18:51:22 shawn-world NetworkManager[1012]: nm_device_get_device_type: assertion 'NM_IS_DEVICE (self)' failed
Apr 11 18:51:22 shawn-world NetworkManager[1012]: <info>  [1491907882.7432] manager: (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/8)
Apr 11 18:51:22 shawn-world NetworkManager[1012]: <info>  [1491907882.7540] devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Apr 11 18:51:22 shawn-world pppd[6886]: Using interface ppp0
Apr 11 18:51:22 shawn-world NetworkManager[1012]: <info>  [1491907882.7540] device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
Apr 11 18:51:22 shawn-world pppd[6886]: Connect: ppp0 <-->
Apr 11 18:51:22 shawn-world systemd[1]: Starting Laptop Mode Tools - Battery Polling Service...
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 5 / phase 'establish'
Apr 11 18:51:22 shawn-world pppd[6886]: Overriding mtu 1500 to 1400
Apr 11 18:51:22 shawn-world pppd[6886]: Overriding mru 1500 to mtu value 1400
Apr 11 18:51:22 shawn-world pppd[6886]: Overriding mtu 1500 to 1400
Apr 11 18:51:22 shawn-world pppd[6886]: Overriding mru 1500 to mtu value 1400
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 6 / phase 'authenticate'
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] passwd-hook: requesting credentials...
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] passwd-hook: got credentials from NetworkManager-l2tp
Apr 11 18:51:22 shawn-world pppd[6886]: PAP authentication succeeded
Apr 11 18:51:22 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 8 / phase 'network'
Apr 11 18:51:22 shawn-world systemd[1]: Reloading Laptop Mode Tools.
Apr 11 18:51:22 shawn-world systemd[1]: Started Laptop Mode Tools - Battery Polling Service.
Apr 11 18:51:22 shawn-world laptop-mode: Laptop mode
Apr 11 18:51:22 shawn-world laptop_mode[6898]: Laptop mode
Apr 11 18:51:22 shawn-world laptop-mode: enabled, not active [unchanged]
Apr 11 18:51:22 shawn-world laptop_mode[6898]: enabled, not active [unchanged]
Apr 11 18:51:22 shawn-world systemd[1]: Reloaded Laptop Mode Tools.
Apr 11 18:51:25 shawn-world charon: 13[KNL] 192.168.210.147 appeared on ppp0
Apr 11 18:51:25 shawn-world pppd[6886]: local  IP address 192.168.210.147
Apr 11 18:51:25 shawn-world pppd[6886]: remote IP address 137.189.99.189
Apr 11 18:51:25 shawn-world pppd[6886]: primary   DNS address 137.189.96.200
Apr 11 18:51:25 shawn-world pppd[6886]: secondary DNS address 137.189.96.50
Apr 11 18:51:25 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 9 / phase 'running'
Apr 11 18:51:25 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] ip-up: event
Apr 11 18:51:25 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] ip-up: sending Ip4Config to NetworkManager-l2tp...
Apr 11 18:51:25 shawn-world charon: 14[KNL] 192.168.210.147 disappeared from ppp0
Apr 11 18:51:25 shawn-world charon: 15[KNL] 192.168.210.147 appeared on ppp0
Apr 11 18:51:25 shawn-world charon: 04[KNL] interface ppp0 activated
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7669] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",0]: VPN connection: (IP4 Config Get) reply received from old-style plugin
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7680] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data: VPN Gateway: 137.189.99.189
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7685] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data: Tunnel Device: "ppp0"
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7690] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data: IPv4 configuration:
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7693] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Internal Address: 192.168.210.147
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7696] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Internal Prefix: 32
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7696] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Internal Point-to-Point Address: 137.189.99.189
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7696] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Maximum Segment Size (MSS): 0
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7697] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Forbid Default Route: no
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7697] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Internal DNS: 137.189.96.200
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7697] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   Internal DNS: 137.189.96.50
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7697] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data:   DNS Domain: '(none)'
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7697] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: Data: No IPv6 configuration
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7699] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: VPN plugin: state changed: started (4)
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.7711] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: VPN connection: (IP Config Get) complete
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.8116] manager: NetworkManager state is now CONNECTED_LOCAL
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.8117] manager: NetworkManager state is now CONNECTED_GLOBAL
Apr 11 18:51:25 shawn-world NetworkManager[1012]: <info>  [1491907885.8121] dns-mgr: Writing DNS information to /sbin/resolvconf
Apr 11 18:51:25 shawn-world whoopsie[983]: [18:51:25] offline
Apr 11 18:51:25 shawn-world dnsmasq[2092]: setting upstream servers from DBus
Apr 11 18:51:25 shawn-world dnsmasq[2092]: using nameserver 137.189.96.200#53(via ppp0)
Apr 11 18:51:25 shawn-world dnsmasq[2092]: using nameserver 137.189.96.50#53(via ppp0)
Apr 11 18:51:25 shawn-world dnsmasq[2092]: using nameserver 137.189.96.200#53 for domain 147.210.168.192.in-addr.arpa
Apr 11 18:51:25 shawn-world dnsmasq[2092]: using nameserver 137.189.96.50#53 for domain 147.210.168.192.in-addr.arpa
Apr 11 18:51:25 shawn-world dnsmasq[2092]: using nameserver 137.189.192.3#53(via wlan0)
Apr 11 18:51:25 shawn-world dnsmasq[2092]: using nameserver 137.189.196.3#53(via wlan0)
Apr 11 18:51:25 shawn-world dbus[919]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr 11 18:51:25 shawn-world whoopsie[983]: [18:51:25] The default IPv4 route is: /org/freedesktop/NetworkManager/ActiveConnection/6
Apr 11 18:51:25 shawn-world whoopsie[983]: [18:51:25] Not a paid data plan: /org/freedesktop/NetworkManager/ActiveConnection/6
Apr 11 18:51:25 shawn-world whoopsie[983]: [18:51:25] Found usable connection: /org/freedesktop/NetworkManager/ActiveConnection/6
Apr 11 18:51:25 shawn-world whoopsie[983]: [18:51:25] online
Apr 11 18:51:25 shawn-world systemd[1]: Starting Network Manager Script Dispatcher Service...
Apr 11 18:51:25 shawn-world dbus[919]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 11 18:51:25 shawn-world systemd[1]: Started Network Manager Script Dispatcher Service.
Apr 11 18:51:25 shawn-world nm-dispatcher: req:1 'vpn-up' [ppp0]: new request (1 scripts)
Apr 11 18:51:25 shawn-world nm-dispatcher: req:1 'vpn-up' [ppp0]: start running ordered scripts...
Apr 11 18:51:27 shawn-world org.gnome.OnlineAccounts[3015]: (goa-daemon:3354): GLib-GIO-CRITICAL **: g_simple_async_result_take_error: assertion 'error != NULL' failed
Apr 11 18:51:35 shawn-world systemd[1]: Reloading OpenBSD Secure Shell server.
Apr 11 18:51:35 shawn-world systemd[1]: Reloaded OpenBSD Secure Shell server.
Apr 11 18:51:46 shawn-world whoopsie[983]: [18:51:46] Cannot reach: https://daisy.ubuntu.com
Apr 11 18:51:46 shawn-world whoopsie[983]: [18:51:46] offline
Apr 11 18:51:48 shawn-world google-chrome.desktop[5090]: [5090:5209:0411/185148.371742:ERROR:connection_factory_impl.cc(386)] Failed to connect to MCS endpoint with error -137
Apr 11 18:51:49 shawn-world charon: 07[IKE] sending keep alive to 137.189.99.189[4500]
Apr 11 18:51:55 shawn-world ntpdate[7072]: name server cannot be used: Temporary failure in name resolution (-3)
Apr 11 18:52:09 shawn-world charon: 09[IKE] sending keep alive to 137.189.99.189[4500]
Apr 11 18:52:27 shawn-world NetworkManager[1012]: xl2tpd[6885]: Maximum retries exceeded for tunnel 45495.  Closing.
Apr 11 18:52:27 shawn-world NetworkManager[1012]: xl2tpd[6885]: Terminating pppd: sending TERM signal to pid 6886
Apr 11 18:52:27 shawn-world NetworkManager[1012]: xl2tpd[6885]: Connection 900 closed to 137.189.99.189, port 1701 (Timeout)
Apr 11 18:52:27 shawn-world pppd[6886]: Terminating on signal 15
Apr 11 18:52:27 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 10 / phase 'terminate'
Apr 11 18:52:27 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 8 / phase 'network'
Apr 11 18:52:27 shawn-world pppd[6886]: Connect time 1.1 minutes.
Apr 11 18:52:27 shawn-world pppd[6886]: Sent 3522738740 bytes, received 0 bytes.
Apr 11 18:52:27 shawn-world charon: 13[KNL] interface ppp0 deactivated
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <error> [1491907947.7572] platform-linux: do-add-ip4-route[9: 0.0.0.0/0 50]: failure 100 (Network is down)
Apr 11 18:52:27 shawn-world charon: 14[KNL] 192.168.210.147 disappeared from ppp0
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <warn>  [1491907947.7573] default-route: failed to add default route 0.0.0.0/0 via 0.0.0.0 dev 9 metric 50 mss 0 src vpn with effective metric 50
Apr 11 18:52:27 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 5 / phase 'establish'
Apr 11 18:52:27 shawn-world pppd[6886]: Overriding mtu 1500 to 1400
Apr 11 18:52:27 shawn-world pppd[6886]: Overriding mru 1500 to mtu value 1400
Apr 11 18:52:27 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 11 / phase 'disconnect'
Apr 11 18:52:27 shawn-world pppd[6886]: Connection terminated.
Apr 11 18:52:27 shawn-world charon: 11[KNL] interface ppp0 deleted
Apr 11 18:52:27 shawn-world NetworkManager[1012]: nm-l2tp[6810] <info>  Terminated xl2tpd daemon with PID 6885.
Apr 11 18:52:27 shawn-world NetworkManager[1012]: xl2tpd[6885]: death_handler: Fatal signal 15 received
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <info>  [1491907947.7617] vpn-connection[0x228a800,e49c1c36-84a6-46e8-8b9a-709ff34f7fbf,"IE",9:(ppp0)]: VPN plugin: state changed: stopping (5)
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <error> [1491907947.7627] platform-linux: do-change-link[9]: failure changing link: failure 19 (No such device)
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <warn>  [1491907947.7628] device (ppp0): failed to disable userspace IPv6LL address handling
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <error> [1491907947.7635] platform-linux: do-add-ip4-route[9: 0.0.0.0/0 50]: failure 19 (No such device)
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <warn>  [1491907947.7641] default-route: failed to add default route 0.0.0.0/0 via 0.0.0.0 dev 9 metric 50 mss 0 src vpn with effective metric 50
Apr 11 18:52:27 shawn-world NetworkManager[1012]: <info>  [1491907947.7650] devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Apr 11 18:52:27 shawn-world whoopsie[983]: [18:52:27] online
Apr 11 18:52:27 shawn-world NetworkManager[1012]: Stopping strongSwan IPsec...
Apr 11 18:52:27 shawn-world google-chrome.desktop[5090]: [5090:5209:0411/185227.767028:ERROR:connection_factory_impl.cc(386)] Failed to connect to MCS endpoint with error -21
Apr 11 18:52:27 shawn-world gnome-session[3184]: Gjs-Message: JS LOG: Removing a network device that was not added
Apr 11 18:52:27 shawn-world google-chrome.desktop[5090]: [5090:5455:0411/185227.770795:ERROR:get_updates_processor.cc(244)] PostClientToServerMessage() failed during GetUpdates
Apr 11 18:52:27 shawn-world charon: 00[DMN] signal of type SIGINT received. Shutting down
Apr 11 18:52:27 shawn-world charon: 00[IKE] closing CHILD_SA nm-ipsec-l2tp-6810{1} with SPIs c28c60c1_i (525 bytes) 30f103c4_o (7627844503 bytes) and TS 10.6.5.202/32[udp/l2f] === 137.189.99.189/32[udp/l2f]
Apr 11 18:52:27 shawn-world charon: 00[IKE] sending DELETE for ESP CHILD_SA with SPI c28c60c1
Apr 11 18:52:27 shawn-world charon: 00[ENC] generating INFORMATIONAL_V1 request 1371578295 [ HASH D ]
Apr 11 18:52:27 shawn-world charon: 00[NET] sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (76 bytes)
Apr 11 18:52:27 shawn-world charon: 00[IKE] deleting IKE_SA nm-ipsec-l2tp-6810[1] between 10.6.5.202[10.6.5.202]...137.189.99.189[137.189.99.189]
Apr 11 18:52:27 shawn-world charon: 00[IKE] sending DELETE for IKE_SA nm-ipsec-l2tp-6810[1]
Apr 11 18:52:27 shawn-world charon: 00[ENC] generating INFORMATIONAL_V1 request 1556435212 [ HASH D ]
Apr 11 18:52:27 shawn-world charon: 00[NET] sending packet: from 10.6.5.202[4500] to 137.189.99.189[4500] (84 bytes)
Apr 11 18:52:27 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] phasechange: status 1 / phase 'dead'
Apr 11 18:52:27 shawn-world pppd[6886]: nm-l2tp[6810] <info>  [helper-6886] exit: cleaning up
Apr 11 18:52:27 shawn-world pppd[6886]: Exit.
Apr 11 18:52:27 shawn-world NetworkManager[1012]: ** Message: ipsec shut down
dkosovic commented 7 years ago

The config files network-manager-l2tp generates are found under /var/run/. Are you able to establish a L2TP/IPsec connection with the config files you provided using strongswan and xl2tpd on the command-line? I can see a few options in your config files that aren't used by network-manager-l2tp which might be significant.

Regarding the new IPsec dialog box, the following settings should make it the same as the commit version you are using :

The above Phase1 Algorithms has the additional 3des-sha1-modp1024 which I didn't include in the example in the README.md file, but I did mention earlier versions used it, also your corresponding config file includes it.

shawnLeeZX commented 7 years ago

Using the config files I provided, I can manage to establish the ipsec connection (ipsec up IE is successful), and activate ppp0 interface. But after that, the system started to freeze, or frequently soft lockup (ifconfig just stuck). The log is rather similar (with the log I attached) up to the point of connection being down, except the connection does not down, but stuck. I have to do hard reboot. The situation is similar with this thread, which says there is some kernel bug in linux. But I figured someone says your package works fine, so I still think there may be some config I got wrong. So I tried your package, which I got the above logs.

I do not understand the config files I used much ... but in Ubuntu 14.04 things works fine with l2tp-ipsec-vpn which uses openswan (I used a GUI before: https://soeasytomakeitwork.wordpress.com/2014/05/02/set-up-a-l2tpipsec-vpn-connection-on-ubuntu-desktop/). I just put the gateway ip address, account and username, then everything works. I am writing this on the purpose of offering some default setting that works I guess. I do not need to hand pick the encryption algorithm in this scenario. So the default of openswan may be good, but I do not know what they are.

I do not think fallback to 14.04 is an option, so please offer some advice, or how should I debug my problem. Thanks very much!

dkosovic commented 7 years ago

Earlier versions of Ubuntu didn't use a kernel module with xl2tpd, so one thing you could try is modify the xl2tpd source's Makefile by commenting out the line that contains:

OSFLAGS+= -DUSE_KERNEL

then rebuild and reinstall xl2tpd with:

make clean
make
sudo make install

Then see if you are able to reproduce the softlock.

The pppol2tp kernel module that xl2tpd uses has been known to completely freeze some systems :

I suspect it won't make much difference, but as you were using openswan previously, you could also try libreswan which forked from openswan only a few years ago (unlike strongswan which has a much older common ancestor of FreeS/WAN) . Have a look at https://github.com/nm-l2tp/network-manager-l2tp/issues/36#issuecomment-272849766 which describes how to build libreswan.

shawnLeeZX commented 7 years ago

I compiled xl2tpd from source. This time, the system won't hang up. But the connection is down after a few seconds the connection is established. The same with the case if I used your package.

Then I compiled and installed libreswan, same things happen. 

xl2tpd[9832]: Maximum retries exceeded for tunnel 57312.  Closing.
xl2tpd[9832]: Terminating pppd: sending TERM signal to pid 32456
xl2tpd[9832]: Connection 1032 closed to 137.189.99.189, port 1701 (Timeout)
xl2tpd[9832]: Can not find tunnel 57312 (refhim=0)
xl2tpd[9832]: network_thread: unable to find call or tunnel to handle packet.  call = 5938, tunnel = 57312 Dumping.
xl2tpd[9832]: Can not find tunnel 57312 (refhim=0)
xl2tpd[9832]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 57312 Dumping

But the output of ipsec auto --up IE this time may be more informative. Is it cipher algorithm is not agreed at all in the end?:

002 "IE" #1: initiating Main Mode
104 "IE" #1: STATE_MAIN_I1: initiate
002 "IE" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
106 "IE" #1: STATE_MAIN_I2: sent MI2, expecting MR2
003 "IE" #1: ignoring unknown Vendor ID payload [85aac747a48d8f5bab26126ffbd1143d]
002 "IE" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
108 "IE" #1: STATE_MAIN_I3: sent MI3, expecting MR3
002 "IE" #1: Main mode peer ID is ID_IPV4_ADDR: '137.189.99.189'
002 "IE" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
004 "IE" #1: STATE_MAIN_I4: ISAKMP SA established {auth=PRESHARED_KEY cipher=3des_cbc_192 integ=md5 group=MODP1024}
002 "IE" #2: initiating Quick Mode PSK+ENCRYPT+UP+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO {using isakmp#1 msgid:d1c96fd2 proposal=defaults pfsgroup=no-pfs}
117 "IE" #2: STATE_QUICK_I1: initiate
003 "IE" #2: NAT-Traversal: received 1 NAT-OA. Ignored because peer is not NATed
003 "IE" #2: our client subnet returned doesn't match my proposal - us:10.6.45.81/32 vs them:137.189.240.198/32
003 "IE" #2: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL]
003 "IE" #2: our client peer returned port doesn't match my proposal - us:1701 vs them:0
003 "IE" #2: Allowing bad L2TP/IPsec proposal (see bug #849) anyway
002 "IE" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
004 "IE" #2: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP/NAT=>0xf02cf025 <0xd5f28a88 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=137.189.99.189:4500 DPD=passive}

The config file I used for ipsec.conf is different (I used the conf previously for openswan):

config setup
    # which IPsec stack to use, "netkey" (the default), "klips" or "mast".
    # For MacOSX use "bsd"
    protostack=netkey
    #
    # Normally, pluto logs via syslog. If you want to log to a file,
    # specify below or to disable logging, eg for embedded systems, use
    # the file name /dev/null
    # Note: SElinux policies might prevent pluto writing to a log file at
    #       an unusual location.
    #logfile=/var/log/pluto.log
    #
    # Do not enable debug options to debug configuration issues!
    #
    # plutodebug "all", "none" or a combation from below:
    # "raw crypt parsing emitting control controlmore kernel pfkey
    #  natt x509 dpd dns oppo oppoinfo private".
    # Note: "private" is not included with "all", as it can show confidential
    #       information. It must be specifically specified
    # examples:
    # plutodebug="control parsing"
    # plutodebug="all crypt"
    # Again: only enable plutodebug when asked by a developer
    #plutodebug=none
    #
    # Enable core dumps (might require system changes, like ulimit -C)
    # This is required for abrtd to work properly
    # Note: SElinux policies might prevent pluto writing the core at
    #       unusual locations
    dumpdir=/var/run/pluto/
    #
    # NAT-TRAVERSAL support
    # exclude networks used on server side by adding %v4:!a.b.c.0/24
    # It seems that T-Mobile in the US and Rogers/Fido in Canada are
    # using 25/8 as "private" address space on their wireless networks.
    # This range has never been announced via BGP (at least upto 2015)
    virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/16,%v4:172.16.0.0/12,%v4:25.0.0.0/8,%v4:100.64.0.0/10,%v6:fd00::/8,%v6:fe80::/10

    # Added by me (config from L2TP IPsec VPN Manager)
    plutodebug=none
    strictcrlpolicy=no
    nat_traversal=yes
    interfaces=%defaultroute
    oe=off

# For example connections, see your distribution's documentation directory,
# or https://libreswan.org/wiki/
#
# There is also a lot of information in the manual page, "man ipsec.conf"
#
# It is best to add your IPsec connections as separate files in /etc/ipsec.d/
include /etc/ipsec.d/*.conf

conn %default
    keyingtries=3
    pfs=no
    rekey=yes
    type=transport
    left=%defaultroute
    leftprotoport=17/1701
    rightprotoport=17/1701

conn IE
    authby=secret

    right=SERVE_IP
    rightid=""
    auto=add
    ikelifetime=8h
    lifetime=8h
dkosovic commented 7 years ago

You are seeing some proposal warnings, for the following:

003 "IE" #2: our client subnet returned doesn't match my proposal - us:10.6.45.81/32 vs them:137.189.240.198/32

Could probably be quietened by setting the following in ipsec.conf :

rightid=%any

For the following:

003 "IE" #2: our client peer returned port doesn't match my proposal - us:1701 vs them:0

it's related to the following:

leftprotoport=17/1701
rightprotoport=17/1701

It's pretty odd that the VPN server used port 0 instead of 1701.

Only real suggestion I have is to try and build the same version number of xl2tpd as what you used on Ubuntu 14.04

shawnLeeZX commented 7 years ago

I checked a working Ubuntu workstation, whose xl2tpd version is the same (1.3.6). Maybe there is something wrong with the kernel algorithm.

Thanks very much for the help. I guess I have to leave this as it is for some time, having spent too much time, and starting worrying about deadline. Maybe I will switch to arch when I have more time.

I will leave this issue open, thinking I may come back in the future, maybe with a fix.

dkosovic commented 7 years ago

I'll close this issue, I'm just cleaning up open issues that can be closed.

I'll reopen it whenever you reply with an email in the future.

But as you seem to be having an issue with the command-line tools also, it doesn't seem like a bug specifically with this VPN plug-in