plugin NeedSecrets request #1 failed with Libreswan

Ri0n commented 8 years ago

I can't find solution for this problem. Google says it's something with keyring manager, but it seems only nm-l2tp suffers.

Gentoo. KDE-5

dkosovic commented 8 years ago

I suspect you might need to upgrade to a newer version of plasma-nm or the libsecret "Secret Service" isn't running properly.

This is the plug-in that plasma-nm is having NeedSecrets issues : https://github.com/nm-l2tp/network-manager-l2tp/blob/master/src/nm-l2tp-pppd-plugin.c#L233

I have tested once with KDE's plama-nm, but I can't remember which version.

Ri0n commented 8 years ago

In dbus-monitor I see

method call time=1469692092.028447 sender=:1.77 -> destination=:1.85 serial=5103 path=/org/freedesktop/NetworkManager/VPN/Plugin; interface=org.freedesktop.NetworkManager.VPN.Plugin; member=NeedSecrets with some body.

No response to this request.

So if I understand properly owner of org.freedesktop.NetworkManager.VPN.Plugin isn't running or not properly initialized.

How can I check it?

plasma-nm-5.7.2

dkosovic commented 8 years ago

To rule out a plasma-nm issue, could you try with the command-line. I'll assume you have a configured VPN connection with plasma-nm's connection editor.

List the NetworkManager connections with:

nmcli c

Bring up the VPN connection and ask for the password in the terminal :

nmcli --ask c up my-vpn-connection

( replace my-vpn-connection with your actual VPN connection name ).

dkosovic commented 8 years ago

Forgot to mention, I'll also assume you built the network-manager-l2tp master branch more or less the same way as the networkmanager-pptp-1.2.2 ebuild in regards to the prerequisites and configure line.

The only differences would be:

pptpclient package isn't required.
xl2tp package is required for L2TP at runtime.
libreswan (or strongswan) is required at runtime if optional IPsec is needed.

EDIT: I just had a look at the networkmanager-pptp-1.2.2 ebuild.

I think app-crypt/libsecret might be required even if GTK isn't used.

the following configure switch is no longer required as the deprecated APIs are no longer used :

--disable-more-warnings

the following switch is just wrong:

--with-dist-version=Gentoo

It's supposed to be the Linux Distribution's version and revision of the package, e.g --with-dist-version=1.2.2-1.fc24, but isn't really required.

What it is doing with --with-pppd-plugin-dir is right.

I'm pretty sure whatever gnome2_src_configure expands to is right also.

Ri0n commented 8 years ago

I'll try this in few hours as soon as I get home. As far as I remember only --with-pppd-plugin-dir=somthing is passed to configure. libreswan and xl2tp are installed.

Ri0n commented 8 years ago

nmcli --ask c up "vpn work" fails the same way. It does not ask anything in console.

Ri0n commented 8 years ago

after system reboot nmcli --ask c up "vpn work" asked for kwallet password once and I see different errors in syslog (something about peer ID mismatch). But next attempts again failed with NeedSecret timeout

dkosovic commented 8 years ago

I'll try and install Gentoo on a VM over the weekend to see if I can reproduce.

Ri0n commented 8 years ago

Oops. Wrong button. Btw I can commit my ebuild to my public overlay

siriuslee commented 8 years ago

I am also hitting this issue on Ubuntu Gnome 16.04. nmcli --ask c up "vpn work" fails with error: Connection activation failed: no valid VPN secrets.

dkosovic commented 8 years ago

@siriuslee I'm not sure if it is the same issue, are you also seeing the peer ID mismatch error also?

I had someone else using Ubuntu 16.04 running as a qemu VM, the "no valid VPN secrets" error frequency happened most after a reboot. The issue was also affecting network-manager-pptp that came with Ubuntu.

I would also try again after issuing :

sudo systemctl restart NetworkManager

dkosovic commented 8 years ago

Forgot to mention with Ubuntu 16.04, I also had the "no valid VPN secrets" error initially when Ubuntu 16.04 first came out, but I hadn't seen it for months after doing :

sudo apt update
sudo apt upgrade

siriuslee commented 8 years ago

I do not see the "peer ID mismatch" error. Running nmcli --ask c up "vpn work" does give me a password prompt just after a reboot, but it just says "connection failed". Subsequent attempts give the "no valid VPN secrets" error, even after restarting NetworkManager. I've fully updated the system and still no change.

Perhaps interestingly, attempting to connect sometimes brings up a new network interface virbr0 that receives an IP address, but it's not within the correct destination IP range.

If you think my issue is separate, I'd be happy to create a new issue thread. Fortunately, thanks to this package in the AUR I am able to connect to the VPN using a separate install of Antergos. I am just more comfortable in Ubuntu based distros and was hoping to get this working in 16.04.

