search

nm-l2tp / NetworkManager-l2tp

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

Cannot establish IPSec connection #32

Closed disharmonized closed 7 years ago

disharmonized commented 7 years ago

Problem

I cannot connect via network-manager-l2tp to l2tp/ipsec VPN. I dont know how to identify the cause of problem, so i just attach my config all logs and hope you can help me with that.

Configuration

rbikkinin@rbikkinin:~$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 16.04.1 LTS
Release:    16.04
Codename:   xenial
rbikkinin@rbikkinin:~$ uname -a
Linux rbikkinin 4.4.0-53-generic #74-Ubuntu SMP Fri Dec 2 15:59:10 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

l2tp connection settings

image

image

Debug output

I ran such commands in parallel:

$ tail -f -n 0 /var/log/syslog

Dec 14 09:59:45 rbikkinin NetworkManager[876]: <info>  [1481698785.8120] audit: op="connection-activate" uuid="67f5190e-7399-4a25-b4cd-8e429aa2413a" name="l2tp" pid=6208 uid=1000 result="success"
Dec 14 09:59:45 rbikkinin NetworkManager[876]: <info>  [1481698785.8148] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: Started the VPN service, PID 15496
Dec 14 09:59:45 rbikkinin NetworkManager[876]: <info>  [1481698785.8212] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: Saw the service appear; activating connection
Dec 14 09:59:45 rbikkinin NetworkManager[876]: <info>  [1481698785.8790] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: VPN connection: (ConnectInteractive) reply received
Dec 14 09:59:45 rbikkinin NetworkManager[876]: nm-l2tp[15496] <info>  ipsec enable flag: yes
Dec 14 09:59:45 rbikkinin NetworkManager[876]: ** Message: Check port 1701
Dec 14 09:59:45 rbikkinin NetworkManager[876]: nm-l2tp[15496] <info>  starting ipsec
Dec 14 09:59:45 rbikkinin NetworkManager[876]: Stopping strongSwan IPsec...
Dec 14 09:59:45 rbikkinin charon: 00[DMN] signal of type SIGINT received. Shutting down
Dec 14 09:59:47 rbikkinin NetworkManager[876]: Starting strongSwan 5.3.5 IPsec [starter]...
Dec 14 09:59:47 rbikkinin NetworkManager[876]: Loading config setup
Dec 14 09:59:47 rbikkinin NetworkManager[876]: Loading conn 'nm-ipsec-l2tp-15496'
Dec 14 09:59:47 rbikkinin NetworkManager[876]: found netkey IPsec stack
Dec 14 09:59:47 rbikkinin charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.3.5, Linux 4.4.0-53-generic, x86_64)
Dec 14 09:59:48 rbikkinin charon: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Dec 14 09:59:48 rbikkinin charon: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Dec 14 09:59:48 rbikkinin charon: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Dec 14 09:59:48 rbikkinin charon: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Dec 14 09:59:48 rbikkinin charon: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Dec 14 09:59:48 rbikkinin charon: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 14 09:59:48 rbikkinin charon: 00[CFG] line 1: malformed secret: missing second delimiter
Dec 14 09:59:48 rbikkinin 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
Dec 14 09:59:48 rbikkinin charon: 00[LIB] dropped capabilities, running as uid 0, gid 0
Dec 14 09:59:48 rbikkinin charon: 00[JOB] spawning 16 worker threads
Dec 14 09:59:48 rbikkinin charon: 05[CFG] received stroke: add connection 'nm-ipsec-l2tp-15496'
Dec 14 09:59:48 rbikkinin charon: 05[CFG] added configuration 'nm-ipsec-l2tp-15496'
Dec 14 09:59:49 rbikkinin charon: 07[CFG] rereading secrets
Dec 14 09:59:49 rbikkinin charon: 07[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 14 09:59:49 rbikkinin charon: 07[CFG] line 1: malformed secret: missing second delimiter
Dec 14 09:59:49 rbikkinin charon: 09[CFG] received stroke: initiate 'nm-ipsec-l2tp-15496'
Dec 14 09:59:49 rbikkinin charon: 11[IKE] initiating Main Mode IKE_SA nm-ipsec-l2tp-15496[1] to 192.168.0.247
Dec 14 09:59:49 rbikkinin charon: 11[ENC] generating ID_PROT request 0 [ SA V V V V ]
Dec 14 09:59:49 rbikkinin charon: 11[NET] sending packet: from 192.168.0.50[500] to 192.168.0.247[500] (280 bytes)
Dec 14 09:59:49 rbikkinin charon: 12[NET] received packet: from 192.168.0.247[500] to 192.168.0.50[500] (208 bytes)
Dec 14 09:59:49 rbikkinin charon: 12[ENC] parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 14 09:59:49 rbikkinin charon: 12[IKE] received MS NT5 ISAKMPOAKLEY vendor ID
Dec 14 09:59:49 rbikkinin charon: 12[IKE] received NAT-T (RFC 3947) vendor ID
Dec 14 09:59:49 rbikkinin charon: 12[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 14 09:59:49 rbikkinin charon: 12[IKE] received FRAGMENTATION vendor ID
Dec 14 09:59:49 rbikkinin charon: 12[ENC] received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 14 09:59:49 rbikkinin charon: 12[ENC] received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 14 09:59:49 rbikkinin charon: 12[ENC] generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 14 09:59:49 rbikkinin charon: 12[NET] sending packet: from 192.168.0.50[500] to 192.168.0.247[500] (244 bytes)
Dec 14 09:59:49 rbikkinin charon: 13[NET] received packet: from 192.168.0.247[500] to 192.168.0.50[500] (260 bytes)
Dec 14 09:59:49 rbikkinin charon: 13[ENC] parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 14 09:59:49 rbikkinin charon: 13[ENC] generating INFORMATIONAL_V1 request 216276590 [ N(INVAL_KE) ]
Dec 14 09:59:49 rbikkinin charon: 13[NET] sending packet: from 192.168.0.50[500] to 192.168.0.247[500] (56 bytes)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: initiating Main Mode IKE_SA nm-ipsec-l2tp-15496[1] to 192.168.0.247
Dec 14 09:59:49 rbikkinin NetworkManager[876]: generating ID_PROT request 0 [ SA V V V V ]
Dec 14 09:59:49 rbikkinin NetworkManager[876]: sending packet: from 192.168.0.50[500] to 192.168.0.247[500] (280 bytes)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received packet: from 192.168.0.247[500] to 192.168.0.50[500] (208 bytes)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received MS NT5 ISAKMPOAKLEY vendor ID
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received NAT-T (RFC 3947) vendor ID
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received FRAGMENTATION vendor ID
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 14 09:59:49 rbikkinin NetworkManager[876]: generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 14 09:59:49 rbikkinin NetworkManager[876]: sending packet: from 192.168.0.50[500] to 192.168.0.247[500] (244 bytes)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: received packet: from 192.168.0.247[500] to 192.168.0.50[500] (260 bytes)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 14 09:59:49 rbikkinin NetworkManager[876]: generating INFORMATIONAL_V1 request 216276590 [ N(INVAL_KE) ]
Dec 14 09:59:49 rbikkinin NetworkManager[876]: sending packet: from 192.168.0.50[500] to 192.168.0.247[500] (56 bytes)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: establishing connection 'nm-ipsec-l2tp-15496' failed
Dec 14 09:59:49 rbikkinin NetworkManager[876]: nm-l2tp[15496] <warn>  Could not establish IPsec tunnel.
Dec 14 09:59:49 rbikkinin charon: 06[CFG] rereading secrets
Dec 14 09:59:49 rbikkinin charon: 06[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 14 09:59:49 rbikkinin NetworkManager[876]: (nm-l2tp-service:15496): GLib-GIO-CRITICAL **: g_dbus_method_invocation_take_error: assertion 'error != NULL' failed
Dec 14 09:59:49 rbikkinin NetworkManager[876]: <info>  [1481698789.0333] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: VPN plugin: state changed: stopped (6)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: <info>  [1481698789.0339] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: VPN plugin: state change reason: unknown (0)
Dec 14 09:59:49 rbikkinin NetworkManager[876]: <info>  [1481698789.0348] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: VPN service disappeared
Dec 14 09:59:49 rbikkinin NetworkManager[876]: <warn>  [1481698789.0354] vpn-connection[0x13d17d0,67f5190e-7399-4a25-b4cd-8e429aa2413a,"l2tp",0]: VPN connection: failed to connect: 'Message recipient disconnected from message bus without replying'
$ sudo tcpdump host 192.168.0.247
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
09:59:49.010822 IP 192.168.0.50.isakmp > 192.168.0.247.isakmp: isakmp: phase 1 I ident
09:59:49.012357 ARP, Request who-has 192.168.0.50 tell 192.168.0.247, length 46
09:59:49.012373 ARP, Reply 192.168.0.50 is-at bc:5f:f4:df:0f:2e (oui Unknown), length 28
09:59:49.012923 IP 192.168.0.247.isakmp > 192.168.0.50.isakmp: isakmp: phase 1 R ident
09:59:49.014199 IP 192.168.0.50.isakmp > 192.168.0.247.isakmp: isakmp: phase 1 I ident
09:59:49.023652 IP 192.168.0.247.isakmp > 192.168.0.50.isakmp: isakmp: phase 1 R ident
09:59:49.024327 IP 192.168.0.50.isakmp > 192.168.0.247.isakmp: isakmp: phase 2/others I inf
09:59:49.415794 ARP, Request who-has 192.168.0.247 tell 192.168.0.212, length 46
09:59:49.416964 ARP, Request who-has 192.168.0.212 tell 192.168.0.247, length 46
09:59:52.433136 ARP, Request who-has 192.168.0.247 tell 192.168.0.176, length 46
09:59:52.433645 ARP, Request who-has 192.168.0.176 tell 192.168.0.247, length 46
^C
19 packets captured
19 packets received by filter
0 packets dropped by kernel
dkosovic commented 7 years ago

The problem seems to be the following issue in the logs :

charon: 07[CFG] line 1: malformed secret: missing second delimiter

and the "missing second delimiter" error message seems to be coming from the strongswan extract_secret() function :

https://github.com/strongswan/strongswan/blob/master/src/libcharon/plugins/stroke/stroke_cred.c#L615

Which seems to only occur when single quote (') or double quote (") are involved.

Does the pre-shared key (PSK) have a single quote or double quote ? If it has a single quote, you could try putting the PSK between double quotes, similarly if it has a double quote, try pitting it between single quotes and see if that helps.

disharmonized commented 7 years ago

Thanks! My problem was that i copy-pasted password with some extra spaces or whatever, i dont understand what exactly it was. I just hand typed it and it works!

Skybladev2 commented 7 years ago

Hi,

I can not connect to my work VPN server too, and can not identify the problem as well. It seems it is related to AppArmor, but I don't understand the meaning of these messages:

Dec 18 18:12:14 HOME2-PC NetworkManager[1202]: <info>  [1482073934.7322] audit: op="connection-activate" uuid="c9c1c8d2-5b68-4b2f-9375-cec6f7da9741" name="VpnName L2TP" pid=1910 uid=1000 result="success"
Dec 18 18:12:14 HOME2-PC NetworkManager[1202]: <info>  [1482073934.7428] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: Started the VPN service, PID 4032
Dec 18 18:12:14 HOME2-PC NetworkManager[1202]: <info>  [1482073934.7669] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: Saw the service appear; activating connection
Dec 18 18:12:14 HOME2-PC gnome-session[1765]: Gtk-Message: GtkDialog mapped without a transient parent. This is discouraged.
Dec 18 18:12:22 HOME2-PC NetworkManager[1202]: <info>  [1482073942.5717] keyfile: update /etc/NetworkManager/system-connections/VpnName L2TP (c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP")
Dec 18 18:12:22 HOME2-PC NetworkManager[1202]: <info>  [1482073942.5846] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN connection: (ConnectInteractive) reply received
Dec 18 18:12:22 HOME2-PC NetworkManager[1202]: nm-l2tp[4032] <info>  ipsec enable flag: yes
Dec 18 18:12:22 HOME2-PC NetworkManager[1202]: ** Message: Check port 1701
Dec 18 18:12:22 HOME2-PC NetworkManager[1202]: nm-l2tp[4032] <info>  starting ipsec
Dec 18 18:12:22 HOME2-PC NetworkManager[1202]: Stopping strongSwan IPsec...
Dec 18 18:12:22 HOME2-PC kernel: [ 2039.586043] audit_printk_skb: 114 callbacks suppressed
Dec 18 18:12:22 HOME2-PC kernel: [ 2039.586046] audit: type=1400 audit(1482073942.607:201): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=3959 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC NetworkManager[1202]: Starting strongSwan 5.3.5 IPsec [starter]...
Dec 18 18:12:24 HOME2-PC NetworkManager[1202]: Loading config setup
Dec 18 18:12:24 HOME2-PC NetworkManager[1202]: Loading conn 'nm-ipsec-l2tp-4032'
Dec 18 18:12:24 HOME2-PC NetworkManager[1202]: found netkey IPsec stack
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.724683] audit: type=1400 audit(1482073944.747:202): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.734683] audit: type=1400 audit(1482073944.755:203): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.734795] audit: type=1400 audit(1482073944.755:204): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.734868] audit: type=1400 audit(1482073944.755:205): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.734938] audit: type=1400 audit(1482073944.755:206): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.734994] audit: type=1400 audit(1482073944.755:207): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.735058] audit: type=1400 audit(1482073944.755:208): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.735155] audit: type=1400 audit(1482073944.755:209): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:24 HOME2-PC kernel: [ 2041.735381] audit: type=1400 audit(1482073944.755:210): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/lib/ipsec/charon" name="run/systemd/journal/dev-log" pid=4076 comm="charon" requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: initiating Main Mode IKE_SA nm-ipsec-l2tp-4032[1] to 183.122.32.14
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: generating ID_PROT request 0 [ SA V V V V ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (280 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received packet: from 183.122.32.14[500] to 192.168.1.103[500] (208 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received MS NT5 ISAKMPOAKLEY vendor ID
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received NAT-T (RFC 3947) vendor ID
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received FRAGMENTATION vendor ID
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received packet: from 183.122.32.14[500] to 192.168.1.103[500] (260 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: local host is behind NAT, sending keep alives
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: remote host is behind NAT
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (100 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: received packet: from 183.122.32.14[4500] to 192.168.1.103[4500] (68 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: parsed ID_PROT response 0 [ ID HASH ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: IDir '172.22.0.60' does not match to '183.122.32.14'
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: deleting IKE_SA nm-ipsec-l2tp-4032[1] between 192.168.1.103[192.168.1.103]...183.122.32.14[%any]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: sending DELETE for IKE_SA nm-ipsec-l2tp-4032[1]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: generating INFORMATIONAL_V1 request 3167011739 [ HASH D ]
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (84 bytes)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: connection 'nm-ipsec-l2tp-4032' established successfully
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: nm-l2tp[4032] <warn>  Could not establish IPsec tunnel.
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: (nm-l2tp-service:4032): GLib-GIO-CRITICAL **: g_dbus_method_invocation_take_error: assertion 'error != NULL' failed
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: <info>  [1482073945.9414] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state changed: stopped (6)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: <info>  [1482073945.9430] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state change reason: unknown (0)
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: <info>  [1482073945.9460] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN service disappeared
Dec 18 18:12:25 HOME2-PC NetworkManager[1202]: <warn>  [1482073945.9476] vpn-connection[0x1d387b0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN connection: failed to connect: 'Message recipient disconnected from message bus without replying'

I used this instructions to set up L2TP: http://blog.z-proj.com/enabling-l2tp-over-ipsec-on-ubuntu-16-04/

Machine and VPN config matches @disharmonized's settings.

Would you be so kind to cast a light on this problem?

dkosovic commented 7 years ago

As you have the following line in your log file :

IDir '172.22.0.60' does not match to '183.122.32.14'

have your tried setting the Gateway ID to 172.22.0.60 in the IPsec Settings dialog box to try and get them to match?

dkosovic commented 7 years ago

@Skybladev2 sorry forgot to mention regarding the AppArmor issue you use the Apparmor workaround mentioned on the following page :

https://github.com/nm-l2tp/network-manager-l2tp/wiki

Skybladev2 commented 7 years ago

Hi @dkosovic , Thank you for reply!

I filled up Gateway ID and re-run AppArmor workaround. It did not help, and now I get this log:

Dec 20 16:01:16 HOME2-PC NetworkManager[1132]: <info>  [1482238876.8288] keyfile: update /etc/NetworkManager/system-connections/VpnName L2TP (c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP")
Dec 20 16:01:16 HOME2-PC NetworkManager[1132]: <info>  [1482238876.8403] vpn-connection[0xc5a3e0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN connection: (ConnectInteractive) reply received
Dec 20 16:01:16 HOME2-PC NetworkManager[1132]: nm-l2tp[8004] <info>  ipsec enable flag: yes
Dec 20 16:01:16 HOME2-PC NetworkManager[1132]: ** Message: Check port 1701
Dec 20 16:01:16 HOME2-PC NetworkManager[1132]: nm-l2tp[8004] <info>  starting ipsec
Dec 20 16:01:16 HOME2-PC NetworkManager[1132]: Stopping strongSwan IPsec...
Dec 20 16:01:16 HOME2-PC charon: 00[DMN] signal of type SIGINT received. Shutting down
Dec 20 16:01:18 HOME2-PC NetworkManager[1132]: Starting strongSwan 5.3.5 IPsec [starter]...
Dec 20 16:01:18 HOME2-PC NetworkManager[1132]: Loading config setup
Dec 20 16:01:18 HOME2-PC NetworkManager[1132]: Loading conn 'nm-ipsec-l2tp-8004'
Dec 20 16:01:18 HOME2-PC NetworkManager[1132]: found netkey IPsec stack
Dec 20 16:01:19 HOME2-PC charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.3.5, Linux 4.4.0-53-generic, x86_64)
Dec 20 16:01:19 HOME2-PC charon: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Dec 20 16:01:19 HOME2-PC charon: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Dec 20 16:01:19 HOME2-PC charon: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Dec 20 16:01:19 HOME2-PC charon: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Dec 20 16:01:19 HOME2-PC charon: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Dec 20 16:01:19 HOME2-PC charon: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 20 16:01:19 HOME2-PC charon: 00[CFG]   loaded IKE secret for %any @vpn-dev.vpnserver.com
Dec 20 16:01:19 HOME2-PC 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
Dec 20 16:01:19 HOME2-PC charon: 00[LIB] dropped capabilities, running as uid 0, gid 0
Dec 20 16:01:19 HOME2-PC charon: 00[JOB] spawning 16 worker threads
Dec 20 16:01:19 HOME2-PC charon: 04[CFG] received stroke: add connection 'nm-ipsec-l2tp-8004'
Dec 20 16:01:19 HOME2-PC charon: 04[CFG] added configuration 'nm-ipsec-l2tp-8004'
Dec 20 16:01:20 HOME2-PC charon: 06[CFG] rereading secrets
Dec 20 16:01:20 HOME2-PC charon: 06[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 20 16:01:20 HOME2-PC charon: 06[CFG]   loaded IKE secret for %any @vpn-dev.vpnserver.com
Dec 20 16:01:20 HOME2-PC charon: 07[CFG] received stroke: initiate 'nm-ipsec-l2tp-8004'
Dec 20 16:01:20 HOME2-PC charon: 09[IKE] initiating Main Mode IKE_SA nm-ipsec-l2tp-8004[1] to 183.122.32.14
Dec 20 16:01:20 HOME2-PC charon: 09[ENC] generating ID_PROT request 0 [ SA V V V V ]
Dec 20 16:01:20 HOME2-PC charon: 09[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (280 bytes)
Dec 20 16:01:20 HOME2-PC charon: 10[NET] received packet: from 183.122.32.14[500] to 192.168.1.103[500] (208 bytes)
Dec 20 16:01:20 HOME2-PC charon: 10[ENC] parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 20 16:01:20 HOME2-PC charon: 10[IKE] received MS NT5 ISAKMPOAKLEY vendor ID
Dec 20 16:01:20 HOME2-PC charon: 10[IKE] received NAT-T (RFC 3947) vendor ID
Dec 20 16:01:20 HOME2-PC charon: 10[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 20 16:01:20 HOME2-PC charon: 10[IKE] received FRAGMENTATION vendor ID
Dec 20 16:01:20 HOME2-PC charon: 10[ENC] received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 20 16:01:20 HOME2-PC charon: 10[ENC] received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 20 16:01:20 HOME2-PC charon: 10[ENC] generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 20 16:01:20 HOME2-PC charon: 10[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 20 16:01:24 HOME2-PC charon: 14[IKE] sending retransmit 1 of request message ID 0, seq 2
Dec 20 16:01:24 HOME2-PC charon: 14[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 20 16:01:24 HOME2-PC charon: 13[NET] received packet: from 183.122.32.14[500] to 192.168.1.103[500] (260 bytes)
Dec 20 16:01:24 HOME2-PC charon: 13[ENC] parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 20 16:01:24 HOME2-PC charon: 13[ENC] generating INFORMATIONAL_V1 request 2109420487 [ N(INVAL_KE) ]
Dec 20 16:01:24 HOME2-PC charon: 13[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (56 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: initiating Main Mode IKE_SA nm-ipsec-l2tp-8004[1] to 183.122.32.14
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: generating ID_PROT request 0 [ SA V V V V ]
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (280 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received packet: from 183.122.32.14[500] to 192.168.1.103[500] (208 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received MS NT5 ISAKMPOAKLEY vendor ID
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received NAT-T (RFC 3947) vendor ID
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received FRAGMENTATION vendor ID
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: sending retransmit 1 of request message ID 0, seq 2
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: received packet: from 183.122.32.14[500] to 192.168.1.103[500] (260 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: generating INFORMATIONAL_V1 request 2109420487 [ N(INVAL_KE) ]
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (56 bytes)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: establishing connection 'nm-ipsec-l2tp-8004' failed
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: nm-l2tp[8004] <warn>  Could not establish IPsec tunnel.
Dec 20 16:01:24 HOME2-PC charon: 04[CFG] rereading secrets
Dec 20 16:01:24 HOME2-PC charon: 04[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: (nm-l2tp-service:8004): GLib-GIO-CRITICAL **: g_dbus_method_invocation_take_error: assertion 'error != NULL' failed
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: <info>  [1482238884.2889] vpn-connection[0xc5a3e0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state changed: stopped (6)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: <info>  [1482238884.2905] vpn-connection[0xc5a3e0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state change reason: unknown (0)
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: <info>  [1482238884.2925] vpn-connection[0xc5a3e0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN service disappeared
Dec 20 16:01:24 HOME2-PC NetworkManager[1132]: <warn>  [1482238884.2940] vpn-connection[0xc5a3e0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN connection: failed to connect: 'Message recipient disconnected from message bus without replying'
dkosovic commented 7 years ago

I might have lead you astray in asking to set the Gateway ID as the issue with the IDs not matching was probably a side-effect of AppArmor issue which now seems to be fixed.

Have you tried not setting the Gateway ID ?

Skybladev2 commented 7 years ago

@dkosovic Not yet, but don't I have to set it to '183.122.32.14', not '172.22.0.60'? I don't know where '172.22.0.60' IP came from, while '183.122.32.14' is my VPN server address.

Skybladev2 commented 7 years ago

Ok, I tried to remove Gateway ID, and got the same log as the last one except for 2 new lines IDir '172.22.0.60' does not match to '183.122.32.14'.

Then I set it to 172.22.0.60 and almost succeeded:

Dec 22 19:34:31 HOME2-PC gnome-session[1830]: Gtk-Message: GtkDialog mapped without a transient parent. This is discouraged.
Dec 22 19:34:33 HOME2-PC gnome-session[1830]: ** Message: Cannot save connection due to error: Editor initializing...
Dec 22 19:34:33 HOME2-PC gnome-session[1830]: ** Message: Connection validates and can be saved
Dec 22 19:34:36 HOME2-PC gnome-session[1830]: (nm-connection-editor:9692): libnm-CRITICAL **: nm_setting_vpn_add_data_item: assertion 'strlen (item) > 0' failed
Dec 22 19:34:37 HOME2-PC gnome-session[1830]: (nm-connection-editor:9692): libnm-CRITICAL **: nm_setting_vpn_add_data_item: assertion 'strlen (item) > 0' failed
Dec 22 19:34:37 HOME2-PC NetworkManager[1132]: <info>  [1482424477.3329] keyfile: update /etc/NetworkManager/system-connections/VpnName L2TP (c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP")
Dec 22 19:34:37 HOME2-PC NetworkManager[1132]: <info>  [1482424477.3341] audit: op="connection-update" uuid="c9c1c8d2-5b68-4b2f-9375-cec6f7da9741" name="VpnName L2TP" pid=9692 uid=1000 result="success"
Dec 22 19:34:41 HOME2-PC NetworkManager[1132]: <info>  [1482424481.2178] audit: op="connection-activate" uuid="c9c1c8d2-5b68-4b2f-9375-cec6f7da9741" name="VpnName L2TP" pid=1961 uid=1000 result="success"
Dec 22 19:34:41 HOME2-PC NetworkManager[1132]: <info>  [1482424481.2208] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: Started the VPN service, PID 9703
Dec 22 19:34:41 HOME2-PC NetworkManager[1132]: <info>  [1482424481.2287] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: Saw the service appear; activating connection
Dec 22 19:34:41 HOME2-PC gnome-session[1830]: Gtk-Message: GtkDialog mapped without a transient parent. This is discouraged.
Dec 22 19:34:45 HOME2-PC NetworkManager[1132]: <info>  [1482424485.6948] keyfile: update /etc/NetworkManager/system-connections/VpnName L2TP (c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP")
Dec 22 19:34:45 HOME2-PC NetworkManager[1132]: <info>  [1482424485.7080] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN connection: (ConnectInteractive) reply received
Dec 22 19:34:45 HOME2-PC NetworkManager[1132]: nm-l2tp[9703] <info>  ipsec enable flag: yes
Dec 22 19:34:45 HOME2-PC NetworkManager[1132]: ** Message: Check port 1701
Dec 22 19:34:45 HOME2-PC NetworkManager[1132]: nm-l2tp[9703] <info>  starting ipsec
Dec 22 19:34:45 HOME2-PC NetworkManager[1132]: Stopping strongSwan IPsec...
Dec 22 19:34:45 HOME2-PC charon: 00[DMN] signal of type SIGINT received. Shutting down
Dec 22 19:34:47 HOME2-PC NetworkManager[1132]: Starting strongSwan 5.3.5 IPsec [starter]...
Dec 22 19:34:47 HOME2-PC NetworkManager[1132]: Loading config setup
Dec 22 19:34:47 HOME2-PC NetworkManager[1132]: Loading conn 'nm-ipsec-l2tp-9703'
Dec 22 19:34:47 HOME2-PC NetworkManager[1132]: found netkey IPsec stack
Dec 22 19:34:47 HOME2-PC charon: 00[DMN] Starting IKE charon daemon (strongSwan 5.3.5, Linux 4.4.0-53-generic, x86_64)
Dec 22 19:34:47 HOME2-PC charon: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Dec 22 19:34:47 HOME2-PC charon: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Dec 22 19:34:47 HOME2-PC charon: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Dec 22 19:34:47 HOME2-PC charon: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Dec 22 19:34:47 HOME2-PC charon: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Dec 22 19:34:47 HOME2-PC charon: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 22 19:34:47 HOME2-PC charon: 00[CFG]   loaded IKE secret for %any %any
Dec 22 19:34:47 HOME2-PC 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
Dec 22 19:34:47 HOME2-PC charon: 00[LIB] dropped capabilities, running as uid 0, gid 0
Dec 22 19:34:47 HOME2-PC charon: 00[JOB] spawning 16 worker threads
Dec 22 19:34:47 HOME2-PC charon: 05[CFG] received stroke: add connection 'nm-ipsec-l2tp-9703'
Dec 22 19:34:47 HOME2-PC charon: 05[CFG] added configuration 'nm-ipsec-l2tp-9703'
Dec 22 19:34:48 HOME2-PC charon: 07[CFG] rereading secrets
Dec 22 19:34:48 HOME2-PC charon: 07[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 22 19:34:48 HOME2-PC charon: 07[CFG]   loaded IKE secret for %any %any
Dec 22 19:34:48 HOME2-PC charon: 09[CFG] received stroke: initiate 'nm-ipsec-l2tp-9703'
Dec 22 19:34:48 HOME2-PC charon: 10[IKE] initiating Main Mode IKE_SA nm-ipsec-l2tp-9703[1] to 183.122.32.14
Dec 22 19:34:48 HOME2-PC charon: 10[ENC] generating ID_PROT request 0 [ SA V V V V ]
Dec 22 19:34:48 HOME2-PC charon: 10[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (280 bytes)
Dec 22 19:34:48 HOME2-PC charon: 11[NET] received packet: from 183.122.32.14[500] to 192.168.1.103[500] (208 bytes)
Dec 22 19:34:48 HOME2-PC charon: 11[ENC] parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 22 19:34:48 HOME2-PC charon: 11[IKE] received MS NT5 ISAKMPOAKLEY vendor ID
Dec 22 19:34:48 HOME2-PC charon: 11[IKE] received NAT-T (RFC 3947) vendor ID
Dec 22 19:34:48 HOME2-PC charon: 11[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 22 19:34:48 HOME2-PC charon: 11[IKE] received FRAGMENTATION vendor ID
Dec 22 19:34:48 HOME2-PC charon: 11[ENC] received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 22 19:34:48 HOME2-PC charon: 11[ENC] received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 22 19:34:48 HOME2-PC charon: 11[ENC] generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 22 19:34:48 HOME2-PC charon: 11[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 22 19:34:52 HOME2-PC charon: 13[IKE] sending retransmit 1 of request message ID 0, seq 2
Dec 22 19:34:52 HOME2-PC charon: 13[NET] sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 22 19:34:52 HOME2-PC charon: 14[NET] received packet: from 183.122.32.14[500] to 192.168.1.103[500] (260 bytes)
Dec 22 19:34:52 HOME2-PC charon: 14[ENC] parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 22 19:34:52 HOME2-PC charon: 14[IKE] local host is behind NAT, sending keep alives
Dec 22 19:34:52 HOME2-PC charon: 14[IKE] remote host is behind NAT
Dec 22 19:34:52 HOME2-PC charon: 14[ENC] generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Dec 22 19:34:52 HOME2-PC charon: 14[NET] sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (100 bytes)
Dec 22 19:34:52 HOME2-PC charon: 15[NET] received packet: from 183.122.32.14[4500] to 192.168.1.103[4500] (68 bytes)
Dec 22 19:34:52 HOME2-PC charon: 15[ENC] parsed ID_PROT response 0 [ ID HASH ]
Dec 22 19:34:52 HOME2-PC charon: 15[IKE] IKE_SA nm-ipsec-l2tp-9703[1] established between 192.168.1.103[192.168.1.103]...183.122.32.14[172.22.0.60]
Dec 22 19:34:52 HOME2-PC charon: 15[IKE] scheduling reauthentication in 9820s
Dec 22 19:34:52 HOME2-PC charon: 15[IKE] maximum IKE_SA lifetime 10360s
Dec 22 19:34:52 HOME2-PC charon: 15[ENC] generating QUICK_MODE request 123503106 [ HASH SA No ID ID NAT-OA NAT-OA ]
Dec 22 19:34:52 HOME2-PC charon: 15[NET] sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (244 bytes)
Dec 22 19:34:53 HOME2-PC charon: 06[NET] received packet: from 183.122.32.14[4500] to 192.168.1.103[4500] (212 bytes)
Dec 22 19:34:53 HOME2-PC charon: 06[ENC] parsed QUICK_MODE response 123503106 [ HASH SA No ID ID NAT-OA NAT-OA ]
Dec 22 19:34:53 HOME2-PC charon: 06[IKE] CHILD_SA nm-ipsec-l2tp-9703{1} established with SPIs c98c3869_i b1df3486_o and TS 192.168.1.103/32[udp/l2f] === 183.122.32.14/32[udp/l2f]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: initiating Main Mode IKE_SA nm-ipsec-l2tp-9703[1] to 183.122.32.14
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: generating ID_PROT request 0 [ SA V V V V ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (280 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received packet: from 183.122.32.14[500] to 192.168.1.103[500] (208 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: parsed ID_PROT response 0 [ SA V V V V V V ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received MS NT5 ISAKMPOAKLEY vendor ID
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received NAT-T (RFC 3947) vendor ID
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received FRAGMENTATION vendor ID
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: sending retransmit 1 of request message ID 0, seq 2
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[500] to 183.122.32.14[500] (244 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received packet: from 183.122.32.14[500] to 192.168.1.103[500] (260 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: local host is behind NAT, sending keep alives
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: remote host is behind NAT
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (100 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received packet: from 183.122.32.14[4500] to 192.168.1.103[4500] (68 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: parsed ID_PROT response 0 [ ID HASH ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: IKE_SA nm-ipsec-l2tp-9703[1] established between 192.168.1.103[192.168.1.103]...183.122.32.14[172.22.0.60]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: scheduling reauthentication in 9820s
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: maximum IKE_SA lifetime 10360s
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: generating QUICK_MODE request 123503106 [ HASH SA No ID ID NAT-OA NAT-OA ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (244 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: received packet: from 183.122.32.14[4500] to 192.168.1.103[4500] (212 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: parsed QUICK_MODE response 123503106 [ HASH SA No ID ID NAT-OA NAT-OA ]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: CHILD_SA nm-ipsec-l2tp-9703{1} established with SPIs c98c3869_i b1df3486_o and TS 192.168.1.103/32[udp/l2f] === 183.122.32.14/32[udp/l2f]
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: connection 'nm-ipsec-l2tp-9703' established successfully
Dec 22 19:34:53 HOME2-PC charon: 06[ENC] generating QUICK_MODE request 123503106 [ HASH ]
Dec 22 19:34:53 HOME2-PC charon: 06[NET] sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (60 bytes)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: nm-l2tp[9703] <info>  strongSwan ready for action.
Dec 22 19:34:53 HOME2-PC charon: 07[NET] received packet: from 183.122.32.14[4500] to 192.168.1.103[4500] (76 bytes)
Dec 22 19:34:53 HOME2-PC charon: 07[ENC] parsed QUICK_MODE response 123503106 [ HASH N(INIT_CONTACT) ]
Dec 22 19:34:53 HOME2-PC charon: 07[IKE] ignoring fourth Quick Mode message
Dec 22 19:34:53 HOME2-PC charon: 04[CFG] rereading secrets
Dec 22 19:34:53 HOME2-PC charon: 04[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: ** Message: xl2tpd started with pid 9812
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: setsockopt recvref[30]: Protocol not available
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.0725] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state changed: starting (3)
Dec 22 19:34:53 HOME2-PC kernel: [ 5028.645136] NET: Registered protocol family 24
Dec 22 19:34:53 HOME2-PC kernel: [ 5028.662915] l2tp_core: L2TP core driver, V2.0
Dec 22 19:34:53 HOME2-PC kernel: [ 5028.666843] l2tp_netlink: L2TP netlink interface
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Using l2tp kernel support.
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: xl2tpd version xl2tpd-1.3.6 started on HOME2-PC PID:9812
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Forked by Scott Balmos and David Stipp, (C) 2001
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Inherited by Jeff McAdams, (C) 2002
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Forked again by Xelerance (www.xelerance.com) (C) 2006
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Listening on IP address 0.0.0.0, port 1701
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Connecting to host 183.122.32.14, port 1701
Dec 22 19:34:53 HOME2-PC kernel: [ 5028.671363] l2tp_ppp: PPPoL2TP kernel driver, V2.0
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Connection established to 183.122.32.14, 1701.  Local: 21237, Remote: 3392 (ref=0/0).
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Calling on tunnel 21237
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Call established with 183.122.32.14, Local: 58921, Remote: 6, Serial: 1 (ref=0/0)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: start_pppd: I'm running:
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "/usr/sbin/pppd"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "passive"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "nodetach"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: ":"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "file"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "/var/run/nm-ppp-options.xl2tpd.9703"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "plugin"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "pppol2tp.so"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "pppol2tp"
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: "7"
Dec 22 19:34:53 HOME2-PC pppd[9821]: Plugin /usr/lib/pppd/2.4.7/nm-l2tp-pppd-plugin.so loaded.
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] initializing
Dec 22 19:34:53 HOME2-PC pppd[9821]: Plugin pppol2tp.so loaded.
Dec 22 19:34:53 HOME2-PC pppd[9821]: pppd 2.4.7 started by root, uid 0
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 3 / phase 'serial connection'
Dec 22 19:34:53 HOME2-PC pppd[9821]: Using interface ppp0
Dec 22 19:34:53 HOME2-PC pppd[9821]: Connect: ppp0 <-->
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: nm_device_get_device_type: assertion 'NM_IS_DEVICE (self)' failed
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 5 / phase 'establish'
Dec 22 19:34:53 HOME2-PC pppd[9821]: Overriding mtu 1500 to 1400
Dec 22 19:34:53 HOME2-PC pppd[9821]: Overriding mru 1500 to mtu value 1400
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.1771] manager: (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/7)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.1918] devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.1919] device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 6 / phase 'authenticate'
Dec 22 19:34:53 HOME2-PC pppd[9821]: EAP: peer reports authentication failure
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 10 / phase 'terminate'
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 5 / phase 'establish'
Dec 22 19:34:53 HOME2-PC pppd[9821]: Overriding mtu 1500 to 1400
Dec 22 19:34:53 HOME2-PC pppd[9821]: Overriding mru 1500 to mtu value 1400
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 11 / phase 'disconnect'
Dec 22 19:34:53 HOME2-PC pppd[9821]: Connection terminated.
Dec 22 19:34:53 HOME2-PC charon: 14[KNL] interface ppp0 deleted
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: nm-l2tp[9703] <info>  Terminated xl2tpd daemon with PID 9812.
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: death_handler: Fatal signal 15 received
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Terminating pppd: sending TERM signal to pid 9821
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: xl2tpd[9812]: Connection 3392 closed to 183.122.32.14, port 1701 (Server closing)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <warn>  [1482424493.7638] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: failed: connect-failed (1)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.7639] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state changed: stopping (5)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <error> [1482424493.7680] platform-linux: do-change-link[8]: failure changing link: failure 19 (No such device)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <warn>  [1482424493.7681] device (ppp0): failed to disable userspace IPv6LL address handling
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.7687] devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: Stopping strongSwan IPsec...
Dec 22 19:34:53 HOME2-PC charon: 00[DMN] signal of type SIGINT received. Shutting down
Dec 22 19:34:53 HOME2-PC charon: 00[IKE] closing CHILD_SA nm-ipsec-l2tp-9703{1} with SPIs c98c3869_i (538 bytes) b1df3486_o (538 bytes) and TS 192.168.1.103/32[udp/l2f] === 183.122.32.14/32[udp/l2f]
Dec 22 19:34:53 HOME2-PC charon: 00[IKE] sending DELETE for ESP CHILD_SA with SPI c98c3869
Dec 22 19:34:53 HOME2-PC charon: 00[ENC] generating INFORMATIONAL_V1 request 4156019341 [ HASH D ]
Dec 22 19:34:53 HOME2-PC charon: 00[NET] sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (76 bytes)
Dec 22 19:34:53 HOME2-PC charon: 00[IKE] deleting IKE_SA nm-ipsec-l2tp-9703[1] between 192.168.1.103[192.168.1.103]...183.122.32.14[172.22.0.60]
Dec 22 19:34:53 HOME2-PC charon: 00[IKE] sending DELETE for IKE_SA nm-ipsec-l2tp-9703[1]
Dec 22 19:34:53 HOME2-PC charon: 00[ENC] generating INFORMATIONAL_V1 request 250250981 [ HASH D ]
Dec 22 19:34:53 HOME2-PC charon: 00[NET] sending packet: from 192.168.1.103[4500] to 183.122.32.14[4500] (84 bytes)
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] phasechange: status 1 / phase 'dead'
Dec 22 19:34:53 HOME2-PC pppd[9821]: nm-l2tp[9703] <info>  [helper-9821] exit: cleaning up
Dec 22 19:34:53 HOME2-PC pppd[9821]: Exit.
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: ** Message: ipsec shut down
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.8749] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state changed: stopped (6)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.8765] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN plugin: state change reason: unknown (0)
Dec 22 19:34:53 HOME2-PC NetworkManager[1132]: <info>  [1482424493.8785] vpn-connection[0xc5a7c0,c9c1c8d2-5b68-4b2f-9375-cec6f7da9741,"VpnName L2TP",0]: VPN service disappeared

I think I have authentication problem?

Dec 22 19:34:53 HOME2-PC pppd[9821]: EAP: peer reports authentication failure
dkosovic commented 7 years ago

With the EAP peer authentication failure, perhaps the VPN server which is advertising it supports EAP hasn't been correctly configured for EAP or uses different credentials than the other authentication methods.

In the VPN Connection's PPP Settings dialog box, try unticking EAP and the other aurthentication methods except for MSCHAPv2 (and maybe MSCHAP).

Skybladev2 commented 7 years ago

@dkosovic That did the trick! Thank you so much!