Megosztás:


A ThreadPool éhezés hibakeresése

Ez a cikk a .NET 9.0-s és újabb verzióira ✔️ vonatkozik

Ebben az oktatóanyagban megtudhatja, hogyan végezhet hibakeresést a ThreadPool éhezési forgatókönyvében. A ThreadPool éhezése akkor fordul elő, ha a készlet nem rendelkezik olyan szállal, amely új munkaelemeket dolgozna fel, és gyakran az alkalmazások lassan válaszolnak. Az ASP.NET Core webalkalmazás megadott példával szándékosan okozhat ThreadPool éhezést, és megtudhatja, hogyan diagnosztizálhatja azt.

Ebben az oktatóanyagban a következőket meg fogja tanulni:

  • Olyan alkalmazás vizsgálata, amely lassan válaszol a kérelmekre
  • Használja a dotnet-counters eszközt a ThreadPool éhezés valószínű előfordulásának azonosításához
  • A dotnet-stack és a dotnet-trace eszközök használatával állapítsa meg, hogy a ThreadPool-szálakat milyen munka tartja elfoglaltnak

Előfeltételek

Az oktatóanyag a következőket használja:

  • .NET 9 SDK a mintaalkalmazás létrehozásához és futtatásához
  • Minta webalkalmazás a ThreadPool éhezési viselkedésének bemutatásához
  • Bombardier a minta webalkalmazás terhelésének generálásához
  • dotnet-counters a teljesítményszámlálók megfigyeléséhez
  • dotnet-stack a szálveremek vizsgálatához
  • dotnet-trace a várakozási események gyűjtéséhez
  • Nem kötelező: PerfView a várakozási események elemzéséhez

A mintaalkalmazás futtatása

Töltse le a mintaalkalmazás kódját, és futtassa a .NET SDK használatával:

E:\demo\DiagnosticScenarios>dotnet run
Using launch settings from E:\demo\DiagnosticScenarios\Properties\launchSettings.json...
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: https://localhost:5001
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: E:\demo\DiagnosticScenarios

Ha webböngészőt használ, és kéréseket https://localhost:5001/api/diagscenario/taskwaitküld, a válasz success:taskwait körülbelül 500 ms után jelenik meg. Ez azt mutatja, hogy a webkiszolgáló a várt módon szolgálja ki a forgalmat.

Lassú teljesítmény megfigyelése

A bemutató webkiszolgáló több végpontot is tartalmaz, amelyek egy adatbázis-kérést szimulálnak, majd választ adnak a felhasználónak. Ezek a végpontok egyenként körülbelül 500 ms késéssel szolgálnak ki kéréseket, de a teljesítmény sokkal rosszabb, ha a webkiszolgáló terhelésnek van kitéve. Töltse le a Bombardier terheléstesztelő eszközt, és figyelje meg a késés különbségét, amikor 125 egyidejű kérést küldenek az egyes végpontoknak.

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

Ez a második végpont olyan kódmintát használ, amely még rosszabb teljesítményt nyújt:

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

Mindkét végpont jelentősen meghaladja az 500 ms-os átlagos késést, ha a terhelés magas (3,48 s és 15,42 s). Ha ezt a példát a .NET Core egy régebbi verziójában futtatja, valószínűleg mindkét példa egyformán rosszul teljesít. A .NET 6 frissítette a ThreadPool heurisztikusait, amelyek csökkentik az első példában használt rossz kódolási minta teljesítményhatását.

A ThreadPool éhezés észlelése

Ha megfigyelte a fenti viselkedést egy valós világbeli szolgáltatásban, tudnia kell, hogy lassan reagál terhelés alatt, de nem tudja az okát. A dotnet-counters egy olyan eszköz, amely élő teljesítményszámlálókat jeleníthet meg. Ezek a számlálók bizonyos problémákról adhatnak nyomokat, és gyakran könnyen beszerezhetők. Éles környezetben előfordulhat, hogy a távoli monitorozási eszközök és webes irányítópultok hasonló számlálókat biztosítanak. Telepítse a dotnet-counterst, és kezdje el figyelni a webszolgáltatást:

