Bug 1147693
| Summary: | NetworkManger-libreswan can not connect to Red Hat IPSec Xauth VPN | |||
|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | David Jaša <djasa> | |
| Component: | libreswan | Assignee: | Paul Wouters <pwouters> | |
| Status: | CLOSED ERRATA | QA Contact: | Aleš Mareček <amarecek> | |
| Severity: | high | Docs Contact: | ||
| Priority: | high | |||
| Version: | 7.0 | CC: | amarecek, desktop-qa-list, mkoci, pwouters, sforsber | |
| Target Milestone: | rc | Keywords: | Regression | |
| Target Release: | 7.1 | |||
| Hardware: | Unspecified | |||
| OS: | Unspecified | |||
| Whiteboard: | ||||
| Fixed In Version: | Doc Type: | Bug Fix | ||
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 1187184 (view as bug list) | Environment: | ||
| Last Closed: | 2015-03-05 10:22:55 UTC | Type: | Bug | |
| Regression: | --- | Mount Type: | --- | |
| Documentation: | --- | CRM: | ||
| Verified Versions: | Category: | --- | ||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | ||
| Cloudforms Team: | --- | Target Upstream Version: | ||
| Embargoed: | ||||
| Bug Depends On: | 1187184 | |||
| Bug Blocks: | ||||
|
Comment 1
Avesh Agarwal
2014-10-01 19:22:18 UTC
Here are working logs with libreswan 3.8:
Oct 1 15:06:16 rhel7vm-lp NetworkManager[700]: <info> Starting VPN service 'libreswan'...
Oct 1 15:06:16 rhel7vm-lp NetworkManager[700]: <info> VPN service 'libreswan' started (org.freedesktop.NetworkManager.libreswan), PID 3696
Oct 1 15:06:16 rhel7vm-lp NetworkManager[700]: <info> VPN service 'libreswan' appeared; activating connections
Oct 1 15:06:16 rhel7vm-lp NetworkManager[700]: <info> VPN plugin state changed: init (1)
Oct 1 15:06:26 rhel7vm-lp NetworkManager[700]: <info> VPN plugin state changed: starting (3)
Oct 1 15:06:26 rhel7vm-lp NetworkManager: warning: could not open include filename: '/etc/ipsec.d/*.conf' (tried and )
Oct 1 15:06:26 rhel7vm-lp ipsec_starter[3706]: warning: could not open include filename: '/etc/ipsec.d/*.conf' (tried and )
Oct 1 15:06:26 rhel7vm-lp kernel: sha512_ssse3: Neither AVX nor SSSE3 is available/usable.
Oct 1 15:06:26 rhel7vm-lp kernel: sha256_ssse3: Neither AVX nor SSSE3 is available/usable.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX instructions are not detected.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX instructions are not detected.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX instructions are not detected.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX instructions are not detected.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX instructions are not detected.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX or AES-NI instructions are not detected.
Oct 1 15:06:26 rhel7vm-lp kernel: AVX or AES-NI instructions are not detected.
Oct 1 15:06:27 rhel7vm-lp ipsec_starter[3798]: warning: could not open include filename: '/etc/ipsec.d/*.conf' (tried and )
Oct 1 15:06:28 rhel7vm-lp NetworkManager[700]: <info> VPN connection 'jsgnjsmswan' (Connect) reply received.
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> VPN connection 'jsgnjsmswan' (IP4 Config Get) reply received from old-style plugin.
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> VPN Gateway: 66.187.233.55
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Tunnel Device: (none)
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> IPv4 configuration:
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Internal Address: 10.10.57.240
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Internal Prefix: 32
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Internal Point-to-Point Address: 10.10.57.240
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Maximum Segment Size (MSS): 0
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Forbid Default Route: yes
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Internal DNS: 10.11.5.19
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Internal DNS: 10.5.30.160
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> DNS Domain: 'redhat.com'
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> No IPv6 configuration
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Login Banner:
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> -----------------------------------------
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> Unauthorized Access to this or any other Red Hat Inc. device is strictly prohibited. Violators will be prosecuted.
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> -----------------------------------------
Oct 1 15:06:29 rhel7vm-lp avahi-daemon[567]: Registering new address record for 10.10.57.240 on eth0.IPv4.
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> VPN connection 'jsgnjsmswan' (IP Config Get) complete.
Oct 1 15:06:29 rhel7vm-lp NetworkManager[700]: <info> VPN plugin state changed: started (4)
Oct 1 15:06:29 rhel7vm-lp dbus-daemon: dbus[603]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Oct 1 15:06:29 rhel7vm-lp dbus[603]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Oct 1 15:06:29 rhel7vm-lp systemd: Starting Network Manager Script Dispatcher Service...
Oct 1 15:06:29 rhel7vm-lp dbus-daemon: dbus[603]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Oct 1 15:06:29 rhel7vm-lp dbus[603]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Oct 1 15:06:29 rhel7vm-lp systemd: Started Network Manager Script Dispatcher Service.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: Enter passphrase: 003 "nm-conn1" #1: multiple DH groups were set in aggressive mode. Only first one used.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: transform (7,2,2,0) ignored.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: multiple DH groups were set in aggressive mode. Only first one used.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: transform (7,2,2,0) ignored.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 112 "nm-conn1" #1: STATE_AGGR_I1: initiate
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received Vendor ID payload [Cisco-Unity]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received Vendor ID payload [XAUTH]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received Vendor ID payload [Dead Peer Detection]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received Vendor ID payload [RFC 3947]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received Vendor ID payload [FRAGMENTATION c0000000]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: ignoring unknown Vendor ID payload [36f6a74750856790f57018d744990e00]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: ignoring Vendor ID payload [Cisco VPN 3000 Series]
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: protocol/port in Phase 1 ID Payload MUST be 0/0 or 17/500 but are 17/0 (attempting to continue)
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal): i am NATed
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 004 "nm-conn1" #1: STATE_AGGR_I2: sent AI2, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp1536}
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: XAUTH Message: Enter Username and Password.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 040 "nm-conn1" #1: nm-conn1 prompt for Password:
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 004 "nm-conn1" #1: STATE_XAUTH_I1: XAUTH client - awaiting CFG_set
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: XAUTH: Successfully Authenticated
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 004 "nm-conn1" #1: STATE_XAUTH_I1: XAUTH client - awaiting CFG_set
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received IPv4 address: 10.10.57.240/32
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received IP4 NETMASK 255.255.255.255
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received DNS 10.11.5.19
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received DNS 10.5.30.160
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received Banner: Unauthorized Access to this or any other Red Hat Inc. device is strictly prohibited. Violators will be prosecuted.
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received subnet 10.0.0.0/8, maskbits 8
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: Received Domain: redhat.com
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 004 "nm-conn1" #1: STATE_MAIN_I4: ISAKMP SA established
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 117 "nm-conn1" #2: STATE_QUICK_I1: initiate
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 003 "nm-conn1" #2: ignoring informational payload IPSEC_RESPONDER_LIFETIME, msgid=a6d0d255, length=36
Oct 1 15:06:29 rhel7vm-lp NetworkManager: 004 "nm-conn1" #2: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP=>0xd150afc2 <0x950d74df xfrm=AES_256-HMAC_SHA1 NATOA=none NATD=none DPD=none XAUTHuser=avagarwa
Here are the non-working logs with libreswan 3.10: Oct 1 14:53:30 rhel7vm-lp NetworkManager[700]: <info> VPN connection 'jsgnjsmswan' (Connect) reply received. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: multiple DH groups were set in aggressive mode. Only first one used. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: transform (OAKLEY_AES_CBC,OAKLEY_SHA1,OAKLEY_GROUP_MODP1536 keylen 0) ignored. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: transform (OAKLEY_AES_CBC,OAKLEY_SHA1,OAKLEY_GROUP_MODP1024 keylen 0) ignored. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 002 "nm-conn1" #1: initiating Aggressive Mode #1, connection "nm-conn1" Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: multiple DH groups were set in aggressive mode. Only first one used. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: transform (OAKLEY_AES_CBC,OAKLEY_SHA1,OAKLEY_GROUP_MODP1536 keylen 0) ignored. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: transform (OAKLEY_AES_CBC,OAKLEY_SHA1,OAKLEY_GROUP_MODP1024 keylen 0) ignored. Oct 1 14:53:30 rhel7vm-lp NetworkManager: 112 "nm-conn1" #1: STATE_AGGR_I1: initiate Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: ignoring informational payload NO_PROPOSAL_CHOSEN, msgid=00000000, length=112 Oct 1 14:53:30 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received and ignored informational message Oct 1 14:53:39 rhel7vm-lp dbus-daemon: 'list' object has no attribute 'split' Oct 1 14:53:39 rhel7vm-lp dbus-daemon: string index out of range Oct 1 14:53:40 rhel7vm-lp NetworkManager: 010 "nm-conn1" #1: STATE_AGGR_I1: retransmission; will wait 10s for response Oct 1 14:53:40 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: ignoring informational payload NO_PROPOSAL_CHOSEN, msgid=00000000, length=112 Oct 1 14:53:40 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received and ignored informational message Oct 1 14:53:50 rhel7vm-lp NetworkManager: 010 "nm-conn1" #1: STATE_AGGR_I1: retransmission; will wait 20s for response Oct 1 14:53:50 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: ignoring informational payload NO_PROPOSAL_CHOSEN, msgid=00000000, length=112 Oct 1 14:53:50 rhel7vm-lp NetworkManager: 003 "nm-conn1" #1: received and ignored informational message Oct 1 14:53:50 rhel7vm-lp su: (to root) avagarwa on pts/0 Oct 1 14:54:05 rhel7vm-lp pulseaudio[1712]: [alsa-sink] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write! Oct 1 14:54:05 rhel7vm-lp pulseaudio[1712]: [alsa-sink] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers. Oct 1 14:54:05 rhel7vm-lp pulseaudio[1712]: [alsa-sink] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail. Oct 1 14:54:10 rhel7vm-lp NetworkManager[700]: <warn> VPN connection 'jsgnjsmswan' connect timeout exceeded. Oct 1 14:54:10 rhel7vm-lp NetworkManager: 002 "nm-conn1" #1: deleting state (STATE_AGGR_I1) Oct 1 14:54:10 rhel7vm-lp NetworkManager: 002 shutting down Oct 1 14:54:15 rhel7vm-lp NetworkManager: ipsec/pluto started with pid 3007 Oct 1 14:54:15 rhel7vm-lp NetworkManager: pluto_watch: pluto exited with error code 3 Oct 1 14:54:15 rhel7vm-lp NetworkManager[700]: <info> VPN service 'libreswan' disappeared (In reply to Avesh Agarwal from comment #1) > I am able to reproduce your problem and it seems that libreswan has caused > regression in their recent update to 3.10 version. > ... So let's mark it as such and reassingn... Build libreswan-3.11-1.el7.x86_64 works for me. Jan 28 15:24:12 r71 pluto[1541]: "nm-conn1" #2: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP/NAT=
>0xff554507 <0x6fb0f328 xfrm=AES_256-HMAC_SHA1 NATOA=none NATD=209.132.186.252:4500 DPD=passive XAUTHuser=amarecek}
Jan 28 15:24:52 r71 pluto[1541]: shutting down
NM is shutting down libreswan for some reason. Despite the connection having worked and being fine.
As a side note, while I don't mind NM starting up libreswan and shutting it down if it was responsible for starting it, just stopping it would affect other non-NM based VPN tunnels.
the selinux log shows libreswan is not allowed to use the audit subsystem. That is a selinux-policy issue.
So I think this is either an selinux-policy bug, a NM-libreswan bug, or both. But not a core libreswan bug :)
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2015-0431.html |