iOS: connection stalled on TCP

[croma25td]

I could reproduce this problem on both 1.2.5 and 1.2.6 by simply connecting to my VPN and executing a speedtest. After few seconds the connections stops working and even if the "VPN" icon on top bar is present the connection is not working anymore until I close and open again.

On 1.1.1 iOS no problems, no problems also on latest Windows and Android clients.

I also experience connections restarts ("VPN" icon going away) when phone goes to sleep or I quit the app by swiping it up. But I can provide logs for that too if necessary.

Here my server.conf

port 443
port-share 127.0.0.1 444

proto tcp
dev tun
sndbuf 0
rcvbuf 0
ca ca.crt
cert server.crt
key server.key
dh dh.pem
auth SHA512
tls-auth ta.key 0
topology subnet
server 10.8.0.0 255.255.255.0
ifconfig-pool-persist ipp.txt
push "redirect-gateway def1 bypass-dhcp"
push "dhcp-option DNS 8.8.8.8"
push "dhcp-option DNS 8.8.4.4"
keepalive 10 120
cipher AES-256-CBC
comp-lzo
user nobody
group nogroup
persist-key
persist-tun
status openvpn-status.log
verb 4
crl-verify crl.pem

duplicate-cn

tcp-nodelay

log-append /var/log/openvpn.log

And here the log with verbosity = 4 which shows an error