dotnet-counters monitor -n DiagnosticScenarios
Press p to pause, r to resume, q to quit.
    Status: Running

Name                                                            Current Value
[System.Runtime]
    dotnet.assembly.count ({assembly})                               115
    dotnet.gc.collections ({collection})
        gc.heap.generation
        ------------------
        gen0                                                           2
        gen1                                                           1
        gen2                                                           1
    dotnet.gc.heap.total_allocated (By)                       64,329,632
    dotnet.gc.last_collection.heap.fragmentation.size (By)
        gc.heap.generation
        ------------------
        gen0                                                     199,920
        gen1                                                      29,208
        gen2                                                           0
        loh                                                           32
        poh                                                            0
    dotnet.gc.last_collection.heap.size (By)
        gc.heap.generation
        ------------------
        gen0                                                     208,712
        gen1                                                   3,456,000
        gen2                                                   5,065,600
        loh                                                       98,384
        poh                                                    3,147,488
    dotnet.gc.last_collection.memory.committed_size (By)      31,096,832
    dotnet.gc.pause.time (s)                                           0.024
    dotnet.jit.compilation.time (s)                                    1.285
    dotnet.jit.compiled_il.size (By)                             565,249
    dotnet.jit.compiled_methods ({method})                         5,831
    dotnet.monitor.lock_contentions ({contention})                   148
    dotnet.process.cpu.count ({cpu})                                  16
    dotnet.process.cpu.time (s)
        cpu.mode
        --------
        system                                                         2.156
        user                                                           2.734
    dotnet.process.memory.working_set (By)                             1.3217e+08
    dotnet.thread_pool.queue.length ({work_item})                      0
    dotnet.thread_pool.thread.count ({thread})                         0
    dotnet.thread_pool.work_item.count ({work_item})              32,267
    dotnet.timer.count ({timer})                                       0

Ha az alkalmazás a .NET 9-nél régebbi .NET-verziót futtat, a dotnet-számlálók kimeneti felhasználói felülete kissé eltérő lesz; részletekért lásd: dotnet-counters .

Az előző számlálók példaként szolgálnak, miközben a webkiszolgáló nem szolgálta ki a kéréseket. Futtassa újra a Bombardiert a api/diagscenario/tasksleepwait végponttal és a 2 percig tartó terheléssel, így bőven van idő megfigyelni, hogy mi történik a teljesítményszámlálókkal.

bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/tasksleepwait -d 120s

A ThreadPool éhezése akkor fordul elő, ha nincsenek ingyenes szálak az üzenetsorba helyezett munkaelemek kezelésére, és a futtatókörnyezet a ThreadPool-szálak számának növelésével válaszol. A dotnet.thread_pool.thread.count érték gyorsan emelkedik a processzormagok számának 2-3-szorosára a gépen, majd további szálak másodpercenként 1-2-vel növekednek, amíg a stabilizálás valahol 125 fölött nem áll be. A Fő jelek, hogy ThreadPool éhezés jelenleg a teljesítmény szűk keresztmetszete a lassú és állandó növekedése ThreadPool szálak és CPU-használat sokkal kevesebb, mint 100%. A szálszám növekedése mindaddig folytatódik, amíg a készlet nem éri el a szálak maximális számát, elegendő szál lett létrehozva az összes bejövő munkaelem kielégítéséhez, vagy a processzor telített. Gyakran, de nem mindig, a ThreadPool éhezése nagy értékeket dotnet.thread_pool.queue.length, és alacsony értékeket dotnet.thread_pool.work_item.count is megjelenít, ami azt jelenti, hogy nagy mennyiségű munka van függőben, és kevés munka készül el. Íme egy példa a számlálókra, miközben a szálak száma még mindig emelkedik:

