Debug ThreadPool Kelaparan
Artikel ini berlaku untuk: ✔️.NET Core 3.1 dan versi yang lebih baru
Dalam tutorial ini, Anda akan mempelajari cara men-debug skenario kelaparan ThreadPool. Kelaparan ThreadPool terjadi ketika kumpulan tidak memiliki utas yang tersedia untuk memproses item kerja baru dan sering menyebabkan aplikasi merespons dengan lambat. Dengan menggunakan contoh yang disediakan ASP.NET aplikasi web Core, Anda dapat menyebabkan kelaparan ThreadPool dengan sengaja dan mempelajari cara mendiagnosisnya.
Dalam tutorial ini, Anda akan:
- Menyelidiki aplikasi yang merespons permintaan secara perlahan
- Gunakan alat penghitung dotnet untuk mengidentifikasi kelaparan ThreadPool kemungkinan terjadi
- Gunakan alat dotnet-stack untuk menentukan pekerjaan apa yang membuat utas ThreadPool sibuk
Prasyarat
Tutorial ini menggunakan:
- .NET Core 6.0 SDK untuk membangun dan menjalankan aplikasi sampel
- Contoh aplikasi web untuk menunjukkan perilaku kelaparan ThreadPool
- Bombardier untuk menghasilkan beban untuk aplikasi web sampel
- penghitung dotnet untuk mengamati penghitung kinerja
- dotnet-stack untuk memeriksa tumpukan utas
Menjalankan aplikasi contoh
Unduh kode untuk aplikasi sampel dan buat menggunakan .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.26Jalankan aplikasi:
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
Jika Anda menggunakan browser web dan mengirim permintaan ke https://localhost:5001/api/diagscenario/taskwait, Anda akan melihat respons success:taskwait yang dikembalikan setelah sekitar 500 md. Ini menunjukkan bahwa server web melayani lalu lintas seperti yang diharapkan.
Mengamati performa lambat
Server web demo memiliki beberapa titik akhir yang mengejek melakukan permintaan database dan kemudian mengembalikan respons kepada pengguna. Masing-masing titik akhir ini memiliki penundaan sekitar 500 ms saat melayani permintaan satu per satu tetapi performanya jauh lebih buruk ketika server web mengalami beberapa beban. Unduh alat pengujian beban Bombardier dan amati perbedaan latensi ketika 125 permintaan bersamaan dikirim ke setiap titik akhir.
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
Titik akhir kedua ini menggunakan pola kode yang berkinerja lebih buruk:
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
Kedua titik akhir ini menunjukkan secara dramatis lebih dari latensi rata-rata 500 md ketika beban tinggi (masing-masing 3,48 d dan 15,42 dtk). Jika Anda menjalankan contoh ini pada versi .NET Core yang lebih lama, Anda mungkin melihat kedua contoh berkinerja sama buruknya. .NET 6 telah memperbarui heuristik ThreadPool yang mengurangi dampak performa pola pengodean buruk yang digunakan dalam contoh pertama.
Mendeteksi kelaparan ThreadPool
Jika Anda mengamati perilaku di atas pada layanan dunia nyata, Anda akan tahu itu merespons perlahan di bawah beban tetapi Anda tidak akan tahu penyebabnya. penghitung dotnet adalah alat yang dapat menampilkan penghitung kinerja langsung. Penghitung ini dapat memberikan petunjuk tentang masalah tertentu dan sering kali mudah didapatkan. Di lingkungan produksi, Anda mungkin memiliki penghitung serupa yang disediakan oleh alat pemantauan jarak jauh dan dasbor web. Instal penghitung dotnet dan mulai pantau layanan 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
Penghitung di atas adalah contoh saat server web tidak melayani permintaan apa pun. Jalankan Bombardier lagi dengan api/diagscenario/tasksleepwait titik akhir dan beban berkelanjutan selama 2 menit sehingga ada banyak waktu untuk mengamati apa yang terjadi pada penghitung kinerja.
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/tasksleepwait -d 120s
Kelaparan ThreadPool terjadi ketika tidak ada utas gratis untuk menangani item kerja yang diantrekan dan runtime merespons dengan meningkatkan jumlah utas ThreadPool. Anda harus mengamati ThreadPool Thread Count peningkatan cepat menjadi 2-3x jumlah inti prosesor pada komputer Anda dan kemudian utas lebih lanjut ditambahkan 1-2 per detik sampai akhirnya stabil di suatu tempat di atas 125. Peningkatan threadPool yang lambat dan stabil yang dikombinasikan dengan Penggunaan CPU kurang dari 100% adalah sinyal utama bahwa kelaparan ThreadPool saat ini menjadi penyempitan performa. Peningkatan jumlah utas akan berlanjut hingga kumpulan mencapai jumlah maksimum utas, utas yang cukup telah dibuat untuk memenuhi semua item kerja yang masuk, atau CPU telah jenuh. Seringkali, tetapi tidak selalu, kelaparan ThreadPool juga akan menunjukkan nilai besar untuk ThreadPool Queue Length dan nilai rendah untuk ThreadPool Completed Work Item Count, yang berarti bahwa ada sejumlah besar pekerjaan yang tertunda dan sedikit pekerjaan yang diselesaikan. Berikut adalah contoh penghitung saat jumlah utas masih naik:
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
Setelah jumlah utas ThreadPool stabil, kumpulan tidak lagi kelaparan. Tetapi jika stabil pada nilai tinggi (lebih dari sekitar tiga kali jumlah inti prosesor), yang biasanya menunjukkan kode aplikasi memblokir beberapa utas ThreadPool dan ThreadPool mengimbangi dengan menjalankan dengan lebih banyak utas. Berjalan stabil pada jumlah utas tinggi tidak akan selalu berdampak besar pada latensi permintaan, tetapi jika beban bervariasi secara dramatis dari waktu ke waktu atau aplikasi akan dimulai ulang secara berkala, maka setiap kali ThreadPool cenderung memasuki periode kelaparan di mana aplikasi secara perlahan meningkatkan utas dan memberikan latensi permintaan yang buruk. Setiap utas juga mengonsumsi memori, sehingga mengurangi jumlah total utas yang diperlukan memberikan manfaat lain.
Mulai dari .NET 6, heuristik ThreadPool dimodifikasi untuk meningkatkan jumlah utas ThreadPool jauh lebih cepat sebagai respons terhadap API Tugas pemblokiran tertentu. Kelaparan ThreadPool masih dapat terjadi dengan API ini, tetapi durasinya jauh lebih singkat daripada dengan versi .NET yang lebih lama karena runtime merespons lebih cepat. Jalankan Bombardier lagi dengan api/diagscenario/taskwait titik akhir:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
Pada .NET 6 Anda harus mengamati kumpulan meningkatkan jumlah utas lebih cepat daripada sebelumnya dan kemudian menstabilkan pada jumlah utas yang tinggi. ThreadPool kelaparan terjadi saat jumlah utas sedang mendaki.
Mengatasi kelaparan ThreadPool
Untuk menghilangkan kelaparan ThreadPool, utas ThreadPool harus tetap tidak diblokir sehingga tersedia untuk menangani item kerja yang masuk. Ada dua cara untuk menentukan apa yang dilakukan setiap utas, baik menggunakan alat dotnet-stack atau menangkap cadangan dengan dotnet-dump yang dapat dilihat di Visual Studio. dotnet-stack bisa lebih cepat karena menampilkan tumpukan utas segera di konsol, tetapi penelusuran kesalahan cadangan Visual Studio menawarkan visualisasi yang lebih baik yang memetakan bingkai ke sumber, Just My Code dapat memfilter bingkai implementasi runtime, dan fitur Parallel Stacks dapat membantu mengelompokkan sejumlah besar utas dengan tumpukan serupa. Tutorial ini menunjukkan opsi dotnet-stack. Lihat video tutorial kelaparan ThreadPool diagnosis untuk contoh penyelidikan tumpukan utas menggunakan Visual Studio.
Jalankan Bombardier lagi untuk menempatkan server web di bawah beban:
bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s
Kemudian jalankan dotnet-stack untuk melihat jejak tumpukan utas:
dotnet-stack report -n DiagnosticScenarios
Anda akan melihat output panjang yang berisi sejumlah besar tumpukan, banyak di antaranya terlihat seperti ini:
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()
Bingkai di bagian bawah tumpukan ini menunjukkan bahwa utas ini adalah utas ThreadPool:
System.Private.CoreLib.il!System.Threading.ThreadPoolWorkQueue.Dispatch()
System.Private.CoreLib.il!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()
Dan bingkai di dekat bagian atas mengungkapkan bahwa utas diblokir pada panggilan ke GetResultCore(bool) dari fungsi 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()
Sekarang Anda dapat menavigasi ke kode untuk pengontrol ini di file Controllers/DiagnosticScenarios.cs aplikasi sampel untuk melihat bahwa ia memanggil API asinkron tanpa menggunakan await. Ini adalah pola kode sync-over-async , yang diketahui memblokir utas dan merupakan penyebab paling umum dari kelaparan ThreadPool.
public ActionResult<string> TaskWait()
{
// ...
Customer c = PretendQueryCustomerFromDbAsync("Dana").Result;
return "success:taskwait";
}
Dalam hal ini kode dapat dengan mudah diubah untuk menggunakan asinkron/tunggu sebagai gantinya seperti yang TaskAsyncWait() ditunjukkan di titik akhir. Menggunakan tunggu memungkinkan utas saat ini untuk melayani workitem lain saat kueri database sedang berlangsung. Ketika pencarian database selesai, utas ThreadPool akan melanjutkan eksekusi. Dengan cara ini tidak ada utas yang diblokir dalam kode selama setiap permintaan:
public async Task<ActionResult<string>> TaskAsyncWait()
{
// ...
Customer c = await PretendQueryCustomerFromDbAsync("Dana");
return "success:taskasyncwait";
}
Menjalankan Bombadier untuk mengirim beban ke api/diagscenario/taskasyncwait titik akhir menunjukkan bahwa jumlah utas ThreadPool tetap jauh lebih rendah dan latensi rata-rata tetap mendekati 500ms saat menggunakan pendekatan asinkron/tunggu:
>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
Saran dan Komentar
Segera hadir: Sepanjang tahun 2024 kami akan menghentikan penggunaan GitHub Issues sebagai mekanisme umpan balik untuk konten dan menggantinya dengan sistem umpan balik baru. Untuk mengetahui informasi selengkapnya, lihat: https://aka.ms/ContentUserFeedback.
Kirim dan lihat umpan balik untuk