search

eduvpn / apple

app for iOS and macOS
Other
58 stars 18 forks source link

iOS client hang in "configuring" state #470

Closed efef closed 1 year ago

efef commented 2 years ago

Am using iOS Let's Connect VPN version 3.0.1 from App Store.

When connected with vpn-next.tuxed.net I connected a few times with the first profile available. At a certain moment the client was stuck while "configuring" see:

IMG_0E975345B353-1

Maybe the "new" server feature "forced relogin after active user disconnect" which has been turned-on might trigger this issue. Reference: https://todo.sr.ht/~eduvpn/server/78

last lines in client log are: 022-07-07 12:33:01.941 INFO OpenVPNSession.setupEncryption():1125 - Negotiated keep-alive timeout: 1m 2022-07-07 12:33:01.943 INFO OpenVPNTunnelProvider.sessionDidStart():527 - Session did start 2022-07-07 12:33:01.943 INFO OpenVPNTunnelProvider.sessionDidStart():529 - Returned ifconfig parameters: 2022-07-07 12:33:01.943 INFO OpenVPNTunnelProvider.sessionDidStart():530 - Remote: 145.220.52.206 2022-07-07 12:33:01.943 INFO OpenVPNTunnelProvider.sessionDidStart():531 - IPv4: addr 10.222.172.3 netmask 255.255.255.128 gw 10.222.172.1 routes ["{0.0.0.0/0.0.0.0 10.222.172.1}"] excluding [] 2022-07-07 12:33:01.944 INFO OpenVPNTunnelProvider.sessionDidStart():532 - IPv6: addr fde6:76bd:ad97:ac5e::3/112 gw fde6:76bd:ad97:ac5e::1 routes [] excluding [] 2022-07-07 12:33:01.944 INFO OpenVPNTunnelProvider.sessionDidStart():534 - Gateway: ["IPv6", "IPv4"] 2022-07-07 12:33:01.944 INFO OpenVPNTunnelProvider.sessionDidStart():539 - DNS: ["9.9.9.9", "2620:fe::fe"] 2022-07-07 12:33:01.944 INFO OpenVPNTunnelProvider.sessionDidStart():546 - Search domains: not configured 2022-07-07 12:33:01.944 INFO OpenVPNTunnelProvider.bringNetworkUp():625 - Routing.IPv4: Setting default gateway to 10.222.172.1 2022-07-07 12:33:01.945 INFO OpenVPNTunnelProvider.bringNetworkUp():632 - Routing.IPv4: Adding route 0.0.0.0/0.0.0.0 -> 10.222.172.1 2022-07-07 12:33:01.945 INFO OpenVPNTunnelProvider.bringNetworkUp():662 - Routing.IPv6: Setting default gateway to fde6:76bd:ad97:ac5e::1 2022-07-07 12:33:01.945 INFO OpenVPNTunnelProvider.bringNetworkUp():741 - DNS: Using servers ["9.9.9.9", "2620:fe::fe"] 2022-07-07 12:33:01.947 DEBUG OpenVPNSession.sendAck():1271 - Ack successfully written to LINK for packetId 5 2022-07-07 12:33:02.268 DEBUG OpenVPNTunnelProvider.reasserting():146 - Reasserting flag cleared 2022-07-07 12:33:02.268 INFO OpenVPNTunnelProvider.sessionDidStart():578 - Tunnel interface is now UP 2022-07-07 12:33:12.872 DEBUG OpenVPNSession.ping():558 - Send ping 2022-07-07 12:33:23.273 DEBUG OpenVPNSession.ping():558 - Send ping 2022-07-07 12:33:23.659 INFO OpenVPNTunnelProvider.stopTunnel():264 - Stopping tunnel... 2022-07-07 12:33:23.660 DEBUG OpenVPNSession.shutdown():299 - Initiating shutdown 2022-07-07 12:33:23.662 DEBUG OpenVPNSession.deferStop():1283 - Stop method: shutdown; Error: None 2022-07-07 12:33:23.663 DEBUG OpenVPNSession.deferStop():1307 - Attempting to write packets for exit notification 2022-07-07 12:33:23.664 DEBUG OpenVPNSession.deferStop():1309 - Done writing packets for exit notification (Error: None) 2022-07-07 12:33:23.664 INFO OpenVPNSession.doShutdown():1328 - Trigger shutdown on request 2022-07-07 12:33:23.664 INFO OpenVPNTunnelProvider.sessionDidStop():594 - Session did stop 2022-07-07 12:33:23.667 ERROR OpenVPNSession.loopLink():402 - Failed LINK read: Error Domain=NSPOSIXErrorDomain Code=89 "Operation canceled" 2022-07-07 12:33:23.668 DEBUG NEUDPSocket.observeValueInTunnelQueue():137 - Socket state is cancelled (endpoint: 145.220.52.206:1194 -> 145.220.52.206:1194) 2022-07-07 12:33:23.668 INFO OpenVPNSession.cleanup():314 - Cleaning up... 2022-07-07 12:33:23.669 INFO OpenVPNTunnelProvider.finishTunnelDisconnection():372 - Tunnel did stop on request 2022-07-07 12:33:23.669 DEBUG OpenVPNTunnelProvider.flushLog():886 - Flushing log...App: 2022-07-07 12:33:24.358 Continuing connection flow for server 'https://vpn-next.tuxed.net/' for profile id 'prefer-openvpn' 2022-07-07 12:33:24.361 App version: 3.0.1 (1713) 2022-07-07 12:33:24.361 Getting server info for server 'https://vpn-next.tuxed.net/' 2022-07-07 12:33:24.422 Getting tunnel config from API base URL 'https://vpn-next.tuxed.net/vpn-user-portal/api/v3' using APIv3

roop commented 2 years ago

Per your comment, the last line in the log is:

2022-07-07 12:33:24.422 Getting tunnel config from API base URL 'https://vpn-next.tuxed.net/vpn-user-portal/api/v3' using APIv3

Normally, it's followed by a line that says something like:

[date] [time] Got OpenVPN tunnel config expiring at [date][time]

If that line is missing, it might indicate that the server didn't respond to the request. Is that possible? (But even in that case, it should've ideally shown a "timed out" error.)

efef commented 2 years ago

the APIv3 line was the last log line in the app. So far I can't re-enact the issue again, it happened once. There was no server maintenance when it happened, so that can't explain it.