dkosovic commented 8 years ago

@siriuslee although it may or may not end up being the same issue, as Gentoo couldn't be more different than Ubuntu in terms of file install locations and logging. Please submit a new issue, also could I have the output of sudo journalctl -b from the start of the connection to the failed end (but feel free to replace the IP address of you VPN server or anything else that might be publicly sensitive).

The Ubuntu 16.04 running on qemu 'no valid VPN secrets' issue I mentioned before is an open case, I just closed it as the user wasn't too concerned and others started posting unrelated Ubuntu 16.04 issues.

@Ri0n Can you confirm which version of NetworkManager you are using? Similarly could I have the syslog output from start to failure with anything publicly sensitive removed.

I finally got gentoo built and installed, I originally tried a gnome/systemd profile, but gave up and then started fresh and just went for plain gnome. I was expecting NetworkManager-1.2.x, but got the following version instead :

$ equery --quiet list networkmanager
net-misc/networkmanager-1.0.12-r1

So I then had to build network-manager-l2tp 1.0.4 to be compatible. This is what I see when I run it:

$ nmcli --ask c up "My Work"
System policy prevents modification of network settings for all users
(action_id: org.freedesktop.NetworkManager.settings.modify.system)
Password (root): 
A password is required to connect to 'My Work'.
Password (vpn.secrets.password): mypassword
VPN connection successfully activated (D-Bus active path: /org/freedesktop/NetworkManager/ActiveConnection/5)

dkosovic commented 8 years ago

Forgot to mention I'll happy to take a look at your ebuild, although I'm not too familiar with gentoo yet.

