ThreadPool 고갈 디버그
이 문서의 적용 대상: ✔️ .NET Core 3.1 이상 버전
이 자습서에서는 ThreadPool 고갈 시나리오를 디버깅하는 방법을 알아봅니다. ThreadPool 고갈은 풀에 새 작업 항목을 처리하는 데 사용할 수 있는 스레드가 없을 때 발생하며 종종 애플리케이션의 응답 속도가 느려집니다. 제공된 ASP.NET Core 웹앱 예를 사용하면 의도적으로 ThreadPool 고갈 상태를 유발하고 이를 진단하는 방법을 알아볼 수 있습니다.
이 자습서에서는 다음을 수행합니다.
- 요청에 느리게 응답하는 앱 조사
- dotnet-counters 도구를 사용하여 ThreadPool 고갈 상태가 발생할 가능성이 있는지 식별
- dotnet-stack 도구를 사용하여 ThreadPool 스레드를 바쁘게 유지하는 작업을 확인합니다.
필수 조건
이 자습서에서는 다음을 사용하여 작업을 수행합니다.
- 샘플 앱 빌드 및 실행을 위한 .NET Core 6.0 SDK
- ThreadPool 고갈 동작을 보여 주는 샘플 웹앱
- 샘플 웹앱에 대한 로드를 생성하는 Bombardier
- 성능 카운터를 관찰하기 위한 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
웹 브라우저를 사용하여 https://localhost:5001/api/diagscenario/taskwait에 요청을 보내는 경우 약 500ms 후에 반환된 success:taskwait 응답을 확인해야 합니다. 이는 웹 서버가 예상대로 트래픽을 처리하고 있음을 나타냅니다.
느린 성능 관찰
데모 웹 서버에는 데이터베이스 요청을 수행한 다음 사용자에게 응답을 반환하는 모의 엔드포인트가 여러 개 있습니다. 이러한 각 엔드포인트는 한 번에 하나씩 요청을 처리할 때 약 500ms의 지연이 있지만 웹 서버에 일부 부하가 가해지면 성능이 훨씬 더 나빠집니다. 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
두 엔드포인트 모두 로드가 높을 때 평균 대기 시간인 500ms보다 훨씬 더 긴 대기 시간을 나타냅니다(각각 3.48초 및 15.42초). 이전 버전의 .NET Core에서 이 예를 실행하면 두 예 모두 똑같이 성능이 저하되는 것을 볼 수 있습니다. .NET 6에서는 첫 번째 예에서 사용된 잘못된 코딩 패턴이 성능에 미치는 영향을 줄이는 ThreadPool 추론을 업데이트했습니다.
ThreadPool 고갈 감지
실제 서비스에서 위의 동작을 관찰했다면 부하가 걸린 상태에서 느리게 응답한다는 것을 알 수 있지만 원인은 알 수 없습니다. dotnet-counters는 실시간 성능 카운터를 표시할 수 있는 도구입니다. 이러한 카운터는 특정 문제에 대한 단서를 제공할 수 있으며 쉽게 가져올 수 있는 경우가 많습니다. 프로덕션 환경에는 원격 모니터링 도구 및 웹 대시보드에서 제공하는 유사한 카운터가 있을 수 있습니다. dotnet-counters를 설치하고 웹 서비스 모니터링을 시작합니다.
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
위의 카운터는 웹 서버가 요청을 처리하지 않는 동안의 예입니다. 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 이상으로 안정화되는 것을 관찰해야 합니다. 100%보다 훨씬 낮은 CPU 사용량과 결합된 ThreadPool 스레드의 느리고 꾸준한 증가는 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부터 특정 차단 작업 API에 대한 응답으로 ThreadPool 스레드 수를 훨씬 빠르게 스케일 업하도록 ThreadPool 추론이 수정되었습니다. ThreadPool 고갈은 이러한 API에서도 여전히 발생할 수 있지만 런타임이 더 빠르게 응답하기 때문에 이전 .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를 다시 실행하여 웹 서버를 로드 상태로 만듭니다.
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()
그리고 상단 근처의 프레임은 Diagnostic Scenario Controller.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를 사용하지 않고 비동기 API를 호출하는지 확인할 수 있습니다. 이는 스레드를 차단하는 것으로 알려져 있으며 ThreadPool 고갈의 가장 일반적인 원인인 sync-over-async 코드 패턴입니다.
public ActionResult<string> TaskWait()
{
// ...
Customer c = PretendQueryCustomerFromDbAsync("Dana").Result;
return "success:taskwait";
}
이 경우 TaskAsyncWait() 엔드포인트에 표시된 대로 대신 async/await를 사용하도록 코드를 쉽게 변경할 수 있습니다. Wait를 사용하면 데이터베이스 쿼리가 진행되는 동안 현재 스레드가 다른 작업 항목을 서비스할 수 있습니다. 데이터베이스 조회가 완료되면 ThreadPool 스레드가 실행을 다시 시작합니다. 이렇게 하면 각 요청 중에 코드에서 스레드가 차단되지 않습니다.
public async Task<ActionResult<string>> TaskAsyncWait()
{
// ...
Customer c = await PretendQueryCustomerFromDbAsync("Dana");
return "success:taskasyncwait";
}
api/diagscenario/taskasyncwait 엔드포인트로 로드를 전송하기 위해 Bombadier를 실행하면 async/await 방식을 사용할 때 ThreadPool 스레드 수가 훨씬 낮게 유지되고 평균 대기 시간이 500ms 가까이 유지되는 것으로 나타났습니다.
>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
.NET