[System.Runtime]
    dotnet.assembly.count ({assembly})                               115
    dotnet.gc.collections ({collection})
        gc.heap.generation
        ------------------
        gen0                                                           5
        gen1                                                           1
        gen2                                                           1
    dotnet.gc.heap.total_allocated (By)                       1.6947e+08
    dotnet.gc.last_collection.heap.fragmentation.size (By)
        gc.heap.generation
        ------------------
        gen0                                                           0
        gen1                                                     348,248
        gen2                                                           0
        loh                                                           32
        poh                                                            0
    dotnet.gc.last_collection.heap.size (By)
        gc.heap.generation
        ------------------
        gen0                                                           0
        gen1                                                  18,010,920
        gen2                                                   5,065,600
        loh                                                       98,384
        poh                                                    3,407,048
    dotnet.gc.last_collection.memory.committed_size (By)      66,842,624
    dotnet.gc.pause.time (s)                                           0.05
    dotnet.jit.compilation.time (s)                                    1.317
    dotnet.jit.compiled_il.size (By)                             574,886
    dotnet.jit.compiled_methods ({method})                         6,008
    dotnet.monitor.lock_contentions ({contention})                   194
    dotnet.process.cpu.count ({cpu})                                  16
    dotnet.process.cpu.time (s)
        cpu.mode
        --------
        system                                                         4.953
        user                                                           6.266
    dotnet.process.memory.working_set (By)                             1.3217e+08
    dotnet.thread_pool.queue.length ({work_item})                      0
    dotnet.thread_pool.thread.count ({thread})                       133
    dotnet.thread_pool.work_item.count ({work_item})              71,188
    dotnet.timer.count ({timer})                                     124

Ha a ThreadPool szálak száma stabilizálódik, a készlet már nem éhezik. Ha azonban magas értéken stabilizálódik (a processzormagok számának több mint háromszorosa), az általában azt jelzi, hogy az alkalmazáskód blokkolja a ThreadPool-szálak egy részét, és a ThreadPool kompenzálja a több szál futtatásával. A magas szálszámmal való állandó futás nem feltétlenül befolyásolja jelentős mértékben a kérések késleltetését, de ha a terhelés idővel drámaian változik, vagy az alkalmazást időszakosan újraindítják, akkor minden alkalommal, amikor a ThreadPool valószínűleg egy éhezési időszakba kerül, ahol lassan növeli a szálak számát, és rossz kérések késleltetését eredményezi. Minden szál memóriát is használ, így a szükséges szálak számának csökkentése további előnyt jelent.

A .NET 6-tól kezdődően a ThreadPool heurisztika úgy lett módosítva, hogy a ThreadPool-szálak száma sokkal gyorsabban felskálázható legyen bizonyos blokkoló tevékenység API-kra reagálva. A ThreadPool éhezése továbbra is előfordulhat ezekkel az API-kkal, de az időtartam sokkal rövidebb, mint a régebbi .NET-verziók esetében, mert a futtatókörnyezet gyorsabban válaszol. Futtassa újra a Bombardier programot a következő végponttal: api/diagscenario/taskwait.

bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s

A .NET 6-on megfigyelheti, hogy a szálkészlet gyorsabban növeli a szálak számát, mint korábban, majd nagy számú szálnál stabilizálódik. A ThreadPool éhezik, miközben a szálak száma emelkedik.

ThreadPool éhezés feloldása

A ThreadPool-éhezés megszüntetéséhez a ThreadPool-szálaknak blokkolatlannak kell maradniuk, hogy elérhetők legyenek a bejövő munkaelemek kezeléséhez. Többféleképpen is meghatározható, hogy az egyes szálak mit csináltak. Ha a probléma csak alkalmanként fordul elő, akkor a dotnet-trace használatával történő nyomkövetés a legjobb az alkalmazás viselkedésének rögzítése egy adott időszakban. Ha a probléma folyamatosan jelentkezik, használhatja a dotnet-stack eszközt, vagy rögzíthet egy, a Visual Studióban megtekinthető dotnet-dump memóriaképet. A dotnet-stack gyorsabb lehet, mert azonnal megjeleníti a szálveremeket a konzolon. A Visual Studio memóriakép-hibakeresése azonban jobb vizualizációkat kínál, amelyek kereteket képeznek le a forrásra, a Just My Code képes kiszűrni a futásidejű megvalósítási kereteket, a Párhuzamos verem funkció pedig nagy számú, hasonló vermet tartalmazó szál csoportosításában segíthet. Ez az oktatóanyag a dotnet-stack és a dotnet-trace beállításait mutatja be. A szálvermek Visual Studióval történő vizsgálatára példaként tekintse meg a ThreadPool éhezés diagnosztizálására vonatkozó oktatóanyag videóját.