Wed Jan 17 09:12:14 2018 us=691727 CLIENT_IP:60219 TLS: Initial packet from [AF_INET]CLIENT_IP:60219, sid=9bb30151 3b405fa6
Wed Jan 17 09:12:14 2018 us=839044 CLIENT_IP:60219 VERIFY OK: depth=1, CN=ChangeMe
Wed Jan 17 09:12:14 2018 us=839157 CLIENT_IP:60219 VERIFY OK: depth=0, CN=client
Wed Jan 17 09:12:14 2018 us=878513 CLIENT_IP:60219 peer info: IV_GUI_VER=net.openvpn.connect.ios_1.2.6-4
Wed Jan 17 09:12:14 2018 us=878553 CLIENT_IP:60219 peer info: IV_VER=3.1.2
Wed Jan 17 09:12:14 2018 us=878559 CLIENT_IP:60219 peer info: IV_PLAT=ios
Wed Jan 17 09:12:14 2018 us=878564 CLIENT_IP:60219 peer info: IV_NCP=2
Wed Jan 17 09:12:14 2018 us=878569 CLIENT_IP:60219 peer info: IV_TCPNL=1
Wed Jan 17 09:12:14 2018 us=878574 CLIENT_IP:60219 peer info: IV_PROTO=2
Wed Jan 17 09:12:14 2018 us=878579 CLIENT_IP:60219 peer info: IV_LZO=1
Wed Jan 17 09:12:14 2018 us=878583 CLIENT_IP:60219 peer info: IV_AUTO_SESS=1
Wed Jan 17 09:12:14 2018 us=917487 CLIENT_IP:60219 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed Jan 17 09:12:14 2018 us=917533 CLIENT_IP:60219 [client] Peer Connection Initiated with [AF_INET]CLIENT_IP:60219
Wed Jan 17 09:12:14 2018 us=917558 client/CLIENT_IP:60219 MULTI_sva: pool returned IPv4=10.8.0.2, IPv6=(Not enabled)
Wed Jan 17 09:12:14 2018 us=917581 client/CLIENT_IP:60219 MULTI: Learn: 10.8.0.2 -> client/CLIENT_IP:60219
Wed Jan 17 09:12:14 2018 us=917587 client/CLIENT_IP:60219 MULTI: primary virtual IP for client/CLIENT_IP:60219: 10.8.0.2
Wed Jan 17 09:12:14 2018 us=918506 client/CLIENT_IP:60219 PUSH: Received control message: 'PUSH_REQUEST'
Wed Jan 17 09:12:14 2018 us=918550 client/CLIENT_IP:60219 SENT CONTROL [client]: 'PUSH_REPLY,redirect-gateway def1 bypass-dhcp,dhcp-option DNS 8.8.8.8,dhcp-option DNS 8.8.4.4,route-gateway 10.8.0.1,topology subnet,ping 10,ping-restart 120,socket-flags TCP_NODELAY,ifconfig 10.8.0.2 255.255.255.0,peer-id 0,cipher AES-256-GCM' (status=1)
Wed Jan 17 09:12:14 2018 us=918558 client/CLIENT_IP:60219 Data Channel: using negotiated cipher 'AES-256-GCM'
Wed Jan 17 09:12:14 2018 us=918566 client/CLIENT_IP:60219 Data Channel MTU parms [ L:1552 D:1450 EF:52 EB:406 ET:0 EL:3 ]
Wed Jan 17 09:12:14 2018 us=918616 client/CLIENT_IP:60219 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jan 17 09:12:14 2018 us=918623 client/CLIENT_IP:60219 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed Jan 17 09:12:26 2018 us=695994 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=696014 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=696021 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=696028 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=696034 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=696040 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=942950 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=942979 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=942997 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943005 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943011 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943017 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943024 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943030 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943047 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943055 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943061 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943067 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943073 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943079 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943086 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943103 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943110 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943116 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943122 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943128 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943134 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943146 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943256 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=943305 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=957098 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=957171 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=957181 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=958189 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=958228 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=958625 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=958660 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=958682 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:26 2018 us=958689 client/CLIENT_IP:60219 MULTI: packet dropped due to output saturation (multi_process_incoming_tun)
Wed Jan 17 09:12:29 2018 us=437614 client/CLIENT_IP:60219 AEAD Decrypt error: bad packet ID (may be a replay): [ #1596 ] -- see the man page entry for --no-replay and --replay-window for more info or silence this warning with --mute-replay-warnings
Wed Jan 17 09:12:29 2018 us=437658 client/CLIENT_IP:60219 Fatal decryption error (process_incoming_link), restarting
Wed Jan 17 09:12:29 2018 us=437665 client/CLIENT_IP:60219 SIGUSR1[soft,decryption-error] received, client-instance restarting
Wed Jan 17 09:12:29 2018 us=437721 TCP/UDP: Closing socket

Server version

root@server1:/var/log# openvpn --version
OpenVPN 2.4.4 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Sep 26 2017
library versions: OpenSSL 1.0.1t  3 May 2016, LZO 2.06
Originally developed by James Yonan
Copyright (C) 2002-2017 OpenVPN Technologies, Inc. <sales@openvpn.net>
Compile time defines: enable_async_push=no enable_comp_stub=no enable_crypto=yes enable_crypto_ofb_cfb=yes enable_debug=no enable_def_auth=yes enable_dlopen=unknown enable_dlopen_self=unknown enable_dlopen_self_static=unknown enable_fast_install=yes enable_fragment=yes enable_iproute2=no enable_libtool_lock=yes enable_lz4=yes enable_lzo=yes enable_management=yes enable_multihome=yes enable_pam_dlopen=no enable_password_save=yes enable_pedantic=no enable_pf=yes enable_pkcs11=yes enable_plugin_auth_pam=yes enable_plugin_down_root=yes enable_plugins=yes enable_port_share=yes enable_selinux=no enable_server=yes enable_shared=yes enable_shared_with_static_runtimes=no enable_small=no enable_static=yes enable_strict=no enable_strict_options=no enable_systemd=no enable_werror=no enable_win32_dll=yes enable_x509_alt_username=no with_crypto_library=openssl with_gnu_ld=yes with_mem_check=no with_sysroot=no

root@server1:/var/log# uname -r
3.16.0-0.bpo.4-amd64

[croma25td]

I messed up and can't assign the component of this ticket anymore, sorry :(

[Antonio Quartulli]

Can you reproduce this problem also when using UDP as protocol?

[GainfulShrimp]

I also have this problem with my TCP/443 based OpenVPN server (in both 1.2.5 and same in 1.2.6) and can confirm that I cannot replicate this issue with my UDP servers at all.

EDIT: Just wanted to add, in case it wasn't clear, that the TCP/443 connection works fine from other clients (Linux ARM and Mac OS x86_64) - it's just OpenVPN Connect (iOS) that seems to stall/fail TCP connections under high load. (I haven't got an Android device to test with unfortunately.)

[janvier]

Replying to ordex:

Can you reproduce this problem also when using UDP as protocol?

As I did some test, UDP works well, just only TCP stream (proxy or directly) has this problem.

It is not difficult to reproduce this issue:

1. Established a VPN connection by TCP protocol;
2. Download a big file over VPN.

Then you will be randomly dropped with EOF_ERROR log or without a word.

[Ozwel]

Hi, looks very much like my problem reported here: ​https://community.openvpn.net/openvpn/ticket/991

Except that I have no error message in the logs with verbosity 5.

[orbitarm]

Replying to Ozwel:

Hi, looks very much like my problem reported here: ​https://community.openvpn.net/openvpn/ticket/991

Except that I have no error message in the logs with verbosity 5.

I'm having this exact issue: TCP port 443, no error messages. On verbosity 6, which outputs packet reads/writes (as explained in the ​manpage), I noticed that I was getting a steady number of "Rw" and "Wr" while I was able to access webpages, but only got "Wr" when the connection was lost. This implies that the client was trying to constantly write TCP packets and read TUN packets. Here's my server.conf for reference (I forward port 443 to 1194 internally):

dev tun
proto tcp
port 1194
ca ca.crt
cert server.crt
key server.key
dh dh2048.pem
topology subnet
server 10.8.0.0 255.255.255.0
ifconfig 10.8.0.1 10.8.0.2
push "route 10.8.0.1 255.255.255.255"
push "route 10.8.0.0 255.255.255.0"
push "route 192.168.1.0 255.255.255.0"
push "dhcp-option DNS 192.168.1.101"
push "redirect-gateway def1"
client-to-client
duplicate-cn
keepalive 10 120
tls-version-min 1.2
tls-crypt ta.key
cipher AES-256-CBC
auth SHA256
compress lz4-v2
push "compress lz4-v2"
user nobody
group nogroup
persist-key
persist-tun
crl-verify crl.pem
status /var/log/openvpn-status.log 20
status-version 3
log /var/log/openvpn.log
verb 4

[Ozwel]

I confirm that by changing TCP/443 to UDP/random_port this issue stands no more.

Hence... I also confirm the issue is with iOS OpenVPN Connect client being used with TCP port 443. Should be an easy fix...

[Antonio Quartulli]

A fix for this is in the works. Hopefully it will be out soon

[janvier]

Replying to ordex:

A fix for this is in the works. Hopefully it will be out soon

Awesome! Appreciates for the hard work.

[sevenup]

Replying to ordex:

A fix for this is in the works. Hopefully it will be out soon

Really appreciate your effort! Hope this problem can be solved ASAP

[sevenup]

I can't see ticket #984 in "{4} Accepted, Active Tickets by Owner " category. Does it mean that "Connection stalled on TCP" has been solved?

[Antonio Quartulli]

because it wasn't switched to "accepted".

However, as I said a few comments above, a potential fix for this issue will be shipped with the next release (currently under review by Apple)

[sevenup]

Replying to ordex:

because it wasn't switched to "accepted".

However, as I said a few comments above, a potential fix for this issue will be shipped with the next release (currently under review by Apple)

Thanks Ordex, look forward to the next release.

[Antonio Quartulli]

v1.2.7 is being rolled out to the various AppStore? as we speak. Please test it once you have a chance to upgrade and update this ticket accordingly, if possible. Thanks!

[janvier]

Replying to ordex:

v1.2.7 is being rolled out to the various AppStore? as we speak. Please test it once you have a chance to upgrade and update this ticket accordingly, if possible. Thanks!

I just updated to v1.2.7 and tested on both 4G and Wi-Fi, the TCP stream looks good, this issue seems been fixed. I will do more test in couple days and will update this ticket again if anything not right. Thanks for your effort!

[Antonio Quartulli]

Glad to hear! I am closing this ticket for now, but feel free to update it with more info or re-open it if the issue should persist,