Busy system, blocked threads, wait chains and deadlock: pattern cooperation

In one kernel memory dump we can see the signs of a busy system where all processors are executing non-idle threads:

0: kd> !running

System Processors ff (affinity mask)
  Idle Processors 0

     Prcb      Current   Next   
  0  ffdff120  8b223928            ................
  1  f772f120  8a765380            ................
  2  f7737120  89365db0            ................
  3  f773f120  8833adb0            ................
  4  f7747120  889bbdb0            ................
  5  f774f120  8c085db0            ................
  6  f7757120  8aa79698            ................
  7  f775f120  896c0668            ................

When inspecting them we see that some are kernel worker threads without a process context, for example:

0: kd> !thread 8aa79698 1f
THREAD 8aa79698  Cid 0004.6edc  Teb: 00000000 Win32Thread: 00000000 RUNNING on processor 6
Not impersonating
DeviceMap                 d66008d0
Owning Process            8d15d648       Image:         System
Wait Start TickCount      2548878        Ticks: 3 (0:00:00:00.046)
Context Switch Count      248713            
UserTime                  00:00:00.000
KernelTime                00:00:00.906

Start Address nt!ExpWorkerThread (0×80881860)
Stack Init acfbc000 Current acfbbcec Base acfbc000 Limit acfb9000 Call 0
Priority 13 BasePriority 13 PriorityDecrement 0
ChildEBP RetAddr
WARNING: Stack unwind information not available. Following frames may be wrong.
acfbbaec b19483f3 driver+0×3f65
acfbbb6c 8081e095 driver+0×23f3
acfbbb80 af36044a nt!IofCallDriver+0×45
[…]
acfbbdac 8094bea4 nt!ExpWorkerThread+0xeb
acfbbddc 8088f57e nt!PspSystemThreadStartup+0×2e
00000000 00000000 nt!KiThreadStartup+0×16

some threads with an associated process context are running in kernel space:

0: kd> !thread 889bbdb0 1f
THREAD 889bbdb0  Cid 6c58.6f98  Teb: 00000000 Win32Thread: 00000000 RUNNING on processor 4
Not impersonating
DeviceMap                 d66008d0
Owning Process            89ad8b18       Image:         csrss.exe
Wait Start TickCount      2548880        Ticks: 1 (0:00:00:00.015)
Context Switch Count      129536            
UserTime                  00:00:00.000
KernelTime                00:00:00.312

Start Address displaydriver!Thread (0xbfad4a60)
Stack Init a439d000 Current a439cc70 Base a439d000 Limit a439a000 Call 0
Priority 13 BasePriority 10 PriorityDecrement 3
ChildEBP RetAddr
a439c004 bfad707f displaydriver!CalcRegion+0×30
[…]
a439cddc 8088f57e nt!PspSystemThreadStartup+0×2e
00000000 00000000 nt!KiThreadStartup+0×16

and some threads with an associated process context are running in user space:

0: kd> !thread 8c085db0 1f
THREAD 8c085db0  Cid 2318.231c  Teb: 7ffdd000 Win32Thread: b4b5ebe8 RUNNING on processor 5
Not impersonating
DeviceMap                 dc1a71f0
Owning Process            8b02e458       Image:         Application.EXE
Wait Start TickCount      2548881        Ticks: 0
Context Switch Count      725122                 LargeStack
UserTime                  00:00:01.625
KernelTime                00:00:03.062

Win32 Start Address 0×30001084
Start Address 0×7c8217f8
Stack Init ad648000 Current ad647c50 Base ad648000 Limit ad642000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr
0013fb7c 00000000 0×7c81b910

Because none of them consumed much CPU the patter of Spiking Thread is ruled out and CPU load can be explained by the number of active user sessions and this appears to be normal:

0: kd> !session
Sessions on machine: 50

However looking at ERESOURCE locks we see many blocked threads and signs of possible wait chains:

0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****

