ThreadPool AçlığıNda Hata Ayıklama
Bu makale şunlar için geçerlidir: ✔️ .NET Core 3.1 ve sonraki sürümler
Bu öğreticide ThreadPool açlıktan ölme senaryosunda hata ayıklamayı öğreneceksiniz. Havuzda yeni iş öğelerini işlemek için kullanılabilir iş parçacıkları olmadığında ve genellikle uygulamaların yavaş yanıt vermesine neden olduğunda ThreadPool açlığı oluşur. Sağlanan örnek ASP.NET Core web uygulamasını kullanarak ThreadPool'un açlıktan ölmesine neden olabilir ve tanılamayı öğrenebilirsiniz.
Bu öğreticide şunları yapacaksınız:
- İsteklere yavaş yanıt veren bir uygulamayı araştırma
- ThreadPool aç kalma olasılığını belirlemek için dotnet-counters aracını kullanın
- ThreadPool iş parçacıklarını meşgul eden çalışmayı belirlemek için dotnet-stack aracını kullanın
Önkoşullar
Öğreticide aşağıdakiler kullanılır:
- Örnek uygulamayı derlemek ve çalıştırmak için .NET Core 6.0 SDK'sı
- ThreadPool aç kalma davranışını göstermek için örnek web uygulaması
- Örnek web uygulaması için yük oluşturmak için bombardier
- performans sayaçlarını gözlemlemek için dotnet-counters
- iş parçacığı yığınlarını incelemek için dotnet-stack
Örnek uygulamayı çalıştırma
Örnek uygulamanın kodunu indirin ve .NET SDK'sını kullanarak derleyin:
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.26Uygulamayı çalıştırın:
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
Bir web tarayıcısı kullanıyor ve adresine https://localhost:5001/api/diagscenario/taskwaitistek gönderiyorsanız, yaklaşık 500 ms sonra döndürülen yanıtı success:taskwait görmeniz gerekir. Bu, web sunucusunun trafiği beklendiği gibi hizmet ettiğini gösterir.
Yavaş performansı gözlemleme
Tanıtım web sunucusu, veritabanı isteği yaparken sahte işlem yapan ve ardından kullanıcıya yanıt döndüren çeşitli uç noktalara sahiptir. Bu uç noktaların her birinde istekler birer birer sunulurken yaklaşık 500 ms gecikme olur, ancak web sunucusu bir miktar yüke maruz bırakıldığında performans çok daha kötüdür. Bombardier yük testi aracını indirin ve her uç noktaya 125 eşzamanlı istek gönderildiğinde gecikme süresi farkını gözlemleyin.
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
Bu ikinci uç nokta daha da kötü performans gösteren bir kod deseni kullanır:
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
Bu uç noktaların her ikisi de yük yüksek olduğunda ortalama 500 ms'lik gecikme süresinden (sırasıyla 3,48 sn ve 15,42 sn) önemli ölçüde fazladır. Bu örneği daha eski bir .NET Core sürümünde çalıştırırsanız, her iki örneğin de aynı derecede kötü performans sergilediğini görmeniz olasıdır. .NET 6, ilk örnekte kullanılan hatalı kodlama deseninin performans etkisini azaltan güncelleştirilmiş ThreadPool buluşsal yöntemlerine sahiptir.
ThreadPool aç kalmasını algılama
Yukarıdaki davranışı gerçek bir dünya hizmetinde gözlemlediyseniz yük altında yavaş yanıt verdiğini anlarsınız ancak nedenini bilmezsiniz. dotnet-counters , canlı performans sayaçlarını gösterebilen bir araçtır. Bu sayaçlar belirli sorunlar hakkında ipuçları sağlayabilir ve genellikle kolayca elde edilebilir. Üretim ortamlarında, uzaktan izleme araçları ve web panoları tarafından sağlanan benzer sayaçlarınız olabilir. dotnet-counters'ı yükleyin ve web hizmetini izlemeye başlayın:
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
Yukarıdaki sayaçlar, web sunucusu herhangi bir istek sunmazken bir örnektir. Bombardier'ı uç noktayla api/diagscenario/tasksleepwait yeniden çalıştırın ve 2 dakika boyunca yükü sürdürün, böylece performans sayaçlarına ne olduğunu gözlemlemek için bol bol zaman vardır.
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/tasksleepwait -d 120s
ThreadPool açlığı, kuyruğa alınan iş öğelerini işlemek için boş iş parçacığı olmadığında oluşur ve çalışma zamanı ThreadPool iş parçacığı sayısını artırarak yanıt verir. Makinenizdeki işlemci çekirdeği sayısının 2-3 kat daha hızlı arttığını gözlemlemeniz ThreadPool Thread Count gerekir ve daha sonra 125'in üzerinde bir yerde dengelenene kadar saniyede 1-2 iş parçacığı eklenir. ThreadPool iş parçacıklarının %100'den çok daha az CPU Kullanımı ile birlikte yavaş ve kararlı artışı, ThreadPool'un aç kalma sorununun şu anda bir performans sorunu olduğunu gösteren önemli sinyallerdir. havuz en fazla iş parçacığı sayısına ulaşana, tüm gelen iş öğelerini karşılamak için yeterli iş parçacığı oluşturulana veya CPU doygunluğa ulaşana kadar iş parçacığı sayısı artışı devam eder. Genellikle, ancak her zaman değil, ThreadPool yetersizliği için büyük değerler ThreadPool Queue Length ve için ThreadPool Completed Work Item Countdüşük değerler de gösterir. Bu, bekleyen çok fazla iş ve çok az iş tamamlandığı anlamına gelir. İş parçacığı sayısı artmaktayken sayaçlara bir örnek aşağıda verilmiştir:
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 iş parçacıklarının sayısı dengelendikten sonra havuz artık aç kalmaz. Ancak yüksek bir değerde kararlı hale gelirse (işlemci çekirdeği sayısının yaklaşık üç katı), bu genellikle uygulama kodunun bazı ThreadPool iş parçacıklarını engellediğini ve ThreadPool'un daha fazla iş parçacığıyla çalıştırılarak telafi ettiğini gösterir. Yüksek iş parçacığı sayılarında sürekli çalışmak, istek gecikme süresi üzerinde büyük etki yaratmaz, ancak yük zaman içinde önemli ölçüde değişirse veya uygulama düzenli olarak yeniden başlatılırsa ThreadPool yavaş yavaş artan ve istek gecikme süresini kısaltan bir açlık süresine girer. Her iş parçacığı bellek de tüketir, bu nedenle gereken toplam iş parçacığı sayısını azaltmak başka bir avantaj sağlar.
.NET 6'dan başlayarak ThreadPool buluşsal yöntemleri, bazı engelleyici Görev API'lerine yanıt olarak ThreadPool iş parçacığı sayısının ölçeğini çok daha hızlı artıracak şekilde değiştirildi. Bu API'lerde ThreadPool açlığı oluşmaya devam edebilir, ancak çalışma zamanı daha hızlı yanıt verdiği için süre eski .NET sürümlerinde olduğundan çok daha kısadır. Bombardier'ı uç noktayla api/diagscenario/taskwait yeniden çalıştırın:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
.NET 6'da havuzun iş parçacığı sayısını öncekinden daha hızlı artırıp yüksek sayıda iş parçacığında kararlı hale getirerek gözlemlemeniz gerekir. İş parçacığı sayısı tırmanırken ThreadPool açlığı oluşuyor.
ThreadPool aç kalma sorununu çözme
ThreadPool açlığını ortadan kaldırmak için ThreadPool iş parçacıklarının, gelen iş öğelerini işleyebilmeleri için engelsiz kalması gerekir. Her iş parçacığının ne yaptığını belirlemenin iki yolu vardır: dotnet-stack aracını kullanarak veya Visual Studio'da görüntülenebilen dotnet-dump ile dökümü yakalama. dotnet-stack, iş parçacığı yığınlarını konsolda hemen gösterdiğinden daha hızlı olabilir, ancak Visual Studio dökümü hata ayıklaması çerçeveleri kaynağa eşleyen daha iyi görselleştirmeler sunar, Just My Code çalışma zamanı uygulama çerçevelerini filtreleyebilir ve Paralel Yığınlar özelliği benzer yığınlara sahip çok sayıda iş parçacığını gruplandırmaya yardımcı olabilir. Bu öğreticide dotnet-stack seçeneği gösterilir. Visual Studio kullanarak iş parçacığı yığınlarını araştırma örneği için ThreadPool açlıktan ölme öğreticisi videosunu inceleyin .
Web sunucusunu yük altına almak için Bombardier'ı yeniden çalıştırın:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
Ardından iş parçacığı yığını izlemelerini görmek için dotnet-stack komutunu çalıştırın:
dotnet-stack report -n DiagnosticScenarios
Çok sayıda yığın içeren ve birçoğu aşağıdaki gibi görünen uzun bir çıkış görmeniz gerekir:
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()
Bu yığınların altındaki çerçeveler, bu iş parçacıklarının ThreadPool iş parçacıkları olduğunu gösterir:
System.Private.CoreLib.il!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.il!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()
Ve üstteki çerçeveler, DiagnosticScenarioController.TaskWait() işlevinden çağrısında GetResultCore(bool) iş parçacığının engellendiğini gösterir:
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()
Artık örnek uygulamanın Controllers/DiagnosticScenarios.cs dosyasında bu denetleyicinin koduna gidip kullanmadan awaitzaman uyumsuz bir API çağırdığını görebilirsiniz. Bu, iş parçacıklarını engellediği bilinen ve ThreadPool aç kalma sorununun en yaygın nedeni olan zaman uyumsuz kod desenidir.
public ActionResult<string> TaskWait()
{
// ...
Customer c = PretendQueryCustomerFromDbAsync("Dana").Result;
return "success:taskwait";
}
Bu durumda kod, uç noktada gösterildiği TaskAsyncWait() gibi async/await kullanacak şekilde kolayca değiştirilebilir. Await kullanılması, veritabanı sorgusu devam ederken geçerli iş parçacığının diğer iş öğelerine hizmet vermesine olanak tanır. Veritabanı araması tamamlandığında threadPool iş parçacığı yürütmeyi sürdürür. Bu şekilde, her istek sırasında kodda hiçbir iş parçacığı engellenmez:
public async Task<ActionResult<string>> TaskAsyncWait()
{
// ...
Customer c = await PretendQueryCustomerFromDbAsync("Dana");
return "success:taskasyncwait";
}
Uç noktaya yük api/diagscenario/taskasyncwait göndermek için Bombadier çalıştırıldığında ThreadPool iş parçacığı sayısının çok daha düşük kaldığını ve zaman uyumsuz/await yaklaşımı kullanılırken ortalama gecikme süresinin 500ms'ye yakın kaldığını gösterir:
>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