A dotnet-stack folyamatos problémáinak diagnosztizálása

Futtassa újra a Bombardiert a webkiszolgáló terhelés alá helyezéséhez:

bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s

Ezután futtassa a dotnet-stack parancsot a szálverem lenyomatok megtekintéséhez.

dotnet-stack report -n DiagnosticScenarios

Nagy számú vermet tartalmazó hosszú kimenetnek kell megjelennie, amelyek közül sok a következőképpen néz ki:

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()

A verem alján lévő keretek azt jelzik, hogy ezek a szálak ThreadPool-szálak:

  System.Private.CoreLib.il!System.Threading.ThreadPoolWorkQueue.Dispatch()
  System.Private.CoreLib.il!System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()

A felső képkockák pedig azt mutatják, hogy a szál le van tiltva a GetResultCore(bool) DiagnosticScenarioController.TaskWait() függvény hívásánál:

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()

Időszakos probléma diagnosztizálása dotnet-trace használatával

A dotnet-stack megközelítés csak a minden kérésben előforduló nyilvánvaló, konzisztens blokkolási műveletek esetében hatékony. Bizonyos esetekben a blokkolás szórványosan csak néhány percenként történik, így a dotnet-stack kevésbé hasznos a probléma diagnosztizálása szempontjából. Ebben az esetben a dotnet-trace használatával összegyűjtheti az eseményeket egy adott időszakban, és mentheti őket egy később elemezhető nettrace-fájlba.

Van egy konkrét esemény, amely segít diagnosztizálni a szálkészlet éhezését: a WaitHandleWait esemény, amelyet a .NET 9-ben vezettek be. Ez akkor kerül kibocsátásra, amikor egy szálat olyan műveletek blokkolnak, mint a szinkron-aszinkron hívások (például Task.Result, Task.Wait és Task.GetAwaiter().GetResult()), vagy más zárolási műveletek, például lock, Monitor.Enter, ManualResetEventSlim.Wait és SemaphoreSlim.Wait.

Futtassa újra a Bombardiert a webkiszolgáló terhelés alá helyezéséhez:

bombardier-windows-amd64.exe https://localhost:5001/api/diagscenario/taskwait -d 120s

Ezután futtassa a dotnet-trace parancsot a várakozási események gyűjtéséhez:

dotnet trace collect -n DiagnosticScenarios --clrevents waithandle --clreventlevel verbose --duration 00:00:30

Ennek létre kell hoznia egy, az eseményeket tartalmazó fájlt DiagnosticScenarios.exe_yyyyddMM_hhmmss.nettrace . Ez a nettrace két különböző eszközzel elemezhető:

Az alábbi szakaszok bemutatják, hogyan használható az egyes eszközök a nettrace-fájl olvasására.

Nettrace elemzése a Perfview használatával

  1. Töltse le a PerfView-t , és futtassa.

  2. A nettrace fájl megnyitásához kattintson rá duplán.

    Képernyőkép egy nettrace megnyitásáról a PerfView-ban

  3. Kattintson duplán az Advanced Group>Any Stacks. Megnyílik egy új ablak.

    Képernyőkép a PerfView bármely veremnézetéről.

  4. Kattintson duplán az "Event Microsoft-Windows-DotNETRuntime/WaitHandleWait/Start" sorra.

    Most látnia kell a verem nyomkövetéseit, ahol a WaitHandleWait események ki lettek bocsátva. Ezeket a "WaitSource" osztja fel. Jelenleg két forrás létezik: MonitorWait a Monitor.Wait szolgáltatáson keresztül kibocsátott eseményekhez és Unknown az összes többihez.

    Képernyőkép a PerfView-ban a várakozási események halomnézetéről.

  5. Kezdje a MonitorWaittal, mivel ez az események 64,8%-át képviseli% tekintetében. A jelölőnégyzetek bejelölésével megjelenítheti az esemény kibocsátásáért felelős veremnyomokat.

    Képernyőkép a PerfView-ban a várakozási események kibontott halomnézetéről.

    Ez a verem-követés így olvasható: Task<T>.Result egy WaitHandleWait eseményt bocsátott ki a WaitSource MonitorWait segítségével, ahol Task<T>.Result a Monitor.Wait használatával hajtja végre a várakozást. Meghívta DiagScenarioController.TaskWait, amit egy lambda hívott meg, amelyet valamilyen ASP.NET kód hívott meg.

