Bug 1404371 - NetworkManager-openconnect fails to remain connected
Summary: NetworkManager-openconnect fails to remain connected
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager-openconnect
Version: 25
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: David Woodhouse
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-12-13 16:56 UTC by Dhaval Giani
Modified: 2017-12-12 10:41 UTC (History)
11 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-12-12 10:41:09 UTC


Attachments (Terms of Use)

Description Dhaval Giani 2016-12-13 16:56:09 UTC
Description of problem:
I use openconnect to connect to VPN. With the latest update (1.2.4.1), the VPN starts silently dropping connections.

Version-Release number of selected component (if applicable):
1.2.4.1

How reproducible:
Everytime

Steps to Reproduce:
1. Connect to VPN
2. Wait a minute
3.

Actual results:
Connections start dropping

Expected results:
Things work just fine ;-)

Additional info:
Downgrading has helped and now I am connecting. I am pretty sure it is a regression.

Comment 1 David Woodhouse 2016-12-14 10:24:52 UTC
I am *so* tempted to file a 'NetworkManager doesn't let VPN plugin give a *reason* for disconnection, and just says they failed' bug, and make this one depend on it.

But let's live with that utter crappiness for now and try to work around it. Whatever the reason, OpenConnect will have send it to the system log. Please can you show it?

Comment 2 Dhaval Giani 2016-12-16 22:09:34 UTC
Ah, for some reason this comment did not make it to my email.

I finally figured out the difference between the two versions.

(I am not sure if this is a generic setup, or something specific to our VPN so bear with me)

With previous version, on connection, the MTU was being set correctly to 1290. However, with this version, it is getting set to 1300. Changing it back to 1290, fixes it all for me.

The actual symptom of the issue is the following log message,

Dec 12 22:52:41 localhost.localdomain openconnect[2745]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 12 22:52:41 localhost.localdomain openconnect[2745]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).

Not sure if that is a problem with NetworkManager or with openconnect.

More logs, that might be useful
Dec 13 09:07:10 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:10 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:07:14 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:14 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:07:18 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:18 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:07:22 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:22 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:07:26 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:26 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:07:30 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:30 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:07:34 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:07:34 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:08:38 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:08:39 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:08:42 openconnect[4360]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 13 09:08:42 openconnect[4360]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 13 09:08:44 openconnect[4360]: Failed to send DPD request (1295): The transmitted packet is too large (EMSGSIZE).
Dec 13 09:08:44 openconnect[4360]: Failed to send DPD request (1292): The transmitted packet is too large (EMSGSIZE).
Dec 13 09:08:44 openconnect[4360]: Failed to send DPD request (1291): The transmitted packet is too large (EMSGSIZE).
Dec 13 09:08:44 openconnect[4360]: Detected MTU of 1290 bytes (was 1300)

Comment 3 David Woodhouse 2016-12-16 22:25:00 UTC
Hm, and this started happening when you updated NetworkManager-openconnect, not when you updated openconnect itself? That seems odd.

Did the openconnect 7.08 update *fix* it? The above log looks like it's 7.08, with the dynamic MTU detection, correctly detecting a 1290-byte MTU.

Comment 4 Dhaval Giani 2016-12-16 22:27:52 UTC
Correct, it is happening with the NetworkManager-openconnect update.

Hmm. I have openconnect-7.07-2 and I don't see an update for it. (Fedora 25)

Is the rpm in updates-testing?

To answer your question, no, it is not getting set correctly automatically, and I am setting it manually.

Comment 5 David Woodhouse 2016-12-16 22:37:58 UTC
Please try with https://bodhi.fedoraproject.org/updates/FEDORA-2016-236fdd6917

Comment 6 Dhaval Giani 2016-12-16 22:48:00 UTC
Dec 16 17:47:05 localhost.localdomain openconnect[3393]: Too long time in MTU detect loop; MTU set to 1289.
Dec 16 17:47:05 localhost.localdomain openconnect[3393]: Detected MTU of 1289 bytes (was 1300)

(And sets the MTU to 1289)

Comment 7 David Woodhouse 2016-12-16 23:00:32 UTC
Which is suboptimal and *might* cause problems in some (broken) environments because it really ought to be 1290. But is basically working? Can you show the full output and the set of sizes tried, please?

Comment 8 Dhaval Giani 2016-12-17 02:42:28 UTC
[dhaval@localhost ~]$ sudo openconnect -u dgiani_ca --passwd-on-stdin <vpnhost > vpn.log
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1300 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1299 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1298 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1297 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1296 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1295 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1294 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1293 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1292 -5)
Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1291 -5)
Too long time in MTU detect loop; MTU set to 1289.
^C[dhaval@localhost ~]$ 

