Opened 6 years ago

Closed 4 years ago

Last modified 18 months ago

#356 closed Bug / Defect (fixed)

iPhone: wifi -> cellular switch pauses the vpn connection

Reported by: eugene Owned by: jamesyonan
Priority: major Milestone:
Component: OpenVPN Connect Version:
Severity: Not set (select this one, unless your'e a OpenVPN developer) Keywords: ios
Cc:

Description

Hello,

I setup server on ubuntu 13.04 and client on iPhone 5S (OpenVPN Connect v1.0.2, iOS 7.0.4). When I switch off WiFi? it fails to reconnect, and no websites work. When I switch wifi on it works fine.

Steps to reproduce

  1. setup a simple vpn server
  2. While on wifi connect to openvpn server on iPhone
  3. Open web browser, and make sure everything works fine
  4. Switch off the wifi

Expected

  1. VPN icon to blink once and browser working as expected

Actual

  1. VPN icon goes away, browser cannot open the webpage

Server log:

Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 TLS: Initial packet from [AF_INET]95.97.134.250:39942, sid=2a472401 3f692322
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 VERIFY OK: depth=1, C=NL, ST=NH, L=Amsterdam, O=Wakoopa, OU=Whatever, CN=wakoopa vpn, name=Eugene Pimenov, emailAddress=eugene@wakoopa.com
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 VERIFY OK: depth=0, C=NL, ST=NH, L=Amsterdam, O=Whatever, OU=whatever, CN=eugene_vpn, name=Eugene, emailAddress=eugene@wakoopa.com
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: 95.97.134.250:39942 [eugene_vpn] Peer Connection Initiated with [AF_INET]95.97.134.250:39942
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: eugene_vpn/95.97.134.250:39942 MULTI_sva: pool returned IPv4=10.8.0.6, IPv6=(Not enabled)
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: eugene_vpn/95.97.134.250:39942 MULTI: Learn: 10.8.0.6 -> eugene_vpn/95.97.134.250:39942
Dec 19 14:01:33 ip-10-58-101-47 ovpn-server[2353]: eugene_vpn/95.97.134.250:39942 MULTI: primary virtual IP for eugene_vpn/95.97.134.250:39942: 10.8.0.6
Dec 19 14:01:34 ip-10-58-101-47 ovpn-server[2353]: eugene_vpn/95.97.134.250:39942 PUSH: Received control message: 'PUSH_REQUEST'
Dec 19 14:01:34 ip-10-58-101-47 ovpn-server[2353]: eugene_vpn/95.97.134.250:39942 send_push_reply(): safe_cap=940
Dec 19 14:01:34 ip-10-58-101-47 ovpn-server[2353]: eugene_vpn/95.97.134.250:39942 SENT CONTROL [eugene_vpn]: 'PUSH_REPLY,redirect-gateway def1,route 10.8.0.1,topology net30,ping 10,ping-restart 120,ifconfig 10.8.0.6 10.8.0.5' (status=1)

Client log:

Dec 19 15:01:34 Eugenes-iPhone OpenVPN[13024] <Warning>: OpenVPNView: processEvent active=1 {
	    clientIp = "";
	    error = 0;
	    info = "@54.220.174.166:1194 (54.220.174.166) via /UDPv4 on tun/10.8.0.6/";
	    name = CONNECTED;
	    serverHost = "54.220.174.166";
	    serverIp = "54.220.174.166";
	    serverPort = 1194;
	    serverProto = UDPv4;
	    tunName = tun;
	    user = "";
	    vpnIp4 = "10.8.0.6";
	    vpnIp6 = "";
	}
Dec 19 15:01:38 Eugenes-iPhone OpenVPN[13024] <Warning>: AppDelegate: applicationWillResignActive
Dec 19 15:01:38 Eugenes-iPhone OpenVPN[13024] <Warning>: OpenVPNView: applicationWillResignActive
Dec 19 15:01:38 Eugenes-iPhone vpnagent[13303] <Error>: VPNTunnelIPCReceivedMessage, type=204
Dec 19 15:01:40 Eugenes-iPhone OpenVPN[13024] <Warning>: AppDelegate: applicationDidEnterBackground
Dec 19 15:01:43 Eugenes-iPhone geod[117] <Warning>: Can't get bundle identifier for process 10322
Dec 19 15:01:43 Eugenes-iPhone kernel[0] <Debug>: 1044775.942957 wlan.A[95368] AppleBCMWLANNetManager::updateLinkQualityMetrics(): Report LQM to User Land 100, fAverageRSSI -70
Dec 19 15:01:43 Eugenes-iPhone geod[117] <Warning>: Can't get bundle identifier for process 10322
Dec 19 15:01:43 Eugenes-iPhone locationd[10322] <Notice>: Location icon should now be in state 'Active'
Dec 19 15:01:43 Eugenes-iPhone kbd[115] <Warning>: -[PFUbiquitySwitchboardEntryMetadata setUseLocalStorage:](754): CoreData: Ubiquity:  mobile~9227CCEC-A310-58A9-A7D1-9DCC2E1702D4:UserDictionary
	Using local storage: 1
Dec 19 15:01:43 Eugenes-iPhone kbd[115] <Warning>: -[PFUbiquitySwitchboardEntryMetadata setUseLocalStorage:](754): CoreData: Ubiquity:  mobile~9227CCEC-A310-58A9-A7D1-9DCC2E1702D4:UserDictionary
	Using local storage: 0
Dec 19 15:01:44 Eugenes-iPhone awdd[13305] <Error>: CoreLocation: CLClient is deprecated. Will be obsolete soon.
Dec 19 15:01:48 Eugenes-iPhone kernel[0] <Debug>: AppleH6CamIn::setPowerStateGated: 1
Dec 19 15:01:48 Eugenes-iPhone kernel[0] <Debug>: AppleH6CamIn::power_on_hardware
Dec 19 15:01:49 Eugenes-iPhone wifid[40] <Error>: _dispatchDriverAvailable: available 0, reason -528345084, subreason 0
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.793938 wlan.N[95369] AppleBCMWLANCore::setPOWER():  [wifid]: Setting power state to 0. stateFlags(3000f)
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.793950 wlan.N[95370] AppleBCMWLANCore::powerOff():  fStateFlags(3100f)
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.821731 wlan.N[95371] [tearDownLink] AppleBCMWLAN Left BSS(down):   @0xffffff8096f7f800 BSSID=10:9a:dd:88:a9:ba rssi=-63 noise=-89  snr= 24 cca= 3 rate=135 (100%) channel=100 encryption=0x8 ap=1 failures=  0 age=0 ssid[ 7]='Wakoopa'
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.821757 wlan.A[95372] Active Ports:
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.821782 wlan.A[95373] AppleBCMWLANCore::deleteAllPktFilters():  Deleted IPv4/IPv6 and Magic packet filters
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: AirPort: Link Down on en0. Reason 1 (Unspecified).
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: en0::stopOutputQueues
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: en0::IO80211Interface::postMessage bssid changed
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.822073 wlan.A[95374] AppleBCMWLANNetManager::resetLinkQualityMetrics(): Report LQM as -2
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.822120 wlan.N[95375] AppleBCMWLANCore::resetAutoCountry(): EnhancedLocaleEnabled: 1, HostCountry:0, fDefaultCountryCode:XZ, fCurrentCountryCode:XZ
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.866927 wlan.N[95376] AppleBCMWLANPacketTransmitter::disablePropTxStatus():  Forced 0
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.868905 wlan.N[95377] AppleBCMWLANPacketTransmitter::disablePropTxStatus():  Disabled
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.868911 wlan.N[95378] AppleBCMWLANPacketTransmitter::disablePropTxStatus():  Requesting disable
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.868917 wlan.C[95379] AppleBCMWLANPacketTransmitter::disablePropTxStatus():  Proptx state 0
Dec 19 15:01:49 Eugenes-iPhone kernel[0] <Debug>: 1044783.870906 wlan.N[95380] AppleBCMWLANCore::powerOff():  Ready to power off
Dec 19 15:01:50 Eugenes-iPhone kernel[0] <Debug>: 1044783.950619 wlan.A[95381] AppleBCMWLANCore::setProperties(): Active during sleep supported (false)
Dec 19 15:01:50 Eugenes-iPhone configd[42] <Notice>: network changed: v4(utun0:10.8.0.6, en0, pdp_ip0) DNS Proxy
Dec 19 15:01:50 Eugenes-iPhone vpnagent[13303] <Error>: LOG: OS Event: NET UNAVAILABLE (PAUSE): Reachability<reachable=1 connectionRequired=0 isWWAN=0>
Dec 19 15:01:50 Eugenes-iPhone vpnagent[13303] <Error>: tun_builder_teardown
Dec 19 15:01:50 Eugenes-iPhone vpnagent[13303] <Error>: LOG: UDP send error: send: Can't assign requested address
Dec 19 15:01:50 Eugenes-iPhone vpnagent[13303] <Error>: LOG: EVENT: PAUSE
Dec 19 15:01:50 Eugenes-iPhone configd[42] <Notice>: Captive: CNPluginHandler en0: Inactive
Dec 19 15:01:50 Eugenes-iPhone configd[42] <Notice>: network changed: v4(utun0:10.8.0.6, pdp_ip0, en0-:172.16.1.50) DNS* Proxy
Dec 19 15:01:50 Eugenes-iPhone configd[42] <Notice>: IPv4 over pdp_ip0 demoted: not primary for IPv6
Dec 19 15:01:50 Eugenes-iPhone configd[42] <Notice>: network changed: DNS- Proxy-
Dec 19 15:01:53 Eugenes-iPhone vpnagent[13303] <Error>: Resume timer callback: Reachability<reachable=0 connectionRequired=0 isWWAN=0>
Dec 19 15:01:55 Eugenes-iPhone locationd[10322] <Notice>: Location icon should now be in state 'Inactive'
Dec 19 15:01:56 Eugenes-iPhone kernel[0] <Debug>: AppleH6CamIn::setPowerStateGated: 0
Dec 19 15:01:56 Eugenes-iPhone kernel[0] <Debug>: AppleH6CamIn::power_off_hardware
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.818377]: Disable WoW requested by "apsd"
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.820474]: Unable to dispatch WowStateChanged message to client MobileMail (268435460)
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.821288]: Unable to dispatch WowStateChanged message to client itunesstored (268435460)
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.822028]: Unable to dispatch WowStateChanged message to client dataaccessd (268435460)
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.822475]: Unable to dispatch WowStateChanged message to client SpringBoard (268435460)
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.822905]: Unable to dispatch WowStateChanged message to client dataaccessd (268435460)
Dec 19 15:02:25 Eugenes-iPhone wifid[40] <Error>: WiFi:[409154545.823319]: Unable to dispatch WowStateChanged message to client softwareupdatese (268435460)