Resource @ 0x8cbfaa68    Exclusively owned
    Contention Count = 22969
    NumberOfSharedWaiters = 1
    NumberOfExclusiveWaiters = 109
     Threads: 8a961db0-01<*> 8bf532b0-01   
     Threads Waiting On Exclusive Access:
              8b4532f0       884fc648       88c58a00       8a751360      
              88ed64f8       89aa6738       89870db0       881dedb0      
              8a6d7b40       8b4a4db0       89818ad0       8afcedb0      
              8a2ca020       88684db0       8b411020       89d595c0      
              8d1573f0       88d06020       8aed8b38       8a8c9020      
              8a5a0a50       8a1f63b0       89b66688       89bf1db0      
              880dab18       882e6730       895d8020       88e6d3f0      
              896e6748       89802100       8a604508       8907c5e8      
              8890a020       885e2300       8a061bd8       88445340      
              88113db0       8a680db0       89b53370       88c3f2a0      
              88a774f8       8834ddb0       89d78888       88386020      
              897ca8d8       8b3532d0       882341d0       8a4a9b80      
              87e7c4f8       895e5db0       8846f4e8       89df3db0      
              889b8b40       89d82db0       89e4b720       8aadadb0      
              8aa63020       88852020       8a249ba8       891b8c20      
              8b3f95f0       8aace760       8b470020       897ad388      
              8c07dba8       8a331628       896c74d0       8997cb40      
              88e133c8       886eddb0       8864e518       89ab5698      
              88d8bdb0       89996db0       8ac54d28       87f42020      
              882b1020       8857fdb0       895f3db0       88b0ab40      
              8a1aadb0       8b819020       8b3bf388       88315660      
              8a45db18       883fbdb0       88f53db0       87f209a0      
              8978ddb0       8840c868       8823c1c8       88277db0      
              89c0a8c8       88322940       8a475db0       8a6ad460      
              8a35a4c8       88e3da40       886b1b40       8886a2a0      
              8897d750       8b30bdb0       8a123020       8b0ad7f8      
              8a256930       885cedb0       88ec8db0       887d7ba8      
              88175b90      

Resource @ 0x8b8f09a8    Shared 1 owning threads
    Contention Count = 123597
    NumberOfSharedWaiters = 1
    NumberOfExclusiveWaiters = 6
     Threads: 88200840-01    8a92ddb0-01<*>
     Threads Waiting On Exclusive Access:
              8a317db0       8d151840       899acdb0       8a961db0
              891ac940       89ee5db0      

Resource @ 0x8ac79f08    Exclusively owned
    Contention Count = 717691
    NumberOfExclusiveWaiters = 12
     Threads: 8a5193f0-01<*>
     Threads Waiting On Exclusive Access:
              880e7b40       8a60adb0       8a543108       8a4be020      
              8a77c360       8a470730       87f12db0       8a4618d0      
              895c5600       8a942b98       8a453b40       8a3bf020      

Resource @ 0x8a73ed28    Exclusively owned
    Contention Count = 4
    NumberOfExclusiveWaiters = 2
     Threads: 8a45db18-01<*>
     Threads Waiting On Exclusive Access:
              8a412db0       8a542268      

Resource @ 0x8a621bf8    Exclusively owned
    Contention Count = 8532
    NumberOfExclusiveWaiters = 3
     Threads: 8a412db0-01<*>
     Threads Waiting On Exclusive Access:
              8a5193f0       8a60cdb0       8a595c78      

Resource @ 0x8a4c8b20    Exclusively owned
    Contention Count = 1
    NumberOfExclusiveWaiters = 1
     Threads: 8a92ddb0-01<*>
     Threads Waiting On Exclusive Access:
              89524a70      

Resource @ 0x8a43b0e8    Exclusively owned
    Contention Count = 1135854
    NumberOfSharedWaiters = 1
    NumberOfExclusiveWaiters = 9
     Threads: 8aaa3020-01<*> 88efb400-01   
     Threads Waiting On Exclusive Access:
              89f883b0       8a273a70       89f82c10       89fd9020      
              89ec0db0       89571290       89edcdb0       88930400      
              8845f4c8      

Resource @ 0x89f7dbe8    Exclusively owned
    Contention Count = 2
    NumberOfExclusiveWaiters = 2
     Threads: 891b8c20-01<*>
     Threads Waiting On Exclusive Access:
              89ecedb0       89fc3020      

Resource @ 0x89f82f28    Exclusively owned
    Contention Count = 26674
    NumberOfExclusiveWaiters = 2
     Threads: 89fc3020-01<*>
     Threads Waiting On Exclusive Access:
              8aaa3020       8a02db40      

Resource @ 0x89315320    Exclusively owned
    Contention Count = 509247
    NumberOfSharedWaiters = 1
    NumberOfExclusiveWaiters = 19
     Threads: 89261428-01<*> 89313a08-01   
     Threads Waiting On Exclusive Access:
              89cc7db0       8ad26528       8970db68       88ef64d0      
              8a629020       89450798       8825c9a8       89206378      
              8a7c7b90       89162890       8ae7c020       883318e0      
              88bd6358       89367db0       8952aaa0       8a817b40      
              881d65b8       8ab74db0       889202c0      

