Bug 1375006 - NM-PPTP VPN Connection Fails
Summary: NM-PPTP VPN Connection Fails
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager-pptp
Version: 26
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Lubomir Rintel
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1376990 1378450 1392185 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-09-11 17:18 UTC by John Browning
Modified: 2018-05-29 12:35 UTC (History)
12 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-05-29 12:35:16 UTC


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Red Hat Bugzilla 1369489 None CLOSED Kernel 4.7 and net.netfilter.nf_conntrack_helper = 0 as new default 2019-07-16 22:35:34 UTC
Red Hat Bugzilla 1373014 None CLOSED VPN PPTP sessions no longer work under kernel 4.7.2 2019-07-16 22:35:34 UTC
Red Hat Bugzilla 1373689 None CLOSED PPTP broken after kernel update 2019-07-16 22:35:34 UTC

Internal Links: 1369489 1373014 1373689

Description John Browning 2016-09-11 17:18:08 UTC
Description of problem:
Attempting to establish a PPTP VPN Connection fails with " platform-linux: do-change-link[3]: failure changing link: failure 19 (No such device)" error

Version-Release number of selected component (if applicable):
NetworkManager-pptp-1.2.2-1.fc24.x86_64
NetworkManager-pptp-gnome-1.2.2-1.fc24.x86_64
pptp-1.8.0-8.fc24.x86_64
4.7.2-201.fc24.x86_64 #1 SMP Fri Aug 26 15:58:40 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

How reproducible:
Always

Steps to Reproduce:
1. Configure PPTP VPN Client
2. Attempt to connect to VPN Service
3.

Actual results:
Failure 19 (no such device)

Expected results:
Successful VPN Connection

