System.Net.HttpClient - 调用 GetAsync 时出现无法解释的超时

Question

我们有一个由 IIS 8.5 托管的 ASP.NET 应用程序 (.NET 4.5.2)。它调用托管在同一台机器上的多个 Web 服务。我们使用 HttpClient 来调用 Web 服务，并使用服务器的 FQDN 来寻址 Web 服务。在任何给定时间，可能有多个用户连接到服务器。

我们在应用程序中看到了一些莫名其妙的超时，并试图了解如何解决它。我们已在 System.Net 跟踪中隔离了该问题，但我不知道如何将其映射到应用程序中可能发生的情况。

我们总是看到大致如下所示的痕迹：

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

在每次发生此超时的情况下，我们都会看到以下调用顺序： DNS::TryInternalResolve 然后到： 套接字#########::InternalBind([::]:0#-1630021378)

在成功的连接中，我们看到： ::内部绑定（0.0.0.0:0#0） 无需调用解析 DNS

奇怪的是应用程序从来没有看到任何错误。对 HttpClient 的调用似乎需要很长时间。

有人知道这里发生了什么，或者是否有更多调试信息我可以打开以了解更多信息？

Answer 1

一些想法 -

• 检查主机上的 IPv6 是否被禁用。听起来最初的 DNS 查找（可能在缓存记录 TTL 过期时发生）有时是通过 IPv6 尝试的，它可能有一个与之关联的虚假 DNS 服务器（检查您的 IP 配置并测试 ping {fqdn} -6 是否真的有效.. ...或者如上所述只是禁用它）

• DNS 在这里可能是一个红鲱鱼，真正的问题是您达到了最大连接限制。有很多地方可能会发生这种情况，但有两件容易检查 - 首先确保您没有为每次调用重新创建/处理 HttpClient ....它应该是静态的。其次，如果您每秒建立的 tcp 连接数超过 100 个，请考虑增加 ServicePointManager 最大连接数限制