Ladění vzájemného zablokování v .NET Core
Tento článek se týká sady ✔️ .NET Core 3.1 SDK a novějších verzí.
V tomto kurzu se dozvíte, jak ladit scénář vzájemného zablokování. Pomocí uvedeného příkladu ASP.NET Core úložišti zdrojového kódu webové aplikace můžete záměrně způsobit vzájemné zablokování. Koncový bod přestane reagovat a dojde k akumulace vláken. Dozvíte se, jak můžete k analýze problému použít různé nástroje, jako jsou výpisy paměti jádra, analýza výpisu paměti jádra a trasování procesů.
V tomto kurzu:
- Prozkoumání aplikace, která přestala reagovat
- Vygenerování základního souboru s výpisem paměti
- Analýza vláken procesu v souboru s výpisem
- Analýza volání a bloků synchronizace
- Diagnostika a řešení vzájemného zablokování
Požadavky
Kurz používá:
- .NET Core 3.1 SDK nebo novější verze
- Ukázkový cíl ladění – webová aplikace pro aktivaci scénáře
- dotnet-trace to list procesů
- dotnet-dump pro shromáždění a analýzu souboru s výpisem paměti
Generování výpisu paměti jádra
Pokud chcete prozkoumat nereagování aplikace, můžete pomocí výpisu paměti nebo základního výpisu paměti zkontrolovat stav jejích vláken a případné zámky, u kterých může docházet k problémům s kolizemi. Spusťte ukázkovou ladicí aplikaci pomocí následujícího příkazu z ukázkového kořenového adresáře:
dotnet run
K vyhledání ID procesu použijte následující příkaz:
dotnet-trace ps
Poznamenejte si ID procesu z výstupu příkazu. Naše ID procesu bylo 4807, ale vaše id se bude lišit. Přejděte na následující adresu URL, což je koncový bod rozhraní API na ukázkovém webu:
https://localhost:5001/api/diagscenario/deadlock
Požadavek rozhraní API na web přestane reagovat. Nechte požadavek běžet asi 10 až 15 sekund. Pak vytvořte výpis paměti jádra pomocí následujícího příkazu:
Analýza základního výpisu
Pokud chcete spustit analýzu výpisu paměti jádra, otevřete výpis paměti jádra pomocí následujícího dotnet-dump analyze příkazu. Argument je cesta k souboru s výpisem paměti jádra, který byl shromážděn dříve.
dotnet-dump analyze ~/.dotnet/tools/core_20190513_143916
Vzhledem k tomu, že se díváte na aplikaci, která může nereagovat, chcete mít celkový dojem na aktivitu vlákna v procesu. Můžete použít příkaz, threads jak je znázorněno níže:
> threads
*0 0x1DBFF (121855)
1 0x1DC01 (121857)
2 0x1DC02 (121858)
3 0x1DC03 (121859)
4 0x1DC04 (121860)
5 0x1DC05 (121861)
6 0x1DC06 (121862)
7 0x1DC07 (121863)
8 0x1DC08 (121864)
9 0x1DC09 (121865)
10 0x1DC0A (121866)
11 0x1DC0D (121869)
12 0x1DC0E (121870)
13 0x1DC10 (121872)
14 0x1DC11 (121873)
15 0x1DC12 (121874)
16 0x1DC13 (121875)
17 0x1DC14 (121876)
18 0x1DC15 (121877)
19 0x1DC1C (121884)
20 0x1DC1D (121885)
21 0x1DC1E (121886)
22 0x1DC21 (121889)
23 0x1DC22 (121890)
24 0x1DC23 (121891)
25 0x1DC24 (121892)
26 0x1DC25 (121893)
...
...
317 0x1DD48 (122184)
318 0x1DD49 (122185)
319 0x1DD4A (122186)
320 0x1DD4B (122187)
321 0x1DD4C (122188)
Výstup zobrazí všechna vlákna aktuálně spuštěná v procesu s přidruženým ID vlákna ladicího programu a ID vlákna operačního systému. Na základě výstupu existuje více než 300 vláken.
Dalším krokem je získat lepší přehled o tom, co vlákna aktuálně dělají, a to získáním fondu volání jednotlivých vláken. K clrstack výstupu volání lze použít příkaz . Výstupem může být jeden nebo všechny volání. K výstupu všech volání pro všechna vlákna v procesu použijte následující příkaz:
clrstack -all
Reprezentativní část výstupu vypadá takto:
...
...
...
Child SP IP Call Site
00007F2AE37B5680 00007f305abc6360 [GCFrame: 00007f2ae37b5680]
00007F2AE37B5770 00007f305abc6360 [GCFrame: 00007f2ae37b5770]
00007F2AE37B57D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae37b57d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE37B5920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE37B5950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE37B5CA0 00007f30593044af [GCFrame: 00007f2ae37b5ca0]
00007F2AE37B5D70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae37b5d70]
OS Thread Id: 0x1dc82
Child SP IP Call Site
00007F2AE2FB4680 00007f305abc6360 [GCFrame: 00007f2ae2fb4680]
00007F2AE2FB4770 00007f305abc6360 [GCFrame: 00007f2ae2fb4770]
00007F2AE2FB47D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae2fb47d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE2FB4920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE2FB4950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE2FB4CA0 00007f30593044af [GCFrame: 00007f2ae2fb4ca0]
00007F2AE2FB4D70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae2fb4d70]
OS Thread Id: 0x1dc83
Child SP IP Call Site
00007F2AE27B3680 00007f305abc6360 [GCFrame: 00007f2ae27b3680]
00007F2AE27B3770 00007f305abc6360 [GCFrame: 00007f2ae27b3770]
00007F2AE27B37D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae27b37d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE27B3920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE27B3950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE27B3CA0 00007f30593044af [GCFrame: 00007f2ae27b3ca0]
00007F2AE27B3D70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae27b3d70]
OS Thread Id: 0x1dc84
Child SP IP Call Site
00007F2AE1FB2680 00007f305abc6360 [GCFrame: 00007f2ae1fb2680]
00007F2AE1FB2770 00007f305abc6360 [GCFrame: 00007f2ae1fb2770]
00007F2AE1FB27D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae1fb27d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE1FB2920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE1FB2950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE1FB2CA0 00007f30593044af [GCFrame: 00007f2ae1fb2ca0]
00007F2AE1FB2D70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae1fb2d70]
OS Thread Id: 0x1dc85
Child SP IP Call Site
00007F2AE17B1680 00007f305abc6360 [GCFrame: 00007f2ae17b1680]
00007F2AE17B1770 00007f305abc6360 [GCFrame: 00007f2ae17b1770]
00007F2AE17B17D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae17b17d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE17B1920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE17B1950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE17B1CA0 00007f30593044af [GCFrame: 00007f2ae17b1ca0]
00007F2AE17B1D70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae17b1d70]
OS Thread Id: 0x1dc86
Child SP IP Call Site
00007F2AE0FB0680 00007f305abc6360 [GCFrame: 00007f2ae0fb0680]
00007F2AE0FB0770 00007f305abc6360 [GCFrame: 00007f2ae0fb0770]
00007F2AE0FB07D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae0fb07d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE0FB0920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE0FB0950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE0FB0CA0 00007f30593044af [GCFrame: 00007f2ae0fb0ca0]
00007F2AE0FB0D70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae0fb0d70]
OS Thread Id: 0x1dc87
Child SP IP Call Site
00007F2AE07AF680 00007f305abc6360 [GCFrame: 00007f2ae07af680]
00007F2AE07AF770 00007f305abc6360 [GCFrame: 00007f2ae07af770]
00007F2AE07AF7D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2ae07af7d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2AE07AF920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2AE07AF950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2AE07AFCA0 00007f30593044af [GCFrame: 00007f2ae07afca0]
00007F2AE07AFD70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2ae07afd70]
OS Thread Id: 0x1dc88
Child SP IP Call Site
00007F2ADFFAE680 00007f305abc6360 [GCFrame: 00007f2adffae680]
00007F2ADFFAE770 00007f305abc6360 [GCFrame: 00007f2adffae770]
00007F2ADFFAE7D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2adffae7d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2ADFFAE920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2ADFFAE950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2ADFFAECA0 00007f30593044af [GCFrame: 00007f2adffaeca0]
00007F2ADFFAED70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2adffaed70]
...
...
Sledování volání pro všechna více než 300 vláken ukazuje vzor, ve kterém většina vláken sdílí společný fond volání:
OS Thread Id: 0x1dc88
Child SP IP Call Site
00007F2ADFFAE680 00007f305abc6360 [GCFrame: 00007f2adffae680]
00007F2ADFFAE770 00007f305abc6360 [GCFrame: 00007f2adffae770]
00007F2ADFFAE7D0 00007f305abc6360 [HelperMethodFrame_1OBJ: 00007f2adffae7d0] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
00007F2ADFFAE920 00007F2FE392B31F testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_1() [/home/marioh/webapi/Controllers/diagscenario.cs @ 36]
00007F2ADFFAE950 00007F2FE392B46D System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/__w/3/s/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
00007F2ADFFAECA0 00007f30593044af [GCFrame: 00007f2adffaeca0]
00007F2ADFFAED70 00007f30593044af [DebuggerU2MCatchHandlerFrame: 00007f2adffaed70]
Zdá se, že calltack ukazuje, že požadavek přišel do naší metody vzájemného zablokování, která pak provádí volání do Monitor.ReliableEnter. Tato metoda označuje, že vlákna se pokouší zadat zámek monitoru. Čekají na dostupnost zámku. Pravděpodobně je uzamčen jiným vláknem.
Dalším krokem je zjistit, které vlákno ve skutečnosti drží zámek monitoru. Vzhledem k tomu, že monitory obvykle ukládají informace o zámku v tabulce bloků synchronizace, můžeme k získání dalších informací použít syncblk příkaz :
> syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner
43 00000246E51268B8 603 1 0000024B713F4E30 5634 28 00000249654b14c0 System.Object
44 00000246E5126908 3 1 0000024B713F47E0 51d4 29 00000249654b14d8 System.Object
-----------------------------
Total 344
CCW 1
RCW 2
ComClassFactory 0
Free 0
Dva zajímavé sloupce jsou MonitorHeld a Owning Thread Info. Sloupec MonitorHeld zobrazuje, zda je zámek monitoru získán vláknem a počet čekajících vláken. Sloupec Vlastnící informace o vlákně ukazuje, které vlákno aktuálně vlastní zámek monitoru. Informace o vlákně mají tři různé podsloupce. Druhý podsloupce zobrazuje ID vlákna operačního systému.
V tuto chvíli víme, že dvě různá vlákna (0x5634 a 0x51d4) drží zámek monitoru. Dalším krokem je podívat se, co tato vlákna dělají. Musíme zkontrolovat, jestli nejsou zablokované na neomezenou dobu. Pojďme pomocí setthread příkazů a clrstack přepnout na jednotlivá vlákna a zobrazit volání.
Pokud se chcete podívat na první vlákno, spusťte setthread příkaz a vyhledejte index vlákna 0x5634 (náš index byl 28). Funkce vzájemného zablokování čeká na získání zámku, ale zámek už vlastní. Je ve vzájemném zablokování a čeká na zámek, který už má.
> setthread 28
> clrstack
OS Thread Id: 0x5634 (28)
Child SP IP Call Site
0000004E46AFEAA8 00007fff43a5cbc4 [GCFrame: 0000004e46afeaa8]
0000004E46AFEC18 00007fff43a5cbc4 [GCFrame: 0000004e46afec18]
0000004E46AFEC68 00007fff43a5cbc4 [HelperMethodFrame_1OBJ: 0000004e46afec68] System.Threading.Monitor.Enter(System.Object)
0000004E46AFEDC0 00007FFE5EAF9C80 testwebapi.Controllers.DiagScenarioController.DeadlockFunc() [C:\Users\dapine\Downloads\Diagnostic_scenarios_sample_debug_target\Controllers\DiagnosticScenarios.cs @ 58]
0000004E46AFEE30 00007FFE5EAF9B8C testwebapi.Controllers.DiagScenarioController.<deadlock>b__3_0() [C:\Users\dapine\Downloads\Diagnostic_scenarios_sample_debug_target\Controllers\DiagnosticScenarios.cs @ 26]
0000004E46AFEE80 00007FFEBB251A5B System.Threading.ThreadHelper.ThreadStart_Context(System.Object) [/_/src/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 44]
0000004E46AFEEB0 00007FFE5EAEEEEC System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 201]
0000004E46AFEF20 00007FFEBB234EAB System.Threading.ThreadHelper.ThreadStart() [/_/src/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 93]
0000004E46AFF138 00007ffebdcc6b63 [GCFrame: 0000004e46aff138]
0000004E46AFF3A0 00007ffebdcc6b63 [DebuggerU2MCatchHandlerFrame: 0000004e46aff3a0]
Druhé vlákno je podobné. Pokouší se také získat zámek, který už vlastní. Zbývajících více než 300 vláken, která čekají, pravděpodobně také čeká na jeden ze zámků, které vzájemné zablokování způsobily.
Viz také
- dotnet-trace to list procesů
- dotnet-counters ke kontrole využití spravované paměti
- dotnet-dump pro shromáždění a analýzu souboru s výpisem paměti
- dotnet/diagnostics
Další kroky
Váš názor
Připravujeme: V průběhu roku 2024 budeme postupně vyřazovat problémy z GitHub coby mechanismus zpětné vazby pro obsah a nahrazovat ho novým systémem zpětné vazby. Další informace naleznete v tématu: https://aka.ms/ContentUserFeedback.
Odeslat a zobrazit názory pro