Although I installed Gnome, I only installed it for nm-connection-editor which I used with a SSH X11 tunnel to setup the L2TP/IPsec connection (as I didn't have a X11 server setup on Gentoo yet). I then used nmcli to test the VPN connection.

On Gentoo the password I enter for nmcli --ask c up "My Work" is echoed to the screen, but on Ubuntu it isn't, but I believe this is more a difference between NetworkManager 1.0 and 1.2. In either case I don't see any GUI prompt for the password.

Ri0n commented 8 years ago

Here is a log file right after reboot exposing issues for another reports (peer id mismatch, connection to non-standard port)

Jul 31 20:24:44 [xl2tpd] setsockopt recvref[30]: Protocol not available_
Jul 31 20:24:44 [kernel] PPP generic driver version 2.4.2
Jul 31 20:24:44 [kernel] NET: Registered protocol family 24
Jul 31 20:24:44 [kernel] l2tp_core: L2TP core driver, V2.0
Jul 31 20:24:44 [kernel] l2tp_netlink: L2TP netlink interface
Jul 31 20:24:44 [xl2tpd] Using l2tp kernel support._
Jul 31 20:24:44 [kernel] l2tp_ppp: PPPoL2TP kernel driver, V2.0
Jul 31 20:24:44 [xl2tpd] xl2tpd version xl2tpd-1.3.6 started on dizzynb PID:5562_
Jul 31 20:24:44 [xl2tpd] Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc._
Jul 31 20:24:44 [xl2tpd] Forked by Scott Balmos and David Stipp, (C) 2001_
Jul 31 20:24:44 [xl2tpd] Inherited by Jeff McAdams, (C) 2002_
Jul 31 20:24:44 [xl2tpd] Forked again by Xelerance (www.xelerance.com) (C) 2006_
Jul 31 20:24:44 [xl2tpd] Listening on IP address 0.0.0.0, port 1701_
Jul 31 20:25:11 [polkitd] Registered Authentication Agent for unix-process:5580:18034 (system bus name :1.33 [nmcli --ask c up vpn work], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale C)
Jul 31 20:25:11 [NetworkManager] <info>  [1469978711.1722] audit: op="connection-activate" uuid="0b2f5cd9-c67a-4487-a4bf-d91e691dfca8" name="vpn work" pid=5580 uid=1000 result="success"
Jul 31 20:25:11 [NetworkManager] <info>  [1469978711.1770] vpn-connection[0x9cf1f0,0b2f5cd9-c67a-4487-a4bf-d91e691dfca8,"vpn work",0]: Started the VPN service, PID 5611
Jul 31 20:25:11 [NetworkManager] <info>  [1469978711.1812] vpn-connection[0x9cf1f0,0b2f5cd9-c67a-4487-a4bf-d91e691dfca8,"vpn work",0]: Saw the service appear; activating connection
Jul 31 20:25:15 [kernel] Initializing XFRM netlink socket
Jul 31 20:25:15 [kernel] NET: Registered protocol family 15
Jul 31 20:25:15 [/etc/init.d/NetworkManager] /etc/init.d/ipsec uses runscript, please convert to openrc-run.
Jul 31 20:25:15 [/etc/init.d/ipsec] WARNING: ipsec is already stopped
Jul 31 20:25:15 [/etc/init.d/NetworkManager] /etc/init.d/ipsec uses runscript, please convert to openrc-run.
Jul 31 20:25:15 [kernel] ip_tables: (C) 2000-2006 Netfilter Core Team
Jul 31 20:25:15 [pluto] NSS DB directory: sql:/etc/ipsec.d
Jul 31 20:25:15 [pluto] NSS initialized
Jul 31 20:25:15 [pluto] libcap-ng support [disabled]
Jul 31 20:25:15 [pluto] FIPS HMAC integrity support [disabled]
Jul 31 20:25:15 [pluto] Linux audit support [disabled]
Jul 31 20:25:15 [pluto] Starting Pluto (Libreswan Version 3.17 XFRM(netkey) KLIPS USE_FORK USE_PTHREAD_SETSCHEDPRIO NSS XAUTH_PAM NETWORKMANAGER) pid:6313
Jul 31 20:25:15 [pluto] core dump dir: /var/run/pluto/
Jul 31 20:25:15 [pluto] secrets file: /etc/ipsec.secrets
Jul 31 20:25:15 [pluto] leak-detective disabled
Jul 31 20:25:15 [pluto] NSS crypto [enabled]
Jul 31 20:25:15 [pluto] XAUTH PAM support [enabled]
Jul 31 20:25:15 [pluto] NAT-Traversal support  [enabled]
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_AES_CTR: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_AES_GCM_A: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_AES_GCM_B: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_AES_GCM_C: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_hash(): Activating DISABLED-OAKLEY_AES_XCBC: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_CAMELLIA_CBC: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating OAKLEY_CAMELLIA_CTR: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_hash(): Activating OAKLEY_SHA2_384: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok
Jul 31 20:25:15 [pluto] starting up 7 crypto helpers
Jul 31 20:25:15 [pluto] started thread for crypto helper 0 (master fd 11)
Jul 31 20:25:15 [pluto] started thread for crypto helper 1 (master fd 13)
Jul 31 20:25:15 [pluto] started thread for crypto helper 2 (master fd 15)
Jul 31 20:25:15 [pluto] started thread for crypto helper 3 (master fd 17)
Jul 31 20:25:15 [pluto] started thread for crypto helper 4 (master fd 19)
Jul 31 20:25:15 [pluto] started thread for crypto helper 5 (master fd 21)
Jul 31 20:25:15 [pluto] started thread for crypto helper 6 (master fd 23)
Jul 31 20:25:15 [pluto] Using Linux XFRM/NETKEY IPsec interface code on 4.7.0-gentoo
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating aes_ccm_8: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating aes_ccm_12: Ok
Jul 31 20:25:15 [pluto] ike_alg_register_enc(): Activating aes_ccm_16: Ok
Jul 31 20:25:15 [pluto] listening for IKE messages
Jul 31 20:25:15 [pluto] adding interface eth0/eth0 192.168.2.100:500
Jul 31 20:25:15 [pluto] adding interface eth0/eth0 192.168.2.100:4500
Jul 31 20:25:15 [pluto] adding interface lo/lo 127.0.0.1:500
Jul 31 20:25:15 [pluto] adding interface lo/lo 127.0.0.1:4500
Jul 31 20:25:15 [pluto] adding interface lo/lo ::1:500
Jul 31 20:25:15 [pluto] loading secrets from "/etc/ipsec.secrets"
Jul 31 20:25:15 [pluto] no secrets filename matched "/etc/ipsec.d/*.secrets"
Jul 31 20:25:15 [pluto] loading secrets from "/etc/ipsec.secrets"
Jul 31 20:25:15 [pluto] added connection description "nm-ipsec-l2tp-5611"
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: initiating Main Mode
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: STATE_MAIN_I2: sent MI2, expecting MR2
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: STATE_MAIN_I3: sent MI3, expecting MR3
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: Main mode peer ID is ID_IPV4_ADDR: '192.168.73.2'
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: we require IKEv1 peer to have ID '@192.168.73.2', but peer declares '192.168.73.2'
Jul 31 20:25:15 [pluto] "nm-ipsec-l2tp-5611" #1: sending encrypted notification INVALID_ID_INFORMATION to 194.60.247.123:4500
Jul 31 20:25:16 [pluto] added connection description "v6neighbor-hole-in"
Jul 31 20:25:16 [pluto] added connection description "v6neighbor-hole-out"
Jul 31 20:25:16 [pluto] listening for IKE messages
Jul 31 20:25:16 [pluto] forgetting secrets
Jul 31 20:25:16 [pluto] loading secrets from "/etc/ipsec.secrets"
Jul 31 20:25:16 [pluto] reapchild failed with errno=10 No child processes
Jul 31 20:25:17 [pluto] "nm-ipsec-l2tp-5611" #1: Main mode peer ID is ID_IPV4_ADDR: '192.168.73.2'
Jul 31 20:25:17 [pluto] "nm-ipsec-l2tp-5611" #1: we require IKEv1 peer to have ID '@192.168.73.2', but peer declares '192.168.73.2'
Jul 31 20:25:17 [pluto] "nm-ipsec-l2tp-5611" #1: sending encrypted notification INVALID_ID_INFORMATION to 194.60.247.123:4500
Jul 31 20:25:19 [pluto] "nm-ipsec-l2tp-5611" #1: Main mode peer ID is ID_IPV4_ADDR: '192.168.73.2'
Jul 31 20:25:19 [pluto] "nm-ipsec-l2tp-5611" #1: we require IKEv1 peer to have ID '@192.168.73.2', but peer declares '192.168.73.2'
Jul 31 20:25:19 [pluto] "nm-ipsec-l2tp-5611" #1: sending encrypted notification INVALID_ID_INFORMATION to 194.60.247.123:4500
Jul 31 20:25:21 [pluto] "nm-ipsec-l2tp-5611" #1: Main mode peer ID is ID_IPV4_ADDR: '192.168.73.2'
Jul 31 20:25:21 [pluto] "nm-ipsec-l2tp-5611" #1: we require IKEv1 peer to have ID '@192.168.73.2', but peer declares '192.168.73.2'
Jul 31 20:25:21 [pluto] "nm-ipsec-l2tp-5611" #1: sending encrypted notification INVALID_ID_INFORMATION to 194.60.247.123:4500
Jul 31 20:25:25 [pluto] "nm-ipsec-l2tp-5611" #1: byte 2 of ISAKMP Hash Payload should have been zero, but was not (ignored)
Jul 31 20:25:25 [pluto] "nm-ipsec-l2tp-5611" #1: length of ISAKMP Hash Payload is larger than can fit
Jul 31 20:25:25 [pluto] "nm-ipsec-l2tp-5611" #1: malformed payload in packet
Jul 31 20:25:25 [pluto] "nm-ipsec-l2tp-5611" #1: next payload type of ISAKMP Hash Payload has an unknown value: 170 (0xaa)
Jul 31 20:25:25 [pluto] "nm-ipsec-l2tp-5611" #1: malformed payload in packet
Jul 31 20:25:39 [NetworkManager] <warn>  [1469978739.5382] vpn-connection[0x9cf1f0,0b2f5cd9-c67a-4487-a4bf-d91e691dfca8,"vpn work",0]: VPN connection: failed to connect: 'Время ожидания истекло'
Jul 31 20:25:39 [polkitd] Unregistered Authentication Agent for unix-process:5580:18034 (system bus name :1.33, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale C) (disconnected from bus)

No if I restart my LANG=C nmcli --ask c up "vpn work" I get next

Jul 31 20:40:21 [polkitd] Registered Authentication Agent for unix-process:6727:109100 (system bus name :1.36 [nmcli --ask c up vpn work], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale C)
Jul 31 20:40:21 [NetworkManager] <info>  [1469979621.7617] audit: op="connection-activate" uuid="0b2f5cd9-c67a-4487-a4bf-d91e691dfca8" name="vpn work" pid=6727 uid=1000 result="success"
Jul 31 20:40:21 [NetworkManager] <info>  [1469979621.7623] vpn-connection[0x9cf3e0,0b2f5cd9-c67a-4487-a4bf-d91e691dfca8,"vpn work",0]: Saw the service appear; activating connection
Jul 31 20:40:46 [NetworkManager] <error> [1469979646.7675] vpn-connection[0x9cf3e0,0b2f5cd9-c67a-4487-a4bf-d91e691dfca8,"vpn work",0]: plugin NeedSecrets request #1 failed: Время ожидания истекло
Jul 31 20:40:46 [polkitd] Unregistered Authentication Agent for unix-process:6727:109100 (system bus name :1.36, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale C) (disconnected from bus)

And ebuild is there https://github.com/rion-overlay/rion-overlay/blob/master/net-misc/networkmanager-l2tp/networkmanager-l2tp-9999.ebuild It was mostly copied from another overlay but looks good for me.

Ri0n commented 8 years ago

Network Manager 1.2.2 password is not echoed for me.

rion@dizzynb ~ $ LANG=C nmcli --ask c up "vpn work"
Error: Connection activation failed: the VPN service failed to start.
rion@dizzynb ~ $ LANG=C nmcli --ask c up "vpn work"
Error: Connection activation failed: no valid VPN secrets.

dkosovic commented 8 years ago

I've reproduced this Libreswan issue :

we require IKEv1 peer to have ID '@192.168.73.2', but peer declares '192.168.73.2'

when I filled in the IPsec Gateway ID.

I then had to kill all processes that had l2tp somewhere as an argument to get things back to normal.

In the NetworkManager-l2tp IPsec options dialog box, I would recommend leaving the Group Name and Gateway ID fields blank, unless you are using a Cisco VPN server.

Ri0n commented 8 years ago

Now the fields are blank. Nothing changed except in error message I now see public IP of vpn server as required peer ID. And the same NeedSecret timeout on second try.

dkosovic commented 8 years ago

I assume the Libreswan IPsec connection still isn't getting established. The NeedSecret timeout on subsequent attempts is just a side-effect that I'll look into.

Without looking at the logs it's hard to suggest what the issue is now. But I would probably start with trying to turn off "Perfect Forward Secrecy" in the IPsec settings and see if that helps.

You could try the following to verify if there is anything wrong with Libreswan :

sudo ipsec restart
sudo ipsec verify

You could then try connecting using the command-line and config file that gets generated by NetworkManager-l2tp, but first you need to add a pre-shared key to /etc/ipsec.secrets with a line that looks something like:

: PSK this-is-my-PSK

but with this-is-my-PSK replaced by the actual PSK.

Assuming you still have a generated /var/run/nm-ipsec-l2tp.*/ipsec.conf file. Issue something like the following to bring up an IPsec connection :

sudo ipsec restart
sudo ipsec --config /var/run/nm-ipsec-l2tp.5611/ipsec.conf --verbose
sudo ipsec --add nm-ipsec-l2tp-5611
sudo auto --up nm-ipsec-l2tp-5611

If it doesn't connect, edit the ipsec.conf file and try again. The ipsec.conf options can be found here:

https://libreswan.org/man/ipsec.conf.5.html

If you are still having issues, you could try strongSwan instead of Libreswan.

Ri0n commented 8 years ago

I was able to make ipsec tunnel For that on my gentoo system I created two files in /etc/ipsec.d/

vpn.conf

conn nm-ipsec-l2tp-5661
        left=%defaultroute
        leftnexthop=%defaultroute
        leftprotoport=17/1701
        right=vpn server public IP here
        rightprotoport=17/1701
    rightid=192.168.73.2
        authby=secret
        keyingtries=0
        auto=add
        type=transport
        compress=no
        pfs=no
        ikepad=yes
        phase2=esp
        ikev2=permit
        esn=no

Few differences from original generated file:

pfs=no
removed duplicate of "authby"
added "rightid" without which it anyway gave me peer ID mismatch

vpn.secrets

%any %any : PSK "my psk here"

Then I did

ipsec restart
ipsec auto --verbose --up nm-ipsec-l2tp-5661

And it successfully established ipsec tunnel.

Next step is xl2tpd and here I have some inexplicable problems syslog:

Aug 03 11:34:34 [xl2tpd] Connecting to host public_ip_of_vpn_server, port 1701_
Aug 03 11:34:34 [xl2tpd] Connection established to public_ip_of_vpn_server, 1701.  Local: 25785, Remote: 1 (ref=0/0)._
Aug 03 11:34:34 [xl2tpd] Calling on tunnel 25785_
Aug 03 11:34:34 [xl2tpd] Call established with public_ip_of_vpn_server, Local: 26770, Remote: 1, Serial: 2 (ref=0/0)_
Aug 03 11:34:34 [pppd] Plugin pppol2tp.so loaded.
Aug 03 11:34:34 [pppd] pppd 2.4.7 started by rion, uid 0
Aug 03 11:34:34 [pppd] Using interface ppp0
Aug 03 11:34:34 [pppd] Connect: ppp0 <--> 
Aug 03 11:34:34 [pppd] Overriding mtu 1500 to 1410
Aug 03 11:34:34 [pppd] Overriding mru 1500 to mtu value 1410
Aug 03 11:34:34 [NetworkManager] <info>  [1470206074.3364] manager: (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/4)
Aug 03 11:34:34 [pppd] Overriding mtu 1500 to 1410
Aug 03 11:34:34 [pppd] PAP authentication succeeded
Aug 03 11:34:35 [pppd] local  IP address 192.168.73.89
Aug 03 11:34:35 [pppd] remote IP address 1.0.0.1
Aug 03 11:34:35 [pppd] primary   DNS address 192.168.73.1
Aug 03 11:34:35 [pppd] secondary DNS address 192.168.77.1
Aug 03 11:34:39 [kernel] device ppp0 entered promiscuous mode
Aug 03 11:35:35 [xl2tpd] control_finish: Connection closed to public_ip_of_vpn_server, serial 2 ()_
Aug 03 11:35:35 [pppd] Terminating on signal 15
Aug 03 11:35:35 [pppd] Connect time 1.0 minutes.
Aug 03 11:35:35 [pppd] Sent 9344747 bytes, received 0 bytes.
Aug 03 11:35:35 [pppd] Overriding mtu 1500 to 1410
Aug 03 11:35:35 [pppd] Overriding mru 1500 to mtu value 1410
Aug 03 11:35:39 [xl2tpd] Maximum retries exceeded for tunnel 25785.  Closing._
Aug 03 11:35:39 [xl2tpd] Connection 1 closed to public_ip_of_vpn_server, port 1701 (Timeout)_
Aug 03 11:35:39 [kernel] device ppp0 left promiscuous mode
Aug 03 11:35:41 [pppd] Connection terminated.
Aug 03 11:35:41 [NetworkManager] <error> [1470206141.5193] platform-linux: do-change-link[12]: failure changing link: failure 19 (Нет такого устройства)
Aug 03 11:35:41 [NetworkManager] <warn>  [1470206141.5193] device (ppp0): failed to disable userspace IPv6LL address handling
Aug 03 11:35:41 [pppd] Modem hangup
Aug 03 11:35:41 [pppd] Exit.

in xl2tpd.conf I have

[global]
debug avp = yes
debug network = yes
debug packet = yes
debug state = yes
debug tunnel = yes

[lac vpn-connection]
lns = public_ip_of_vpn_server
ppp debug = yes
pppoptfile = /etc/ppp/options.xl2tpd
length bit = yes

/etc/ppp/options.xl2tpd

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 my_login_here
password my_password_here

From wireshark and stats I see thousands of ESP tx packets on ppp0 before it disconnected and few l2tp tx control packets. No rx packets at all.

UPDATE: I've removed defaultroute from ppp options and manually added route for remote subnet and now it works :) The only problem is dns search zone for internal hosts but I'll solve this somehow =)