vpn log:

2013-12-19 15:01:33 ----- OpenVPN Start (iOS 64-bit) -----
2013-12-19 15:01:33 UNUSED OPTIONS
4 [resolv-retry] [infinite] 
5 [nobind] 
6 [persist-key] 
7 [persist-tun] 
9 [verb] [3] 

2013-12-19 15:01:33 LZO-ASYM init swap=0 asym=0
2013-12-19 15:01:33 EVENT: RESOLVE
2013-12-19 15:01:33 Contacting 54.220.174.166:1194 via UDP
2013-12-19 15:01:33 EVENT: WAIT
2013-12-19 15:01:33 Connecting to 54.220.174.166:1194 (54.220.174.166) via UDPv4
2013-12-19 15:01:33 EVENT: CONNECTING
2013-12-19 15:01:33 Tunnel Options:V4,dev-type tun,link-mtu 1542,tun-mtu 1500,proto UDPv4,comp-lzo,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client
2013-12-19 15:01:33 Peer Info:
IV_VER=3.0
IV_PLAT=ios
IV_NCP=1
IV_LZO=1

2013-12-19 15:01:33 VERIFY OK: depth=1
cert. version : 3
serial number : CD:5C:F9:3D:14:7E:02:42
issuer name  : C=NL, ST=NH, L=Amsterdam, O=Wakoopa, OU=Whatever, CN=wakoopa vpn, 0x29=Eugene Pimenov, emailAddress=eugene@wakoopa.com
subject name  : C=NL, ST=NH, L=Amsterdam, O=Wakoopa, OU=Whatever, CN=wakoopa vpn, 0x29=Eugene Pimenov, emailAddress=eugene@wakoopa.com
issued  on    : 2013-12-19 11:23:16
expires on    : 2023-12-17 11:23:16
signed using  : RSA+SHA1
RSA key size  : 1024 bits

