调试 ThreadPool 资源不足
本文适用于:✔️ .NET Core 3.1 及更高版本
本教程将介绍如何调试 ThreadPool 资源不足的情况。 当池没有可用于处理新工作项的线程时,会发生 ThreadPool 资源不足的情况,这通常会导致应用程序响应缓慢。 使用所提供的示例 ASP.NET Core Web 应用,可以有意地导致 ThreadPool 资源不足,并了解如何诊断此问题。
在本教程中,你将:
- 调查响应请求速度缓慢的应用
- 使用 dotnet-counters 工具识别可能发生的 ThreadPool 资源不足
- 使用 dotnet-stack 工具确定哪些工作使 ThreadPool 线程繁忙
先决条件
本教程使用:
- .NET Core 6.0 SDK,用于生成和运行示例应用
- 示例 Web 应用,用于演示 ThreadPool 资源不足行为
- Bombardier,用于为示例 Web 应用生成负载
- dotnet-counters,用于观察性能计数器
- dotnet-stack,用于检查线程堆栈
运行示例应用
下载示例应用的代码,并使用 .NET SDK 生成它:
E:\demo\DiagnosticScenarios>dotnet build Microsoft (R) Build Engine version 17.1.1+a02f73656 for .NET Copyright (C) Microsoft Corporation. All rights reserved. Determining projects to restore... All projects are up-to-date for restore. DiagnosticScenarios -> E:\demo\DiagnosticScenarios\bin\Debug\net6.0\DiagnosticScenarios.dll Build succeeded. 0 Warning(s) 0 Error(s) Time Elapsed 00:00:01.26
运行应用:
E:\demo\DiagnosticScenarios>bin\Debug\net6.0\DiagnosticScenarios.exe info: Microsoft.Hosting.Lifetime[14] Now listening on: http://localhost:5000 info: Microsoft.Hosting.Lifetime[14] Now listening on: https://localhost:5001 info: Microsoft.Hosting.Lifetime[0] Application started. Press Ctrl+C to shut down. info: Microsoft.Hosting.Lifetime[0] Hosting environment: Production info: Microsoft.Hosting.Lifetime[0] Content root path: E:\demo\DiagnosticScenarios
如果使用 Web 浏览器并向 https://localhost:5001/api/diagscenario/taskwait
发送请求,应会看到在大约 500 毫秒后返回响应 success:taskwait
。 这表明 Web 服务器正在按预期提供流量。
观察缓慢的性能
演示 Web 服务器有几个终结点,这些终结点模拟执行数据库请求,然后向用户返回响应。 每个终结点在一次提供一个请求时有大约 500 毫秒的延迟,但在 Web 服务器受到一定的负载约束时,性能会更差。 下载 Bombardier 负载测试工具,并观察在将 125 个并发请求发送到每个终结点时的延迟差异。
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait
Bombarding https://localhost:5001/api/diagscenario/taskwait for 10s using 125 connection(s)
[=============================================================================================] 10s
Done!
Statistics Avg Stdev Max
Reqs/sec 33.06 234.67 3313.54
Latency 3.48s 1.39s 10.79s
HTTP codes:
1xx - 0, 2xx - 454, 3xx - 0, 4xx - 0, 5xx - 0
others - 0
Throughput: 75.37KB/s
第二个终结点使用性能更差的代码模式:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/tasksleepwait
Bombarding https://localhost:5001/api/diagscenario/tasksleepwait for 10s using 125 connection(s)
[=============================================================================================] 10s
Done!
Statistics Avg Stdev Max
Reqs/sec 1.61 35.25 788.91
Latency 15.42s 2.18s 18.30s
HTTP codes:
1xx - 0, 2xx - 140, 3xx - 0, 4xx - 0, 5xx - 0
others - 0
Throughput: 36.57KB/s
当负载较高(分别为 3.48 秒和 15.42 秒)时,这两个终结点显示的延迟都明显高于 500 毫秒的平均延迟。 如果在较旧版本的 .NET Core 上运行此示例,可能会看到这两个示例的性能同样不佳。 .NET 6 更新了 ThreadPool 启发式方法,从而减少了第一个示例中使用的不良编码模式对性能的影响。
检测 ThreadPool 资源不足问题
如果你在实际服务中观察到上述行为,你会知道它在负载下响应缓慢,但你不知道原因。 dotnet-counters 是一个可以显示实时性能计数器的工具。 这些计数器可以提供有关某些问题的线索,而且通常很容易得到。 在生产环境中,你可能有远程监视工具和 Web 仪表板提供的类似计数器。 安装 dotnet-counters 并开始监视 Web 服务:
dotnet-counters monitor -n DiagnosticScenarios
Press p to pause, r to resume, q to quit.
Status: Running
[System.Runtime]
% Time in GC since last GC (%) 0
Allocation Rate (B / 1 sec) 0
CPU Usage (%) 0
Exception Count (Count / 1 sec) 0
GC Committed Bytes (MB) 0
GC Fragmentation (%) 0
GC Heap Size (MB) 34
Gen 0 GC Count (Count / 1 sec) 0
Gen 0 Size (B) 0
Gen 1 GC Count (Count / 1 sec) 0
Gen 1 Size (B) 0
Gen 2 GC Count (Count / 1 sec) 0
Gen 2 Size (B) 0
IL Bytes Jitted (B) 279,021
LOH Size (B) 0
Monitor Lock Contention Count (Count / 1 sec) 0
Number of Active Timers 0
Number of Assemblies Loaded 121
Number of Methods Jitted 3,223
POH (Pinned Object Heap) Size (B) 0
ThreadPool Completed Work Item Count (Count / 1 sec) 0
ThreadPool Queue Length 0
ThreadPool Thread Count 1
Time spent in JIT (ms / 1 sec) 0.387
Working Set (MB) 87
上面的计数器是 Web 服务器没有提供任何请求的一个示例。 再次使用 api/diagscenario/tasksleepwait
终结点运行 Bombardier 并持续负载 2 分钟,留出足够的时间来观察性能计数器会发生什么情况。
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/tasksleepwait -d 120s
当没有可用线程来处理排队的工作项时,将出现 ThreadPool 资源不足的情况,运行时通过增加 ThreadPool 线程数来响应。 你应该观察到 ThreadPool Thread Count
迅速增加到你的计算机上处理器核心数的 2-3 倍,然后每秒增加 1-2 个线程,直到最终稳定在超过 125 的某个位置。 ThreadPool 线程数缓慢而稳定地增加,再加上 CPU 使用率远远低于 100%,这些都是指明 ThreadPool 资源不足目前是性能瓶颈的关键信号。 线程计数持续增加,直到池达到最大线程数,已创建足够的线程来满足所有传入的工作项,或者 CPU 已饱和。 通常(但并非一直如此),ThreadPool 资源不足也会显示 ThreadPool Queue Length
的较大值和 ThreadPool Completed Work Item Count
的较小值,这意味着有大量的待处理工作,而正在完成的工作很少。 下面是线程计数仍在上升时的计数器示例:
Press p to pause, r to resume, q to quit.
Status: Running
[System.Runtime]
% Time in GC since last GC (%) 0
Allocation Rate (B / 1 sec) 24,480
CPU Usage (%) 0
Exception Count (Count / 1 sec) 0
GC Committed Bytes (MB) 56
GC Fragmentation (%) 40.603
GC Heap Size (MB) 89
Gen 0 GC Count (Count / 1 sec) 0
Gen 0 Size (B) 6,306,160
Gen 1 GC Count (Count / 1 sec) 0
Gen 1 Size (B) 8,061,400
Gen 2 GC Count (Count / 1 sec) 0
Gen 2 Size (B) 192
IL Bytes Jitted (B) 279,263
LOH Size (B) 98,576
Monitor Lock Contention Count (Count / 1 sec) 0
Number of Active Timers 124
Number of Assemblies Loaded 121
Number of Methods Jitted 3,227
POH (Pinned Object Heap) Size (B) 1,197,336
ThreadPool Completed Work Item Count (Count / 1 sec) 2
ThreadPool Queue Length 29
ThreadPool Thread Count 96
Time spent in JIT (ms / 1 sec) 0
Working Set (MB) 152
ThreadPool 线程计数稳定后,池将不再出现资源不足的情况。 但是,如果它稳定在一个较高的值(超过处理器核心数的 3 倍左右),通常表明应用程序代码正在阻止一些 ThreadPool 线程,并且 ThreadPool 正在通过运行更多线程来补偿。 在高线程计数下保持稳定运行不一定对请求延迟产生很大影响,但如果负载随时间变化很大,或者应用将定期重启,则每次 ThreadPool 都可能会进入一段资源不足的时期,其中线程缓慢增加并传递较差的请求延迟。 每个线程也会消耗内存,因此,减少所需的线程总数是另一个好处。
从 .NET 6 开始,修改了 ThreadPool 启发式方法,可以更快地纵向扩展 ThreadPool 线程数,以响应某些阻止的任务 API。 使用这些 API 仍会发生 ThreadPool 资源不足,但持续时间比旧版 .NET 版本要短得多,因为运行时的响应速度更快。 使用 api/diagscenario/taskwait
终结点再次运行 Bombardier:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
在 .NET 6 上,应能观察到池的线程计数比以前增加得更快,然后稳定在一个较高的线程数上。 在线程数增加的同时,出现了 ThreadPool 资源不足的情况。
解决 ThreadPool 资源不足的问题
为了消除 ThreadPool 资源不足的问题,ThreadPool 线程需要保持不被阻止的状态,让它们可用于处理传入的工作项。 有两种方法可以确定每个线程执行的操作,即使用 dotnet-stack 工具,或使用可在 Visual Studio 中查看的 dotnet-dump 捕获转储。 dotnet-stack 可能更快,因为它会立即在控制台上显示线程堆栈,但 Visual Studio 转储调试提供了更好的可视化效果,可将帧映射到源,“仅我的代码”可以筛选出运行时实现帧,并行堆栈功能可以帮助将大量线程与类似堆栈分组在一起。 本教程演示 dotnet-stack 选项。 有关使用 Visual Studio 调查线程堆栈的示例,请参阅诊断 ThreadPool 资源不足的教程视频。
再次运行 Bombardier,将 Web 服务器置于负载之下:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
然后运行 dotnet-stack,查看线程堆栈跟踪:
dotnet-stack report -n DiagnosticScenarios
应会看到一个包含大量堆栈的长输出,其中许多内容如下所示:
Thread (0x25968):
[Native Frames]
System.Private.CoreLib.il!System.Threading.ManualResetEventSlim.Wait(int32,value class System.Threading.CancellationToken)
System.Private.CoreLib.il!System.Threading.Tasks.Task.SpinThenBlockingWait(int32,value class System.Threading.CancellationToken)
System.Private.CoreLib.il!System.Threading.Tasks.Task.InternalWaitCore(int32,value class System.Threading.CancellationToken)
System.Private.CoreLib.il!System.Threading.Tasks.Task`1[System.__Canon].GetResultCore(bool)
DiagnosticScenarios!testwebapi.Controllers.DiagScenarioController.TaskWait()
Anonymously Hosted DynamicMethods Assembly!dynamicClass.lambda_method1(pMT: 00007FF7A8CBF658,class System.Object,class System.Object[])
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor+SyncObjectResultExecutor.Execute(class Microsoft.AspNetCore.Mvc.Infrastructure.IActionResultTypeMapper,class Microsoft.Extensions.Internal.ObjectMethodExecutor,class System.Object,class System.Object[])
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(value class State&,value class Scope&,class System.Object&,bool&)
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(value class State&,value class Scope&,class System.Object&,bool&)
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(value class State&,value class Scope&,class System.Object&,bool&)
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(value class State&,value class Scope&,class System.Object&,bool&)
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync()
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeAsync()
Microsoft.AspNetCore.Mvc.Core.il!Microsoft.AspNetCore.Mvc.Routing.ControllerRequestDelegateFactory+<>c__DisplayClass10_0.<CreateRequestDelegate>b__0(class Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Routing.il!Microsoft.AspNetCore.Routing.EndpointMiddleware.Invoke(class Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Authorization.Policy.il!Microsoft.AspNetCore.Authorization.AuthorizationMiddleware+<Invoke>d__6.MoveNext()
System.Private.CoreLib.il!System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start(!!0&)
Microsoft.AspNetCore.Authorization.Policy.il!Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(class Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.HttpsPolicy.il!Microsoft.AspNetCore.HttpsPolicy.HttpsRedirectionMiddleware.Invoke(class Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.HttpsPolicy.il!Microsoft.AspNetCore.HttpsPolicy.HstsMiddleware.Invoke(class Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.HostFiltering.il!Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware.Invoke(class Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Server.Kestrel.Core.il!Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol+<ProcessRequests>d__223`1[System.__Canon].MoveNext()
System.Private.CoreLib.il!System.Threading.ExecutionContext.RunInternal(class System.Threading.ExecutionContext,class System.Threading.ContextCallback,class System.Object)
System.Private.CoreLib.il!System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[System.Threading.Tasks.VoidTaskResult,Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol+<ProcessRequests>d__223`1[System.__Canon]].MoveNext(class System.Threading.Thread)
System.Private.CoreLib.il!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(class System.Runtime.CompilerServices.IAsyncStateMachineBox,bool)
System.Private.CoreLib.il!System.Threading.Tasks.Task.RunContinuations(class System.Object)
System.IO.Pipelines.il!System.IO.Pipelines.StreamPipeReader+<<ReadAsync>g__Core|36_0>d.MoveNext()
System.Private.CoreLib.il!System.Threading.ExecutionContext.RunInternal(class System.Threading.ExecutionContext,class System.Threading.ContextCallback,class System.Object)
System.Private.CoreLib.il!System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[System.IO.Pipelines.ReadResult,System.IO.Pipelines.StreamPipeReader+<<ReadAsync>g__Core|36_0>d].MoveNext(class System.Threading.Thread)
System.Private.CoreLib.il!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(class System.Runtime.CompilerServices.IAsyncStateMachineBox,bool)
System.Private.CoreLib.il!System.Threading.Tasks.Task.RunContinuations(class System.Object)
System.Private.CoreLib.il!System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[System.Int32].SetExistingTaskResult(class System.Threading.Tasks.Task`1<!0>,!0)
System.Net.Security.il!System.Net.Security.SslStream+<ReadAsyncInternal>d__186`1[System.Net.Security.AsyncReadWriteAdapter].MoveNext()
System.Private.CoreLib.il!System.Threading.ExecutionContext.RunInternal(class System.Threading.ExecutionContext,class System.Threading.ContextCallback,class System.Object)
System.Private.CoreLib.il!System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[System.Int32,System.Net.Security.SslStream+<ReadAsyncInternal>d__186`1[System.Net.Security.AsyncReadWriteAdapter]].MoveNext(class System.Threading.Thread)
Microsoft.AspNetCore.Server.Kestrel.Core.il!Microsoft.AspNetCore.Server.Kestrel.Core.Internal.DuplexPipeStream+<ReadAsyncInternal>d__27.MoveNext()
System.Private.CoreLib.il!System.Threading.ExecutionContext.RunInternal(class System.Threading.ExecutionContext,class System.Threading.ContextCallback,class System.Object)
System.Private.CoreLib.il!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.il!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()
这些堆栈底部的帧指示这些线程是 ThreadPool 线程:
System.Private.CoreLib.il!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.il!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()
顶部附近的帧显示线程在从 DiagnosticScenarioController.TaskWait() 函数调用 GetResultCore(bool)
时被阻止:
Thread (0x25968):
[Native Frames]
System.Private.CoreLib.il!System.Threading.ManualResetEventSlim.Wait(int32,value class System.Threading.CancellationToken)
System.Private.CoreLib.il!System.Threading.Tasks.Task.SpinThenBlockingWait(int32,value class System.Threading.CancellationToken)
System.Private.CoreLib.il!System.Threading.Tasks.Task.InternalWaitCore(int32,value class System.Threading.CancellationToken)
System.Private.CoreLib.il!System.Threading.Tasks.Task`1[System.__Canon].GetResultCore(bool)
DiagnosticScenarios!testwebapi.Controllers.DiagScenarioController.TaskWait()
现在,可以在示例应用的 Controllers/DiagnosticScenarios.cs 文件中导航到此控制器的代码,看到它在不使用 await
的情况下调用 async API。 这是 sync-over-async 代码模式,已知会阻止线程,这是导致 ThreadPool 资源不足的最常见原因。
public ActionResult<string> TaskWait()
{
// ...
Customer c = PretendQueryCustomerFromDbAsync("Dana").Result;
return "success:taskwait";
}
在这种情况下,可以轻松地更改代码以使用 async/await,如 TaskAsyncWait()
终结点中所示。 使用 await 可让当前线程在数据库查询过程中为其他工作项提供服务。 当数据库查找完成后,ThreadPool 线程将恢复执行。 这样,在每个请求期间,代码中没有任何线程被阻止:
public async Task<ActionResult<string>> TaskAsyncWait()
{
// ...
Customer c = await PretendQueryCustomerFromDbAsync("Dana");
return "success:taskasyncwait";
}
运行 Bombadier 以将负载发送到 api/diagscenario/taskasyncwait
终结点显示,在使用 async/await 方法时,ThreadPool 线程计数会保持较低,平均延迟仍接近 500 毫秒:
>bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskasyncwait
Bombarding https://localhost:5001/api/diagscenario/taskasyncwait for 10s using 125 connection(s)
[=============================================================================================] 10s
Done!
Statistics Avg Stdev Max
Reqs/sec 227.92 274.27 1263.48
Latency 532.58ms 58.64ms 1.14s
HTTP codes:
1xx - 0, 2xx - 2390, 3xx - 0, 4xx - 0, 5xx - 0
others - 0
Throughput: 98.81KB/s