Felsöka ThreadPool-svält
Den här artikeln gäller för: ✔️ .NET Core 3.1 och senare versioner
I den här självstudien får du lära dig hur du felsöker ett ThreadPool-svältscenario. ThreadPool svälter när poolen inte har några tillgängliga trådar för att bearbeta nya arbetsobjekt och det ofta gör att program svarar långsamt. Med hjälp av det angivna exemplet ASP.NET Core webbapp kan du avsiktligt orsaka ThreadPool-svält och lära dig hur du diagnostiserar den.
I de här självstudierna får du:
- Undersöka en app som svarar långsamt på begäranden
- Använd verktyget dotnet-counters för att identifiera att ThreadPool-svält sannolikt inträffar
- Använd verktyget dotnet-stack för att avgöra vilket arbete som håller ThreadPool-trådarna upptagna
Krav
I självstudien används:
- .NET Core 6.0 SDK för att skapa och köra exempelappen
- Exempelwebbapp för att demonstrera ThreadPool-svältbeteende
- Bombardier genererar belastning för exempelwebbappen
- dotnet-counters för att observera prestandaräknare
- dotnet-stack för att undersöka trådstackar
Köra exempelappen
Ladda ned koden för exempelappen och skapa den med hjälp av .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.26Kör appen:
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
Om du använder en webbläsare och skickar begäranden till https://localhost:5001/api/diagscenario/taskwaitbör svaret success:taskwait returneras efter cirka 500 ms. Detta visar att webbservern hanterar trafik som förväntat.
Observera långsamma prestanda
Demowebbservern har flera slutpunkter som simulerar att göra en databasbegäran och sedan returnerar ett svar till användaren. Var och en av dessa slutpunkter har en fördröjning på cirka 500 ms när begäranden hanteras en i taget, men prestandan är mycket sämre när webbservern utsätts för viss belastning. Ladda ned load testing-verktyget För Bombardier och observera skillnaden i svarstid när 125 samtidiga begäranden skickas till varje slutpunkt.
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
Den andra slutpunkten använder ett kodmönster som presterar ännu sämre:
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
Båda dessa slutpunkter visar betydligt mer än den genomsnittliga svarstiden på 500 ms när belastningen är hög (3,48 s respektive 15,42 s). Om du kör det här exemplet på en äldre version av .NET Core ser du förmodligen att båda exemplen fungerar lika dåligt. .NET 6 har uppdaterat ThreadPool-heuristiken som minskar prestandaeffekten av det dåliga kodningsmönstret som används i det första exemplet.
Identifiera ThreadPool-svält
Om du observerade beteendet ovan på en verklig tjänst skulle du veta att den svarar långsamt under belastning, men du vet inte orsaken. dotnet-counters är ett verktyg som kan visa liveprestandaräknare. Dessa räknare kan ge ledtrådar om vissa problem och är ofta lätta att få. I produktionsmiljöer kan du ha liknande räknare som tillhandahålls av fjärrövervakningsverktyg och webbinstrumentpaneler. Installera dotnet-counters och börja övervaka webbtjänsten:
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
Räknarna ovan är ett exempel medan webbservern inte betjänade några begäranden. Kör Bombardier igen med api/diagscenario/tasksleepwait slutpunkten och varaktig belastning i 2 minuter så det finns gott om tid att observera vad som händer med prestandaräknarna.
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/tasksleepwait -d 120s
ThreadPool svälter när det inte finns några lediga trådar för att hantera de köade arbetsobjekten och körningen svarar genom att öka antalet ThreadPool-trådar. Du bör observera att ThreadPool Thread Count snabbt öka till 2-3x antalet processorkärnor på din dator och sedan ytterligare trådar läggs 1-2 per sekund tills slutligen stabilisera någonstans över 125. Den långsamma och stadiga ökningen av ThreadPool-trådar i kombination med CPU-användning som är mycket mindre än 100 % är de viktigaste signalerna om att ThreadPool-svält för närvarande är en flaskhals för prestanda. Antalet trådar fortsätter tills poolen når det maximala antalet trådar, tillräckligt med trådar har skapats för att uppfylla alla inkommande arbetsobjekt, eller så har processorn mättats. Ofta, men inte alltid, visar ThreadPool även stora värden för ThreadPool Queue Length och låga värden för ThreadPool Completed Work Item Count, vilket innebär att det finns en stor mängd väntande arbete och lite arbete som slutförs. Här är ett exempel på räknarna medan antalet trådar fortfarande ökar:
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
När antalet ThreadPool-trådar stabiliseras svälter inte poolen längre. Men om den stabiliseras vid ett högt värde (mer än ungefär tre gånger antalet processorkärnor) indikerar det vanligtvis att programkoden blockerar vissa ThreadPool-trådar och ThreadPool kompenserar genom att köra med fler trådar. Att köra stabilt vid höga trådantal har inte nödvändigtvis stor inverkan på svarstiden för begäranden, men om belastningen varierar dramatiskt över tid, eller om appen startas om regelbundet, kommer ThreadPool sannolikt att gå in i en period av svält där den långsamt ökar trådarna och ger dålig svarstid för begäranden. Varje tråd förbrukar också minne, så att minska det totala antalet trådar som behövs ger en annan fördel.
Från och med .NET 6 har ThreadPool-heuristik ändrats för att skala upp antalet ThreadPool-trådar mycket snabbare som svar på vissa blockerande aktivitets-API:er. ThreadPool-svält kan fortfarande inträffa med dessa API:er, men varaktigheten är mycket kortare än med äldre .NET-versioner eftersom körningen svarar snabbare. Kör Bombardier igen med api/diagscenario/taskwait slutpunkten:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
På .NET 6 bör du observera att poolen ökar antalet trådar snabbare än tidigare och sedan stabiliseras vid ett stort antal trådar. ThreadPool svälter medan antalet trådar ökar.
Lösa ThreadPool-svält
För att eliminera ThreadPool-svält måste ThreadPool-trådar förbli avblockerade så att de är tillgängliga för att hantera inkommande arbetsobjekt. Det finns två sätt att avgöra vad varje tråd gjorde, antingen med verktyget dotnet-stack eller genom att samla in en dump med dotnet-dump som kan visas i Visual Studio. dotnet-stack kan gå snabbare eftersom den visar trådstackarna direkt i konsolen, men felsökning av Visual Studio-dumpar ger bättre visualiseringar som mappar ramar till källan, Just My Code kan filtrera bort implementeringsramar för körning och funktionen Parallella staplar kan hjälpa till att gruppera ett stort antal trådar med liknande staplar. Den här självstudien visar alternativet dotnet-stack. Ett exempel på hur du undersöker trådstackarna med Visual Studio finns i självstudievideon diagnostisera ThreadPool-svält .
Kör Bombardier igen för att belastningssätta webbservern:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
Kör sedan dotnet-stack för att se trådstackens spårningar:
dotnet-stack report -n DiagnosticScenarios
Du bör se långa utdata som innehåller ett stort antal staplar, varav många ser ut så här:
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()
Ramarna längst ned i dessa staplar anger att dessa trådar är ThreadPool-trådar:
System.Private.CoreLib.il!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.il!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()
Och bildrutorna längst upp visar att tråden blockeras vid ett anrop till GetResultCore(bool) från funktionen DiagnosticScenarioController.TaskWait():
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()
Nu kan du navigera till koden för den här kontrollanten i exempelappens Controllers/DiagnosticScenarios.cs-fil för att se att den anropar ett asynkront API utan att använda await. Det här är kodmönstret sync-over-async , som är känt för att blockera trådar och är den vanligaste orsaken till ThreadPool-svält.
public ActionResult<string> TaskWait()
{
// ...
Customer c = PretendQueryCustomerFromDbAsync("Dana").Result;
return "success:taskwait";
}
I det här fallet kan koden enkelt ändras för att använda async/await i stället, som visas i TaskAsyncWait() slutpunkten. Med await kan den aktuella tråden betjäna andra arbetsobjekt medan databasfrågan pågår. När databassökningen är klar återupptas körningen av trådpoolen. På så sätt blockeras ingen tråd i koden under varje begäran:
public async Task<ActionResult<string>> TaskAsyncWait()
{
// ...
Customer c = await PretendQueryCustomerFromDbAsync("Dana");
return "success:taskasyncwait";
}
Körningen av Bombadier för att skicka belastning till api/diagscenario/taskasyncwait slutpunkten visar att antalet ThreadPool-trådar förblir mycket lägre och den genomsnittliga svarstiden ligger kvar nära 500 ms när du använder metoden async/await:
>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
