超时异常 - 请求排队？线程不够？

Question

背景:

我有一个服务,它聚合来自多个其他服务的数据.为了使事情及时发生,我在整个代码中使用异步,然后将各种请求收集到任务列表中.

以下是代码的一些摘录:

private async Task<List<Foo>> Baz(..., int timeout)
{
    var tasks = new List<Task<IEnumerable<Foo>>>();
    Tasks.Add(GetFoo1(..., timeout));
    Tasks.Add(GetFoo2(..., timeout));
    // Up to 6, depending on other parameters.  Some tasks return multiple objects.

    return await Task.WhenAll(tasks).ContinueWith((antecedent) => { return antecedent.Result.AsEnumerable().SelectMany(f => f).ToList(); }).ConfigureAwait(false);
}    
private async Task<IEnumerable<Foo>> GetFoo1(..., int timeout)
{
Stopwatch sw = new Stopwatch();
sw.Start();

    var value = await SomeAsyncronousService.GetAsync(..., timeout).ConfigureAwait(false);

sw.Stop();
// Record timing...
    return new[] { new Foo(..., value) };
}
private async Task<IEnumerable<Foo>> GetFoo2(..., int timeout)
{
return await Task.Run(() => {
    Stopwatch sw = new Stopwatch();
    sw.Start();
    var r = new[] { new Foo(..., SomeSyncronousService.Get(..., timeout)) };
    sw.Start();
    sw.Stop();
    // Record timing...
    return r;
}).ConfigureAwait(false);
}  

// In class SomeAsyncronousService
public async Task<string> GetAsync(..., int timeout)
{
...
    try
    {
        using (var httpClient = HttpClientFactory.Create())
        {
            // I have tried it with both timeout and CTS.  The behavior is the same.
            //httpClient.Timeout = TimeSpan.FromMilliseconds(timeout);
            var cts = new CancellationTokenSource();
            cts.CancelAfter(timeout);

            var content = ...;
            var responseMessage = await httpClient.PostAsync(Endpoint, content, cts.Token).ConfigureAwait(false);
            if (responseMessage.IsSuccessStatusCode)
            {
                var contentData = await responseMessage.Content.ReadAsStringAsync().ConfigureAwait(false);
                ...
                return ...
            }
            ...             
        }
    }
    catch (OperationCanceledException ex)
    {
        // Log statement ...
    }
    catch (Exception ex)
    {
        // Log statement ...
    }
    return ...;
}

症状:

此代码在我的本地计算机上运行良好,并且在大多数情况下它在我们的测试服务器上运行良好.但是,偶尔我们会得到一堆大量记录的超时 - 通过上面的"记录时间"注释和OperationCanceledExceptions上的Log语句记录.我无论如何都不知道我打电话的服务是否实际超时.

现在,当我说一系列超时时,我的意思是大多数或所有任务(以及除了一个使用的HttpClients,另一个使用WCF服务)都在大约同一时间超时.

现在,我知道你在想什么,我正在同一时间内通过.这是正确的,但我通过了250毫秒,各种秒表报告的运行时间大约为800毫秒或更高.

现在,我确实在日志中看到了OperationCanceledExceptions,但是异常的时间戳与秒表结束时(或在2-3毫秒内)的时间戳相同,并且我的服务失败,因为客户希望它响应500毫秒或更短,而不是800毫秒.

现在,通常各种服务在不到100毫秒内响应,结果之间存在很大差异.当我们出现问题,并且大多数/全部在800毫秒或更长时间内返回时,它们仅变化~10毫秒.我调用的依赖项都在不同的域上.似乎所有这些人都不太可能在同一时间做出这么长的回应.

我想可能存在网络问题,同时影响所有请求,但我们网络中的其他服务不会遇到相同的行为 - 它仅限于我正在编写的新服务.

即使是这种情况,我希望取消例外发生在250毫秒之后,然后结束任务,秒表记录250(加上5-20毫秒左右的异常处理).

