vpnhood / VpnHood

Undetectable Fast Portable VPN
GNU Lesser General Public License v2.1
933 stars 144 forks source link

Not enough wait time before NetworkCheck results in VPN disruption #546

Closed SSgumS closed 3 months ago

SSgumS commented 3 months ago

Hello

When connecting to a VPN sever, the client waits for 2 seconds. Then, by assuming that the connection is established, it starts checking the VPN connection. I have seen in a lot of cases where the connection has not been fully established in the 2 seconds time frame and obviously in this situation the NetworkCheck is checked using the homeland internet, not the VPN. So, it fails because one of the URLs is blocked in the homeland internet (for example in Iran, www.quad9.net is blocked). If there exists any method to detect the establishment of the VPN connection (instead of the 2 seconds delay), NetworkCheck should be checked after the detection was successful. And if there isn't any method for this, maybe the removal of this check would be better. Or maybe just removing www.quad9.net is sufficient, because blockage of www.google.com and www.microsoft.com is uncommon but www.quad9.net is more possible like what has happened is Iran.

The section of the code I referred is here.

Here is the log that shows the situation I described:

Info
| 01:45:59.4587 | | VpnHood Client is Connecting ...
Info
| 01:45:59.4925 | | AppVersion: 4.3.485.0
Info
| 01:45:59.4926 | | Time: 2024-05-17 21:45:59Z
Info
| 01:45:59.4927 | | OS: Xiaomi: 2201116SG, Android: 14
Info
| 01:45:59.4927 | | UserAgent: X
Info
| 01:46:02.0400 | | Country: Iran
Info
| 01:46:02.0401 | | TokenId: X, SupportId: 0
Info
| 01:46:02.0653 | | UserSettings: { "Logging": { "LogToConsole": false, "LogToFile": false, "LogVerbose": false, "LogAnonymous": true }, "CultureCode": null, "DefaultClientProfileId": "X", "MaxReconnectCount": 2147483647, "MaxDatagramChannelCount": 4, "TunnelClientCountry": false, "IpGroupFilters": null, "IpGroupFiltersMode": "All", "CustomIpRanges": null, "AppFilters": [ "ir.balad", "ir.nasim", "digital.neobank", "com.farsitel.bazaar", "com.samanpr.blu", "world.arteh.cheetah", "com.digikala", "com.fardabank.farda", "com.fidibo.app", "com.android.stk", "com.myirancell", "ir.mci.ecareapp", "ir.mservices.market", "org.rajman.neshan.traffic.tehran.navigator", "ir.torob", "com.mobiliha.badesaba", "ir.bmi.bam.nativeweb", "com.picsoft.picodic", "gov.shahrzad", "ir.mservices.mybook", "taxi.tap30.passenger", "cab.snapp.passenger" ], "AppFiltersMode": "Exclude", "UseUdpChannel": false, "DropUdpPackets": false, "ExcludeLocalNetwork": true, "PacketCaptureIncludeIpRanges": [ "0.0.0.0-255.255.255.255", "::-ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff" ], "PacketCaptureExcludeIpRanges": [], "AllowAnonymousTracker": true, "DnsServers": null }
Trac
| 01:46:02.0831 | | Checking the Internet connection...
Info
| 01:46:02.0884 | | PingTest: Started, RemoteAddress: 8.8.8.8, Timeout: 10000...
Info
| 01:46:02.0905 | | PingTest: Started, RemoteAddress: 1.1.1.1, Timeout: 10000...
Info
| 01:46:02.0928 | | UdpTest: Started, DnsName: www.google.com, NsServer: 8.8.8.8:53, Timeout: 10000...
Info
| 01:46:02.0935 | | UdpTest: Started, DnsName: www.google.com, NsServer: 1.1.1.1:53, Timeout: 10000...
Info
| 01:46:02.0939 | | HttpTest: Started, Url: https://www.google.com/, Timeout: 10000...
Info
| 01:46:02.0948 | | HttpTest: Started, Url: https://www.quad9.net/, Timeout: 10000...
Info
| 01:46:02.0954 | | HttpTest: Started, Url: https://www.microsoft.com/, Timeout: 10000...
Info
| 01:46:02.1115 | | UdpTest: Succeeded, DnsName: www.google.com, NsServer: 8.8.8.8:53.
Info
| 01:46:02.1117 | | UdpTest: Succeeded, DnsName: www.google.com, NsServer: 1.1.1.1:53.
Info
| 01:46:02.1363 | | PingTest: Succeeded, RemoteAddress: 8.8.8.8.
Info
| 01:46:02.1900 | | PingTest: Succeeded, RemoteAddress: 1.1.1.1.
Info
| 01:46:02.2827 | | HttpTest: Succeeded, Url: https://www.microsoft.com/.
Trac
| 01:46:02.2853 | | Checking the VpnServer ping...
Info
| 01:46:02.2856 | | PingTest: Started, RemoteAddress: X, Timeout: 10000...
Info
| 01:46:02.3022 | | PingTest: Succeeded, RemoteAddress: X.
Trac
| 01:46:02.3023 | | Pinging server is OK. Info =>
Client
| 01:46:02.3073 | | UseUdpChannel: False, DropUdpPackets: False, ExcludeLocalNetwork: True, MinWorkerThreads: 8, CompletionPortThreads: 1 Info =>
Client
| 01:46:02.3074 | | ClientVersion: 4.3.485.0, ClientProtocolVersion: 4, ClientId: X Info =>
Client
| 01:46:02.3075 | | Client state is changed. NewState: Connecting Trac =>
Client
| 01:46:02.3087 | Session | Sending a request. RequestCode: Hello, RequestId: X:client Trac =>
Client
| 01:46:02.3148 | Tcp | Connecting to Server... EndPoint: X:443 Trac =>
Client
| 01:46:02.3228 | Tcp | TLS Authenticating... HostName: X
Info
| 01:46:02.6042 | | HttpTest: Succeeded, Url: https://www.google.com/.
Warn
| 01:46:05.8346 | | HttpTest: Failed!, Url: https://www.quad9.net/. Message: net_http_request_timedout, 10
Erro
| 01:46:07.7849 | Session | Disposing...
Exception: VpnHood.Client.Exceptions.ConnectorEstablishException: net_io_eof ---> System.IO.IOException: net_io_eof at System.Net.Security.SslStream.<ReceiveHandshakeFrameAsync>d1511[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=X]].MoveNext() at System.Net.Security.SslStream.<ForceAuthenticationAsync>d1501[[System.Net.Security.AsyncReadWriteAdapter, System.Net.Security, Version=8.0.0.0, Culture=neutral, PublicKeyToken=X]].MoveNext() at VpnHood.Client.ConnectorServices.ConnectorServiceBase.GetTlsConnectionToServer(String streamId, CancellationToken cancellationToken) Exception_EndOfInnerExceptionStack at VpnHood.Client.ConnectorServices.ConnectorServiceBase.GetTlsConnectionToServer(String streamId, CancellationToken cancellationToken) at VpnHood.Client.ConnectorServices.ConnectorService.<SendRequest>d21[[VpnHood.Tunneling.Messaging.HelloResponse, VpnHood.Tunneling, Version=4.3.485.0, Culture=neutral, PublicKeyToken=null]].MoveNext() at VpnHood.Client.ConnectorServices.ConnectorService.<SendRequest>d11[[VpnHood.Tunneling.Messaging.HelloResponse, VpnHood.Tunneling, Version=4.3.485.0, Culture=neutral, PublicKeyToken=null]].MoveNext() at VpnHood.Client.ConnectorServices.ConnectorService.<SendRequest>d11[[VpnHood.Tunneling.Messaging.HelloResponse, VpnHood.Tunneling, Version=4.3.485.0, Culture=neutral, PublicKeyToken=null]].MoveNext() at VpnHood.Client.VpnHoodClient.<SendRequest>d1371[[VpnHood.Tunneling.Messaging.HelloResponse, VpnHood.Tunneling, Version=4.3.485.0, Culture=neutral, PublicKeyToken=null]].MoveNext() at VpnHood.Client.VpnHoodClient.ConnectInternal(CancellationToken cancellationToken, Boolean redirecting) at VpnHood.Client.VpnHoodClient.Connect(CancellationToken cancellationToken)
Trac
| 01:46:07.7942 | | Shutting down...
Info
| 01:46:07.7943 | | Client state is changed. NewState: Disconnecting
Trac
| 01:46:07.7972 | | Disposing ClientHost...
Trac
| 01:46:07.7973 | | Disposing Tunnel...
Trac
| 01:46:07.7973 | | Disposing ProxyManager...
Trac
| 01:46:07.7974 | | Disposing Nat...
Trac
| 01:46:07.7974 | | Disposing ConnectorService...
Info
| 01:46:07.7974 | | Client state is changed. NewState: Disposed
Info
| 01:46:07.8015 | | Bye Bye!
Info
| 01:46:07.8018 | | Trying to get a new ServerToken from url. Url: X
Erro
| 01:46:07.8027 | | net_io_eof
Trac
| 01:46:07.8276 | | Closing VpnService...
Trac
| 01:46:07.8321 | | VpnService has been destroyed!