So now need it via Network Manager.

dkosovic commented 8 years ago

Thanks for summarising the Libreswan issues.

With the next version of nm-l2tp I was actually thinking of making pfs=no the default again and will do that.

I'll also remove the @ in the following rightid code so the Gateway ID field will then work:

value = nm_setting_vpn_get_data_item (s_vpn, NM_L2TP_KEY_IPSEC_GATEWAY_ID); 
if(value)write_config_option (ipsec_fd, "  rightid=@%s\n", value);

You mention a duplicate authby, but I can't see where that would be coming from as there is only one instance of it in the code.

With xl2tpd I might be able to spot something unusual if I see the start of the xlt2pd log, not sure if you are using the l2tp kernel module and which xl2tpd plugins you have installed. I would give you a sample log of a working xl2tpd connection, but I'm currently sitting in front of a Windows PC at the moment.

Ri0n commented 8 years ago

In any case vpn now works for me.

Regarding authby, I'm now looking at /var/run/nm-ipsec-l2tp.5661/ipsec.conf and it's pretty much different from my copy in /etc/ipsec.d/. Maybe I copied some part of config from some different place and forgot about it. Or it was somehow regenerated. In any case the new config works.

dkosovic commented 8 years ago

Glad to hear you got it working!

I'll close this issue. But I will look into the the NetworkManager NeedSecret timeout side effect issue and maybe put a timeout on Libreswan or stronSwan and kill them if they take to long to establish the initial IPsec connection.

