0

We have an ASP.NET application (.NET 4.5.2) that's hosted by IIS 8.5. It makes calls into several web services that are hosted on the same machine. We use HttpClient to make the calls to the web services and we use the FQDN of the server to address the web services. There may be several users connected to the server at any given time.

We're seeing somewhat inexplicable timeouts in the application and trying to understand how we can fix it. We've isolated the issue in the System.Net trace but I don't know how to map this to what might be happening in the app.

We always see a trace that looks roughly like this:

System.Net Verbose: 0 : [7040] ServicePoint#54409111::ServicePoint([fqdn]:443)
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net Information: 0 : [7040] Associating HttpWebRequest#63284140 with ServicePoint#54409111
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net Information: 0 : [7040] Associating Connection#66464819 with HttpWebRequest#63284140
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Socket#15069449::Socket(AddressFamily#2)
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Exiting Socket#15069449::Socket() 
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Socket#36384690::Socket(AddressFamily#23)
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Exiting Socket#36384690::Socket() 
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] DNS::TryInternalResolve([fqdn])
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Socket#36384690::BeginConnectEx()
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Socket#36384690::InternalBind([::]:0#-1630021378)
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Exiting Socket#36384690::InternalBind() 
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [7040] Exiting Socket#36384690::BeginConnectEx()    -> ConnectOverlappedAsyncResult#20281278
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net Verbose: 0 : [7040] Exiting HttpWebRequest#63284140::BeginGetResponse()  -> ContextAwareResult#61049080
    DateTime=2018-07-31T14:19:39.8579341Z
System.Net.Sockets Verbose: 0 : [1988] Socket#36384690::EndConnect(ConnectOverlappedAsyncResult#20281278)
    DateTime=2018-07-31T14:20:00.8591809Z
System.Net.Sockets Error: 0 : [1988] Socket#36384690::UpdateStatusAfterSocketError() - TimedOut
    DateTime=2018-07-31T14:20:00.8591809Z
System.Net.Sockets Error: 0 : [1988] Exception in Socket#36384690::EndConnect - A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond [fe80::10f8:605a:8a44:5f1e%12]:443.
    DateTime=2018-07-31T14:20:00.8591809Z

In every case where we have this timeout occur we see this call sequence: DNS::TryInternalResolve and then to: Socket#########::InternalBind([::]:0#-1630021378)

In a successful connection we see: ::InternalBind(0.0.0.0:0#0) with no call to resolve the DNS

The weird thing is that the application never sees any errors. The call to HttpClient just seems to take a long time.

Anyone know what's happening here or if there's more debugging information I can turn on to learn more?

1 Answer 1

1

A couple of thoughts -

  • check IPv6 is disabled on the host machine. It sounds like initial DNS lookups (perhaps occurring when a cached record TTL expires) are sometimes attempted via IPv6 which may have a bogus DNS server associated with it (check your IP config and also test that ping {fqdn} -6 actually works.....or as said above just disable it)

  • DNS might be a red herring here and the real problem is that you’re hitting a maximum connections limit. There are many places that this could be occurring but two easy things to check - First make sure you’re not recreating/disposing your HttpClient for each call....it should be static. Second, if you have more than 100 tcp connections being made per second consider increasing the ServicePointManager max connections limit

Sign up to request clarification or add additional context in comments.

3 Comments

I think the IPv6 suggestion is interesting. Ping -6 appears to work on the machine but the format of the response looks similar to the error. I turned it off for now and will see if the issue repros tomorrow. Is there a way to perform a dns lookup in my code that simulates the one in HttpCLient to see if there's an error there?
It should be using the managed DNS api in .NET: learn.microsoft.com/en-us/dotnet/api/…
When i disabled IPv6 this issue went away. I'm going to need to sort out why the IPv6 DNS resolution was busted but that issue has been identified.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.