2013-12-19 15:01:33 VERIFY OK: depth=0
cert. version : 3
serial number : 01
issuer name  : C=NL, ST=NH, L=Amsterdam, O=Wakoopa, OU=Whatever, CN=wakoopa vpn, 0x29=Eugene Pimenov, emailAddress=eugene@wakoopa.com
subject name  : C=NL, ST=NH, L=Amsterdam, O=Wakoopa, OU=Whatever, CN=vpn.wakoopa.com, 0x29=Eugene Pimenov, emailAddress=eugene@wakoopa.com
issued  on    : 2013-12-19 11:24:00
expires on    : 2023-12-17 11:24:00
signed using  : RSA+SHA1
RSA key size  : 1024 bits

2013-12-19 15:01:33 SSL Handshake: TLSv1.0/TLS-DHE-RSA-WITH-AES-256-CBC-SHA
2013-12-19 15:01:33 Session is ACTIVE
2013-12-19 15:01:34 EVENT: GET_CONFIG
2013-12-19 15:01:34 Sending PUSH_REQUEST to server...
2013-12-19 15:01:34 OPTIONS:
0 [redirect-gateway] [def1] 
1 [route] [10.8.0.1] 
2 [topology] [net30] 
3 [ping] [10] 
4 [ping-restart] [120] 
5 [ifconfig] [10.8.0.6] [10.8.0.5] 