Additional info:
Sep 11 12:51:09 spectre NetworkManager[1146]: <info>  [1473612669.3232] audit: op="connection-activate" uuid="74aca530-9815-40ff-852b-e0d969640572" name="REDACTED" pid=1661 uid=1337 result="success"
Sep 11 12:51:09 spectre NetworkManager[1146]: <info>  [1473612669.3300] vpn-connection[0x55dd189e11f0,74aca530-9815-40ff-852b-e0d969640572,"REDACTED",0]: Started the VPN service, PID 2621
Sep 11 12:51:09 spectre org.gnome.Shell.desktop[1321]: (gnome-shell:1321): Gjs-WARNING **: JS ERROR: TypeError: a._connection is null
Sep 11 12:51:09 spectre org.gnome.Shell.desktop[1321]: NMVPNSection<.setActiveConnections/<@resource:///org/gnome/shell/ui/status/network.js:1534
Sep 11 12:51:09 spectre org.gnome.Shell.desktop[1321]: NMVPNSection<.setActiveConnections@resource:///org/gnome/shell/ui/status/network.js:1533
Sep 11 12:51:09 spectre org.gnome.Shell.desktop[1321]: wrapper@resource:///org/gnome/gjs/modules/lang.js:178
Sep 11 12:51:09 spectre org.gnome.Shell.desktop[1321]: NMApplet<._syncVPNConnections@resource:///org/gnome/shell/ui/status/network.js:1822
Sep 11 12:51:09 spectre org.gnome.Shell.desktop[1321]: wrapper@resource:///org/gnome/gjs/modules/lang.js:178
Sep 11 12:51:09 spectre NetworkManager[1146]: <info>  [1473612669.3378] vpn-connection[0x55dd189e11f0,74aca530-9815-40ff-852b-e0d969640572,"REDACTED",0]: Saw the service appear; activating connection
Sep 11 12:51:09 spectre NetworkManager[1146]: <info>  [1473612669.4542] vpn-connection[0x55dd189e11f0,74aca530-9815-40ff-852b-e0d969640572,"REDACTED",0]: VPN connection: (ConnectInteractive) reply received
Sep 11 12:51:09 spectre NetworkManager[1146]: ** Message: pppd started with pid 2632
Sep 11 12:51:09 spectre NetworkManager[1146]: <info>  [1473612669.5119] vpn-connection[0x55dd189e11f0,74aca530-9815-40ff-852b-e0d969640572,"REDACTED",0]: VPN plugin: state changed: starting (3)
Sep 11 12:51:09 spectre pppd[2632]: Plugin /usr/lib64/pppd/2.4.7/nm-pptp-pppd-plugin.so loaded.
Sep 11 12:51:09 spectre NetworkManager[1146]: Plugin /usr/lib64/pppd/2.4.7/nm-pptp-pppd-plugin.so loaded.
Sep 11 12:51:09 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (plugin_init): initializing
Sep 11 12:51:09 spectre kernel: PPP generic driver version 2.4.2
Sep 11 12:51:09 spectre pppd[2632]: pppd 2.4.7 started by root, uid 0
Sep 11 12:51:09 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
Sep 11 12:51:09 spectre pptp[2640]: nm-pptp-service-2621 log[main:pptp.c:333]: The synchronous pptp option is NOT activated
Sep 11 12:51:09 spectre pppd[2632]: Using interface ppp0
Sep 11 12:51:09 spectre pppd[2632]: Connect: ppp0 <--> /dev/pts/1
Sep 11 12:51:09 spectre NetworkManager[1146]: Using interface ppp0
Sep 11 12:51:09 spectre NetworkManager[1146]: Connect: ppp0 <--> /dev/pts/1
Sep 11 12:51:09 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
Sep 11 12:51:09 spectre NetworkManager[1146]: <info>  [1473612669.5606] manager: (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/2)
Sep 11 12:51:09 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_rep:pptp_ctrl.c:258]: Sent control packet type is 1 'Start-Control-Connection-Request'
Sep 11 12:51:09 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_disp:pptp_ctrl.c:758]: Received Start Control Connection Reply
Sep 11 12:51:09 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_disp:pptp_ctrl.c:792]: Client connection established.
Sep 11 12:51:10 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_rep:pptp_ctrl.c:258]: Sent control packet type is 7 'Outgoing-Call-Request'
Sep 11 12:51:10 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_disp:pptp_ctrl.c:877]: Received Outgoing Call Reply.
Sep 11 12:51:10 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_disp:pptp_ctrl.c:916]: Outgoing call established (call ID 0, peer's call ID 15353).
Sep 11 12:51:40 spectre pppd[2632]: LCP: timeout sending Config-Requests
Sep 11 12:51:40 spectre NetworkManager[1146]: LCP: timeout sending Config-Requests
Sep 11 12:51:40 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Sep 11 12:51:40 spectre NetworkManager[1146]: Connection terminated.
Sep 11 12:51:40 spectre pppd[2632]: Connection terminated.
Sep 11 12:51:40 spectre NetworkManager[1146]: ** Message: Terminated ppp daemon with PID 2632.
Sep 11 12:51:40 spectre NetworkManager[1146]: <error> [1473612700.5961] platform-linux: do-change-link[3]: failure changing link: failure 19 (No such device)
Sep 11 12:51:40 spectre NetworkManager[1146]: <warn>  [1473612700.5963] device (ppp0): failed to disable userspace IPv6LL address handling
Sep 11 12:51:40 spectre NetworkManager[1146]: <info>  [1473612700.6000] vpn-connection[0x55dd189e11f0,74aca530-9815-40ff-852b-e0d969640572,"REDACTED",0]: VPN service disappeared
Sep 11 12:51:40 spectre org.gnome.Shell.desktop[1661]: Gjs-Message: JS LOG: Removing a network device that was not added
Sep 11 12:51:40 spectre org.gnome.Shell.desktop[1321]: Gjs-Message: JS LOG: Removing a network device that was not added
Sep 11 12:51:40 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
Sep 11 12:51:40 spectre NetworkManager[1146]: Terminating on signal 15
Sep 11 12:51:40 spectre NetworkManager[1146]: Modem hangup
Sep 11 12:51:40 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (nm_exit_notify): cleaning up
Sep 11 12:51:40 spectre pppd[2632]: Terminating on signal 15
Sep 11 12:51:40 spectre pptp[2652]: nm-pptp-service-2621 log[callmgr_main:pptp_callmgr.c:245]: Closing connection (unhandled)
Sep 11 12:51:40 spectre pptp[2652]: nm-pptp-service-2621 log[ctrlp_rep:pptp_ctrl.c:258]: Sent control packet type is 12 'Call-Clear-Request'
Sep 11 12:51:40 spectre pppd[2632]: Modem hangup
Sep 11 12:51:40 spectre pptp[2652]: nm-pptp-service-2621 log[call_callback:pptp_callmgr.c:84]: Closing connection (call state)
Sep 11 12:51:40 spectre pppd[2632]: Exit.

Comment 1 Blueowl 2016-09-13 15:35:12 UTC
Did it work for you before with the same pptp connection (configuration)?

The problem is that pppd did not receive LCP configuration from the peer. 

Sep 11 12:51:40 spectre pppd[2632]: LCP: timeout sending Config-Requests
Sep 11 12:51:40 spectre NetworkManager[1146]: LCP: timeout sending Config-Requests
Sep 11 12:51:40 spectre NetworkManager[1146]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Sep 11 12:51:40 spectre NetworkManager[1146]: Connection terminated.
Sep 11 12:51:40 spectre pppd[2632]: Connection terminated.
Sep 11 12:51:40 spectre NetworkManager[1146]: ** Message: Terminated ppp daemon with PID 2632.

You can look at the following link for more information and debugging pptp and pppd:
http://pptpclient.sourceforge.net/howto-diagnosis.phtml#lcp_timeout

Comment 2 John Browning 2016-09-13 16:25:07 UTC
Yep this worked previously on Fedora 23.
Thanks for the link, I will verify and debug further and post back with results.

Comment 3 Adam DiFrischia 2016-09-13 22:26:42 UTC
Confirm similar issues, worked on F24 up until roughly a week ago or so. Verified server operation using WIndows and CentOS machines.

Sep 13 18:23:32 my-hostname NetworkManager[1176]: <info>  [1473805412.6780] audit: op="connection-activate" uuid="c107ac90-44a3-4473-9bf7-74521e5f10af" name="VPN 1" pid=5930 uid=1855001104 result="success"
Sep 13 18:23:32 my-hostname NetworkManager[1176]: <info>  [1473805412.6920] vpn-connection[0x55c691ce85c0,c107ac90-44a3-4473-9bf7-74521e5f10af,"VPN 1",0]: Started the VPN service, PID 10456
Sep 13 18:23:32 my-hostname org.gnome.Shell.desktop[1430]: (gnome-shell:1430): Gjs-WARNING **: JS ERROR: TypeError: a._connection is null
Sep 13 18:23:32 my-hostname org.gnome.Shell.desktop[1430]: NMVPNSection<.setActiveConnections/<@resource:///org/gnome/shell/ui/status/network.js:1534
Sep 13 18:23:32 my-hostname org.gnome.Shell.desktop[1430]: NMVPNSection<.setActiveConnections@resource:///org/gnome/shell/ui/status/network.js:1533
Sep 13 18:23:32 my-hostname org.gnome.Shell.desktop[1430]: wrapper@resource:///org/gnome/gjs/modules/lang.js:178
Sep 13 18:23:32 my-hostname org.gnome.Shell.desktop[1430]: NMApplet<._syncVPNConnections@resource:///org/gnome/shell/ui/status/network.js:1822
Sep 13 18:23:32 my-hostname org.gnome.Shell.desktop[1430]: wrapper@resource:///org/gnome/gjs/modules/lang.js:178
Sep 13 18:23:32 my-hostname NetworkManager[1176]: <info>  [1473805412.7036] vpn-connection[0x55c691ce85c0,c107ac90-44a3-4473-9bf7-74521e5f10af,"VPN 1",0]: Saw the service appear; activating connection
Sep 13 18:23:35 my-hostname NetworkManager[1176]: <info>  [1473805415.3869] keyfile: update /etc/NetworkManager/system-connections/VPN 1-c107ac90-44a3-4473-9bf7-74521e5f10af (c107ac90-44a3-4473-9bf7-74521e5f10af,"VPN 1")
Sep 13 18:23:35 my-hostname NetworkManager[1176]: <info>  [1473805415.4036] vpn-connection[0x55c691ce85c0,c107ac90-44a3-4473-9bf7-74521e5f10af,"VPN 1",0]: VPN connection: (ConnectInteractive) reply received
Sep 13 18:23:35 my-hostname NetworkManager[1176]: ** Message: pppd started with pid 10473
Sep 13 18:23:35 my-hostname NetworkManager[1176]: <info>  [1473805415.4106] vpn-connection[0x55c691ce85c0,c107ac90-44a3-4473-9bf7-74521e5f10af,"VPN 1",0]: VPN plugin: state changed: starting (3)
Sep 13 18:23:35 my-hostname pppd[10473]: Plugin /usr/lib64/pppd/2.4.7/nm-pptp-pppd-plugin.so loaded.
Sep 13 18:23:35 my-hostname NetworkManager[1176]: Plugin /usr/lib64/pppd/2.4.7/nm-pptp-pppd-plugin.so loaded.
Sep 13 18:23:35 my-hostname NetworkManager[1176]: ** Message: nm-pptp-ppp-plugin: (plugin_init): initializing
Sep 13 18:23:35 my-hostname pppd[10473]: pppd 2.4.7 started by root, uid 0
Sep 13 18:23:35 my-hostname NetworkManager[1176]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
Sep 13 18:23:35 my-hostname pppd[10473]: Using interface ppp0
Sep 13 18:23:35 my-hostname NetworkManager[1176]: Using interface ppp0
Sep 13 18:23:35 my-hostname NetworkManager[1176]: Connect: ppp0 <--> /dev/pts/1
Sep 13 18:23:35 my-hostname NetworkManager[1176]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
Sep 13 18:23:35 my-hostname pppd[10473]: Connect: ppp0 <--> /dev/pts/1
Sep 13 18:23:35 my-hostname NetworkManager[1176]: <info>  [1473805415.4320] manager: (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/17)
Sep 13 18:23:35 my-hostname pptp[10476]: nm-pptp-service-10456 log[main:pptp.c:333]: The synchronous pptp option is NOT activated
Sep 13 18:23:35 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_rep:pptp_ctrl.c:258]: Sent control packet type is 1 'Start-Control-Connection-Request'
Sep 13 18:23:35 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_disp:pptp_ctrl.c:758]: Received Start Control Connection Reply
Sep 13 18:23:35 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_disp:pptp_ctrl.c:792]: Client connection established.
Sep 13 18:23:36 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_rep:pptp_ctrl.c:258]: Sent control packet type is 7 'Outgoing-Call-Request'
Sep 13 18:23:36 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_disp:pptp_ctrl.c:877]: Received Outgoing Call Reply.
Sep 13 18:23:36 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_disp:pptp_ctrl.c:916]: Outgoing call established (call ID 0, peer's call ID 48128).
Sep 13 18:24:06 my-hostname pppd[10473]: LCP: timeout sending Config-Requests
Sep 13 18:24:06 my-hostname pppd[10473]: Connection terminated.
Sep 13 18:24:06 my-hostname NetworkManager[1176]: LCP: timeout sending Config-Requests
Sep 13 18:24:06 my-hostname NetworkManager[1176]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Sep 13 18:24:06 my-hostname NetworkManager[1176]: Connection terminated.
Sep 13 18:24:06 my-hostname NetworkManager[1176]: ** Message: Terminated ppp daemon with PID 10473.
Sep 13 18:24:06 my-hostname NetworkManager[1176]: <error> [1473805446.4663] platform-linux: do-change-link[18]: failure changing link: failure 19 (No such device)
Sep 13 18:24:06 my-hostname NetworkManager[1176]: <warn>  [1473805446.4669] device (ppp0): failed to disable userspace IPv6LL address handling
Sep 13 18:24:06 my-hostname NetworkManager[1176]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
Sep 13 18:24:06 my-hostname NetworkManager[1176]: Terminating on signal 15
Sep 13 18:24:06 my-hostname NetworkManager[1176]: Modem hangup
Sep 13 18:24:06 my-hostname NetworkManager[1176]: ** Message: nm-pptp-ppp-plugin: (nm_exit_notify): cleaning up
Sep 13 18:24:06 my-hostname pppd[10473]: Terminating on signal 15
Sep 13 18:24:06 my-hostname pptp[10486]: nm-pptp-service-10456 log[callmgr_main:pptp_callmgr.c:245]: Closing connection (unhandled)
Sep 13 18:24:06 my-hostname pptp[10486]: nm-pptp-service-10456 log[ctrlp_rep:pptp_ctrl.c:258]: Sent control packet type is 12 'Call-Clear-Request'
Sep 13 18:24:06 my-hostname org.gnome.Shell.desktop[1430]: Gjs-Message: JS LOG: Removing a network device that was not added
Sep 13 18:24:06 my-hostname org.gnome.Shell.desktop[1813]: Gjs-Message: JS LOG: Removing a network device that was not added
Sep 13 18:24:06 my-hostname NetworkManager[1176]: <info>  [1473805446.5000] vpn-connection[0x55c691ce85c0,c107ac90-44a3-4473-9bf7-74521e5f10af,"VPN 1",0]: VPN service disappeared
Sep 13 18:24:06 my-hostname pptp[10486]: nm-pptp-service-10456 log[pptp_read_some:pptp_ctrl.c:563]: read returned zero, peer has closed
Sep 13 18:24:06 my-hostname pptp[10486]: nm-pptp-service-10456 log[call_callback:pptp_callmgr.c:84]: Closing connection (call state)
Sep 13 18:24:06 my-hostname pppd[10473]: Modem hangup
Sep 13 18:24:06 my-hostname pppd[10473]: Exit.

Comment 4 Adam DiFrischia 2016-09-13 22:41:07 UTC
Upon further investiagtion, I am able to succesfully connect in kernels 4.6.6 and 4.6.7, but not 4.7.2.

Comment 5 Blueowl 2016-09-14 08:38:29 UTC
(In reply to Adam DiFrischia from comment #4)
> Upon further investiagtion, I am able to succesfully connect in kernels
> 4.6.6 and 4.6.7, but not 4.7.2.

Adam, thanks for investigating. It was really a change in kernel. A quickfix can be
sysctl net.netfilter.nf_conntrack_helper=1

See bug 1373014 and bug 1369489.

There is also upstream bug:  https://bugzilla.kernel.org/show_bug.cgi?id=152101

Maybe NetworkManager-pptp should start setting nf_conntrack_helper=1 to mitigate the problem.

Comment 6 Thomas Haller 2016-10-03 10:56:50 UTC
*** Bug 1378450 has been marked as a duplicate of this bug. ***

Comment 7 Thomas Haller 2016-10-03 10:59:15 UTC
*** Bug 1376990 has been marked as a duplicate of this bug. ***

Comment 8 Dave Cain 2016-10-04 21:56:52 UTC
The above workaround doesn't seem to be work for me on kernel 4.7.3-200.  I've even tried booting into kernel 4.6.7-300 and my PPTP VPN doesn't come up with the same error messages as John Browning.  Same thing, the server sends the routes to the client (my system) and then I get the same "failure changing link" error message.

MSCHAPv2 authentication only, security: all available. Left the other settings at their default values.

Comment 9 Brendan Shephard 2016-10-04 22:44:46 UTC
$ echo 'net.netfilter.nf_conntrack_helper=1' >> /etc/sysctl.conf 
$ sysctl -p

has resolved the issue for me on Kernel 4.7.5-200.fc24.x86_64

Comment 10 aizikil 2016-11-06 14:08:15 UTC
*** Bug 1392185 has been marked as a duplicate of this bug. ***

Comment 11 Jonathan S 2016-11-14 19:29:05 UTC
Re https://bugzilla.redhat.com/show_bug.cgi?id=1390961

firewalld now accepts pptp connections regardless of the value of net.netfilter.nf_conntrack_helper, but, as the developer there points out (comment 11), NetworkManager takes care of the connection and loads the pptp conntrack helper module itself, so NM for pptp also needs to be amended in order to work when net.netfilter.nf_conntrack_helper=0.

Comment 12 Hedayat Vatankhah 2017-07-24 07:38:48 UTC
Same problem, and same workaround (sysctl net.netfilter.nf_conntrack_helper=1) for Fedora 26.

Comment 13 aizikil 2017-11-30 13:54:20 UTC
I confirm that this bug still exist on Fedora 26 and 27. Guys that's need to be patched !

Comment 14 Fedora End Of Life 2018-05-03 08:16:55 UTC
This message is a reminder that Fedora 26 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 26. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '26'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 26 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 15 Fedora End Of Life 2018-05-29 12:35:16 UTC
Fedora 26 changed to end-of-life (EOL) status on 2018-05-29. Fedora 26
is no longer maintained, which means that it will not receive any
further security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.