Ri0n commented 8 years ago

Finally it work via NM too! But I had to remove that '@' from source code.

NeedSecrets is still here when something wrong with ipsec.

dkosovic commented 8 years ago

For Libreswan, if leftid or rightid is an IP address, it no longer prefixes with '@' in commit https://github.com/nm-l2tp/network-manager-l2tp/commit/58d5c3b79fb7008d6bb40654cec9548461b54d0b

Vitexus commented 1 year ago

Neverendig Story :(

NetworkManager 1.30.6-1+deb11u1 network-manager-l2tp 1.2.18-1+b2

`Jan 27 12:21:21 exiv NetworkManager[903]: <error> [1674818481.7678] vpn-connection[0x563f063d6380,3726a050-cb78-4937-880f-84bc6c2389f1,"VPN",0]: plugin NeedSecrets request #1 failed: Timeout was reached

dkosovic commented 1 year ago

Neverendig Story :(

NetworkManager 1.30.6-1+deb11u1 network-manager-l2tp 1.2.18-1+b2

`Jan 27 12:21:21 exiv NetworkManager[903]: [1674818481.7678] vpn-connection[0x563f063d6380,3726a050-cb78-4937-880f-84bc6c2389f1,"VPN",0]: plugin NeedSecrets request #1 failed: Timeout was reached

NetworkManager-l2tp uses the libsecret library for storing and retrieving passwords. It communicates with the "Secret Service" using D-Bus. gnome-keyring and ksecretservice are both implementations of a Secret Service.

Make sure you have something that provides a Secret Service and that it is running.

You can use the command-line secret-tool to confirm the Secret Service implementation is working and also lookup the VPN password, e.g.:

secret-tool  lookup setting-name vpn

dkosovic commented 1 year ago

@Vitexus sorry I might have misled you.

The NeedSecrets error is just nm-l2tp-pppd-plugin timing out while waiting for nm-l2tp-service to provide the credentials. So, the nm-l2tp-service is probably having issues with establishing the IPsec connection (or possibly the L2TP connection).

The original issue in this thread was due to nm-l2tp-service calling /usr/bin/ipsec up which brings up an IPsec connection, but it didn't have a timeout and it could sit there indefinitely waiting for the IPsec connection to be made, which would also have consequences when a second instance of nm-l2tp-service was started. Later versions of NetworkManager-l2tp implemented a timeout for establishing the IPsec connection (which complemented the existing L2TP timeout).

Although unlikely, I would kill any existing nm-l2tp-service process with:

sudo killall -TERM nm-l2tp-service

I would recommend opening a new issue and providing the following log output:

journalctl --no-hostname _SYSTEMD_UNIT=NetworkManager.service + SYSLOG_IDENTIFIER=pppd

(Obfuscate any IP addresses if they are sensitive)

I suspect it is an issue somewhere with establishing the IPsec Main Mode (i.e., phase 1) or Quick Mode (i.e., phase 2).

Vitexus commented 1 year ago

@dkosovic Thanks for your hints.

root@exiv:~# nmcli connection up Paymont 
Error: Connection activation failed: No valid secrets
Hint: use 'journalctl -xe NM_CONNECTION=3726a050-cb78-4937-880f-84bc6c2389f1 + NM_DEVICE=enx509a4cc6e189' to get more details.

with log output:

Feb 09 18:26:00 NetworkManager[946]: <info>  [1675963560.4652] audit: op="connection-activate" uuid="3726a050-cb78-4937-880f-84bc6c2389f1" name="Paymont" pid=2524 uid=1000 result="success"
Feb 09 18:26:00 NetworkManager[946]: <info>  [1675963560.4823] vpn-connection[0x557a288640f0,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: Started the VPN service, PID 13173
Feb 09 18:26:00 charon-nm[13173]: 00[DMN] Starting charon NetworkManager backend (strongSwan 5.9.1)
Feb 09 18:26:00 charon-nm[13173]: 00[KNL] unable to create IPv4 routing table rule
Feb 09 18:26:00 charon-nm[13173]: 00[KNL] unable to create IPv6 routing table rule
Feb 09 18:26:00 NetworkManager[946]: <info>  [1675963560.5243] vpn-connection[0x557a288640f0,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: Saw the service appear; activating connection
Feb 09 18:26:00 charon-nm[13173]: 00[LIB] loaded plugins: nm-backend charon-nm ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md5 mgf1 rdrand random nonce x509 revocation constraints pkcs1 pkcs7 pkcs8 sshkey pem opens>
Feb 09 18:26:00 charon-nm[13173]: 00[LIB] dropped capabilities, running as uid 0, gid 0
Feb 09 18:26:00 charon-nm[13173]: 00[JOB] spawning 16 worker threads
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] installed bypass policy for 10.11.23.0/24
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] installed bypass policy for 169.254.0.0/16
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] installed bypass policy for ::1/128
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] installed bypass policy for 2001:67c:2190:1020::/64
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] installed bypass policy for fe80::/64
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] interface change for bypass policy for 10.11.23.0/24 (from enx509a4cc6e189 to wlp0s20f3)
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] interface change for bypass policy for 2001:67c:2190:1020::/64 (from enx509a4cc6e189 to wlp0s20f3)
Feb 09 18:26:00 charon-nm[13173]: 06[IKE] interface change for bypass policy for fe80::/64 (from enx509a4cc6e189 to wlp0s20f3)
Feb 09 18:26:00 charon-nm[13173]: 05[LIB] building CRED_PRIVATE_KEY - ANY failed, tried 8 builders
Feb 09 18:26:00 charon-nm[13173]: 05[CFG] received initiate for NetworkManager connection Paymont
Feb 09 18:26:06 NetworkManager[946]: <info>  [1675963566.5968] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:26:06 NetworkManager[946]: <info>  [1675963566.5988] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:26:23 NetworkManager[946]: <info>  [1675963583.1595] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:26:23 NetworkManager[946]: <info>  [1675963583.1733] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:26:25 NetworkManager[946]: <warn>  [1675963585.5317] vpn-connection[0x557a288640f0,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: VPN connection: failed to connect: 'Timeout was reached'
Feb 09 18:26:31 NetworkManager[946]: <info>  [1675963591.7137] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:26:31 NetworkManager[946]: <info>  [1675963591.7158] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:28:54 NetworkManager[946]: <info>  [1675963734.3930] dhcp4 (enx509a4cc6e189): state changed extended -> extended, address=10.11.23.113
Feb 09 18:29:48 NetworkManager[946]: <info>  [1675963788.5226] agent-manager: agent[93efcdf367772cb5,:1.198/nmcli-connect/0]: agent registered
Feb 09 18:29:48 NetworkManager[946]: <info>  [1675963788.5237] audit: op="connection-activate" uuid="3726a050-cb78-4937-880f-84bc6c2389f1" name="Paymont" pid=13510 uid=0 result="success"
Feb 09 18:29:48 NetworkManager[946]: <info>  [1675963788.5264] vpn-connection[0x557a28864300,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: Saw the service appear; activating connection
Feb 09 18:30:13 NetworkManager[946]: <error> [1675963813.5323] vpn-connection[0x557a28864300,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: plugin NeedSecrets request #1 failed: Timeout was reached
Feb 09 18:30:21 NetworkManager[946]: <info>  [1675963821.3305] dhcp4 (wlp0s20f3): state changed extended -> extended, address=10.11.23.137
Feb 09 18:30:38 NetworkManager[946]: <info>  [1675963838.0887] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:30:38 NetworkManager[946]: <info>  [1675963838.1040] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:30:40 NetworkManager[946]: <info>  [1675963840.7995] audit: op="connection-activate" uuid="3726a050-cb78-4937-880f-84bc6c2389f1" name="Paymont" pid=2524 uid=1000 result="success"
Feb 09 18:30:40 NetworkManager[946]: <info>  [1675963840.8026] vpn-connection[0x557a28864510,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: Saw the service appear; activating connection
Feb 09 18:31:01 NetworkManager[946]: <info>  [1675963861.4130] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:31:01 NetworkManager[946]: <info>  [1675963861.4152] audit: op="statistics" arg="refresh-rate-ms" pid=2524 uid=1000 result="success"
Feb 09 18:31:05 NetworkManager[946]: <error> [1675963865.8080] vpn-connection[0x557a28864510,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: plugin NeedSecrets request #1 failed: Timeout was reached
Feb 09 18:34:02 NetworkManager[946]: <info>  [1675964042.0365] agent-manager: agent[93efcdf367772cb5,:1.201/nmcli-connect/0]: agent registered
Feb 09 18:34:02 NetworkManager[946]: <info>  [1675964042.0382] audit: op="connection-activate" uuid="3726a050-cb78-4937-880f-84bc6c2389f1" name="Paymont" pid=13607 uid=0 result="success"
Feb 09 18:34:02 NetworkManager[946]: <info>  [1675964042.0423] vpn-connection[0x557a28864720,3726a050-cb78-4937-880f-84bc6c2389f1,"Paymont",0]: Saw the service appear; activating connection

There in log is not glue what is wrong/broken :(

dkosovic commented 1 year ago

@Vitexus your log output has charon-nm which is NetworkManager-strongswan and its support is :

https://github.com/strongswan/strongswan/issues

There is nothing in the logs from NetworkManager-l2tp (which uses the older strongswan charon daemon, not charon-nm).

So, it appears you are trying to establish an IPsec IKEv2 VPN connection using NetworkManager-strongswan, not a L2TP/IPsec VPN connection.

The log output indicates you are using the strongswan bypass-lan plugin that takes at least 6 seconds to complete and I suspect might be causing the issues that leads to the timeout. On many other Linux distros the experimental bypass-lan plug-in is not loaded or enabled by default. I think you need to edit /etc/strongswan.d/charon/bypass-lan.conf so that bypass-lan is not loaded, but it might be different for charon-nm, I'm not sure.

Correction: It is probably not the strongswan bypass-lan plugin that is the issue and isn't what is causing the 6 second delay, but no harm in disabling it.

The issue is building CRED_PRIVATE_KEY - ANY failed, tried 8 builders, I have no idea what is causing that, it would be best to contact strongswan support for your issue.

dkosovic commented 1 year ago

@Vitexus If you intend to use NetworkManger-l2tp even though you posted the wrong log output which was actually from NetworkManager-strongswan, please don't reply to this closed issue, but instead open a new issue.

I've also added a correction to my previous message for what the actual issue is from the logs.

nm-l2tp / NetworkManager-l2tp

plugin NeedSecrets request #1 failed with Libreswan #15