Resource @ 0x893872d8    Exclusively owned
    Contention Count = 5079
    NumberOfExclusiveWaiters = 3
     Threads: 896e6748-01<*>
     Threads Waiting On Exclusive Access:
              89261428       893bc3c8       892a88a8      

Resource @ 0x8924adf8    Exclusively owned
    Contention Count = 1
    NumberOfExclusiveWaiters = 1
     Threads: 88ed64f8-01<*>
     Threads Waiting On Exclusive Access:
              89146660      

Resource @ 0x890281b0    Exclusively owned
    Contention Count = 4
    NumberOfExclusiveWaiters = 4
     Threads: 88d06020-01<*>
     Threads Waiting On Exclusive Access:
              88b5c528       88c5aa98       87ef77b8       88c48b40      

Resource @ 0x88d40440    Exclusively owned
    Contention Count = 13
    NumberOfExclusiveWaiters = 1
     Threads: 899acdb0-01<*>
     Threads Waiting On Exclusive Access:
              895e6db0      

Resource @ 0x88ed0c20    Exclusively owned
    Contention Count = 2
    NumberOfExclusiveWaiters = 2
     Threads: 895e6db0-01<*>
     Threads Waiting On Exclusive Access:
              88ad7540       88b5f620      

Resource @ 0x894e7990    Exclusively owned
    Contention Count = 3852647
    NumberOfExclusiveWaiters = 12
     Threads: 881b14b8-01<*>
     Threads Waiting On Exclusive Access:
              88a13db0       87f12020       8aad7a20       8820a020      
              8824bdb0       88213db0       88eefdb0       88ab7550      
              889fe808       89df17a0       8aa83430       8a8f73c8      

Resource @ 0x88559288    Exclusively owned
    Contention Count = 7422
    NumberOfExclusiveWaiters = 3
     Threads: 880dab18-01<*>
     Threads Waiting On Exclusive Access:
              881b14b8       88311020       882ab660      

Resource @ 0x8aff12b0    Exclusively owned
    Contention Count = 6
    NumberOfExclusiveWaiters = 1
     Threads: 89524a70-01<*>
     Threads Waiting On Exclusive Access:
              8a92ddb0      

62174 total locks, 75 locks currently held

Starting with the thread 8a961db0 that blocks 109 other threads we can unravel the following deadlock:

109 threads -> 8a961db0 -> 8a92ddb0 -> 89524a70 -> 8a92ddb0 -> 89524a70 -> …

Looking at threads involved in the deadlock we see that they belong to the same process and deadlocked in kernel space when running through driverA.sys code:

0: kd> !thread 89524a70 1f
THREAD 89524a70  Cid 1fdc.26cc  Teb: 7ffdd000 Win32Thread: b4d0fea8 WAIT: (Unknown) KernelMode Non-Alertable
    89170648  SynchronizationEvent
    89524ae8  NotificationTimer
IRP List:
    88e7a008: (0006,0268) Flags: 00000000  Mdl: 00000000
    8a7cc228: (0006,0268) Flags: 00000000  Mdl: 00000000
    89e67b90: (0006,0268) Flags: 00000000  Mdl: 00000000 Not impersonating
DeviceMap                 e2e671d0
Owning Process            88c37020       Image:         ApplicationA.exe
Wait Start TickCount      2548760        Ticks: 121 (0:00:00:01.890)
Context Switch Count      4850                 LargeStack
UserTime                  00:00:00.734
KernelTime                00:00:01.718
Win32 Start Address 0×00404054
Start Address 0×7c8217f8
Stack Init 91971000 Current 91970278 Base 91971000 Limit 9196a000 Call 0
Priority 14 BasePriority 10 PriorityDecrement 4
ChildEBP RetAddr
91970290 80833ec5 nt!KiSwapContext+0×26
919702bc 80829bc0 nt!KiSwapThread+0×2e5
91970304 8087e0db nt!KeWaitForSingleObject+0×346
91970340 8087e2f5 nt!ExpWaitForResource+0xd5
91970360 b0a1cf6d nt!ExAcquireResourceExclusiveLite+0×8d
91970374 b0a08cef driverA+0×2ef6d
919703cc b0a089cc driverA+0×1acef
919703f4 b0a209d9 driverA+0×1a9cc
9197056c b0a20386 driverA+0×329d9
91970630 b0a1dc32 driverA+0×32386
919706e8 b0a20508 driverA+0×2fc32
919707ac b0a1eec1 driverA+0×32508
919708a0 b0a21e90 driverA+0×30ec1
91970930 b0a171c9 driverA+0×33e90
919709c4 b0a16c9d driverA+0×291c9
91970a38 b0a600b3 driverA+0×28c9d
91970a84 b0a45dda driverA+0×720b3
91970afc b0a4657a driverA+0×57dda
91970b48 8081e095 driverA+0×5857a

