Consider using Happy Eyeballs or similar in SocketsHttpHandler

[JustArchi]

Repro: HttpClientBug.zip

using System;
using System.Net.Http;
using System.Threading.Tasks;

internal static class Program
{
    private static async Task Main()
    {
        AppDomain.CurrentDomain.UnhandledException += OnUnhandledException;
        TaskScheduler.UnobservedTaskException += OnUnobservedTaskException;
        using (var httpClient = new HttpClient())
        {
            try
            {
                await httpClient.GetAsync("https://translate.google.com").ConfigureAwait(false);
                Console.WriteLine("OK");
            }
            catch (Exception e)
            {
                Console.WriteLine(e);
            }
        }
    }

    private static void OnUnobservedTaskException(object sender, UnobservedTaskExceptionEventArgs e)
    {
        Console.WriteLine(e.Exception);
    }

    private static void OnUnhandledException(object sender, UnhandledExceptionEventArgs e)
    {
        Console.WriteLine(e.ExceptionObject);
    }
}

I reproduced this one on Linux and I didn't have much luck on Windows.

Run repro with dotnet run. After a default timeout of around 60 seconds, you'll get:

$ dotnet run
System.OperationCanceledException: The operation was canceled.
   at System.Net.Http.HttpClient.HandleFinishSendAsyncError(Exception e, CancellationTokenSource cts)
   at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
   at HttpClientBug.Program.Main() in /tmp/httpclientbug/Program.cs:line 17

Doing the same by forcing older curl handler:

$ DOTNET_SYSTEM_NET_HTTP_USESOCKETSHTTPHANDLER=0 dotnet run
OK

Please note that this issue is specific and not reproducible with just any https server, as majority of them work just fine. I encountered this issue when accessing https://translate.google.com, which is what I used in my repro above.

I reproduced this bug on latest master as well as .NET Core 2.1 rc1.

This bug could be some sort of regression because previously my app running master SDK worked just fine with this URL, including SocketHttpHandler that I used for a longer while. It could also be regression caused by Google's servers configuration change that triggered bug existing in the code since quite some time, which is more likely. Of course this one is not reproducible on .NET Core 2.0, since there is no SocketHttpHandler there.

Thank you in advance for looking into this.

.NET Core SDK (reflecting any global.json):
 Version:   2.2.100-preview1-008636
 Commit:    6c9942bae6

Runtime Environment:
 OS Name:     debian
 OS Version:
 OS Platform: Linux
 RID:         debian-x64
 Base Path:   /opt/dotnet/sdk/2.2.100-preview1-008636/

Host (useful for support):
  Version: 2.1.0-preview3-26411-06
  Commit:  8faa8fcfcf