vpn.log doesn't contain anything interesting.

Comment 9 Dhaval Giani 2016-12-17 03:54:44 UTC
So additional information.

For fun, with mtu being set by openconnect as 1289, I changed it to 1290 and suddenly the connection started to break

Dec 16 22:48:43 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:45 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:45 localhost.localdomain openconnect[7344]: Unknown DTLS packet type d8, len 1
Dec 16 22:48:46 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:46 localhost.localdomain google-chrome.desktop[2649]: [2649:2680:1216/224846:ERROR:ssl_client_socket_impl.cc(1146)] handshake failed; returned -1, SSL error code 1, net_error -101
Dec 16 22:48:46 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:46 localhost.localdomain openconnect[7344]: Unknown DTLS packet type d8, len 1
Dec 16 22:48:47 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:48 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:49 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:52 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:53 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:55 localhost.localdomain google-chrome.desktop[2649]: [2649:2680:1216/224855:ERROR:ssl_client_socket_impl.cc(1146)] handshake failed; returned -1, SSL error code 1, net_error -101
Dec 16 22:48:56 localhost.localdomain google-chrome.desktop[2649]: [2649:2680:1216/224856:ERROR:ssl_client_socket_impl.cc(1146)] handshake failed; returned -1, SSL error code 1, net_error -101
Dec 16 22:48:56 localhost.localdomain wpa_supplicant[1274]: wlp2s0: WPA: Group rekeying completed with be:4d:fb:55:36:a0 [GTK=TKIP]
Dec 16 22:48:56 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:56 localhost.localdomain openconnect[7344]: Unknown DTLS packet type d8, len 1
Dec 16 22:48:57 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:48:59 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:49:03 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:49:06 localhost.localdomain google-chrome.desktop[2649]: [2649:2680:1216/224906:ERROR:ssl_client_socket_impl.cc(1146)] handshake failed; returned -1, SSL error code 1, net_error -101
Dec 16 22:49:07 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:49:07 localhost.localdomain openconnect[7344]: Unknown DTLS packet type d8, len 1
Dec 16 22:49:08 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:49:10 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1
Dec 16 22:49:14 localhost.localdomain openconnect[7344]: Unknown DTLS packet type 2e, len 1


(The chrome connections going through the VPN). Setting it back to 1289 allowed the VPN connection to work again. So this one, I think might be an issue at the end of my VPN as opposed to a bug with openconnect.

Comment 10 Andy Campbell 2016-12-18 06:35:12 UTC
I've been having the same issue with the sane errors since I upgraded to F25.

I've got a spare PC, so I installed F24 there as a quick test and the VPN connection seems stable.

F25 ...

NetworkManager-openconnect-gnome-1.2.4-1.fc25.x86_64
NetworkManager-openconnect-1.2.4-1.fc25.x86_64
openconnect-7.07-2.fc25.x86_64

F24
NetworkManager-openconnect-1.2.2-1.fc24.x86_64
openconnect-7.07-2.fc24.x86_64


MTU on F24 is 1300, and stay the same.

MFU on F25 seem to get changed to 1290 ...

Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Failed to send DPD request (1295): The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1292): The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1291): The transmitted packet is too large (EMSGSIZE).
Detected MTU of 1290 bytes (was 1300)


Starting the connection from the command line with mtu starting 1290 ...

openconnect -m 1290 https://

Seems to be working so far.

Comment 11 David Woodhouse 2016-12-18 09:58:34 UTC
Hm, but when OpenConnect *logs* that it's reducing the MTU, the actual MTU reported by 'ifconfig vpn0' doesn't match?

Comment 12 Andy Campbell 2016-12-18 10:55:21 UTC
Opening connections through Network Manager.

Attempt 1.
================

-- Initial
   vpn0: flags=4240<POINTOPOINT,NOARP,MULTICAST>  mtu 1300
-- Open connection

Dec 18 10:19:14 neotrantor openconnect[23031]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 18 10:19:14 neotrantor openconnect[23031]: Failed to send DPD request (1295): The transmitted packet is too large (EMSGSIZE).
Dec 18 10:19:14 neotrantor openconnect[23031]: Failed to send DPD request (1292): The transmitted packet is too large (EMSGSIZE).
Dec 18 10:19:15 neotrantor openconnect[23031]: Failed to send DPD request (1291): The transmitted packet is too large (EMSGSIZE).
Dec 18 10:19:15 neotrantor openconnect[23031]: Detected MTU of 1290 bytes (was 1300)
Dec 18 10:19:16 neotrantor openconnect[23031]: SIOCSIFMTU: Operation not permitted

vpn0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1290

*** VPN - seems stable this time

Attempt 2.
================

-- Initial
   vpn0: flags=4240<POINTOPOINT,NOARP,MULTICAST>  mtu 1290