所以我不认为这是一个网络问题.现在我确信至少部分问题与我没有正确取消/超时相关,但在我看来,来自服务的所有外出请求同时受到影响,与HttpClient无关.

我之所以这么说是因为当剩下的请求超时时,WCF服务也会显示800+ ms(根据秒表).WCF服务不是异步的.超时设置如下:

var binding = new BasicHttpBinding()
{
    Security = new BasicHttpSecurity()
    {
        Mode = BasicHttpSecurityMode.TransportCredentialOnly,
        Transport = new HttpTransportSecurity()
        {
            ClientCredentialType = HttpClientCredentialType.Ntlm
        }

    },
    ReceiveTimeout = TimeSpan.FromMilliseconds(timeout)
};

问题:

所以,简而言之,我认为某些事情导致所有传出的请求到任何域暂停或排队,导致观察到的行为.

我花了几天时间试图弄清楚发生了什么,但没有运气.有任何想法吗？

编辑

我认为正在发生的事情是请求被搁置,因为没有可用的线程,然后几百毫秒后线程可用并且任务开始.定时方法调用显示它花费800毫秒,但是在线程可用于运行异步调用之前,HttpClient上的超时不会启动.

它还解释了为什么我看到该方法需要800多毫秒,但有时它仍然完成而没有显示超时异常.其他时候它会抛出超时异常并且无法完成.

我已经尝试在Application_Start中将ServicePointManager.DefaultConnectionLimit设置为200,但这并没有解决问题.

与我们的其他服务相比,该服务没有占用太多流量,其他服务似乎没有相同的问题.

有任何想法吗？

编辑2

我在进行(次要)负载测试时登录到框并监视netstat.

使用HttpClient,每秒1-2个请求,端口将显示ESTABLISHED,然后移动到TIME_WAIT大约4分钟.每秒有3个以上的请求,我最终会得到大约每秒100 x请求的ESTABLISHED端口(每秒3次加载测试300个),然后我会开始看到它们转到CLOSE_WAIT而不是TIME_WAIT - 表示错误条件关闭.与此同时,我会看到执行请求的异常和时间数量激增.(TcpTimedWaitDelay不适用于CLOSE_WAIT).

所以我重写了整个事情,以串行方式使用HttpWebRequests,而不是并行使用HttpClient.然后我运行了相同的测试.

现在ESTABLISHED端口等于每秒0-2 x个请求,然后端口按预期移动到TIME_CLOSE.性能和吞吐量有所改善,但并未完全消除.

然后我将TcpTimedWaitDelay设置为30(默认为240).表现急剧增加.我有一个原始的负载测试,每秒有40个请求,没有任何问题.我将获得更全面的测试设置,但我认为问题已经解决.

我不知道发生了什么,但似乎HttpClient没有正确关闭下面的ephemoral端口.我公司的许多开发人员和架构师都在研究它,并且看不出代码有什么问题.我尝试在每个请求的using语句中使用一个HttpClient,并在后端调用每个api一个HttpClient.我尝试过并行和串行使用HttpClient.我已经尝试过async/await而没有.无论我尝试什么,行为都是一样的.

我希望能够使用HttpClient,但我不能再花时间在这个问题上,因为我使用HttpWebRequest.我的下一步是使HttpWebRequests并行发生.

谢谢您的意见.

Answer 1

我在使用 HttpClient 时也经历过类似的挫折。在我的场景中，我发现在 ServicePointManager 上将 MaxServicePointIdleTime 设置为低得多的值并将 DefaultConnectionLimit 设置为高值解决了我的问题。我相信在我的情况下，当连接保持打开状态时，我正在经历池饥饿。

如果您还没有这样做，您可能还希望在发布时不附加调试器进行测试，因为 TaskScheduler 在调试时的行为有所不同。

以下 MSDN 文章非常有帮助：http://blogs.msdn.com/b/jpsanders/archive/2009/05/20/understanding-maxservicepointidletime-and-defaultconnectionlimit.aspx