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 在这里可能是一个转移注意力的问题，真正的问题是您达到了最大连接数限制。有很多地方可能会发生这种情况，但有两点很容易检查 - 首先确保你不是 recreating/disposing 你的 HttpClient 每次调用......它应该是静态的。其次，如果每秒建立的 tcp 连接超过 100 个，请考虑增加 ServicePointManager 最大连接数限制

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

System.Net.HttpClient - Unexplained timeout when calling GetAsync

system.net

dotnet-httpclient