2013-12-19 15:01:34 LZO-ASYM init swap=0 asym=0
2013-12-19 15:01:34 EVENT: ASSIGN_IP
2013-12-19 15:01:34 Connected via tun
2013-12-19 15:01:34 EVENT: CONNECTED @54.220.174.166:1194 (54.220.174.166) via /UDPv4 on tun/10.8.0.6/
2013-12-19 15:01:50 OS Event: NET UNAVAILABLE (PAUSE): Reachability<reachable=1 connectionRequired=0 isWWAN=0>
2013-12-19 15:01:50 UDP send error: send: Can't assign requested address
2013-12-19 15:01:50 EVENT: PAUSE

Client config:

client
dev tun
proto udp

remote 54.220.174.166 1194

resolv-retry infinite

nobind

# Try to preserve some state across restarts.
persist-key
persist-tun

# ca ca.crt
# cert client.crt
# key client.key

comp-lzo

verb 3

Server config:

port 1194
proto udp
dev tun
ca ca.crt
cert vpn.wakoopa.com.crt
key vpn.wakoopa.com.key  # This file should be kept secret
dh dh1024.pem
server 10.8.0.0 255.255.255.0
ifconfig-pool-persist ipp.txt
keepalive 10 120
comp-lzo
persist-key
persist-tun
status openvpn-status.log
push "redirect-gateway def1"
float
duplicate-cn
verb 3

Change History (8)

comment:1 Changed 6 years ago by krzee king

Type: Bug / DefectFeature Wish

hey eugene,
it seems that even in the open source version of openvpn (as opposed to connect for IOS) this would not work outside of using p2p mode. For that reason I changed this from "bug" to "feature request"

[13:19] <plaisthos> krzee: even float would not help
[13:19] <plaisthos> since float is ignored in non p2p mode
[13:19] <plaisthos> see also the hmac patches for that

comment:2 Changed 6 years ago by eugene

I do not understand your reasoning. Why does 4G -> WiFI change works fine then? Shouldn't it also be "unsupported" in the server mode?

For me it really seems that iOS decides to "pause" in that case, instead of reconnecting.

comment:3 Changed 6 years ago by Samuli Seppänen

Owner: set to jamesyonan
Status: newassigned
Type: Feature WishBug / Defect
Version: 2.3.2

I believe this is a known problem (=bug). Assigning to jamesyonan, who knows the details and can potentially fix this.

comment:4 Changed 6 years ago by Samuli Seppänen

Keywords: ios added

comment:5 Changed 5 years ago by Samuli Seppänen

Can you reproduce this issue with the latest iOS and OpenVPN Connect release?

comment:6 Changed 5 years ago by eugene

Nope.

It was fixed by the release that mentioned that in the changelog. I assumed that ticket would be closed by now.

Cheers

comment:7 Changed 4 years ago by Samuli Seppänen

Resolution: fixed
Status: assignedclosed

comment:8 Changed 18 months ago by OriolOMM

Hi

We are developing a VPN application on iOS. We are developing it on C. We are having the same or similar issue as you. When we change from 3g to wifi we can see this wifid error on the logs. Also, we ar eusing C, so we use sendto() to send packets. sendto() returns ENOMEM error.

How did you solve it?

Thanks!!

Note: See TracTickets for help on using tickets.