.NET Core SDKs installed:
  2.2.100-preview1-008636 [/opt/dotnet/sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.1.0-preview2-30475 [/opt/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.0-preview2-30475 [/opt/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.0-preview3-26411-06 [/opt/dotnet/shared/Microsoft.NETCore.App]

[EDIT] Inline C# source code by @karelz

[davidsh]

cc: @stephentoub

[karelz]

Thanks @JustArchi for your report!
Can you please clarify repro status on Windows? Did it repro or not? Or did you not try at all? (that's ok, just clarifying your comment above)

[karelz]

@wfurt can you please take a look?
cc @geoffkizer

[JustArchi]

@karelz I checked .NET Core 2.1 rc1 on Windows and couldn't reproduce the issue, got OK from my repro.

[wfurt]

I did quick try on Ubuntu 16.04 and I also get OK. What base OS do you use @JustArchi ?

[JustArchi]

It's Debian Testing (currently 10/Butcher) with all available updates, kernel 4.16.0-1-amd64 (Debian 4.16.5-1).

I also thought the OS could have something to do with it, but then curl handler wouldn't work either, so it's possible that it's some OS-layer incompatibility.

[JustArchi]

It's also good to note that I couldn't reproduce it with other https servers, only Google's one gave me issues, so it's not entirely broken either. I'm sure that my SSL certs are OK, otherwise curl wouldn't work either.

I checked my other dev machine running on Debian sid and I also couldn't reproduce my issue there either, I'll set up other one on testing in the meantime to ensure it's not on Debian's end, but then again, if it was some IP-related block or likewise, curl shouldn't work either.

[JustArchi]

I tested another machine on Debian Testing and couldn't reproduce the issue either, so it has to be something with one of my machines. I wonder how I can help narrow down this issue and what is the root cause of it in the first place. Do you have any idea what I could provide do to help?

In the meantime I'll keep looking, maybe I find some factor that could possibly be causing this on OS side.

[wfurt]

You can always try packet capture. You can also check if the name resolves to same IP address.
Also is the hardware on both machines similar? number of cores would for example impact size of thread pool.

[karelz]

@JustArchi so it seems it is one machine problem (with a specific URL) on Debian development branch. Is that correct?
If that's the case, I think the best thing is to debug it through all layers and identify which one behaves incorrectly.

[JustArchi]

Yes, one machine for now, and I found out the first clue.

My dev machines that I tried to reproduce this issue on (and had no luck) don't have IPv6, they used IPv4 address of the translate.google.com and that worked. On the machine with the bug reproduced, I forced usage of IPv4 by manually hardcoding 216.58.215.46 translate.google.com to /etc/hosts, and that one did the trick, I couldn't run into the bug anymore. So this issue is IPv6 related, now the question is whether this is still my machine-specific IPv6 related issue, or something more global.

Since I don't have more IPv6 machines around, could you try to reproduce this bug for me on IPv6-enabled Linux machine? I don't believe Debian has anything to do with it, so it could be any Linux machine.

I wonder if curl handler also uses IPv6 by default, this could be the reason why I see behaviour change between those two, gonna keep digging and let you know if I found out something more. It could also be some IPv6-related bug in socket handler, although in this case I'm pretty sure somebody else would find it out much sooner than me, maybe it's some specific combination, I'll try to find out.

[wfurt]

can you do packet capture and trace the attempt? I'm wondering if IPv6 is really used or if it falls back to IPv4 after some time.

[JustArchi]

I did the test and I indeed confirmed my initial thought, this is not a bug in socket http handler itself, but rather different behaviour compared to curl handler. Could be also called a regression if we're comparing default behaviour between .NET Core 2.0 and 2.1.

In general, my machine can't access translate.google.com through IPv6, why exactly - I'm going to find out myself, this is not important for now.

What is important is the fact that it seems that curl handler tries to fallback to IPv4 when IPv6 fails, this is why curl handler works.

If I force curl to use IPv6 exclusively, this also fails:

$ curl -I -m 5 -6 "https://translate.google.com"
curl: (28) Connection timed out after 5001 milliseconds

While -4 works:

$ curl -I -m 5 -4 "https://translate.google.com"
HTTP/2 403

(We're getting 403 but it's irrelevant, the connection being established matters)

So what is curl doing by default? Let's find out:

$ curl -v -I -m 5 "https://translate.google.com"
* Rebuilt URL to: https://translate.google.com/
*   Trying 2a00:1450:400c:c0a::8a...
* TCP_NODELAY set
*   Trying 216.58.215.46...
* TCP_NODELAY set
* Connected to translate.google.com (216.58.215.46) port 443 (#0)

Like you can see, it tries IPv6 first, fails, then tries IPv4 next. SocketHttpHandler doesn't do that, once it gets IPv6 from DNS resolve, it'll try to connect through that IP address only, even if it doesn't work while IPv4 address does.

Question is, if this is intended behaviour (then we can close the issue), or if perhaps we could do something to improve it (e.g. make it work like curl handler), since I strongly believe that it'd greatly benefit HttpClient if it did exactly the same what curl does - attempt to try the next (different) IP address for the same domain, if possible.

I'm pretty sure that you can reproduce this reliably with any IPv6-enabled machine requesting any domain with AAAA and A DNS entries where IPv6 address simply times out, while IPv4 works just fine. It happened to be google server in my case, why exactly - probably a coincidence, temporary issue, or some machine-specific problem I'm going to find out myself, since it's not important for this issue.