-- Open Connection
Dec 18 10:22:54 neotrantor openconnect[23745]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 18 10:22:59 neotrantor openconnect[23745]: SIOCSIFMTU: Operation not permitted

vpn0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1300

-- do some network 

Dec 18 10:24:40 neotrantor openconnect[23745]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 18 10:24:40 neotrantor openconnect[23745]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 18 10:24:40 neotrantor openconnect[23745]: Failed to send DPD request (1295): The transmitted packet is too large (EMSGSIZE).
Dec 18 10:24:41 neotrantor openconnect[23745]: Failed to send DPD request (1292): The transmitted packet is too large (EMSGSIZE).
Dec 18 10:24:41 neotrantor openconnect[23745]: Failed to send DPD request (1291): The transmitted packet is too large (EMSGSIZE).
Dec 18 10:24:41 neotrantor openconnect[23745]: Detected MTU of 1290 bytes (was 1300)
Dec 18 10:24:41 neotrantor openconnect[23745]: DTLS got write error: The transmitted packet is too large (EMSGSIZE).. Falling back to SSL
Dec 18 10:24:41 neotrantor openconnect[23745]: Established DTLS connection (using GnuTLS). Ciphersuite (DTLS0.9)-(RSA)-(AES-256-CBC)-(SHA1).
Dec 18 10:24:42 neotrantor openconnect[23745]: Unknown DTLS packet type 43, len 10
Dec 18 10:24:42 neotrantor openconnect[23745]: Unknown DTLS packet type 1c, len 10
Dec 18 10:24:42 neotrantor openconnect[23745]: Unknown DTLS packet type 63, len 10
Dec 18 10:24:42 neotrantor openconnect[23745]: Unknown DTLS packet type ed, len 10

MTU stays at 1300 ..

vpn0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1300

*** VPN stopped working.

Comment 13 Knut Omang 2017-05-08 07:02:51 UTC
I just experienced this same issue after going from Fedora 24 to Fedora 25.
I also happen to have the old setup still running on my to-be-decommisioned 
desktop so I was able to compare easily.

Both systems runs the same openconnect, apart from the build,
but gnutls is newer on f25.

I tried to use the --mtu 1290  workaround - that did not seem to have any effect.
Downgrading gnutls on the other hand did the trick.

Openconnect version:     openconnect-7.08-1.fc25.x86_64
GNU TLS version:         gnutls-3.5.11-1.fc25.x86_64

Downgrading GNU TLS to   gnutls-3.5.5-2.fc25.x86_64
and it all works again, without any --mtu parameter

Comment 14 Nikos Mavrogiannopoulos 2017-05-09 07:19:04 UTC
Could you try versions of gnutls in between? If the issue is in 3.5.7, the difference is in a more precise MTU detection (previous versions were conservative on the lower end), and that could have issues on problematic links.

Comment 15 Knut Omang 2017-08-07 15:54:30 UTC
Sorry for the slow followup on this - I did start trying to build gnutls to test versions in between 3.5.7 and 3.5.2 but got pulled into something else and never got around to finish it. 

I noticed now that with 3.5.14 the problem seems to have been fixed, as I can see from the log the same attempts to move from 1300 to 1290 bytes, but with success and established communication at 1290 bytes at the end. Thanks!

Comment 16 Daniel Moerner 2017-10-27 02:10:54 UTC
Hi,

I can confirm that I am seeing the same problem on Fedora 25, with openconnect 7.08 and gnutls 3.5.15. If I start openconnect with "-m 1274", then it works. ("--no-dtls" also works). Otherwise, I see the following messages:

Failed to write to SSL socket: The transmitted packet is too large (EMSGSIZE).
Failed to send DPD request (1275 -5)
Sending MTU DPD probe (1274 bytes, min=640, max=1274)
Received MTU DPD probe (1275 bytes of 1274)
Detected MTU of 1274 bytes (was 1280)
[...]
Unknown DTLS packet type be, len 2

Interestingly, if I start it with "-m 1275" or "-m 1273", it also works. But any value above 1275 that I have tested seems to produce a failure.

However, so far as I can tell, ip link set vpn0 mtu 1274 does not work. Even though ifconfig vpn0 says the mtu is 1274, I still can't resolve anything on the VPN. Only running openconnect on the commandline with "-m" is successful. So I can't use a workaround like http://www.0xf8.org/2015/08/setting-the-mtu-on-networkmanager-connections/.

Comment 17 Fedora End Of Life 2017-11-16 18:35:43 UTC
This message is a reminder that Fedora 25 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 25. 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 '25'.

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 25 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 18 Fedora End Of Life 2017-12-12 10:41:09 UTC
Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 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.