Thanks in advance

trudyhood commented 3 months ago

Hi, Thank you for trying to find issues in the VpnHood code. I understand that it may fail due to some of our check sites being blocked, but this happens only in diagnostic mode. VpnHood does not use that in a successful connection!

Anyway, perhaps we should choose better diagnostic check websites and increase the timeout.

SSgumS commented 3 months ago

Hi, Thank you for trying to find issues in the VpnHood code. I understand that it may fail due to some of our check sites being blocked, but this happens only in diagnostic mode. VpnHood does not use that in a successful connection!

Anyway, perhaps we should choose better diagnostic check websites and increase the timeout.

From when www.quad9.com blockage ran in Iran (I think it was a week ago if I'm not wrong), some of the users usually failed in the initial stages of the connection process (In a same environment but with different devices. I mean, a phone with same internet encounter net_io_eof error and another phone with the same internet connection succeed. This hints us that the problem may resides in something similar to the delay case we mentioned). In my own case, sometime I must try 2 or 3 times to successfully connect. Are you sure that this kind of check doesn't exist in normal connection process?

trudyhood commented 3 months ago

Yes. they send you that report because after they failed to initialize the connection, VpnHood tries to start diagnostic procedure to report their network status to developers. and of course usually you can see those sites does reply properly because their network is not good. I know those sites maybe already blacked in some networks, but VpnHood doesnt count on it, thats just for diagnostic report and it does not reflect on their connection.

SSgumS commented 3 months ago

OK. Thank you. However, still I can't grasp the reason for the disruption in normal connection procedure by the explanation you kindly provided to me.

By the way, here is a video showing the normal connection procedure occurring sometimes for me. In the first time, in a glimpse, diagnosing icon appears and net_io_eof error occurs. But the second time, it connects smoothly.

https://github.com/vpnhood/VpnHood/assets/25867589/7bfb93bb-fb16-42ad-b4d3-f90cb176bef4

trudyhood commented 3 months ago

Does it happen all the time after opening the app or randomly? Can you find the situation that this happened?

SSgumS commented 3 months ago

Recently most of the times it happens. I don't know what specific situation is required to reproduce it; it is totally random in my eye.