FS#74089 - networkmanager 1.36 breaks vpn with networkmanager-l2tp

Attached to Project: Arch Linux
Opened by Jakob Lund (jakob_fra_svendborg) - Thursday, 10 March 2022, 19:47 GMT
Last edited by Toolybird (Toolybird) - Saturday, 03 June 2023, 00:18 GMT
Task Type Bug Report
Category Packages: Extra
Status Closed
Assigned To Jan Alexander Steffens (heftig)
Architecture All
Severity Low
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 3
Private No

Details

Description:

The vpn to my employer, which I've been using for years, stopped working a few weeks ago. I tried figuring out the problem, but the messages were cryptic (see below)

I then tried to downgrade some packages, and I find that the current combination works -- only networkmanager itself has been rewound:

networkmanager 1.34.0-1
networkmanager-l2tp 1.20.0-2


Additional info:
* package version(s)
* config and/or log files etc.

output from networkmanager-l2tp:

connection
id : 'Swann vpn'
permissions : ['user:jakob:']
type : 'vpn'
uuid : 'e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2'

vpn
data : {'gateway': 'mail.avforlaget.dk', 'ipsec-enabled': 'yes', 'ipsec-psk': 'yyyyy', 'password-flags': '1', 'refuse-chap': 'yes
', 'refuse-eap': 'yes', 'refuse-mschap': 'yes', 'refuse-pap': 'yes', 'require-mppe-128': 'yes', 'user': 'vpn-jl'}
secrets : {'password': 'xxxxxx'}
service-type : 'org.freedesktop.NetworkManager.l2tp'
user-name : 'jakob'

ipv4
address-data : []
dns : [37202112]
dns-search : ['avforlaget.local']
method : 'auto'
route-data : []

ipv6
address-data : []
dns-search : []
method : 'auto'
route-data : []

proxy

nm-l2tp[164189] <info> starting ipsec
Stopping strongSwan IPsec failed: starter is not running
Starting strongSwan 5.9.5 IPsec [starter]...
Loading config setup
Loading conn 'e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2'
nm-l2tp[164189] <info> Spawned ipsec up script with PID 164235.
initiating Main Mode IKE_SA e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2[1] to 80.208.2.58
generating ID_PROT request 0 [ SA V V V V V ]
sending packet: from 192.168.50.180[500] to 80.208.2.58[500] (532 bytes)
received packet: from 80.208.2.58[500] to 192.168.50.180[500] (406 bytes)
parsed ID_PROT response 0 [ SA V V V V V V V V V V V ]
received unknown vendor ID: f7:58:f2:26:68:75:0f:03:b0:8d:f6:eb:e1:d0:04:03
received draft-ietf-ipsec-nat-t-ike-02 vendor ID
received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
received draft-ietf-ipsec-nat-t-ike-03 vendor ID
received NAT-T (RFC 3947) vendor ID
received XAuth vendor ID
received DPD vendor ID
received unknown vendor ID: af:ca:d7:13:68:a1:f1:c9:6b:86:96:fc:77:57
received unknown vendor ID: f9:19:6d:f8:6b:81:2f:b0:f6:80:26:d8:87:6d:cb:7b:00:04:32:00
received unknown vendor ID: ac:40:f8:c4:38:99:27:c6:e8:ac:24:53:1b:b7:8b:2b:fc:85:f7:13:1a:cf:e7:62:ed:38:ac:ee:f8:2e:4c:1d:14:0e:64:76:2f:4b
:58:7a:85:71:68:5f:93:84:44:ec:a0:be:92:06:1a:22:4b:1d:08:2f:1b:b5:ad:19:00:46:1c:6e:c4:d8:8a:50:5d:b2:29:85:87:e4:39:2e:36:30:3e:fe:1e:7c:3b
:ca:69:55:7d:13:e9:42:d3:ca:06:01:e1:aa:da:70:c5:c3:46:6b:e6:2d:c4:48:c7:23:5a:dc:a0:46:c7:8f:6f:b0:e8:11:49:bc:4f:a3:c6:f1:c8:ca
received unknown vendor ID: b6:c9:8c:ca:29:0a:eb:be:37:f1:9f:31:12:d2:d7:cb
selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
sending packet: from 192.168.50.180[500] to 80.208.2.58[500] (244 bytes)
received packet: from 80.208.2.58[500] to 192.168.50.180[500] (228 bytes)
parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
local host is behind NAT, sending keep alives
generating ID_PROT request 0 [ ID HASH ]
sending packet: from 192.168.50.180[4500] to 80.208.2.58[4500] (68 bytes)
received packet: from 80.208.2.58[4500] to 192.168.50.180[4500] (68 bytes)
parsed ID_PROT response 0 [ ID HASH ]
IKE_SA e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2[1] established between 192.168.50.180[192.168.50.180]...80.208.2.58[80.208.2.58]
scheduling reauthentication in 9839s
maximum IKE_SA lifetime 10379s
generating QUICK_MODE request 1922545136 [ HASH SA No ID ID NAT-OA NAT-OA ]
sending packet: from 192.168.50.180[4500] to 80.208.2.58[4500] (244 bytes)
received packet: from 80.208.2.58[4500] to 192.168.50.180[4500] (172 bytes)
parsed QUICK_MODE response 1922545136 [ HASH SA No ID ID NAT-OA NAT-OA ]
selected proposal: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
CHILD_SA e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2{1} established with SPIs c1f771a3_i b37c7771_o and TS 192.168.50.180/32[udp/l2f] === 80.208.2.5
8/32[udp/l2f]
connection 'e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2' established successfully
nm-l2tp[164189] <info> strongSwan IPsec tunnel is up.
** Message: 19:39:32.365: xl2tpd started with pid 164245
xl2tpd[164245]: Not looking for kernel SAref support.
xl2tpd[164245]: Using l2tp kernel support.
xl2tpd[164245]: xl2tpd version xl2tpd-1.3.17 started on goldilocks PID:164245
xl2tpd[164245]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
xl2tpd[164245]: Forked by Scott Balmos and David Stipp, (C) 2001
xl2tpd[164245]: Inherited by Jeff McAdams, (C) 2002
xl2tpd[164245]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
xl2tpd[164245]: Listening on IP address 0.0.0.0, port 1701
xl2tpd[164245]: get_call: allocating new tunnel for host 80.208.2.58, port 1701.
xl2tpd[164245]: Connecting to host 80.208.2.58, port 1701
xl2tpd[164245]: control_finish: message type is (null)(0). Tunnel is 0, call is 0.
xl2tpd[164245]: control_finish: sending SCCRQ
xl2tpd[164245]: message_type_avp: message type 2 (Start-Control-Connection-Reply)
xl2tpd[164245]: protocol_version_avp: peer is using version 1, revision 0.
xl2tpd[164245]: framing_caps_avp: supported peer frames: sync
xl2tpd[164245]: hostname_avp: peer reports hostname '(none)'
xl2tpd[164245]: assigned_tunnel_avp: using peer's tunnel 45856
xl2tpd[164245]: bearer_caps_avp: supported peer bearers:
xl2tpd[164245]: firmware_rev_avp: peer reports firmware version 1025 (0x0401)
xl2tpd[164245]: vendor_avp: peer reports vendor 'SafeNet Inc.'
xl2tpd[164245]: receive_window_size_avp: peer wants RWS of 16. Will use flow control.
xl2tpd[164245]: control_finish: message type is Start-Control-Connection-Reply(2). Tunnel is 45856, call is 0.
xl2tpd[164245]: control_finish: sending SCCCN
xl2tpd[164245]: Connection established to 80.208.2.58, 1701. Local: 50593, Remote: 45856 (ref=0/0).
xl2tpd[164245]: Calling on tunnel 50593
xl2tpd[164245]: control_finish: message type is (null)(0). Tunnel is 45856, call is 0.
xl2tpd[164245]: control_finish: sending ICRQ
xl2tpd[164245]: message_type_avp: message type 11 (Incoming-Call-Reply)
xl2tpd[164245]: assigned_call_avp: using peer's call 32207
xl2tpd[164245]: control_finish: message type is Incoming-Call-Reply(11). Tunnel is 45856, call is 32207.
xl2tpd[164245]: control_finish: Sending ICCN
xl2tpd[164245]: Call established with 80.208.2.58, Local: 30491, Remote: 32207, Serial: 1 (ref=0/0)
xl2tpd[164245]: start_pppd: I'm running:
xl2tpd[164245]: "/usr/sbin/pppd"
xl2tpd[164245]: "plugin"
xl2tpd[164245]: "pppol2tp.so"
xl2tpd[164245]: "pppol2tp"
xl2tpd[164245]: "7"
xl2tpd[164245]: "passive"
xl2tpd[164245]: "nodetach"
xl2tpd[164245]: ":"
xl2tpd[164245]: "debug"
xl2tpd[164245]: "file"
xl2tpd[164245]: "/var/run/nm-l2tp-e1eaa068-8d2d-4629-8b0b-3cdc58a2afa2/ppp-options"
xl2tpd[164245]: message_type_avp: message type 16 (Set-Link-Info)
xl2tpd[164245]: ignore_avp : Ignoring AVP
xl2tpd[164245]: control_finish: message type is Set-Link-Info(16). Tunnel is 45856, call is 32207.
xl2tpd[164245]: message_type_avp: message type 6 (Hello)
xl2tpd[164245]: control_finish: message type is Hello(6). Tunnel is 45856, call is 0.
xl2tpd[164245]: check_control: Received out of order control packet on tunnel 45856 (got 3, expected 4)
xl2tpd[164245]: handle_control: bad control packet!
xl2tpd[164245]: network_thread: bad packet
xl2tpd[164245]: check_control: Received out of order control packet on tunnel 45856 (got 3, expected 4)
xl2tpd[164245]: handle_control: bad control packet!
xl2tpd[164245]: network_thread: bad packet
xl2tpd[164245]: check_control: Received out of order control packet on tunnel 45856 (got 3, expected 4)
xl2tpd[164245]: handle_control: bad control packet!
xl2tpd[164245]: network_thread: bad packet
xl2tpd[164245]: check_control: Received out of order control packet on tunnel 45856 (got 3, expected 4)
xl2tpd[164245]: handle_control: bad control packet!
xl2tpd[164245]: network_thread: bad packet
xl2tpd[164245]: Maximum retries exceeded for tunnel 50593. Closing.
xl2tpd[164245]: Terminating pppd: sending TERM signal to pid 164246
xl2tpd[164245]: Connection 45856 closed to 80.208.2.58, port 1701 (Timeout)
nm-l2tp[164189] <info> Terminated xl2tpd daemon with PID 164245.
xl2tpd[164245]: death_handler: Fatal signal 15 received
Stopping strongSwan IPsec...
** Message: 19:41:04.579: ipsec shut down
nm-l2tp[164189] <warn> xl2tpd exited with error code 1
Stopping strongSwan IPsec failed: starter is not running
** Message: 19:41:04.599: ipsec shut down

* link to upstream bug report, if any

Steps to reproduce:
This task depends upon

Closed by  Toolybird (Toolybird)
Saturday, 03 June 2023, 00:18 GMT
Reason for closing:  Fixed
Additional comments about closing:  Fixed according to comments in linked upstream ticket.
Comment by David Thurstenson (thurstylark) - Saturday, 12 March 2022, 20:08 GMT Comment by Douglas Kosovic (dkosovic) - Monday, 25 April 2022, 02:34 GMT
I've created the following strongswan bug report with a suggested fix for not loading certain problem/experimental strongswan plugins by default which seem to be breaking IPsec VPN connections with networkmanager >= 1.36 :
https://bugs.archlinux.org/task/74553

Unrelated networkmanager-l2tp 1.20.0 issues:

- Can't edit L2TP VPN connection with gtk4 based gnome-control-center.
needs to be updated to version 1.20.2 that supports gtk4.
PKGBUILD needs to have `--with-gtk4`, e.g. :
https://github.com/archlinux/svntogit-packages/commit/3fb0e3bc0fe6dea7d8eee55deb3197028b4fb83f

- Should support libreswan DH2 (modp1024).
AUR libreswan is built with DH2 support.
PKGBUILD should have `--enable-libreswan-dh2`

Loading...