c# - 同步 Web Api 和响应时间取决于线程和请求计数

Question

我正在搞乱同步/异步以更好地学习它们，并遇到了一件我无法解释的事情。我已经设置了具有两个从数据库读取数据的端点的 Web Api 项目。一种是同步，另一种是异步。两者都执行相同的操作，在数据库端需要大约 5 秒(故意限制)。我还根据线程限制了网络服务器:

ThreadPool.SetMinThreads(2, 2);
ThreadPool.SetMaxThreads(2, 2);

目前我对同步方法的行为感到担心，异步的工作方式正如我所期望的那样。

当我同时向同步端点发送 3 个请求时，我最终在 5 秒内得到 2 个响应，在 10 秒内得到 1 个响应，这对我来说似乎是合乎逻辑的:

但是，当我同时向同步端点发送 4 个请求时，我最终得到 4 个响应，这些响应都需要 10 秒(但我预计 2 个为 5 秒，其他 2 个为 10 秒)

在网络服务器日志中，我看到这 4 个请求实际上是同步处理的，响应时间约为 5 秒:

 

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:57128/test/syncDb  
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:57128/test/syncDb  
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "GetSyncDb", controller = "Test"}. Executing controller action with signature System.String GetSyncDb() on controller WebApiAsyncAwait.Controllers.TestController (WebApiAsyncAwait).
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "GetSyncDb", controller = "Test"}. Executing controller action with signature System.String GetSyncDb() on controller WebApiAsyncAwait.Controllers.TestController (WebApiAsyncAwait).
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.String'.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.String'.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait) in 5008.3885ms
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait) in 5010.472000000001ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 5026.9979ms 200 text/plain; charset=utf-8
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 5032.421200000001ms 200 text/plain; charset=utf-8
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:57128/test/syncDb  
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:57128/test/syncDb  
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "GetSyncDb", controller = "Test"}. Executing controller action with signature System.String GetSyncDb() on controller WebApiAsyncAwait.Controllers.TestController (WebApiAsyncAwait).
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "GetSyncDb", controller = "Test"}. Executing controller action with signature System.String GetSyncDb() on controller WebApiAsyncAwait.Controllers.TestController (WebApiAsyncAwait).
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.String'.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.String'.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait) in 5007.105500000001ms
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait) in 5005.6482000000005ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'WebApiAsyncAwait.Controllers.TestController.GetSyncDb (WebApiAsyncAwait)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 5021.8341ms 200 text/plain; charset=utf-8
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 5023.8319ms 200 text/plain; charset=utf-8

 

端点代码:

[HttpGet]
[Route("syncDb")]
public string GetSyncDb()
{
    string connStr = @"Server=localhost\SQLEXPRESS;Database=AdventureWorks;Trusted_Connection=True;";
    using (SqlConnection conn = new SqlConnection(connStr))
    {
        conn.Open();
        using (SqlCommand cmd = conn.CreateCommand())
        {
            cmd.CommandText = @"SELECT TOP (1) * FROM [AdventureWorks].[Sales].[CreditCard] WAITFOR DELAY '00:00:05'";

            using (SqlDataReader reader = cmd.ExecuteReader())
            {
                var res = reader.Read();
                return "Ok";
            }
        }
    }
}

我正在使用 Fiddler 发送请求。是 Fiddler 的问题(因为日志没问题)，还是我在理解它是如何工作的过程中遗漏了一些东西？

Answer 1

在 ASP .NET Core 中，有很多异步内容在幕后执行。特别是，在执行 Controller 操作之前，线程必须读取并解析 fiddler 发送的 HTTP 请求。操作执行后，需要另一个线程(可能相同)将响应写回 fiddler 。

那么第一个有 3 个请求的案例中发生了什么:

1. 由于您允许最多 2 个线程，因此两个操作同时启动，并立即被同步调用 reader.Read() 阻止。
2. 大约 5 秒后，两个线程都完成了操作 GetSyncDb()，但响应尚未发送。
3. 现在有 2 个空闲线程，其中一个可以处理第三个请求(并被阻塞约 5 秒)，另一个可供 ASP 用于向客户端写入响应。

因此，2 个请求在约 5 秒后结束，而第三个请求在约 10 秒后结束。

如果有 4 个请求:

1. 两个操作同时启动，并立即被同步调用 reader.Read() 阻止。
2. 大约 5 秒后，两个线程都完成了操作 GetSyncDb()，但响应尚未发送。
3. 另外 2 个请求已启动并阻止所有可用线程。 ASP 没有任何可用的工作线程。但它需要他们编写响应并完成前 2 个请求。
4. 接下来约 5 秒后，两个线程都被释放，ASP 最终可以写入所有响应。

因此所有请求都会在约 10 秒后结束。但当然它是随机的。有时，ASP 可以捕获空闲线程并在被其他请求阻止之前完成第一个响应。