Intermittent WinHttpException on Azure

[Roblinde]

I have had an issue running ASP.NET Core 2.0 app in Azure and have had a conversation with the Azure support team. They have, after some investigation, suggested I open the issue here for further help.

The scenario is as follows. I have a completely standard, out of the box, ASP.NET Core app that I published to Azure. The only modification I've made to this application is I've added a singleton HttpClient to the service container like this: services.TryAddSingleton<HttpClient>();

I've also modified the About.cshtml.cs file with the following additions:

private readonly HttpClient _client;

public AboutModel(HttpClient client)
{
    _client = client;
}

public string Message { get; set; }

public async Task OnGet()
{
    Message = "Your application description page.";
    var responses = new List<HttpResponseMessage>();

    responses.Add(await _client.GetAsync("https://cdn.contentful.com/spaces/qz0n5cdakyl9/entries/?access_token=secretTokenHere"));
    responses.Add(await _client.GetAsync("https://cdn.contentful.com/spaces/qz0n5cdakyl9/entries/?access_token=secretTokenHere&content_type=layout"));
    responses.Add(await _client.GetAsync("https://cdn.contentful.com/spaces/qz0n5cdakyl9/entries/?access_token=secretTokenHere&content_type=lessonCopy"));

    if(responses.Any(c => c.IsSuccessStatusCode == false))
    {
        throw new Exception("Got a !200 code");
    }
}

Basically the about page now makes 3 outgoing http requests. When I run this application under some simulated load (around 3000 req/min) every now and then one of the httprequests fail with an HttpException.

An error occurred while sending the request.The connection with the server was terminated abnormally

System.Net.Http.HttpRequestException:
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
Inner exception System.Net.Http.WinHttpException handled at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw:
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
at System.Threading.Tasks.RendezvousAwaitable`1.GetResult (System.Net.Http, Version=4.2.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a)
at System.Net.Http.WinHttpHandler+d__105.MoveNext (System.Net.Http, Version=4.2.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a)

I've cut out part of the outer exception stack trace as I doubt it's relevant, but let me know if you want to see it.

I've skimmed through the source code and from the looks of it the problem arises from somewhere around here https://github.com/dotnet/corefx/blob/master/src/System.Net.Http.WinHttpHandler/src/System/Net/Http/WinHttpHandler.cs#L791
or here:
https://github.com/dotnet/corefx/blob/master/src/System.Net.Http.WinHttpHandler/src/System/Net/Http/WinHttpHandler.cs#L824

I should also add that this happens very infrequently (while I was screen sharing with Azure support I ran 6000 requests over about 5 minutes and this happened 4 times) and immediately retrying the exact same requests works fine.

Grateful if someone could try to shed some light on this.

Many thanks!

[EDIT] Add C# syntax highlighting by @karelz

[Roblinde]

@karelz adding the labels I take it this has been recognized as a framework bug? Could you shed any light on the cause? Would be interesting.

Thanks!

[davidsh]

@karelz adding the labels I take it this has been recognized as a framework bug? Could you shed any light on the cause? Would be interesting.

It has not been identified as a bug yet. The labels were added simply to guide the bug to the right team.

This particular exception is "normal", in that it indicates that the remote endpoint terminated the connection. It is not clear this is a bug in the .NET Core HTTP stack layer. It needs investigation and really needs a good Wireshark trace to help evaluate what is happening on the wire.

[Roblinde]

Thanks @davidsh!

I haven't been able to replicate it locally so I haven't been able to monitor the actual traffic since it's happening on the remote server. Is there any steps I can take to enable such remote monitoring?

[karelz]

Agreed with what @davidsh said.
My best guess was that this is a bug and we should treat it as such until proven otherwise, or someone with deeper expertise overrides my guess by experienced judgement :).

@Roblinde do you have dedicated VM in Azure you can collect additional logs from? If not, try to ask the support folks how to collect additional logs in the Azure service you're using.

[Roblinde]

Afraid not, just a regular app service :/ I could setup a VM I guess, see if I can reproduce there.

I've spoken to Azure support, but they couldn't discern anything unusual, which is why I was ferried over here I guess 😄

I'll experiment some more and get back to you with any further findings.

[karelz]

Might be good to compare VM in Azure vs. app service. If you can reproduce on VM, you can collect logs. If you can't, you should push on their support to explain the difference / help to track it down :)

[Roblinde]

I have now deployed the exact same app to an Azure VM and have run the exact same tests against it. Not a single failure.

I even ramped up the test to run 10k requests in a Parallel.For loop instead of 3k, still nothing.

I think it's safe to assume that this is an Azure Web App issue.

What I'd like to ask, though, is when would this error occurr? @davidsh mentioned that this issue is "normal" and is indicative of the remote endpoint terminating the connection. When and how would such a termination happen?

What I'm getting at is that since this isn't (so far) reproduceable in any other environment but Azure App Service I'm suspecting that it is some part of the Azure infrastructure that terminates the connection. But what could possibly be the reason for such a termination?

Grateful for any help.

[karelz]

BTW: @davidsh is out for the rest of the year.
The termination is happening outside of your process - it can be the remote server (unlikely as you would see it repro also on your VM), or the server executing your code, or anything in the middle.

It would be best to ask Azure App Service support to help explain the differences in their environment vs. VMs. Feel free to loop me in on the case (see email in my GH profile).

[Roblinde]

Great @karelz thank you. The remote server is very unlikely as I work at Contentful and have checked our internal logs many times (also it would most likely affect many of our clients).

I will CC you on the Azure ticket and we'll see what gives.

Closing this and my apologies for disturbing David on his holidays.

Merry Christmas!

[karelz]

No need to apologize. It is in everyone's best interest to make sure Azure works great with .NET Core. We just need the right people helping to root cause the issue :)
If you don't get any response, please ping me with your case ID details, I can contact the dev team internally.

[karelz]

@Roblinde if you can look at the server traffic & logs, can you check if the failing requests even gets to the server and what happens if it does? (e.g. Wireshark traces from server)
It may be easier to set up a test server to check that ...

[karelz]

Another interesting data point might be to run the same client code from another language/runtime - Java/Node.js/PHP/anything else. I wonder if it hits the same problem (that would point to Azure App Service infra, not .NET Core runtime).

[suwatch]

@Roblinde We could take a look at the client (Azure WebApps side). We need a site name and UTC time of the incident. We can check if there was some limit or throttle that we impose within the Azure WebApps.

Better yet, if you could have a simpler repro (such as an exe that we can try ourselves) - it would speed things up.

[Roblinde]

@suwatch @karelz Thanks! I will email you both the details and the repro I have right now and CC you in on the Azure support thread.