91970b5c f7876d28 nt!IofCallDriver+0×45
91970b88 8081e095 fltmgr!FltpDispatch+0×152
91970b9c f74fc6ca nt!IofCallDriver+0×45
91970bb4 f7876d28 driverB+0×56ca
91970be0 8081e095 fltmgr!FltpDispatch+0×152
91970bf4 b195a4e1 nt!IofCallDriver+0×45
91970c18 b195a5d0 driverC!PassThrough+0xd1
91970c28 8081e095 driverC!Dispatch+0×80
91970c3c f7876d28 nt!IofCallDriver+0×45
91970c68 8081e095 fltmgr!FltpDispatch+0×152
91970c7c 808f7601 nt!IofCallDriver+0×45
91970c90 808f5339 nt!IopSynchronousServiceTail+0×10b
91970d38 8088ac9c nt!NtWriteFile+0×663
91970d38 7c9485ec nt!KiFastCallEntry+0xfc

0: kd> !thread 8a92ddb0 1f
THREAD 8a92ddb0  Cid 1fdc.7b98  Teb: 7ffa9000 Win32Thread: b4deeae8 WAIT: (Unknown) KernelMode Non-Alertable
    8b422388  SynchronizationEvent
    8a92de28  NotificationTimer
Not impersonating
DeviceMap                 e2e671d0
Owning Process            88c37020       Image:         ApplicationA.exe
Wait Start TickCount      2548760        Ticks: 121 (0:00:00:01.890)
Context Switch Count      956                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.015
Win32 Start Address 0×01381fa0
Start Address 0×7c8217ec
Stack Init 917c1000 Current 917c034c Base 917c1000 Limit 917bd000 Call 0
Priority 14 BasePriority 10 PriorityDecrement 4
ChildEBP RetAddr
917c0364 80833ec5 nt!KiSwapContext+0×26
917c0390 80829bc0 nt!KiSwapThread+0×2e5
917c03d8 8087e0db nt!KeWaitForSingleObject+0×346
917c0414 8087e2f5 nt!ExpWaitForResource+0xd5
917c0434 b0a1cf6d nt!ExAcquireResourceExclusiveLite+0×8d
917c0448 b0a08cef driverA+0×2ef6d
917c04a0 b0a089cc driverA+0×1acef
917c04c8 b0a13787 driverA+0×1a9cc
917c053c b0a0bfaa driverA+0×25787
917c057c b0a0c3b3 driverA+0×1dfaa
917c0858 b0a0ccaf driverA+0×1e3b3
917c0934 b0a6074c driverA+0×1ecaf
917c097c b0a4f9d2 driverA+0×7274c
917c0a18 b0a501f6 driverA+0×619d2
917c0a40 b0a5020c driverA+0×621f6
917c0a4c b0a50442 driverA+0×6220c
917c0a6c b0a50687 driverA+0×62442
917c0ac4 b0a50cb0 driverA+0×62687
917c0b08 b0a50ddd driverA+0×62cb0
917c0b18 8081e095 driverA+0×62ddd

917c0b2c f7876d28 nt!IofCallDriver+0×45
917c0b58 8081e095 fltmgr!FltpDispatch+0×152
917c0b6c f74fc6ca nt!IofCallDriver+0×45
917c0b84 f7876d28 driverB+0×56ca
917c0bb0 8081e095 fltmgr!FltpDispatch+0×152
917c0bc4 b195a4e1 nt!IofCallDriver+0×45
917c0be8 b195a5d0 driverC!PassThrough+0xd1
917c0bf8 8081e095 driverC!Dispatch+0×80
917c0c0c f7876d28 nt!IofCallDriver+0×45
917c0c38 8081e095 fltmgr!FltpDispatch+0×152
917c0c4c 808f7601 nt!IofCallDriver+0×45
917c0c60 808f1b45 nt!IopSynchronousServiceTail+0×10b
917c0c84 afdfebd5 nt!NtQueryDirectoryFile+0×5d
917c0cf8 afdff95d driverD+0×8bd5
917c0d30 8088ac9c driverD+0×995d
917c0d30 7c9485ec nt!KiFastCallEntry+0xfc

Other wait chains seem to be subordinate to the main deadlock chain. 

- Dmitry Vostokov @ DumpAnalysis.org -

Leave a Reply

You must be logged in to post a comment.