Nettrace elemzése a .NET-események megjelenítőjével

  1. Lépjen a verdie-g.github.io/dotnet-events-viewer.

  2. Húzza és ejtse a nettrace-fájlt.

    Képernyőkép egy nettrace megnyitásáról a .NET-események megjelenítőjében.

  3. Lépjen az Eseményfa lapra, válassza a "WaitHandleWaitStart" eseményt, majd válassza a Lekérdezés futtatása lehetőséget.

    Képernyőkép egy esemény lekérdezéséről a .NET Eseménynaplóban.

  4. Látnia kell azokat a verem-nyomkövetéseket, ahol a WaitHandleWait események ki lettek bocsátva. Kattintson a nyilakra az esemény kibocsátásáért felelős veremnyomok kibontásához.

    Képernyőkép a fa nézetről a .NET-események megjelenítőjében.

    Ez a verem-nyomkövetés a következőképpen olvasható: ManualResetEventSlim.Wait egy WaitHandleWait eseményt bocsát ki. Meghívta Task.SpinThenBlockWait, amelyet meghívott Task.InternalWaitCore, amelyet meghívott Task<T>.Result, amelyet meghívott DiagScenario.TaskWait, amelyet valamilyen lambda hívott meg, amelyet valamilyen ASP.NET kód hívott meg.

Valós forgatókönyvekben sok várakozási eseményt találhat a szálkészleten kívüli szálakból. Itt egy szálkészlet éhezésének vizsgálatával foglalkozik, így a szálkészleten kívüli dedikált szálra való várakozás nem releváns. Az első módszerek megvizsgálásával megállapítható, hogy a veremkövetés egy szálpool szálából származik-e, amelynek tartalmaznia kell a szálpool említését (például WorkerThread.WorkerThreadStart vagy ThreadPoolWorkQueue).

A szálkészlet szálverem-nyomkövetésének felső része.

Kódjavítás

Most a mintaalkalmazás Vezérlők/DiagnosticScenarios.cs fájljában navigálhat a vezérlő kódjához, és láthatja, hogy az aszinkron API-t hív meg anélkül, hogy használna await. Ez a sync-over-async kódminta, amely ismerten blokkolja a szálakat, és a ThreadPool éhezésének leggyakoribb oka.

public ActionResult<string> TaskWait()
{
    // ...
    Customer c = PretendQueryCustomerFromDbAsync("Dana").Result;
    return "success:taskwait";
}

Ebben az esetben a kód egyszerűen módosítható az aszinkron/várakozási kód használatára a TaskAsyncWait() végponton látható módon. A várakozás használata lehetővé teszi, hogy az aktuális szál más munkaelemeket is kiszolgáljon, amíg az adatbázis-lekérdezés folyamatban van. Ha az adatbázis-keresés befejeződött, egy ThreadPool-szál folytatja a végrehajtást. Így az egyes kérések során egyetlen szál sem lesz blokkolva a kódban.

public async Task<ActionResult<string>> TaskAsyncWait()
{
    // ...
    Customer c = await PretendQueryCustomerFromDbAsync("Dana");
    return "success:taskasyncwait";
}

Ha a Bombadier a végpontnak api/diagscenario/taskasyncwait küld betöltést, az azt mutatja, hogy a ThreadPool-szál száma sokkal alacsonyabb marad, és az átlagos késés közel 500 ms marad az aszinkron/várakozási megközelítés használatakor:

>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